HiveBrain v1.2.0
Get Started
← Back to all entries
snippetsqlMinor

How to log DML statements executed by a pl/pgsql function?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
logstatementsfunctionexecuteddmlpgsqlhow

Problem

I have a pl/pgsql function (see below) that lists some fields and clears their contents using dynamically constructed UPDATE commands.

When I set log_statement = 'mod', I can see nothing on the log upon execution of the function with SELECT fnct_clear_temp_fields();.
When I set log_statement = 'all', and execute the function I can see SELECT fnct_clear_temp_fields(); in the log, but not the underlying UPDATE commands.

Is there a way to have the UPDATE commands appear in the log as well ?

For info, here is the function:

CREATE OR REPLACE FUNCTION fnct_clear_temp_fields() RETURNS VOID AS $
DECLARE
    --Put into a cursor a view dynamically listing all user-defined fields beginning with 'temp_'
    dataset_1 CURSOR FOR 
        SELECT 
            column_name,
            table_name
        FROM information_schema.tables 
        NATURAL JOIN information_schema.columns 
        WHERE 
            table_schema='public'
            AND table_type='BASE TABLE'
            AND column_name ~ '^temp_'
        ORDER BY table_name,column_name;

    --Record variable to go through each line of the view above
    dataset_1_row RECORD;

BEGIN
    OPEN dataset_1; --Open the cursor
    FETCH dataset_1 INTO dataset_1_row; --first row of the view

    WHILE FOUND LOOP
        RAISE NOTICE 'Table: %, Column: %',  dataset_1_row.table_name,dataset_1_row.column_name;

        --Set to NULL the contents of the current 'temp_' column
        EXECUTE 'UPDATE '||dataset_1_row.table_name||' SET '||dataset_1_row.column_name||'=NULL WHERE '||dataset_1_row.column_name||' IS NOT NULL';

        FETCH dataset_1 INTO dataset_1_row; --next row please.
    END LOOP; --while end

    CLOSE dataset_1;

    RETURN;
END;
$ LANGUAGE plpgsql;

Solution

Question asked

There is a built-in way to log statements inside PL/pgSQL functions: auto-explain

LOAD 'auto_explain';
SET auto_explain.log_min_duration = 1;  -- exclude very fast trivial queries
SET auto_explain.log_nested_statements = ON;  -- statements inside functions


See:

  • Get query plan for SQL statement nested in a PL/pgSQL function



Potentially generates a lot of log output. Only use it for debugging, not in production.

If you just need the one statement logged, go with @dezso's advice.
Code audit

CREATE OR REPLACE FUNCTION fnct_clear_temp_fields()
  RETURNS void
  LANGUAGE plpgsql AS
$func$
DECLARE
   rec record;
   qry text;
BEGIN
   FOR rec IN
      SELECT quote_ident(c.relname) AS tbl, quote_ident(a.attname) AS col
      FROM   pg_namespace n
      JOIN   pg_class     c ON c.relnamespace = n.oid
      JOIN   pg_attribute a ON a.attrelid = c.oid
      WHERE  n.nspname = 'public'
      AND    c.relkind = 'r'
      AND    a.attname LIKE 'temp_%'  -- LIKE is faster than ~
      AND    a.attnum > 0
      AND    NOT a.attisdropped
      ORDER  BY 1,2
   LOOP

      RAISE NOTICE 'Table: %, Column: %', rec.tbl, rec.col;
      qry := format('UPDATE %1$s SET %2$s = NULL WHERE %2$s IS NOT NULL', rec.tbl, rec.col);
      RAISE LOG 'Query: %', qry;
      EXECUTE qry;

   END LOOP;
END
$func$;


You must sanitize all identifiers concatenated into dynamic SQL, else it can fail with non-standard names that require double-quoting. Worse, you are open to SQL injection.

Demonstrating quote_ident(), since you are using the sanitized identifiers multiple times. There are more options with regclass or format():

  • Table name as a PostgreSQL function parameter



I prefer to base such queries on the system catalog instead of the sometimes slow and convoluted views of the information schema. A question of requirements and personal preference. Demonstrating the equivalent, which is ~ 10 times faster (not regarding UPDATE commands). See:

  • How to check if a table exists in a given schema



LIKE is generally faster than the more powerful regular expression matching (~). If LIKE can do the job, use it.

Related answer with more details:

  • Update record of a cursor where the table name is a parameter

Code Snippets

LOAD 'auto_explain';
SET auto_explain.log_min_duration = 1;  -- exclude very fast trivial queries
SET auto_explain.log_nested_statements = ON;  -- statements inside functions
CREATE OR REPLACE FUNCTION fnct_clear_temp_fields()
  RETURNS void
  LANGUAGE plpgsql AS
$func$
DECLARE
   rec record;
   qry text;
BEGIN
   FOR rec IN
      SELECT quote_ident(c.relname) AS tbl, quote_ident(a.attname) AS col
      FROM   pg_namespace n
      JOIN   pg_class     c ON c.relnamespace = n.oid
      JOIN   pg_attribute a ON a.attrelid = c.oid
      WHERE  n.nspname = 'public'
      AND    c.relkind = 'r'
      AND    a.attname LIKE 'temp_%'  -- LIKE is faster than ~
      AND    a.attnum > 0
      AND    NOT a.attisdropped
      ORDER  BY 1,2
   LOOP

      RAISE NOTICE 'Table: %, Column: %', rec.tbl, rec.col;
      qry := format('UPDATE %1$s SET %2$s = NULL WHERE %2$s IS NOT NULL', rec.tbl, rec.col);
      RAISE LOG 'Query: %', qry;
      EXECUTE qry;

   END LOOP;
END
$func$;

Context

StackExchange Database Administrators Q#71178, answer score: 8

Revisions (0)

No revisions yet.