Thread: debug_print_plan (pg7.4) doesn't seem to do anything
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
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
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
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
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.