Thread: debug_print_plan (pg7.4) doesn't seem to do anything

debug_print_plan (pg7.4) doesn't seem to do anything

From
Eric Brown
Date:
I have the following settings:
syslog = 2
client_min_messages = notice
log_min_messages = debug5 (tried debug1 too)
log_error_verbosity = default (tried verbose too, but still doesn't
print plan)
log_statement = true
log_duration = true
debug_print_plan = true
debug_print_parse = true

I thought setting debug_print_plan was supposed to explain every query
in my log file? I don't see the plan print either.

I'm running version 7.4.6 (from fink) on OS X 10.3.7.

Thanks.

Eric Brown
408-571-6341
www.propel.com

Re: debug_print_plan (pg7.4) doesn't seem to do anything

From
Tom Lane
Date:
Eric Brown <eric.brown@propel.com> writes:
> I thought setting debug_print_plan was supposed to explain every query
> in my log file? I don't see the plan print either.

No, it just prints the plan.  With settings like yours I get

DEBUG:  StartTransactionCommand
LOG:  statement: select 2+2;
DEBUG:  parse tree:
DETAIL:  {QUERY :commandType 1 :querySource 0 :canSetTag true :utilityStmt <>
    :resultRelation 0 :into <> :hasAggs false :hasSubLinks false :rtable <>
    :jointree {FROMEXPR :fromlist <> :quals <>} :rowMarks () :targetList
    ({TARGETENTRY :resdom {RESDOM :resno 1 :restype 23 :restypmod -1 :resname
    ?column? :ressortgroupref 0 :resorigtbl 0 :resorigcol 0 :resjunk false} :expr
    {OPEXPR :opno 551 :opfuncid 0 :opresulttype 23 :opretset false :args ({CONST
    :consttype 23 :constlen 4 :constbyval true :constisnull false :constvalue 4 [
    0 0 0 2 ]} {CONST :consttype 23 :constlen 4 :constbyval true :constisnull
    false :constvalue 4 [ 0 0 0 2 ]})}}) :groupClause <> :havingQual <>
    :distinctClause <> :sortClause <> :limitOffset <> :limitCount <>
    :setOperations <> :resultRelations ()}

DEBUG:  plan:
DETAIL:  {RESULT :startup_cost 0.00 :total_cost 0.01 :plan_rows 1 :plan_width 0
    :targetlist ({TARGETENTRY :resdom {RESDOM :resno 1 :restype 23 :restypmod -1
    :resname ?column? :ressortgroupref 0 :resorigtbl 0 :resorigcol 0 :resjunk
    false} :expr {CONST :consttype 23 :constlen 4 :constbyval true :constisnull
    false :constvalue 4 [ 0 0 0 4 ]}}) :qual <> :lefttree <> :righttree <>
    :initPlan <> :extParam () :allParam () :nParamExec 0 :resconstantqual <>}

DEBUG:  PortalRun
DEBUG:  CommitTransactionCommand
LOG:  duration: 7.439 ms

Maybe you forgot "pg_ctl reload" after changing your config?

            regards, tom lane

Re: debug_print_plan (pg7.4) doesn't seem to do anything

From
Eric Brown
Date:
On Dec 29, 2004, at 2:28 PM, Tom Lane wrote:
> Eric Brown <eric.brown@propel.com> writes:
>> I thought setting debug_print_plan was supposed to explain every query
>> in my log file? I don't see the plan print either.
>
> No, it just prints the plan.  With settings like yours I get
I don't get the the "DEBUG:  parse tree:" or the DETAIL lines at all. I
restarted via pg_ctl. I assume that that's the same as reload.
Actually, if I set client_min_messages to 'debug1' via the SET command
in psql, then I get the detail information in my client. But I want the
information in my syslog, not my client. (My client's driver will barf
if I try to send the information there.) I wonder if their is too much
information and syslog being UDP never gets the detail line? (But then
it appears that postgresql is specifically breaking most longer
messages up into multiple lines, so I doubt this is it either.)

Thanks.

>
> DEBUG:  StartTransactionCommand
> LOG:  statement: select 2+2;
> DEBUG:  parse tree:
> DETAIL:  {QUERY :commandType 1 :querySource 0 :canSetTag true
> :utilityStmt <>
>     :resultRelation 0 :into <> :hasAggs false :hasSubLinks false :rtable
> <>
>     :jointree {FROMEXPR :fromlist <> :quals <>} :rowMarks () :targetList
>     ({TARGETENTRY :resdom {RESDOM :resno 1 :restype 23 :restypmod -1
> :resname
>     ?column? :ressortgroupref 0 :resorigtbl 0 :resorigcol 0 :resjunk
> false} :expr
>     {OPEXPR :opno 551 :opfuncid 0 :opresulttype 23 :opretset false :args
> ({CONST
>     :consttype 23 :constlen 4 :constbyval true :constisnull false
> :constvalue 4 [
>     0 0 0 2 ]} {CONST :consttype 23 :constlen 4 :constbyval true
> :constisnull
>     false :constvalue 4 [ 0 0 0 2 ]})}}) :groupClause <> :havingQual <>
>     :distinctClause <> :sortClause <> :limitOffset <> :limitCount <>
>     :setOperations <> :resultRelations ()}
>
> DEBUG:  plan:
> DETAIL:  {RESULT :startup_cost 0.00 :total_cost 0.01 :plan_rows 1
> :plan_width 0
>     :targetlist ({TARGETENTRY :resdom {RESDOM :resno 1 :restype 23
> :restypmod -1
>     :resname ?column? :ressortgroupref 0 :resorigtbl 0 :resorigcol 0
> :resjunk
>     false} :expr {CONST :consttype 23 :constlen 4 :constbyval true
> :constisnull
>     false :constvalue 4 [ 0 0 0 4 ]}}) :qual <> :lefttree <> :righttree <>
>     :initPlan <> :extParam () :allParam () :nParamExec 0 :resconstantqual
> <>}
>
> DEBUG:  PortalRun
> DEBUG:  CommitTransactionCommand
> LOG:  duration: 7.439 ms
>
> Maybe you forgot "pg_ctl reload" after changing your config?
>
>             regards, tom lane

Re: debug_print_plan (pg7.4) doesn't seem to do anything

From
Tom Lane
Date:
Eric Brown <eric.brown@propel.com> writes:
> On Dec 29, 2004, at 2:28 PM, Tom Lane wrote:
>> Eric Brown <eric.brown@propel.com> writes:
>>> I thought setting debug_print_plan was supposed to explain every query
>>> in my log file? I don't see the plan print either.
>>
>> No, it just prints the plan.  With settings like yours I get

> I don't get the the "DEBUG:  parse tree:" or the DETAIL lines at all.

[ scratches head... ]  Are you sure debug_print_plan is really on?
Check it with SHOW.  It's hard to see why that debug output wouldn't get
to the log if the rest of the debug messages do.

            regards, tom lane

Re: debug_print_plan (pg7.4) doesn't seem to do anything

From
Eric Brown
Date:
On Dec 29, 2004, at 3:16 PM, Tom Lane wrote:
> Eric Brown <eric.brown@propel.com> writes:
>> On Dec 29, 2004, at 2:28 PM, Tom Lane wrote:
>>> Eric Brown <eric.brown@propel.com> writes:
>>>> I thought setting debug_print_plan was supposed to explain every
>>>> query
>>>> in my log file? I don't see the plan print either.
>>>
>>> No, it just prints the plan.  With settings like yours I get
>
>> I don't get the the "DEBUG:  parse tree:" or the DETAIL lines at all.
>
> [ scratches head... ]  Are you sure debug_print_plan is really on?
> Check it with SHOW.  It's hard to see why that debug output wouldn't
> get
> to the log if the rest of the debug messages do.

The problem was syslog. Postgresql logs to facility local0 by default
and I wasn't logging that at debug level.