Re: [HACKERS] syslog output from explain looks weird...
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
Re: [HACKERS] syslog output from explain looks weird...
Applied.
* Tom Lane [EMAIL PROTECTED] [001122 22:44]:
Larry Rosenman [EMAIL PROTECTED] 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.c2000/11/14 19:13:27 1.67
--- src/backend/utils/error/elog.c2000/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: [EMAIL PROTECTED]
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
--
Bruce Momjian| http://candle.pha.pa.us
[EMAIL PROTECTED] | (610) 853-3000
+ If your life is a hard drive, | 830 Blythe Avenue
+ Christ can be your backup.| Drexel Hill, Pennsylvania 19026
Re: [HACKERS] syslog output from explain looks weird...
Applied. :-) * Larry Rosenman [EMAIL PROTECTED] [001123 01:10]: * Tom Lane [EMAIL PROTECTED] [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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 -- Bruce Momjian| http://candle.pha.pa.us [EMAIL PROTECTED] | (610) 853-3000 + If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup.| Drexel Hill, Pennsylvania 19026
Re: [HACKERS] syslog output from explain looks weird...
Someone ought to backpatch to REL_7_0_PATCHES, as it's syslog also looks bad... LER * Bruce Momjian [EMAIL PROTECTED] [001124 22:38]: Applied. :-) * Larry Rosenman [EMAIL PROTECTED] [001123 01:10]: * Tom Lane [EMAIL PROTECTED] [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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 -- Bruce Momjian| http://candle.pha.pa.us [EMAIL PROTECTED] | (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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
Re: [HACKERS] syslog output from explain looks weird...
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 [EMAIL PROTECTED] [001124 22:38]: Applied. :-) * Larry Rosenman [EMAIL PROTECTED] [001123 01:10]: * Tom Lane [EMAIL PROTECTED] [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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 -- Bruce Momjian| http://candle.pha.pa.us [EMAIL PROTECTED] | (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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749 -- Bruce Momjian| http://candle.pha.pa.us [EMAIL PROTECTED] | (610) 853-3000 + If your life is a hard drive, | 830 Blythe Avenue + Christ can be your backup.| Drexel Hill, Pennsylvania 19026
Re: [HACKERS] syslog output from explain looks weird...
* Larry Rosenman [EMAIL PROTECTED] [001123 01:10]: * Tom Lane [EMAIL PROTECTED] [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: [EMAIL PROTECTED] US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
Re: [HACKERS] syslog output from explain looks weird...
* Larry Rosenman [EMAIL PROTECTED] [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 0006
Nov 22 14:58:44 lerami pg-test[4005]: [3] DEBUG: MoveOfflineLogs:
skip 0005
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: [EMAIL PROTECTED]
US Mail: 1905 Steamboat Springs Drive, Garland, TX 75044-6749
Re: [HACKERS] syslog output from explain looks weird...
* Larry Rosenman [EMAIL PROTECTED] [001122 15:25]:
* Larry Rosenman [EMAIL PROTECTED] [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 0006
Nov 22 14:58:44 lerami pg-test[4005]: [3] DEBUG: MoveOfflineLogs:
skip 0005
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
