Thread: syslog output from explain looks weird...
Just playing with the syslog functionality on 7.1devel, and the explain output looks weird to me: Nov 22 14:58:44 lerami pg-test[4005]: [2] DEBUG: MoveOfflineLogs: skip 0000000000000006 Nov 22 14:58:44 lerami pg-test[4005]: [3] DEBUG: MoveOfflineLogs: skip 0000000000000005 Nov 22 14:59:09 lerami pg-test[4005]: [4] NOTICE: QUERY PLAN: Nov 22 14:59:0 lerami Nov 22 14:59:09Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165 width=28) seems like it should be better. The output at the client looks fine: ler=# explain select * from upslog where upslogdate >='2000-11-01'; NOTICE: QUERY PLAN: Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165 width=28) EXPLAIN ler=# -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
* Larry Rosenman <ler@lerctr.org> [001122 15:03]:
> Just playing with the syslog functionality on 7.1devel, and the
> explain output looks weird to me:
>
> Nov 22 14:58:44 lerami pg-test[4005]: [2] DEBUG: MoveOfflineLogs:
> skip 0000000000000006
> Nov 22 14:58:44 lerami pg-test[4005]: [3] DEBUG: MoveOfflineLogs:
> skip 0000000000000005
> Nov 22 14:59:09 lerami pg-test[4005]: [4] NOTICE: QUERY PLAN:
> Nov 22 14:59:0 lerami Nov 22 14:59:09Index Scan using upslog_index on
> upslog (cost=0.00..88.65 rows=165 width=28)
>
> seems like it should be better.
>
> The output at the client looks fine:
> ler=# explain select * from upslog where upslogdate >='2000-11-01';
> NOTICE: QUERY PLAN:
>
> Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165
> width=28)
>
> EXPLAIN
> ler=#
And here is a fix. What appears to piss off my syslogd is the no
character lines. So, I added spaces to the output. The new client
output looks like:
ler=# explain select * from upslog where upslogdate>='2000-11-01';
NOTICE: QUERY PLAN:Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165
width=28)
EXPLAIN
ler=# \q
$
and the syslog looks like:
Nov 22 15:22:56 lerami pg-test[8299]: [2] NOTICE: QUERY PLAN:
Nov 22 15:22:56 lerami
Nov 22 15:22:56 lerami Index Scan using upslog_index on upslog
(cost=0.00..88.65 rows=165 width=28)
And the patch is:
Index: src/backend/commands/explain.c
===================================================================
RCS file: /home/projects/pgsql/cvsroot/pgsql/src/backend/commands/explain.c,v
retrieving revision 1.62
diff -c -r1.62 explain.c
*** src/backend/commands/explain.c 2000/11/12 00:36:56 1.62
--- src/backend/commands/explain.c 2000/11/22 21:16:47
***************
*** 120,126 **** s = Explain_PlanToString(plan, es); if (s) {
! elog(NOTICE, "QUERY PLAN:\n\n%s", s); pfree(s); } }
--- 120,126 ---- s = Explain_PlanToString(plan, es); if (s) {
! elog(NOTICE, "QUERY PLAN:\n \n %s", s); pfree(s); } }
--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
* Larry Rosenman <ler@lerctr.org> [001122 15:25]:
> * Larry Rosenman <ler@lerctr.org> [001122 15:03]:
> > Just playing with the syslog functionality on 7.1devel, and the
> > explain output looks weird to me:
> >
> > Nov 22 14:58:44 lerami pg-test[4005]: [2] DEBUG: MoveOfflineLogs:
> > skip 0000000000000006
> > Nov 22 14:58:44 lerami pg-test[4005]: [3] DEBUG: MoveOfflineLogs:
> > skip 0000000000000005
> > Nov 22 14:59:09 lerami pg-test[4005]: [4] NOTICE: QUERY PLAN:
> > Nov 22 14:59:0 lerami Nov 22 14:59:09Index Scan using upslog_index on
> > upslog (cost=0.00..88.65 rows=165 width=28)
> >
> > seems like it should be better.
> >
> > The output at the client looks fine:
> > ler=# explain select * from upslog where upslogdate >='2000-11-01';
> > NOTICE: QUERY PLAN:
> >
> > Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165
> > width=28)
> >
> > EXPLAIN
> > ler=#
> And here is a fix. What appears to piss off my syslogd is the no
> character lines. So, I added spaces to the output. The new client
> output looks like:
> ler=# explain select * from upslog where upslogdate>='2000-11-01';
> NOTICE: QUERY PLAN:
>
> Index Scan using upslog_index on upslog (cost=0.00..88.65 rows=165
> width=28)
>
> EXPLAIN
> ler=# \q
> $
>
> and the syslog looks like:
> Nov 22 15:22:56 lerami pg-test[8299]: [2] NOTICE: QUERY PLAN:
> Nov 22 15:22:56 lerami
> Nov 22 15:22:56 lerami Index Scan using upslog_index on upslog
> (cost=0.00..88.65 rows=165 width=28)
>
Looking some more, I found some other places that need a space (I
suspect...), so here is an updated patch.
Index: src/backend/commands/explain.c
===================================================================
RCS file: /home/projects/pgsql/cvsroot/pgsql/src/backend/commands/explain.c,v
retrieving revision 1.62
diff -c -r1.62 explain.c
*** src/backend/commands/explain.c 2000/11/12 00:36:56 1.62
--- src/backend/commands/explain.c 2000/11/22 22:52:39
***************
*** 110,116 **** s = nodeToString(plan); if (s) {
! elog(NOTICE, "QUERY DUMP:\n\n%s", s); pfree(s); } }
--- 110,116 ---- s = nodeToString(plan); if (s) {
! elog(NOTICE, "QUERY DUMP:\n \n %s", s); pfree(s); } }
***************
*** 120,126 **** s = Explain_PlanToString(plan, es); if (s) {
! elog(NOTICE, "QUERY PLAN:\n\n%s", s); pfree(s); } }
--- 120,126 ---- s = Explain_PlanToString(plan, es); if (s) {
! elog(NOTICE, "QUERY PLAN:\n \n %s", s); pfree(s); } }
***************
*** 149,155 **** if (plan == NULL) {
! appendStringInfo(str, "\n"); return; }
--- 149,155 ---- if (plan == NULL) {
! appendStringInfo(str, "\n "); return; }
***************
*** 283,289 **** plan->startup_cost, plan->total_cost,
plan->plan_rows,plan->plan_width); }
! appendStringInfo(str, "\n"); /* initPlan-s */ if (plan->initPlan)
--- 283,289 ---- plan->startup_cost, plan->total_cost,
plan->plan_rows,plan->plan_width); }
! appendStringInfo(str, "\n "); /* initPlan-s */ if (plan->initPlan)
***************
*** 293,299 **** for (i = 0; i < indent; i++) appendStringInfo(str, " ");
! appendStringInfo(str, " InitPlan\n"); foreach(lst, plan->initPlan) { es->rtable
=((SubPlan *) lfirst(lst))->rtable;
--- 293,299 ---- for (i = 0; i < indent; i++) appendStringInfo(str, " ");
! appendStringInfo(str, " InitPlan\n "); foreach(lst, plan->initPlan) { es->rtable
=((SubPlan *) lfirst(lst))->rtable;
***************
*** 369,375 **** for (i = 0; i < indent; i++) appendStringInfo(str, " ");
! appendStringInfo(str, " SubPlan\n"); foreach(lst, plan->subPlan) { es->rtable =
((SubPlan*) lfirst(lst))->rtable;
--- 369,375 ---- for (i = 0; i < indent; i++) appendStringInfo(str, " ");
! appendStringInfo(str, " SubPlan\n "); foreach(lst, plan->subPlan) { es->rtable =
((SubPlan*) lfirst(lst))->rtable;
--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
Larry Rosenman <ler@lerctr.org> writes:
> Looking some more, I found some other places that need a space (I
> suspect...), so here is an updated patch.
This seems like the wrong way to go about it, because anytime anyone
changes any elog output anywhere, we'll risk another failure. If
syslog can't cope with empty lines, I think the right fix is for the
output-to-syslog routine to change the data just before sending ---
then there is only one place to fix. See the syslog output routine in
src/backend/utils/error/elog.c.
regards, tom lane
* Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]:
> Larry Rosenman <ler@lerctr.org> writes:
> > Looking some more, I found some other places that need a space (I
> > suspect...), so here is an updated patch.
>
> This seems like the wrong way to go about it, because anytime anyone
> changes any elog output anywhere, we'll risk another failure. If
> syslog can't cope with empty lines, I think the right fix is for the
> output-to-syslog routine to change the data just before sending ---
> then there is only one place to fix. See the syslog output routine in
> src/backend/utils/error/elog.c.
Makes sense. Here's a new patch, now the output even looks better:
Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN:
Nov 23 00:58:04 lerami pg-test[9914]: [2-2]
Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata
(cost=0.00..2766.62 rows=2308 width=48)
Nov 23 00:58:04 lerami pg-test[9914]: [2-4]
Index: src/backend/utils/error/elog.c
===================================================================
RCS file: /home/projects/pgsql/cvsroot/pgsql/src/backend/utils/error/elog.c,v
retrieving revision 1.67
diff -c -r1.67 elog.c
*** src/backend/utils/error/elog.c 2000/11/14 19:13:27 1.67
--- src/backend/utils/error/elog.c 2000/11/23 06:58:23
***************
*** 657,663 **** seq++; /* divide into multiple syslog() calls if message is too long */
! if (len > PG_SYSLOG_LIMIT) { static char buf[PG_SYSLOG_LIMIT+1]; int chunk_nr = 0;
--- 657,664 ---- seq++; /* divide into multiple syslog() calls if message is too long */
! /* or if the message contains embedded NewLine(s) '\n' */
! if (len > PG_SYSLOG_LIMIT || strchr(line,'\n') != NULL ) { static char buf[PG_SYSLOG_LIMIT+1];
int chunk_nr = 0;
***************
*** 667,675 ****
--- 668,684 ---- { int l; int i;
+ /* if we start at a newline, move ahead one char */
+ if (line[0] == '\n')
+ {
+ line++;
+ len--;
+ } strncpy(buf, line, PG_SYSLOG_LIMIT); buf[PG_SYSLOG_LIMIT] = '\0';
+ if (strchr(buf,'\n') != NULL)
+ *strchr(buf,'\n') = '\0'; l = strlen(buf); #ifdef MULTIBYTE
--
Larry Rosenman http://www.lerctr.org/~ler
Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
* Larry Rosenman <ler@lerctr.org> [001123 01:10]: > * Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]: > Makes sense. Here's a new patch, now the output even looks better: > Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN: > Nov 23 00:58:04 lerami pg-test[9914]: [2-2] > Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata > (cost=0.00..2766.62 rows=2308 width=48) > Nov 23 00:58:04 lerami pg-test[9914]: [2-4] > > [snip] Any comments from the committers crowd? (I can't commit it...) -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
Applied.
> * Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]:
> > Larry Rosenman <ler@lerctr.org> writes:
> > > Looking some more, I found some other places that need a space (I
> > > suspect...), so here is an updated patch.
> >
> > This seems like the wrong way to go about it, because anytime anyone
> > changes any elog output anywhere, we'll risk another failure. If
> > syslog can't cope with empty lines, I think the right fix is for the
> > output-to-syslog routine to change the data just before sending ---
> > then there is only one place to fix. See the syslog output routine in
> > src/backend/utils/error/elog.c.
> Makes sense. Here's a new patch, now the output even looks better:
> Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN:
> Nov 23 00:58:04 lerami pg-test[9914]: [2-2]
> Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata
> (cost=0.00..2766.62 rows=2308 width=48)
> Nov 23 00:58:04 lerami pg-test[9914]: [2-4]
>
>
> Index: src/backend/utils/error/elog.c
> ===================================================================
> RCS file: /home/projects/pgsql/cvsroot/pgsql/src/backend/utils/error/elog.c,v
> retrieving revision 1.67
> diff -c -r1.67 elog.c
> *** src/backend/utils/error/elog.c 2000/11/14 19:13:27 1.67
> --- src/backend/utils/error/elog.c 2000/11/23 06:58:23
> ***************
> *** 657,663 ****
> seq++;
>
> /* divide into multiple syslog() calls if message is too long */
> ! if (len > PG_SYSLOG_LIMIT)
> {
> static char buf[PG_SYSLOG_LIMIT+1];
> int chunk_nr = 0;
> --- 657,664 ----
> seq++;
>
> /* divide into multiple syslog() calls if message is too long */
> ! /* or if the message contains embedded NewLine(s) '\n' */
> ! if (len > PG_SYSLOG_LIMIT || strchr(line,'\n') != NULL )
> {
> static char buf[PG_SYSLOG_LIMIT+1];
> int chunk_nr = 0;
> ***************
> *** 667,675 ****
> --- 668,684 ----
> {
> int l;
> int i;
> + /* if we start at a newline, move ahead one char */
> + if (line[0] == '\n')
> + {
> + line++;
> + len--;
> + }
>
> strncpy(buf, line, PG_SYSLOG_LIMIT);
> buf[PG_SYSLOG_LIMIT] = '\0';
> + if (strchr(buf,'\n') != NULL)
> + *strchr(buf,'\n') = '\0';
>
> l = strlen(buf);
> #ifdef MULTIBYTE
> --
> Larry Rosenman http://www.lerctr.org/~ler
> Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org
> US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
>
-- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610)
853-3000+ If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup. | Drexel Hill,
Pennsylvania19026
Applied. :-) > * Larry Rosenman <ler@lerctr.org> [001123 01:10]: > > * Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]: > > Makes sense. Here's a new patch, now the output even looks better: > > Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN: > > Nov 23 00:58:04 lerami pg-test[9914]: [2-2] > > Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata > > (cost=0.00..2766.62 rows=2308 width=48) > > Nov 23 00:58:04 lerami pg-test[9914]: [2-4] > > > > > [snip] > Any comments from the committers crowd? (I can't commit it...) > > -- > Larry Rosenman http://www.lerctr.org/~ler > Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org > US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 > -- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610) 853-3000+ If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup. | Drexel Hill, Pennsylvania19026
Someone ought to backpatch to REL_7_0_PATCHES, as it's syslog also looks bad... LER * Bruce Momjian <pgman@candle.pha.pa.us> [001124 22:38]: > Applied. :-) > > > * Larry Rosenman <ler@lerctr.org> [001123 01:10]: > > > * Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]: > > > Makes sense. Here's a new patch, now the output even looks better: > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN: > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-2] > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata > > > (cost=0.00..2766.62 rows=2308 width=48) > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-4] > > > > > > > > [snip] > > Any comments from the committers crowd? (I can't commit it...) > > > > -- > > Larry Rosenman http://www.lerctr.org/~ler > > Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org > > US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 > > > > > -- > Bruce Momjian | http://candle.pha.pa.us > pgman@candle.pha.pa.us | (610) 853-3000 > + If your life is a hard drive, | 830 Blythe Avenue > + Christ can be your backup. | Drexel Hill, Pennsylvania 19026 -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 972-414-9812 E-Mail: ler@lerctr.org US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
> Someone ought to backpatch to REL_7_0_PATCHES, as it's syslog also > looks bad... Not sure if we will have a 7.0.4, and I can't see it as a major bug problem anyway. > > LER > > * Bruce Momjian <pgman@candle.pha.pa.us> [001124 22:38]: > > Applied. :-) > > > > > * Larry Rosenman <ler@lerctr.org> [001123 01:10]: > > > > * Tom Lane <tgl@sss.pgh.pa.us> [001122 22:44]: > > > > Makes sense. Here's a new patch, now the output even looks better: > > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-1] NOTICE: QUERY PLAN: > > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-2] > > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-3] Seq Scan on upsdata > > > > (cost=0.00..2766.62 rows=2308 width=48) > > > > Nov 23 00:58:04 lerami pg-test[9914]: [2-4] > > > > > > > > > > > [snip] > > > Any comments from the committers crowd? (I can't commit it...) > > > > > > -- > > > Larry Rosenman http://www.lerctr.org/~ler > > > Phone: +1 972-414-9812 (voice) Internet: ler@lerctr.org > > > US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 > > > > > > > > > -- > > Bruce Momjian | http://candle.pha.pa.us > > pgman@candle.pha.pa.us | (610) 853-3000 > > + If your life is a hard drive, | 830 Blythe Avenue > > + Christ can be your backup. | Drexel Hill, Pennsylvania 19026 > -- > Larry Rosenman http://www.lerctr.org/~ler > Phone: +1 972-414-9812 E-Mail: ler@lerctr.org > US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 > -- Bruce Momjian | http://candle.pha.pa.us pgman@candle.pha.pa.us | (610) 853-3000+ If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup. | Drexel Hill, Pennsylvania19026
> > Someone ought to backpatch to REL_7_0_PATCHES, as it's syslog also > > looks bad... > > Not sure if we will have a 7.0.4, and I can't see it as a major bug > problem anyway. Thinking about 7.0.3 has a new option to enable syslog, we might have more often complaints from users than before, no? I think it's worth to make back patches... -- Tatsuo Ishii
Hi, can anyone tell me when Postgresql 7.1 will be released? thanks, XuYifeng
On Sun, 26 Nov 2000, xuyifeng wrote: > Hi, > > can anyone tell me when Postgresql 7.1 will be released? about a month after it goes beta ... which should be over the next couple of weeks ...