Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit893632b

Browse files
committed
Clean up logging for extended-query-protocol operations, as per my recent
proposal. Parameter logging works even for binary-format parameters, andlogging overhead is avoided when disabled.log_statement = all output for the src/test/examples/testlibpq3.c examplenow looks likeLOG: statement: execute <unnamed>: SELECT * FROM test1 WHERE t = $1DETAIL: parameters: $1 = 'joe''s place'LOG: statement: execute <unnamed>: SELECT * FROM test1 WHERE i = $1::int4DETAIL: parameters: $1 = '2'and log_min_duration_statement = 0 results inLOG: duration: 2.431 ms parse <unnamed>: SELECT * FROM test1 WHERE t = $1LOG: duration: 2.335 ms bind <unnamed> to <unnamed>: SELECT * FROM test1 WHERE t = $1DETAIL: parameters: $1 = 'joe''s place'LOG: duration: 0.394 ms execute <unnamed>: SELECT * FROM test1 WHERE t = $1DETAIL: parameters: $1 = 'joe''s place'LOG: duration: 1.251 ms parse <unnamed>: SELECT * FROM test1 WHERE i = $1::int4LOG: duration: 0.566 ms bind <unnamed> to <unnamed>: SELECT * FROM test1 WHERE i = $1::int4DETAIL: parameters: $1 = '2'LOG: duration: 0.173 ms execute <unnamed>: SELECT * FROM test1 WHERE i = $1::int4DETAIL: parameters: $1 = '2'(This example demonstrates the folly of ignoring parse/bind steps for durationlogging purposes, BTW.)Along the way, create a less ad-hoc mechanism for determining which commandsare logged by log_statement = mod and log_statement = ddl. The former codingwas actually missing quite a few things that look like ddl to me, and itdid not handle EXECUTE or extended query protocol correctly at all.This commit does not do anything about the question of whether log_durationshould be removed or made less redundant with log_min_duration_statement.
1 parentb6eab50 commit893632b

File tree

10 files changed

+826
-317
lines changed

10 files changed

+826
-317
lines changed

‎doc/src/sgml/config.sgml

Lines changed: 66 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.83 2006/09/03 19:06:15 tgl Exp $ -->
1+
<!-- $PostgreSQL: pgsql/doc/src/sgml/config.sgml,v 1.84 2006/09/07 22:51:59 tgl Exp $ -->
22

33
<chapter Id="runtime-config">
44
<title>Server Configuration</title>
@@ -2492,18 +2492,36 @@ SELECT * FROM parent WHERE key = 2400;
24922492
</indexterm>
24932493
<listitem>
24942494
<para>
2495-
Logs thestatement and itsdurationon a single log line if its
2496-
duration is greater than or equal to the specified number of
2497-
milliseconds. Setting this to zerowill printallstatements
2498-
and their durations.Minus-one (the default) disablesthe
2499-
feature.For example, if you set it to <literal>250</literal>
2495+
Causes the durationof each completed statement to be logged
2496+
if the statement ran for at least the specified number of
2497+
milliseconds.Setting this to zeroprintsallstatement durations.
2498+
Minus-one (the default) disableslogging statement durations.
2499+
For example, if you set it to <literal>250</literal>
25002500
then all SQL statements that run 250ms or longer will be
2501-
logged. Enabling this parameter can be useful in tracking down
2502-
unoptimized queries in your applications. This setting is
2503-
independent of <varname>log_statement</varname> and
2504-
<varname>log_duration</varname>. Only superusers can change
2505-
this setting.
2501+
logged. Enabling this parameter can be helpful in tracking down
2502+
unoptimized queries in your applications.
2503+
Only superusers can change this setting.
25062504
</para>
2505+
2506+
<para>
2507+
For clients using extended query protocol, durations of the Parse,
2508+
Bind, and Execute steps are logged independently.
2509+
</para>
2510+
2511+
<note>
2512+
<para>
2513+
When using this option together with
2514+
<xref linkend="guc-log-statement">,
2515+
the text of statements that are logged because of
2516+
<varname>log_statement</> will not be repeated in the
2517+
duration log message.
2518+
If you are not using <application>syslog</>, it is recommended
2519+
that you log the PID or session ID using
2520+
<xref linkend="guc-log-line-prefix">
2521+
so that you can link the statement message to the later
2522+
duration message using the process ID or session ID.
2523+
</para>
2524+
</note>
25072525
</listitem>
25082526
</varlistentry>
25092527

@@ -2695,14 +2713,30 @@ SELECT * FROM parent WHERE key = 2400;
26952713
</indexterm>
26962714
<listitem>
26972715
<para>
2698-
Causes the duration of every completed statement which satisfies
2699-
<varname>log_statement</> to be logged. When using this option,
2700-
if you are not using <application>syslog</>, it is recommended
2701-
that you log the PID or session ID using <varname>log_line_prefix</>
2702-
so that you can link the statement message to the later
2703-
duration message using the process ID or session ID. The default is
2704-
<literal>off</>. Only superusers can change this setting.
2716+
Causes the duration of every completed statement to be logged.
2717+
The default is <literal>off</>.
2718+
Only superusers can change this setting.
27052719
</para>
2720+
2721+
<para>
2722+
For clients using extended query protocol, durations of the Parse,
2723+
Bind, and Execute steps are logged independently.
2724+
</para>
2725+
2726+
<note>
2727+
<para>
2728+
When using this option together with
2729+
<xref linkend="guc-log-statement">,
2730+
the text of statements that are logged because of
2731+
<varname>log_statement</> will not be repeated in the
2732+
duration log message.
2733+
If you are not using <application>syslog</>, it is recommended
2734+
that you log the PID or session ID using
2735+
<xref linkend="guc-log-line-prefix">
2736+
so that you can link the statement message to the later
2737+
duration message using the process ID or session ID.
2738+
</para>
2739+
</note>
27062740
</listitem>
27072741
</varlistentry>
27082742

@@ -2829,28 +2863,28 @@ SELECT * FROM parent WHERE key = 2400;
28292863
Controls which SQL statements are logged. Valid values are
28302864
<literal>none</>, <literal>ddl</>, <literal>mod</>, and
28312865
<literal>all</>. <literal>ddl</> logs all data definition
2832-
commands like <literal>CREATE</>, <literal>ALTER</>, and
2833-
<literal>DROP</> commands. <literal>mod</> logs all
2834-
<literal>ddl</> statements, plus <literal>INSERT</>,
2835-
<literal>UPDATE</>, <literal>DELETE</>, <literal>TRUNCATE</>,
2836-
and <literal>COPY FROM</>. <literal>PREPARE</> and
2837-
<literal>EXPLAIN ANALYZE</> statements are also logged if their
2838-
contained command is of an appropriate type. Protocol-level
2839-
prepare, bind, and execute commands are logged only if
2840-
<varname>log_statement</> is <literal>all</>. Bind parameter
2841-
values are also logged if they are supplied in <literal>text</>
2842-
format (literal single quotes are doubled).
2866+
statements, such as <command>CREATE</>, <command>ALTER</>, and
2867+
<command>DROP</> statements. <literal>mod</> logs all
2868+
<literal>ddl</> statements, plus data-modifying statements
2869+
such as <command>INSERT</>,
2870+
<command>UPDATE</>, <command>DELETE</>, <command>TRUNCATE</>,
2871+
and <command>COPY FROM</>.
2872+
<command>PREPARE</>, <command>EXECUTE</>, and
2873+
<command>EXPLAIN ANALYZE</> statements are also logged if their
2874+
contained command is of an appropriate type. For clients using
2875+
extended query protocol, logging occurs when an Execute message
2876+
is received, and values of the Bind parameters are included
2877+
(with any embedded single-quote marks doubled).
28432878
</para>
2879+
28442880
<para>
28452881
The default is <literal>none</>. Only superusers can change this
28462882
setting.
28472883
</para>
28482884

28492885
<note>
28502886
<para>
2851-
The <command>EXECUTE</command> statement is not considered a
2852-
<literal>ddl</> or <literal>mod</> statement. Statements that
2853-
generate syntax errors are not logged. Set
2887+
Statements that generate syntax errors are not logged. Set
28542888
<varname>log_min_error_statement</> to <literal>error</> to
28552889
log such statements.
28562890
</para>

‎src/backend/commands/portalcmds.c

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@
1414
*
1515
*
1616
* IDENTIFICATION
17-
* $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.54 2006/09/06 20:40:47 tgl Exp $
17+
* $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.55 2006/09/07 22:52:00 tgl Exp $
1818
*
1919
*-------------------------------------------------------------------------
2020
*/
@@ -109,12 +109,11 @@ PerformCursorOpen(DeclareCursorStmt *stmt, ParamListInfo params)
109109

110110
/*
111111
* XXX: debug_query_string is wrong here: the user might have
112-
* submittedmore than one semicolon delimited queries.
112+
* submittedmultiple semicolon delimited queries.
113113
*/
114114
PortalDefineQuery(portal,
115115
NULL,
116116
pstrdup(debug_query_string),
117-
NULL,
118117
"SELECT",/* cursor's query is always a SELECT */
119118
list_make1(query),
120119
list_make1(plan),

‎src/backend/commands/prepare.c

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,7 @@
1010
* Copyright (c) 2002-2006, PostgreSQL Global Development Group
1111
*
1212
* IDENTIFICATION
13-
* $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.63 2006/09/06 20:40:47 tgl Exp $
13+
* $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.64 2006/09/07 22:52:00 tgl Exp $
1414
*
1515
*-------------------------------------------------------------------------
1616
*/
@@ -203,7 +203,6 @@ ExecuteQuery(ExecuteStmt *stmt, ParamListInfo params,
203203
PortalDefineQuery(portal,
204204
NULL,
205205
query_string,
206-
NULL,
207206
entry->commandTag,
208207
query_list,
209208
plan_list,

‎src/backend/executor/spi.c

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@
88
*
99
*
1010
* IDENTIFICATION
11-
* $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.162 2006/09/06 20:40:47 tgl Exp $
11+
* $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.163 2006/09/07 22:52:00 tgl Exp $
1212
*
1313
*-------------------------------------------------------------------------
1414
*/
@@ -921,7 +921,6 @@ SPI_cursor_open(const char *name, void *plan,
921921
PortalDefineQuery(portal,
922922
NULL,/* no statement name */
923923
spiplan->query,
924-
NULL,
925924
CreateQueryTag(PortalListGetPrimaryQuery(qtlist)),
926925
qtlist,
927926
ptlist,

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp