RE: [EXT] Re: log_min_messages = warning

> "Dirschel, Steve" <steve.dirschel@thomsonreuters.com> writes:
>>  setdatabase | setrole |
                                            setconfig 

>> -------------+---------+----------------------------------------------
>> -------------+---------+----------------------------------------------
>> -------------+---------+----------------------------------------------
>> -------------+---------+----------------------------------------------
>> -------------+---------+--
>> ----------------------------------------------------------------------------------------------------
>>        16401 |       0 | {auto_explain.log_min_duration=-1}
>>        16401 |      10 | {log_min_messages=panic}
>>        16436 |       0 | {TimeZone=America/Chicago}
>>            0 |      10 |
{TimeZone=utc,log_statement=all,log_min_error_statement=debug5,log_min_messages=panic,exit_on_error=0,statement_timeout=0,role=rdsadmin,auto_explain.log_min_duration=-1,temp_file_limit=
>> -1,"search_path=pg_catalog,
>> public",pg_hint_plan.enable_hint=off,default_transaction_read_only=off
>> }
>> (4 rows)

>> If I login to the shgroup02s database as postgres user (using psql)
>> and interactively call a procedure that cron calls which causes the
>> RAISE NOTICE commands to be written to the log they do NOT get written
>> to the log when I call the procedure.  The messages will be displayed
>> on my screen but I don't see them getting written to the log.

>You've evidently done "ALTER USER postgres SET log_min_messages=panic", so the lack of any messages under that userid
isunsurprising.  But we're not a lot closer to being sure why it's different for the procedures' normal execution
environment.

>At this point it's hard to avoid the conclusion that those procedures'
>session is changing the value itself.  (This is scary, because it implies that you're running those as superuser,
whichseems like a bad idea.) You might have to enable log_statement = all to verify that. 

>            regards, tom lane

I appreciate your feedback Tom.  To simplify this I created this procedure:

create or replace procedure part.test1()
 LANGUAGE plpgsql
 AS $$
 DECLARE

BEGIN

raise notice '***** raise notice test *****';

END $$;

If I call that through PSQL this is returned to my screen:

shgroup02s=> call part.test1();
NOTICE:  ***** raise notice test *****
CALL

And if I monitor the log file nothing is written to it.  But if I schedule that procedure through pg_cron:

SELECT cron.schedule('Minute test', '* * * * *', 'call part.test1()');

If I monitor the log file I see it writing this to the log-  it actually writes it out 2 times:

2022-09-07 12:54:33 UTC::@:[21535]:LOG: cron job 6: NOTICE: ***** raise notice test *****
CONTEXT: PL/pgSQL function part.test1() line 6 at RAISE
2022-09-07 12:54:33 UTC::@:[21535]:LOG: cron job 6: NOTICE: ***** raise notice test *****
CONTEXT: PL/pgSQL function part.test1() line 6 at RAISE

If I create another test procedure:

create or replace procedure part.test2()
 LANGUAGE plpgsql
 AS $$
 DECLARE

BEGIN

raise exception '***** raise ERROR test *****';

END $$;

When I execute that through PSQL this is returned:

shgroup02s=> call part.test2();
ERROR:  ***** raise ERROR test *****

And in the log file I see this written:

2022-09-07 12:58:00 UTC:10.210.119.217(42434):postgres@shgroup02s:[15409]:ERROR: ***** raise ERROR test *****
2022-09-07 12:58:00 UTC:10.210.119.217(42434):postgres@shgroup02s:[15409]:CONTEXT: PL/pgSQL function part.test2() line
6at RAISE 
2022-09-07 12:58:00 UTC:10.210.119.217(42434):postgres@shgroup02s:[15409]:STATEMENT: call part.test2();

So the raise exception gets written to the log file when I execute it through PSQL which I believe is expected.

I believe this clearly points to an issue with pg_cron.  Would you agree?

Regards
Steve