diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/backend/commands/portalcmds.c | 5 | ||||
| -rw-r--r-- | src/backend/commands/prepare.c | 3 | ||||
| -rw-r--r-- | src/backend/executor/spi.c | 3 | ||||
| -rw-r--r-- | src/backend/tcop/postgres.c | 593 | ||||
| -rw-r--r-- | src/backend/tcop/utility.c | 394 | ||||
| -rw-r--r-- | src/backend/utils/mmgr/README | 16 | ||||
| -rw-r--r-- | src/backend/utils/mmgr/portalmem.c | 10 | ||||
| -rw-r--r-- | src/include/tcop/utility.h | 8 | ||||
| -rw-r--r-- | src/include/utils/portal.h | 13 |
9 files changed, 760 insertions, 285 deletions
diff --git a/src/backend/commands/portalcmds.c b/src/backend/commands/portalcmds.c index e418fabfc51..48833e7dc04 100644 --- a/src/backend/commands/portalcmds.c +++ b/src/backend/commands/portalcmds.c @@ -14,7 +14,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.54 2006/09/06 20:40:47 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.55 2006/09/07 22:52:00 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -109,12 +109,11 @@ PerformCursorOpen(DeclareCursorStmt *stmt, ParamListInfo params) /* * XXX: debug_query_string is wrong here: the user might have - * submitted more than one semicolon delimited queries. + * submitted multiple semicolon delimited queries. */ PortalDefineQuery(portal, NULL, pstrdup(debug_query_string), - NULL, "SELECT", /* cursor's query is always a SELECT */ list_make1(query), list_make1(plan), diff --git a/src/backend/commands/prepare.c b/src/backend/commands/prepare.c index dc264306719..eccce9d10d6 100644 --- a/src/backend/commands/prepare.c +++ b/src/backend/commands/prepare.c @@ -10,7 +10,7 @@ * Copyright (c) 2002-2006, PostgreSQL Global Development Group * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.63 2006/09/06 20:40:47 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/commands/prepare.c,v 1.64 2006/09/07 22:52:00 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -203,7 +203,6 @@ ExecuteQuery(ExecuteStmt *stmt, ParamListInfo params, PortalDefineQuery(portal, NULL, query_string, - NULL, entry->commandTag, query_list, plan_list, diff --git a/src/backend/executor/spi.c b/src/backend/executor/spi.c index dc3ab9e7c32..eb8d11fed9f 100644 --- a/src/backend/executor/spi.c +++ b/src/backend/executor/spi.c @@ -8,7 +8,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.162 2006/09/06 20:40:47 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/executor/spi.c,v 1.163 2006/09/07 22:52:00 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -921,7 +921,6 @@ SPI_cursor_open(const char *name, void *plan, PortalDefineQuery(portal, NULL, /* no statement name */ spiplan->query, - NULL, CreateQueryTag(PortalListGetPrimaryQuery(qtlist)), qtlist, ptlist, diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 2e128ece137..30c722f4adb 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -8,7 +8,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.506 2006/09/06 20:40:48 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.507 2006/09/07 22:52:01 tgl Exp $ * * NOTES * this is the "main" module of the postgres backend and @@ -156,9 +156,12 @@ static int UseNewLine = 0; /* Use EOF as query delimiters */ static int InteractiveBackend(StringInfo inBuf); static int SocketBackend(StringInfo inBuf); static int ReadCommand(StringInfo inBuf); -static bool log_after_parse(List *raw_parsetree_list, - const char *query_string, char **prepare_string); static List *pg_rewrite_queries(List *querytree_list); +static bool check_log_statement_raw(List *raw_parsetree_list); +static bool check_log_statement_cooked(List *parsetree_list); +static bool check_log_duration(char *msec_str); +static int errdetail_execute(List *raw_parsetree_list); +static int errdetail_params(ParamListInfo params); static void start_xact_command(void); static void finish_xact_command(void); static bool IsTransactionExitStmt(Node *parsetree); @@ -533,83 +536,6 @@ pg_parse_query(const char *query_string) return raw_parsetree_list; } -static bool -log_after_parse(List *raw_parsetree_list, const char *query_string, - char **prepare_string) -{ - ListCell *parsetree_item; - bool log_this_statement = (log_statement == LOGSTMT_ALL); - - *prepare_string = NULL; - - /* Check if we need to log the statement, and get prepare_string. */ - foreach(parsetree_item, raw_parsetree_list) - { - Node *parsetree = (Node *) lfirst(parsetree_item); - const char *commandTag; - - if (IsA(parsetree, ExplainStmt) && - ((ExplainStmt *) parsetree)->analyze) - parsetree = (Node *) (((ExplainStmt *) parsetree)->query); - - if (IsA(parsetree, PrepareStmt)) - parsetree = (Node *) (((PrepareStmt *) parsetree)->query); - - if (IsA(parsetree, SelectStmt) && - ((SelectStmt *) parsetree)->into == NULL) - continue; /* optimization for frequent command */ - - if (log_statement == LOGSTMT_MOD && - (IsA(parsetree, InsertStmt) || - IsA(parsetree, UpdateStmt) || - IsA(parsetree, DeleteStmt) || - IsA(parsetree, TruncateStmt) || - (IsA(parsetree, CopyStmt) && - ((CopyStmt *) parsetree)->is_from))) /* COPY FROM */ - log_this_statement = true; - - commandTag = CreateCommandTag(parsetree); - if ((log_statement == LOGSTMT_MOD || - log_statement == LOGSTMT_DDL) && - (strncmp(commandTag, "CREATE ", strlen("CREATE ")) == 0 || - IsA(parsetree, SelectStmt) || /* SELECT INTO, CREATE AS */ - strncmp(commandTag, "ALTER ", strlen("ALTER ")) == 0 || - strncmp(commandTag, "DROP ", strlen("DROP ")) == 0 || - IsA(parsetree, GrantStmt) || /* GRANT or REVOKE */ - IsA(parsetree, CommentStmt))) - log_this_statement = true; - - /* - * For the first EXECUTE we find, record the client statement used by - * the PREPARE. PREPARE doesn't save the parse tree so we have no - * way to conditionally output based on the type of query prepared. - * Parse does save the command tag, so perhaps we can use that. - */ - if (IsA(parsetree, ExecuteStmt)) - { - ExecuteStmt *stmt = (ExecuteStmt *) parsetree; - PreparedStatement *entry; - - if (*prepare_string == NULL && - (entry = FetchPreparedStatement(stmt->name, false)) != NULL && - entry->query_string) - *prepare_string = pstrdup(entry->query_string); - } - } - - if (log_this_statement) - { - ereport(LOG, - (errmsg("statement: %s", query_string), - *prepare_string ? errdetail("prepare: %s", - *prepare_string) : 0)); - return true; - } - else - return false; -} - - /* * Given a raw parsetree (gram.y output), and optionally information about * types of parameter symbols ($n), perform parse analysis and rule rewriting. @@ -817,8 +743,8 @@ exec_simple_query(const char *query_string) List *parsetree_list; ListCell *parsetree_item; bool save_log_statement_stats = log_statement_stats; - char *prepare_string = NULL; bool was_logged = false; + char msec_str[32]; /* * Report query to various monitoring facilities. @@ -871,9 +797,13 @@ exec_simple_query(const char *query_string) parsetree_list = pg_parse_query(query_string); /* Log immediately if dictated by log_statement */ - if (log_statement != LOGSTMT_NONE || log_duration || - log_min_duration_statement >= 0) - was_logged = log_after_parse(parsetree_list, query_string, &prepare_string); + if (check_log_statement_raw(parsetree_list)) + { + ereport(LOG, + (errmsg("statement: %s", query_string), + errdetail_execute(parsetree_list))); + was_logged = true; + } /* * Switch back to transaction context to enter the loop. @@ -954,7 +884,6 @@ exec_simple_query(const char *query_string) PortalDefineQuery(portal, NULL, query_string, - NULL, commandTag, querytree_list, plantree_list, @@ -1066,49 +995,21 @@ exec_simple_query(const char *query_string) /* * Emit duration logging if appropriate. */ - if (log_duration || log_min_duration_statement >= 0) + if (check_log_duration(msec_str)) { - long secs; - int usecs; - int msecs; - - TimestampDifference(GetCurrentStatementStartTimestamp(), - GetCurrentTimestamp(), - &secs, &usecs); - msecs = usecs / 1000; - - /* - * The odd-looking test for log_min_duration_statement being - * exceeded is designed to avoid integer overflow with very - * long durations: don't compute secs * 1000 until we've - * verified it will fit in int. - */ - if (log_duration || - log_min_duration_statement == 0 || - (log_min_duration_statement > 0 && - (secs > log_min_duration_statement / 1000 || - secs * 1000 + msecs >= log_min_duration_statement))) - { - if (was_logged) - ereport(LOG, - (errmsg("duration: %ld.%03d ms", - secs * 1000 + msecs, usecs % 1000))); - else - ereport(LOG, - (errmsg("duration: %ld.%03d ms statement: %s", - secs * 1000 + msecs, usecs % 1000, - query_string), - prepare_string ? errdetail("prepare: %s", - prepare_string) : 0)); - } + if (was_logged) + ereport(LOG, + (errmsg("duration: %s ms", msec_str))); + else + ereport(LOG, + (errmsg("duration: %s ms statement: %s", + msec_str, query_string), + errdetail_execute(parsetree_list))); } if (save_log_statement_stats) ShowUsage("QUERY STATISTICS"); - if (prepare_string != NULL) - pfree(prepare_string); - debug_query_string = NULL; } @@ -1131,6 +1032,7 @@ exec_parse_message(const char *query_string, /* string to execute */ *param_list; bool is_named; bool save_log_statement_stats = log_statement_stats; + char msec_str[32]; /* * Report query to various monitoring facilities. @@ -1144,11 +1046,10 @@ exec_parse_message(const char *query_string, /* string to execute */ if (save_log_statement_stats) ResetUsage(); - if (log_statement == LOGSTMT_ALL) - ereport(LOG, - (errmsg("statement: prepare %s: %s", - *stmt_name ? stmt_name : "<unnamed>", - query_string))); + ereport(DEBUG2, + (errmsg("parse %s: %s", + *stmt_name ? stmt_name : "<unnamed>", + query_string))); /* * Start up a transaction command so we can run parse analysis etc. (Note @@ -1343,6 +1244,16 @@ exec_parse_message(const char *query_string, /* string to execute */ if (whereToSendOutput == DestRemote) pq_putemptymessage('1'); + /* + * Emit duration logging if appropriate. + */ + if (check_log_duration(msec_str)) + ereport(LOG, + (errmsg("duration: %s ms parse %s: %s", + msec_str, + *stmt_name ? stmt_name : "<unnamed>", + query_string))); + if (save_log_statement_stats) ShowUsage("PARSE MESSAGE STATISTICS"); @@ -1368,12 +1279,44 @@ exec_bind_message(StringInfo input_message) Portal portal; ParamListInfo params; List *plan_list; - StringInfoData bind_values_str; + MemoryContext qContext; + bool save_log_statement_stats = log_statement_stats; + char msec_str[32]; + + /* Get the fixed part of the message */ + portal_name = pq_getmsgstring(input_message); + stmt_name = pq_getmsgstring(input_message); + + ereport(DEBUG2, + (errmsg("bind %s to %s", + *portal_name ? portal_name : "<unnamed>", + *stmt_name ? stmt_name : "<unnamed>"))); + + /* Find prepared statement */ + if (stmt_name[0] != '\0') + pstmt = FetchPreparedStatement(stmt_name, true); + else + { + /* special-case the unnamed statement */ + pstmt = unnamed_stmt_pstmt; + if (!pstmt) + ereport(ERROR, + (errcode(ERRCODE_UNDEFINED_PSTATEMENT), + errmsg("unnamed prepared statement does not exist"))); + } - pgstat_report_activity("<BIND>"); + /* + * Report query to various monitoring facilities. + */ + debug_query_string = "bind message"; + + pgstat_report_activity(pstmt->query_string ? pstmt->query_string : "<BIND>"); set_ps_display("BIND", false); + if (save_log_statement_stats) + ResetUsage(); + /* * Start up a transaction command so we can call functions etc. (Note that * this will normally change current memory context.) Nothing happens if @@ -1384,12 +1327,6 @@ exec_bind_message(StringInfo input_message) /* Switch back to message context */ MemoryContextSwitchTo(MessageContext); - initStringInfo(&bind_values_str); - - /* Get the fixed part of the message */ - portal_name = pq_getmsgstring(input_message); - stmt_name = pq_getmsgstring(input_message); - /* Get the parameter format codes */ numPFormats = pq_getmsgint(input_message, 2); if (numPFormats > 0) @@ -1410,19 +1347,6 @@ exec_bind_message(StringInfo input_message) errmsg("bind message has %d parameter formats but %d parameters", numPFormats, numParams))); - /* Find prepared statement */ - if (stmt_name[0] != '\0') - pstmt = FetchPreparedStatement(stmt_name, true); - else - { - /* special-case the unnamed statement */ - pstmt = unnamed_stmt_pstmt; - if (!pstmt) - ereport(ERROR, - (errcode(ERRCODE_UNDEFINED_PSTATEMENT), - errmsg("unnamed prepared statement does not exist"))); - } - if (numParams != list_length(pstmt->argtype_list)) ereport(ERROR, (errcode(ERRCODE_PROTOCOL_VIOLATION), @@ -1521,7 +1445,7 @@ exec_bind_message(StringInfo input_message) { Oid typinput; Oid typioparam; - char *pstring, *p; + char *pstring; getTypeInputInfo(ptype, &typinput, &typioparam); @@ -1536,24 +1460,6 @@ exec_bind_message(StringInfo input_message) pval = OidInputFunctionCall(typinput, pstring, typioparam, -1); - /* Save the parameter values */ - appendStringInfo(&bind_values_str, "%s$%d = ", - bind_values_str.len ? ", " : "", - paramno + 1); - if (pstring) - { - appendStringInfoChar(&bind_values_str, '\''); - for (p = pstring; *p; p++) - { - if (*p == '\'') /* double single quotes */ - appendStringInfoChar(&bind_values_str, *p); - appendStringInfoChar(&bind_values_str, *p); - } - appendStringInfoChar(&bind_values_str, '\''); - } - else - appendStringInfo(&bind_values_str, "NULL"); - /* Free result of encoding conversion, if any */ if (pstring && pstring != pbuf.data) pfree(pstring); @@ -1582,8 +1488,6 @@ exec_bind_message(StringInfo input_message) (errcode(ERRCODE_INVALID_BINARY_REPRESENTATION), errmsg("incorrect binary data format in bind parameter %d", paramno + 1))); - - /* XXX TODO: convert value to text and log it */ } else { @@ -1617,19 +1521,6 @@ exec_bind_message(StringInfo input_message) else params = NULL; - if (log_statement == LOGSTMT_ALL) - { - ereport(LOG, - (errmsg("statement: bind %s%s%s%s%s", - *stmt_name ? stmt_name : "<unnamed>", - *portal->name ? "/" : "", - *portal->name ? portal->name : "", - /* print bind parameters if we have them */ - bind_values_str.len ? ": " : "", - bind_values_str.len ? bind_values_str.data : ""), - errdetail("prepare: %s", pstmt->query_string))); - } - /* Get the result format codes */ numRFormats = pq_getmsgint(input_message, 2); if (numRFormats > 0) @@ -1654,32 +1545,37 @@ exec_bind_message(StringInfo input_message) * * XXX because the planner has a bad habit of scribbling on its input, * we have to make a copy of the parse trees, just in case someone binds - * and executes an unnamed statement multiple times. FIXME someday + * and executes an unnamed statement multiple times; this also means that + * the portal's queryContext becomes its own heap context rather than the + * prepared statement's context. FIXME someday */ if (pstmt->plan_list == NIL && pstmt->query_list != NIL) { MemoryContext oldContext; - oldContext = MemoryContextSwitchTo(PortalGetHeapMemory(portal)); + qContext = PortalGetHeapMemory(portal); + oldContext = MemoryContextSwitchTo(qContext); plan_list = pg_plan_queries(copyObject(pstmt->query_list), params, true); MemoryContextSwitchTo(oldContext); } else + { plan_list = pstmt->plan_list; + qContext = pstmt->context; + } /* * Define portal and start execution. */ PortalDefineQuery(portal, - *stmt_name ? pstrdup(stmt_name) : NULL, + *pstmt->stmt_name ? pstmt->stmt_name : NULL, pstmt->query_string, - bind_values_str.len ? pstrdup(bind_values_str.data) : NULL, pstmt->commandTag, pstmt->query_list, plan_list, - pstmt->context); + qContext); PortalStart(portal, params, InvalidSnapshot); @@ -1693,6 +1589,23 @@ exec_bind_message(StringInfo input_message) */ if (whereToSendOutput == DestRemote) pq_putemptymessage('2'); + + /* + * Emit duration logging if appropriate. + */ + if (check_log_duration(msec_str)) + ereport(LOG, + (errmsg("duration: %s ms bind %s to %s: %s", + msec_str, + *portal_name ? portal_name : "<unnamed>", + *stmt_name ? stmt_name : "<unnamed>", + pstmt->query_string ? pstmt->query_string : "<source not stored>"), + errdetail_params(params))); + + if (save_log_statement_stats) + ShowUsage("BIND MESSAGE STATISTICS"); + + debug_query_string = NULL; } /* @@ -1708,12 +1621,14 @@ exec_execute_message(const char *portal_name, long max_rows) Portal portal; bool completed; char completionTag[COMPLETION_TAG_BUFSIZE]; - const char *sourceText = NULL; - const char *bindText = NULL; + const char *sourceText; const char *prepStmtName; + ParamListInfo portalParams; bool save_log_statement_stats = log_statement_stats; bool is_xact_command; bool execute_is_fetch; + bool was_logged = false; + char msec_str[32]; /* Adjust destination to tell printtup.c what to do */ dest = whereToSendOutput; @@ -1737,6 +1652,18 @@ exec_execute_message(const char *portal_name, long max_rows) return; } + /* + * Report query to various monitoring facilities. + */ + debug_query_string = "execute message"; + + pgstat_report_activity(portal->sourceText ? portal->sourceText : "<EXECUTE>"); + + set_ps_display(portal->commandTag, false); + + if (save_log_statement_stats) + ResetUsage(); + /* Does the portal contain a transaction command? */ is_xact_command = IsTransactionStmtList(portal->parseTrees); @@ -1748,62 +1675,33 @@ exec_execute_message(const char *portal_name, long max_rows) */ execute_is_fetch = !portal->atStart; - /* Should we display the portal names here? */ - if (execute_is_fetch) - { - debug_query_string = "fetch message"; - pgstat_report_activity("<FETCH>"); - } - else - { - debug_query_string = "execute message"; - pgstat_report_activity("<EXECUTE>"); - } - - set_ps_display(portal->commandTag, false); - - /* copy prepStmtName now too, in case portal is destroyed */ - if (portal->prepStmtName) - prepStmtName = pstrdup(portal->prepStmtName); - else - prepStmtName = "<unnamed>"; - /* - * We must copy the sourceText and bindText into MessageContext + * We must copy the sourceText and prepStmtName into MessageContext * in case the portal is destroyed during finish_xact_command. * Can avoid the copy if it's not an xact command, though. */ if (is_xact_command) + { sourceText = pstrdup(portal->sourceText); + if (portal->prepStmtName) + prepStmtName = pstrdup(portal->prepStmtName); + else + prepStmtName = "<unnamed>"; + /* + * An xact command shouldn't have any parameters, which is a good + * thing because they wouldn't be around after finish_xact_command. + */ + portalParams = NULL; + } else - sourceText = portal->sourceText; - - if (portal->bindText) { - if (is_xact_command) - bindText = pstrdup(portal->bindText); + sourceText = portal->sourceText; + if (portal->prepStmtName) + prepStmtName = portal->prepStmtName; else - bindText = portal->bindText; + prepStmtName = "<unnamed>"; + portalParams = portal->portalParams; } - - /* - * We use save_log_statement_stats so ShowUsage doesn't report incorrect - * results because ResetUsage wasn't called. - */ - if (save_log_statement_stats) - ResetUsage(); - - if (log_statement == LOGSTMT_ALL) - ereport(LOG, - (errmsg("statement: execute %s%s%s%s", - execute_is_fetch ? "fetch from " : "", - prepStmtName, - *portal_name ? "/" : "", - *portal_name ? portal_name : ""), - errdetail("prepare: %s%s%s", sourceText, - /* optionally print bind parameters */ - bindText ? " | bind: " : "", - bindText ? bindText : ""))); BeginCommand(portal->commandTag, dest); @@ -1819,6 +1717,23 @@ exec_execute_message(const char *portal_name, long max_rows) */ start_xact_command(); + /* Log immediately if dictated by log_statement */ + if (check_log_statement_cooked(portal->parseTrees)) + { + ereport(LOG, + (errmsg("%s %s%s%s%s%s", + execute_is_fetch ? + _("statement: execute fetch from") : + _("statement: execute"), + prepStmtName, + *portal_name ? "/" : "", + *portal_name ? portal_name : "", + sourceText ? ": " : "", + sourceText ? sourceText : ""), + errdetail_params(portalParams))); + was_logged = true; + } + /* * If we are in aborted transaction state, the only portals we can * actually run are those containing COMMIT or ROLLBACK commands. @@ -1879,6 +1794,96 @@ exec_execute_message(const char *portal_name, long max_rows) /* * Emit duration logging if appropriate. */ + if (check_log_duration(msec_str)) + { + if (was_logged) + ereport(LOG, + (errmsg("duration: %s ms", msec_str))); + else + ereport(LOG, + (errmsg("duration: %s ms %s %s%s%s%s%s", + msec_str, + execute_is_fetch ? + _("execute fetch from") : + _("execute"), + prepStmtName, + *portal_name ? "/" : "", + *portal_name ? portal_name : "", + sourceText ? ": " : "", + sourceText ? sourceText : ""), + errdetail_params(portalParams))); + } + + if (save_log_statement_stats) + ShowUsage("EXECUTE MESSAGE STATISTICS"); + + debug_query_string = NULL; +} + +/* + * check_log_statement_raw + * Determine whether command should be logged because of log_statement + * + * raw_parsetree_list is the raw grammar output + */ +static bool +check_log_statement_raw(List *raw_parsetree_list) +{ + ListCell *parsetree_item; + + if (log_statement == LOGSTMT_NONE) + return false; + if (log_statement == LOGSTMT_ALL) + return true; + + /* Else we have to inspect the statement(s) to see whether to log */ + foreach(parsetree_item, raw_parsetree_list) + { + Node *parsetree = (Node *) lfirst(parsetree_item); + + if (GetCommandLogLevel(parsetree) <= log_statement) + return true; + } + + return false; +} + +/* + * check_log_statement_cooked + * As above, but work from already-analyzed querytrees + */ +static bool +check_log_statement_cooked(List *parsetree_list) +{ + ListCell *parsetree_item; + + if (log_statement == LOGSTMT_NONE) + return false; + if (log_statement == LOGSTMT_ALL) + return true; + + /* Else we have to inspect the statement(s) to see whether to log */ + foreach(parsetree_item, parsetree_list) + { + Query *parsetree = (Query *) lfirst(parsetree_item); + + if (GetQueryLogLevel(parsetree) <= log_statement) + return true; + } + + return false; +} + +/* + * check_log_duration + * Determine whether current command's duration should be logged + * + * If logging is needed, the duration in msec is formatted into msec_str[], + * which must be a 32-byte buffer. + */ +static bool +check_log_duration(char *msec_str) +{ if (log_duration || log_min_duration_statement >= 0) { long secs; @@ -1902,29 +1907,109 @@ exec_execute_message(const char *portal_name, long max_rows) (secs > log_min_duration_statement / 1000 || secs * 1000 + msecs >= log_min_duration_statement))) { - if (log_statement == LOGSTMT_ALL) /* already logged? */ - ereport(LOG, - (errmsg("duration: %ld.%03d ms", - secs * 1000 + msecs, usecs % 1000))); - else - ereport(LOG, - (errmsg("duration: %ld.%03d ms execute %s%s%s%s", - secs * 1000 + msecs, usecs % 1000, - execute_is_fetch ? "fetch from " : "", - prepStmtName, - *portal_name ? "/" : "", - *portal_name ? portal_name : ""), - errdetail("prepare: %s%s%s", sourceText, - /* optionally print bind parameters */ - bindText ? " | bind: " : "", - bindText ? bindText : ""))); + snprintf(msec_str, 32, "%ld.%03d", + secs * 1000 + msecs, usecs % 1000); + return true; } } - if (save_log_statement_stats) - ShowUsage("QUERY STATISTICS"); + return false; +} - debug_query_string = NULL; +/* + * errdetail_execute + * + * Add an errdetail() line showing the query referenced by an EXECUTE, if any. + * The argument is the raw parsetree list. + */ +static int +errdetail_execute(List *raw_parsetree_list) +{ + ListCell *parsetree_item; + + foreach(parsetree_item, raw_parsetree_list) + { + Node *parsetree = (Node *) lfirst(parsetree_item); + + if (IsA(parsetree, ExecuteStmt)) + { + ExecuteStmt *stmt = (ExecuteStmt *) parsetree; + PreparedStatement *pstmt; + + pstmt = FetchPreparedStatement(stmt->name, false); + if (pstmt && pstmt->query_string) + { + errdetail("prepare: %s", pstmt->query_string); + return 0; + } + } + } + + return 0; +} + +/* + * errdetail_params + * + * Add an errdetail() line showing bind-parameter data, if available. + */ +static int +errdetail_params(ParamListInfo params) +{ + /* We mustn't call user-defined I/O functions when in an aborted xact */ + if (params && params->numParams > 0 && !IsAbortedTransactionBlockState()) + { + StringInfoData param_str; + MemoryContext oldcontext; + int paramno; + + /* Make sure any trash is generated in MessageContext */ + oldcontext = MemoryContextSwitchTo(MessageContext); + + initStringInfo(¶m_str); + + for (paramno = 0; paramno < params->numParams; paramno++) + { + ParamExternData *prm = ¶ms->params[paramno]; + Oid typoutput; + bool typisvarlena; + char *pstring; + char *p; + + appendStringInfo(¶m_str, "%s$%d = ", + paramno > 0 ? ", " : "", + paramno + 1); + + if (prm->isnull || !OidIsValid(prm->ptype)) + { + appendStringInfoString(¶m_str, "NULL"); + continue; + } + + getTypeOutputInfo(prm->ptype, &typoutput, &typisvarlena); + + pstring = OidOutputFunctionCall(typoutput, prm->value); + + appendStringInfoCharMacro(¶m_str, '\''); + for (p = pstring; *p; p++) + { + if (*p == '\'') /* double single quotes */ + appendStringInfoCharMacro(¶m_str, *p); + appendStringInfoCharMacro(¶m_str, *p); + } + appendStringInfoCharMacro(¶m_str, '\''); + + pfree(pstring); + } + + errdetail("parameters: %s", param_str.data); + + pfree(param_str.data); + + MemoryContextSwitchTo(oldcontext); + } + + return 0; } /* diff --git a/src/backend/tcop/utility.c b/src/backend/tcop/utility.c index 781026b3237..868da2d5ff4 100644 --- a/src/backend/tcop/utility.c +++ b/src/backend/tcop/utility.c @@ -10,7 +10,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/tcop/utility.c,v 1.267 2006/08/25 04:06:53 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/tcop/utility.c,v 1.268 2006/09/07 22:52:01 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -1815,6 +1815,8 @@ CreateQueryTag(Query *parsetree) { const char *tag; + Assert(IsA(parsetree, Query)); + switch (parsetree->commandType) { case CMD_SELECT: @@ -1856,3 +1858,393 @@ CreateQueryTag(Query *parsetree) return tag; } + + +/* + * GetCommandLogLevel + * utility to get the minimum log_statement level for a command, + * given a raw (un-analyzed) parsetree. + * + * This must handle all raw command types, but since the vast majority + * of 'em are utility commands, it seems sensible to keep it here. + */ +LogStmtLevel +GetCommandLogLevel(Node *parsetree) +{ + LogStmtLevel lev; + + switch (nodeTag(parsetree)) + { + case T_InsertStmt: + case T_DeleteStmt: + case T_UpdateStmt: + lev = LOGSTMT_MOD; + break; + + case T_SelectStmt: + if (((SelectStmt *) parsetree)->into) + lev = LOGSTMT_DDL; /* CREATE AS, SELECT INTO */ + else + lev = LOGSTMT_ALL; + break; + + case T_TransactionStmt: + lev = LOGSTMT_ALL; + break; + + case T_DeclareCursorStmt: + lev = LOGSTMT_ALL; + break; + + case T_ClosePortalStmt: + lev = LOGSTMT_ALL; + break; + + case T_FetchStmt: + lev = LOGSTMT_ALL; + break; + + case T_CreateDomainStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateSchemaStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateTableSpaceStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropTableSpaceStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropStmt: + lev = LOGSTMT_DDL; + break; + + case T_TruncateStmt: + lev = LOGSTMT_MOD; + break; + + case T_CommentStmt: + lev = LOGSTMT_DDL; + break; + + case T_CopyStmt: + if (((CopyStmt *) parsetree)->is_from) + lev = LOGSTMT_MOD; + else + lev = LOGSTMT_ALL; + break; + + case T_RenameStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterObjectSchemaStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterOwnerStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterTableStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterDomainStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterFunctionStmt: + lev = LOGSTMT_DDL; + break; + + case T_GrantStmt: + lev = LOGSTMT_DDL; + break; + + case T_GrantRoleStmt: + lev = LOGSTMT_DDL; + break; + + case T_DefineStmt: + lev = LOGSTMT_DDL; + break; + + case T_CompositeTypeStmt: + lev = LOGSTMT_DDL; + break; + + case T_ViewStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateFunctionStmt: + lev = LOGSTMT_DDL; + break; + + case T_IndexStmt: + lev = LOGSTMT_DDL; + break; + + case T_RuleStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateSeqStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterSeqStmt: + lev = LOGSTMT_DDL; + break; + + case T_RemoveFuncStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreatedbStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterDatabaseStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterDatabaseSetStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropdbStmt: + lev = LOGSTMT_DDL; + break; + + case T_NotifyStmt: + lev = LOGSTMT_ALL; + break; + + case T_ListenStmt: + lev = LOGSTMT_ALL; + break; + + case T_UnlistenStmt: + lev = LOGSTMT_ALL; + break; + + case T_LoadStmt: + lev = LOGSTMT_ALL; + break; + + case T_ClusterStmt: + lev = LOGSTMT_DDL; + break; + + case T_VacuumStmt: + lev = LOGSTMT_ALL; + break; + + case T_ExplainStmt: + { + ExplainStmt *stmt = (ExplainStmt *) parsetree; + + /* Look through an EXPLAIN ANALYZE to the contained stmt */ + if (stmt->analyze) + return GetCommandLogLevel((Node *) stmt->query); + /* Plain EXPLAIN isn't so interesting */ + lev = LOGSTMT_ALL; + } + break; + + case T_VariableSetStmt: + lev = LOGSTMT_ALL; + break; + + case T_VariableShowStmt: + lev = LOGSTMT_ALL; + break; + + case T_VariableResetStmt: + lev = LOGSTMT_ALL; + break; + + case T_CreateTrigStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropPropertyStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreatePLangStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropPLangStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateRoleStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterRoleStmt: + lev = LOGSTMT_DDL; + break; + + case T_AlterRoleSetStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropRoleStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropOwnedStmt: + lev = LOGSTMT_DDL; + break; + + case T_ReassignOwnedStmt: + lev = LOGSTMT_DDL; + break; + + case T_LockStmt: + lev = LOGSTMT_ALL; + break; + + case T_ConstraintsSetStmt: + lev = LOGSTMT_ALL; + break; + + case T_CheckPointStmt: + lev = LOGSTMT_ALL; + break; + + case T_ReindexStmt: + lev = LOGSTMT_ALL; /* should this be DDL? */ + break; + + case T_CreateConversionStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateCastStmt: + lev = LOGSTMT_DDL; + break; + + case T_DropCastStmt: + lev = LOGSTMT_DDL; + break; + + case T_CreateOpClassStmt: + lev = LOGSTMT_DDL; + break; + + case T_RemoveOpClassStmt: + lev = LOGSTMT_DDL; + break; + + case T_PrepareStmt: + { + PrepareStmt *stmt = (PrepareStmt *) parsetree; + + /* Look through a PREPARE to the contained stmt */ + return GetCommandLogLevel((Node *) stmt->query); + } + break; + + case T_ExecuteStmt: + { + ExecuteStmt *stmt = (ExecuteStmt *) parsetree; + PreparedStatement *pstmt; + ListCell *l; + + /* Look through an EXECUTE to the referenced stmt(s) */ + lev = LOGSTMT_ALL; + pstmt = FetchPreparedStatement(stmt->name, false); + if (pstmt) + { + foreach(l, pstmt->query_list) + { + Query *query = (Query *) lfirst(l); + LogStmtLevel stmt_lev; + + stmt_lev = GetQueryLogLevel(query); + lev = Min(lev, stmt_lev); + } + } + } + break; + + case T_DeallocateStmt: + lev = LOGSTMT_ALL; + break; + + case T_Query: + /* + * In complicated situations (eg, EXPLAIN ANALYZE in an extended + * Query protocol), we might find an already-analyzed query + * within a utility statement. Cope. + */ + lev = GetQueryLogLevel((Query *) parsetree); + break; + + default: + elog(WARNING, "unrecognized node type: %d", + (int) nodeTag(parsetree)); + lev = LOGSTMT_ALL; + break; + } + + return lev; +} + +/* + * GetQueryLogLevel + * utility to get the minimum log_statement level for a Query operation. + * + * This is exactly like GetCommandLogLevel, except it works on a Query + * that has already been through parse analysis (and possibly further). + */ +LogStmtLevel +GetQueryLogLevel(Query *parsetree) +{ + LogStmtLevel lev; + + Assert(IsA(parsetree, Query)); + + switch (parsetree->commandType) + { + case CMD_SELECT: + if (parsetree->into != NULL) + lev = LOGSTMT_DDL; /* CREATE AS, SELECT INTO */ + else + lev = LOGSTMT_ALL; + break; + + case CMD_UPDATE: + case CMD_INSERT: + case CMD_DELETE: + lev = LOGSTMT_MOD; + break; + + case CMD_UTILITY: + lev = GetCommandLogLevel(parsetree->utilityStmt); + break; + + default: + elog(WARNING, "unrecognized commandType: %d", + (int) parsetree->commandType); + lev = LOGSTMT_ALL; + break; + } + + return lev; +} diff --git a/src/backend/utils/mmgr/README b/src/backend/utils/mmgr/README index 8c60ad48844..a91dfe3d760 100644 --- a/src/backend/utils/mmgr/README +++ b/src/backend/utils/mmgr/README @@ -1,4 +1,4 @@ -$PostgreSQL: pgsql/src/backend/utils/mmgr/README,v 1.8 2004/08/04 21:34:04 tgl Exp $ +$PostgreSQL: pgsql/src/backend/utils/mmgr/README,v 1.9 2006/09/07 22:52:01 tgl Exp $ Notes about memory allocation redesign -------------------------------------- @@ -202,13 +202,13 @@ data kept here is pending NOTIFY messages, which are sent at top-level commit, but only if the generating subtransaction did not abort. QueryContext --- this is not actually a separate context, but a global -variable pointing to the context that holds the current command's parse -and plan trees. (In simple-Query mode this points to MessageContext; -when executing a prepared statement it will point at the prepared -statement's private context.) Generally it is not appropriate for any -code to use QueryContext as an allocation target --- from the point of -view of any code that would be referencing the QueryContext variable, -it's a read-only context. +variable pointing to the context that holds the current command's parse tree. +(In simple-Query mode this points to MessageContext; when executing a +prepared statement it will point to the prepared statement's private context. +Note that the plan tree may or may not be in this same context.) +Generally it is not appropriate for any code to use QueryContext as an +allocation target --- from the point of view of any code that would be +referencing the QueryContext variable, it's a read-only context. PortalContext --- this is not actually a separate context either, but a global variable pointing to the per-portal context of the currently active diff --git a/src/backend/utils/mmgr/portalmem.c b/src/backend/utils/mmgr/portalmem.c index cae91572cc7..e29ffb53c98 100644 --- a/src/backend/utils/mmgr/portalmem.c +++ b/src/backend/utils/mmgr/portalmem.c @@ -12,7 +12,7 @@ * Portions Copyright (c) 1994, Regents of the University of California * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/utils/mmgr/portalmem.c,v 1.93 2006/08/29 02:11:30 momjian Exp $ + * $PostgreSQL: pgsql/src/backend/utils/mmgr/portalmem.c,v 1.94 2006/09/07 22:52:01 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -266,15 +266,14 @@ CreateNewPortal(void) * Notes: commandTag shall be NULL if and only if the original query string * (before rewriting) was an empty string. Also, the passed commandTag must * be a pointer to a constant string, since it is not copied. The caller is - * responsible for ensuring that the passed sourceText (if any), parse and - * plan trees have adequate lifetime. Also, queryContext must accurately - * describe the location of the parse and plan trees. + * responsible for ensuring that the passed prepStmtName (if any), sourceText + * (if any), parse and plan trees have adequate lifetime. Also, queryContext + * must accurately describe the location of the parse trees. */ void PortalDefineQuery(Portal portal, const char *prepStmtName, const char *sourceText, - const char *bindText, const char *commandTag, List *parseTrees, List *planTrees, @@ -289,7 +288,6 @@ PortalDefineQuery(Portal portal, portal->prepStmtName = prepStmtName; portal->sourceText = sourceText; - portal->bindText = bindText; portal->commandTag = commandTag; portal->parseTrees = parseTrees; portal->planTrees = planTrees; diff --git a/src/include/tcop/utility.h b/src/include/tcop/utility.h index 6674dec129e..985cfb507b7 100644 --- a/src/include/tcop/utility.h +++ b/src/include/tcop/utility.h @@ -7,14 +7,14 @@ * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group * Portions Copyright (c) 1994, Regents of the University of California * - * $PostgreSQL: pgsql/src/include/tcop/utility.h,v 1.28 2006/08/12 20:05:56 tgl Exp $ + * $PostgreSQL: pgsql/src/include/tcop/utility.h,v 1.29 2006/09/07 22:52:01 tgl Exp $ * *------------------------------------------------------------------------- */ #ifndef UTILITY_H #define UTILITY_H -#include "executor/execdesc.h" +#include "tcop/tcopprot.h" extern void ProcessUtility(Node *parsetree, ParamListInfo params, @@ -28,6 +28,10 @@ extern const char *CreateCommandTag(Node *parsetree); extern const char *CreateQueryTag(Query *parsetree); +extern LogStmtLevel GetCommandLogLevel(Node *parsetree); + +extern LogStmtLevel GetQueryLogLevel(Query *parsetree); + extern bool QueryReturnsTuples(Query *parsetree); extern bool QueryIsReadOnly(Query *parsetree); diff --git a/src/include/utils/portal.h b/src/include/utils/portal.h index 4a546bdda96..a377b0ca21a 100644 --- a/src/include/utils/portal.h +++ b/src/include/utils/portal.h @@ -39,7 +39,7 @@ * Portions Copyright (c) 1996-2006, PostgreSQL Global Development Group * Portions Copyright (c) 1994, Regents of the University of California * - * $PostgreSQL: pgsql/src/include/utils/portal.h,v 1.69 2006/09/03 03:19:45 momjian Exp $ + * $PostgreSQL: pgsql/src/include/utils/portal.h,v 1.70 2006/09/07 22:52:01 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -110,7 +110,7 @@ typedef struct PortalData { /* Bookkeeping data */ const char *name; /* portal's name */ - const char *prepStmtName; /* protocol prepare name */ + const char *prepStmtName; /* source prepared statement (NULL if none) */ MemoryContext heap; /* subsidiary memory for portal */ ResourceOwner resowner; /* resources owned by portal */ void (*cleanup) (Portal portal); /* cleanup hook */ @@ -122,20 +122,20 @@ typedef struct PortalData */ /* The query or queries the portal will execute */ - const char *sourceText; /* text of query, if known, might be NULL */ - const char *bindText; /* text of bind parameters, might be NULL */ + const char *sourceText; /* text of query, if known (may be NULL) */ const char *commandTag; /* command tag for original query */ List *parseTrees; /* parse tree(s) */ List *planTrees; /* plan tree(s) */ - MemoryContext queryContext; /* where the above trees live */ + MemoryContext queryContext; /* where the parse trees live */ /* * Note: queryContext effectively identifies which prepared statement the * portal depends on, if any. The queryContext is *not* owned by the * portal and is not to be deleted by portal destruction. (But for a * cursor it is the same as "heap", and that context is deleted by portal - * destruction.) + * destruction.) The plan trees may be in either queryContext or heap. */ + ParamListInfo portalParams; /* params to pass to query */ /* Features/options */ @@ -216,7 +216,6 @@ extern Portal GetPortalByName(const char *name); extern void PortalDefineQuery(Portal portal, const char *prepStmtName, const char *sourceText, - const char *bindText, const char *commandTag, List *parseTrees, List *planTrees, |