Re: [HACKERS] logging statement levels - Mailing list pgsql-patches

From Bruce Momjian
Subject Re: [HACKERS] logging statement levels
Date
Msg-id 200404070505.i3755pf09027@candle.pha.pa.us
Whole thread Raw
In response to Re: [HACKERS] logging statement levels  (Bruce Momjian <pgman@candle.pha.pa.us>)
List pgsql-patches
Patch applied.

---------------------------------------------------------------------------

Bruce Momjian wrote:
> Andrew Dunstan wrote:
> > >>Here are some options:
> > >>
> > >>1. change the type of "log_statement" option from boolean to string,
> > >>with allowed values of "all, mod, ddl, none" with default "none".
> > >>2. same as 1. but make boolean true values synonyms for "all" and
> > >>boolean false values synonyms for "none".
> > >>3. keep "log_statement" option as now and add a new option
> > >>"log_statement_level" with the same options as 1. but default to "all",
> > >>which will have no effect unless "log_statement" is true.
> > >>
> > >>
> > >
> > >I like 1.
>
> OK, here is a patch that implements #1.  Here is sample output:
>
>     test=> set client_min_messages = 'log';
>     SET
>     test=> set log_statement = 'mod';
>     SET
>     test=> select 1;
>      ?column?
>     ----------
>             1
>     (1 row)
>
>     test=> update test set x=1;
>     LOG:  statement: update test set x=1;
>     ERROR:  relation "test" does not exist
>     test=> update test set x=1;
>     LOG:  statement: update test set x=1;
>     ERROR:  relation "test" does not exist
>     test=> copy test from '/tmp/x';
>     LOG:  statement: copy test from '/tmp/x';
>     ERROR:  relation "test" does not exist
>     test=> copy test to  '/tmp/x';
>     ERROR:  relation "test" does not exist
>     test=> prepare xx as select 1;
>     PREPARE
>     test=> prepare xx as update x set y=1;
>     LOG:  statement: prepare xx as update x set y=1;
>     ERROR:  relation "x" does not exist
>     test=> explain analyze select 1;;
>                                          QUERY PLAN
>     ------------------------------------------------------------------------------------
>      Result  (cost=0.00..0.01 rows=1 width=0) (actual time=0.006..0.007 rows=1 loops=1)
>      Total runtime: 0.046 ms
>     (2 rows)
>
>     test=> explain analyze update test set x=1;
>     LOG:  statement: explain analyze update test set x=1;
>     ERROR:  relation "test" does not exist
>     test=> explain update test set x=1;
>     ERROR:  relation "test" does not exist
>
> It checks PREPARE and EXECUTE ANALYZE too.  The log_statement values are
> 'none', 'mod', 'ddl', and 'all'.  For 'all', it prints before the query
> is parsed, and for ddl/mod, it does it right after parsing using the
> node tag (or command tag for CREATE/ALTER/DROP), so any non-parse errors
> will print after the log line.
>
> --
>   Bruce Momjian                        |  http://candle.pha.pa.us
>   pgman@candle.pha.pa.us               |  (610) 359-1001
>   +  If your life is a hard drive,     |  13 Roberts Road
>   +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

> Index: doc/src/sgml/runtime.sgml
> ===================================================================
> RCS file: /cvsroot/pgsql-server/doc/src/sgml/runtime.sgml,v
> retrieving revision 1.257
> diff -c -c -r1.257 runtime.sgml
> *** doc/src/sgml/runtime.sgml    5 Apr 2004 03:02:03 -0000    1.257
> --- doc/src/sgml/runtime.sgml    6 Apr 2004 03:56:08 -0000
> ***************
> *** 2121,2132 ****
>        </varlistentry>
>
>        <varlistentry id="guc-log-statement" xreflabel="log_statement">
> !       <term><varname>log_statement</varname> (<type>boolean</type>)</term>
>         <listitem>
>          <para>
> !         Causes each SQL statement to be logged. The default is
> !         off. Only superusers can disable this option if it has been
> !         enabled by an administrator.
>          </para>
>
>          <note>
> --- 2121,2141 ----
>        </varlistentry>
>
>        <varlistentry id="guc-log-statement" xreflabel="log_statement">
> !       <term><varname>log_statement</varname> (<type>string</type>)</term>
>         <listitem>
>          <para>
> !         Controls which SQL statement are logged. Valid values are
> !         <literal>all</>, <literal>ddl</>, <literal>mod</>, and
> !         <literal>none</>. <literal>ddl</> logs all data definition
> !         commands like <literal>CREATE</>, <literal>ALTER</>, and
> !         <literal>DROP</> commands. <literal>mod</> logs all
> !         <literal>ddl</> statements, plus <literal>INSERT</>,
> !         <literal>UPDATE</>, <literal>DELETE</>, <literal>TRUNCATE</>,
> !         and <literal>COPY FROM</>. <literal>PREPARE</> and
> !         <literal>EXPLAIN ANALYZE</> statements are also considered for
> !         appropriate commands. The default is <literal>none</>. Only
> !         superusers can reduce the detail of this option if it has been
> !         set by an administrator.
>          </para>
>
>          <note>
> Index: src/backend/tcop/postgres.c
> ===================================================================
> RCS file: /cvsroot/pgsql-server/src/backend/tcop/postgres.c,v
> retrieving revision 1.397
> diff -c -c -r1.397 postgres.c
> *** src/backend/tcop/postgres.c    24 Mar 2004 22:40:29 -0000    1.397
> --- src/backend/tcop/postgres.c    6 Apr 2004 03:56:11 -0000
> ***************
> *** 87,92 ****
> --- 87,94 ----
>   /* flag for logging end of session */
>   bool        Log_disconnections = false;
>
> + LogStmtLevel log_statement = LOGSTMT_NONE;
> +
>   /*
>    * Flags for expensive function optimization -- JMH 3/9/92
>    */
> ***************
> *** 471,479 ****
>   List *
>   pg_parse_query(const char *query_string)
>   {
> !     List       *raw_parsetree_list;
>
> !     if (log_statement)
>           ereport(LOG,
>                   (errmsg("statement: %s", query_string)));
>
> --- 473,482 ----
>   List *
>   pg_parse_query(const char *query_string)
>   {
> !     List       *raw_parsetree_list,
> !                *parsetree_item;
>
> !     if (log_statement == LOGSTMT_ALL)
>           ereport(LOG,
>                   (errmsg("statement: %s", query_string)));
>
> ***************
> *** 482,487 ****
> --- 485,535 ----
>
>       raw_parsetree_list = raw_parser(query_string);
>
> +     /* do log_statement tests for mod and ddl */
> +     if (log_statement == LOGSTMT_MOD ||
> +         log_statement == LOGSTMT_DDL)
> +     {
> +         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))
> +                 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 */
> +             {
> +                 ereport(LOG,
> +                         (errmsg("statement: %s", query_string)));
> +                 break;
> +             }
> +             commandTag = CreateCommandTag(parsetree);
> +             if (strncmp(commandTag, "CREATE ", strlen("CREATE ")) == 0 ||
> +                 strncmp(commandTag, "ALTER ", strlen("ALTER ")) == 0 ||
> +                 strncmp(commandTag, "DROP ", strlen("DROP ")) == 0 ||
> +                 IsA(parsetree, GrantStmt) ||    /* GRANT or REVOKE */
> +                 IsA(parsetree, CommentStmt))
> +             {
> +                 ereport(LOG,
> +                         (errmsg("statement: %s", query_string)));
> +                 break;
> +             }
> +         }
> +     }
> +
>       if (log_parser_stats)
>           ShowUsage("PARSER STATISTICS");
>
> ***************
> *** 2488,2494 ****
>           SetConfigOption("log_disconnections", "true", debug_context, gucsource);
>       }
>       if (debug_flag >= 2)
> !         SetConfigOption("log_statement", "true", debug_context, gucsource);
>       if (debug_flag >= 3)
>           SetConfigOption("debug_print_parse", "true", debug_context, gucsource);
>       if (debug_flag >= 4)
> --- 2536,2542 ----
>           SetConfigOption("log_disconnections", "true", debug_context, gucsource);
>       }
>       if (debug_flag >= 2)
> !         SetConfigOption("log_statement", "all", debug_context, gucsource);
>       if (debug_flag >= 3)
>           SetConfigOption("debug_print_parse", "true", debug_context, gucsource);
>       if (debug_flag >= 4)
> Index: src/backend/utils/misc/guc.c
> ===================================================================
> RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/guc.c,v
> retrieving revision 1.197
> diff -c -c -r1.197 guc.c
> *** src/backend/utils/misc/guc.c    5 Apr 2004 03:02:07 -0000    1.197
> --- src/backend/utils/misc/guc.c    6 Apr 2004 03:56:14 -0000
> ***************
> *** 86,103 ****
>                   bool doit, GucSource source);
>   #endif
>
> ! static const char *assign_defaultxactisolevel(const char *newval,
> !                            bool doit, GucSource source);
> ! static const char *assign_log_min_messages(const char *newval,
> !                         bool doit, GucSource source);
>   static const char *assign_client_min_messages(const char *newval,
>                              bool doit, GucSource source);
>   static const char *assign_min_error_statement(const char *newval, bool doit,
>                              GucSource source);
> ! static const char *assign_msglvl(int *var, const char *newval,
> !               bool doit, GucSource source);
>   static const char *assign_log_error_verbosity(const char *newval, bool doit,
>                              GucSource source);
>   static bool assign_phony_autocommit(bool newval, bool doit, GucSource source);
>
>
> --- 86,107 ----
>                   bool doit, GucSource source);
>   #endif
>
> ! static const char *assign_defaultxactisolevel(const char *newval, bool doit,
> !                            GucSource source);
> ! static const char *assign_log_min_messages(const char *newval, bool doit,
> !                            GucSource source);
>   static const char *assign_client_min_messages(const char *newval,
>                              bool doit, GucSource source);
>   static const char *assign_min_error_statement(const char *newval, bool doit,
>                              GucSource source);
> ! static const char *assign_msglvl(int *var, const char *newval, bool doit,
> !                            GucSource source);
>   static const char *assign_log_error_verbosity(const char *newval, bool doit,
>                              GucSource source);
> + static const char *assign_log_statement(const char *newval, bool doit,
> +                            GucSource source);
> + static const char *assign_log_stmtlvl(int *var, const char *newval,
> +                            bool doit, GucSource source);
>   static bool assign_phony_autocommit(bool newval, bool doit, GucSource source);
>
>
> ***************
> *** 107,113 ****
>   #ifdef USE_ASSERT_CHECKING
>   bool        assert_enabled = true;
>   #endif
> - bool        log_statement = false;
>   bool        log_duration = false;
>   bool        Debug_print_plan = false;
>   bool        Debug_print_parse = false;
> --- 111,116 ----
> ***************
> *** 145,150 ****
> --- 148,154 ----
>   static char *client_min_messages_str;
>   static char *log_min_messages_str;
>   static char *log_error_verbosity_str;
> + static char *log_statement_str;
>   static char *log_min_error_statement_str;
>   static char *log_destination_string;
>   static bool phony_autocommit;
> ***************
> *** 528,541 ****
>           false, NULL, NULL
>       },
>       {
> -         {"log_statement", PGC_USERLIMIT, LOGGING_WHAT,
> -             gettext_noop("Logs each SQL statement."),
> -             NULL
> -         },
> -         &log_statement,
> -         false, NULL, NULL
> -     },
> -     {
>           {"log_duration", PGC_USERLIMIT, LOGGING_WHAT,
>               gettext_noop("Logs the duration each completed SQL statement."),
>               NULL
> --- 532,537 ----
> ***************
> *** 1442,1447 ****
> --- 1438,1451 ----
>           &log_error_verbosity_str,
>           "default", assign_log_error_verbosity, NULL
>       },
> +     {
> +         {"log_statement", PGC_USERLIMIT, LOGGING_WHAT,
> +             gettext_noop("Sets the type of statements logged."),
> +             gettext_noop("Valid values are \"none\", \"mod\", \"ddl\", and \"all\".")
> +         },
> +         &log_statement_str,
> +         "none", assign_log_statement, NULL
> +     },
>
>       {
>           {"log_min_error_statement", PGC_USERLIMIT, LOGGING_WHEN,
> ***************
> *** 2007,2020 ****
>                       struct config_string *conf = (struct config_string *) gconf;
>                       char       *str;
>
> !                     /*
> !                      * Check to make sure we only have valid
> !                      * PGC_USERLIMITs
> !                      */
>                       Assert(conf->gen.context != PGC_USERLIMIT ||
>                              conf->assign_hook == assign_log_min_messages ||
> !                        conf->assign_hook == assign_client_min_messages ||
> !                         conf->assign_hook == assign_min_error_statement);
>                       *conf->variable = NULL;
>                       conf->reset_val = NULL;
>                       conf->session_val = NULL;
> --- 2011,2021 ----
>                       struct config_string *conf = (struct config_string *) gconf;
>                       char       *str;
>
> !                     /* Check to make sure we only have valid PGC_USERLIMITs */
>                       Assert(conf->gen.context != PGC_USERLIMIT ||
>                              conf->assign_hook == assign_log_min_messages ||
> !                            conf->assign_hook == assign_min_error_statement ||
> !                            conf->assign_hook == assign_log_statement);
>                       *conf->variable = NULL;
>                       conf->reset_val = NULL;
>                       conf->session_val = NULL;
> ***************
> *** 3025,3039 ****
>                       if (record->context == PGC_USERLIMIT &&
>                           IsUnderPostmaster && !superuser())
>                       {
> !                         int            old_int_value,
> !                                     new_int_value;
>
> !                         /* all USERLIMIT strings are message levels */
> !                         assign_msglvl(&new_int_value, newval,
> !                                       true, source);
> !                         assign_msglvl(&old_int_value, conf->reset_val,
> !                                       true, source);
> !                         if (new_int_value > old_int_value)
>                           {
>                               /* Limit non-superuser changes */
>                               if (source > PGC_S_UNPRIVILEGED)
> --- 3026,3048 ----
>                       if (record->context == PGC_USERLIMIT &&
>                           IsUnderPostmaster && !superuser())
>                       {
> !                         int        var_value, reset_value, new_value;
> !                         const char * (*var_hook) (int *var, const char *newval,
> !                                     bool doit, GucSource source);
> !
> !                         if (conf->assign_hook == assign_log_statement)
> !                             var_hook = assign_log_stmtlvl;
> !                         else
> !                             var_hook = assign_msglvl;
> !
> !                         (*var_hook) (&new_value, newval, true, source);
> !                         (*var_hook) (&reset_value, conf->reset_val,    true,
> !                                      source);
> !                         (*var_hook) (&var_value, *conf->variable, true,
> !                                      source);
>
> !                         /* Limit non-superuser changes */
> !                         if (new_value > reset_value)
>                           {
>                               /* Limit non-superuser changes */
>                               if (source > PGC_S_UNPRIVILEGED)
> ***************
> *** 3046,3055 ****
>                                   return false;
>                               }
>                           }
> !                             /* Allow change if admin should override */
> !                         assign_msglvl(&old_int_value, *conf->variable,
> !                                       true, source);
> !                         if (new_int_value < old_int_value)
>                           {
>                               if (source < PGC_S_UNPRIVILEGED &&
>                                   record->source > PGC_S_UNPRIVILEGED)
> --- 3055,3063 ----
>                                   return false;
>                               }
>                           }
> !
> !                         /* Allow change if admin should override */
> !                         if (new_value < var_value)
>                           {
>                               if (source < PGC_S_UNPRIVILEGED &&
>                                   record->source > PGC_S_UNPRIVILEGED)
> ***************
> *** 4646,4651 ****
> --- 4654,4693 ----
>       {
>           if (doit)
>               Log_error_verbosity = PGERROR_VERBOSE;
> +     }
> +     else
> +         return NULL;            /* fail */
> +     return newval;                /* OK */
> + }
> +
> + static const char *
> + assign_log_statement(const char *newval, bool doit, GucSource source)
> + {
> +     return (assign_log_stmtlvl((int *)&log_statement, newval, doit, source));
> + }
> +
> + static const char *
> + assign_log_stmtlvl(int *var, const char *newval, bool doit, GucSource source)
> + {
> +     if (strcasecmp(newval, "none") == 0)
> +     {
> +         if (doit)
> +             (*var) = LOGSTMT_NONE;
> +     }
> +     else if (strcasecmp(newval, "mod") == 0)
> +     {
> +         if (doit)
> +             (*var) = LOGSTMT_MOD;
> +     }
> +     else if (strcasecmp(newval, "ddl") == 0)
> +     {
> +         if (doit)
> +             (*var) = LOGSTMT_DDL;
> +     }
> +     else if (strcasecmp(newval, "all") == 0)
> +     {
> +         if (doit)
> +             (*var) = LOGSTMT_ALL;
>       }
>       else
>           return NULL;            /* fail */
> Index: src/backend/utils/misc/postgresql.conf.sample
> ===================================================================
> RCS file: /cvsroot/pgsql-server/src/backend/utils/misc/postgresql.conf.sample,v
> retrieving revision 1.112
> diff -c -c -r1.112 postgresql.conf.sample
> *** src/backend/utils/misc/postgresql.conf.sample    5 Apr 2004 03:02:08 -0000    1.112
> --- src/backend/utils/misc/postgresql.conf.sample    6 Apr 2004 03:56:14 -0000
> ***************
> *** 191,197 ****
>                   # %s=session start timestamp
>                   # %x=stop here in non-session processes
>                   # %%='%'
> ! #log_statement = false
>   #log_hostname = false
>
>
> --- 191,197 ----
>                   # %s=session start timestamp
>                   # %x=stop here in non-session processes
>                   # %%='%'
> ! #log_statement = 'none'        # none, mod, ddl, all
>   #log_hostname = false
>
>
> Index: src/include/tcop/tcopprot.h
> ===================================================================
> RCS file: /cvsroot/pgsql-server/src/include/tcop/tcopprot.h,v
> retrieving revision 1.63
> diff -c -c -r1.63 tcopprot.h
> *** src/include/tcop/tcopprot.h    24 Mar 2004 22:40:29 -0000    1.63
> --- src/include/tcop/tcopprot.h    6 Apr 2004 03:56:14 -0000
> ***************
> *** 35,40 ****
> --- 35,53 ----
>   extern char *rendezvous_name;
>   extern int    max_stack_depth;
>
> + /* GUC-configurable parameters */
> +
> + typedef enum
> + {
> +     /* Reverse order so GUC USERLIMIT is easier */
> +     LOGSTMT_ALL = 0,            /* log all statements, can not be -1 */
> +     LOGSTMT_DDL,                /* log data definition statements */
> +     LOGSTMT_MOD,                /* log modification statements, plus DDL */
> +     LOGSTMT_NONE                /* log no statements */
> + } LogStmtLevel;
> +
> + extern LogStmtLevel log_statement;
> +
>   #ifndef BOOTSTRAP_INCLUDE
>
>   extern List *pg_parse_and_rewrite(const char *query_string,
> Index: src/include/utils/guc.h
> ===================================================================
> RCS file: /cvsroot/pgsql-server/src/include/utils/guc.h,v
> retrieving revision 1.44
> diff -c -c -r1.44 guc.h
> *** src/include/utils/guc.h    19 Jan 2004 19:04:40 -0000    1.44
> --- src/include/utils/guc.h    6 Apr 2004 03:56:15 -0000
> ***************
> *** 103,109 ****
>   } GucSource;
>
>   /* GUC vars that are actually declared in guc.c, rather than elsewhere */
> - extern bool log_statement;
>   extern bool log_duration;
>   extern bool Debug_print_plan;
>   extern bool Debug_print_parse;
> --- 103,108 ----

>
> ---------------------------(end of broadcast)---------------------------
> TIP 7: don't forget to increase your free space map settings

--
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

pgsql-patches by date:

Previous
From: Dan Graham
Date:
Subject: LIKE vs regex queries
Next
From: Ludek Finstrle
Date:
Subject: Re: WIN32 psql Ctrl+C support