pg_cron on Aurora cluster strange output
- Dominant language
- C
- Stars
- 3.9k
- Forks
- 260
- Avg merge
- 5d 5h
- Merged PRs (30d)
- 1
Description
AWS Aurora Postresql pg_cron v1.4
I have an anonymous block where I call multiple procedures:
```
select cron.schedule ('load_asrs_snapshot','00 02 10 * *',$command$ do
$$
begin
call asrs_ga_supplement.ingest_asrs_ga_supplement_data();
call asrs_public.ingest_asrs_public_data();
end $$; $command$);
update cron.job
set database = 'feeds',
username = 'asrs'
where jobname = 'load_asrs_snapshot';
commit;
```
If I run the "command" outside of pg_cron, from psql, in the 'feeds' database as role 'asrs' I get something like this output:
```
feeds=> do
all asrsfeeds-> $$
feeds$> begin
feeds$> call asrs_ga_supplement.ingest_asrs_ga_supplement_data();
feeds$> call asrs_public.ingest_asrs_public_data();
feeds$> end $$;
INFO: analyzing "pg_temp_53.temp_all_items"
INFO: "temp_all_items": scanned 17278 of 17278 pages, containing 1546803 live rows and 0 dead rows; 30000 rows in sample, 1546803 estimated total rows
NOTICE: Table asrs_ga_supplement.all_items Rows Inserted: 1546803
NOTICE: Total load time: 00:02:19.303253
INFO: analyzing "pg_temp_53.temp_text"
INFO: "temp_text": scanned 7367 of 7367 pages, containing 57816 live rows and 0 dead rows; 30000 rows in sample, 57816 estimated total rows
NOTICE: Table asrs_ga_supplement.text Rows Inserted: 57816
NOTICE: Total load time: 00:00:18.410682
INFO: analyzing "pg_temp_53.temp_all_items"
INFO: "temp_all_items": scanned 30000 of 111057 pages, containing 2829978 live rows and 0 dead rows; 30000 rows in sample, 10476296 estimated total rows
NOTICE: Table asrs_public.all_items Rows Inserted: 10423030
NOTICE: Total load time: 00:18:05.223828
INFO: analyzing "pg_temp_53.temp_text"
INFO: "temp_text": scanned 30000 of 40242 pages, containing 350886 live rows and 0 dead rows; 30000 rows in sample, 470678 estimated total rows
NOTICE: Table asrs_public.text Rows Inserted: 469961
NOTICE: Total load time: 00:01:42.627377
DO
```
If I allow pg_cron to run this, I get in the postgresql log, in cloudwatch, abbreviated:
```
...
2023-03-08 14:17:22 UTC::@:[13556]:LOG: cron job 100: INFO: analyzing "pg_temp_51.temp_all_items" CONTEXT: SQL statement "ANALYZE VERBOSE temp_all_items" PL/pgSQL function ingest_asrs_ga_supplement_data() line 20 at SQL statement SQL statement "CALL asrs_ga_supplement.ingest_asrs_ga_supplement_data()" PL/pgSQL function inline_code_block line 3 at CALL
--
2023-03-08 14:17:22 UTC::@:[13556]:LOG: cron job 100: INFO: "temp_all_items": scanned 17278 of 17278 pages, containing 1546803 live rows and 0 dead rows; 30000 rows in sample, 1546803 estimated total rows CONTEXT: SQL statement "ANALYZE VERBOSE temp_all_items" PL/pgSQL function ingest_asrs_ga_supplement_data() line 20 at SQL statement SQL statement "CALL asrs_ga_supplement.ingest_asrs_ga_supplement_data()" PL/pgSQL function inline_code_block line 3 at CALL
2023-03-08 14:18:16 UTC::@:[13556]:LOG: cron job 100: NOTICE: Table asrs_ga_supplement.all_items Rows Inserted: 1546803 CONTEXT: PL/pgSQL function ingest_asrs_ga_supplement_data() line 36 at RAISE SQL statement "CALL asrs_ga_supplement.ingest_asrs_ga_supplement_data()" PL/pgSQL function inline_code_block line 3 at CALL
2023-03-08 14:18:16 UTC::@:[13556]:LOG: cron job 100: NOTICE: Total load time: 00:03:16.051938 CONTEXT: PL/pgSQL function ingest_asrs_ga_supplement_data() line 54 at RAISE SQL statement "CALL asrs_ga_supplement.ingest_asrs_ga_supplement_data()" PL/pgSQL function inline_code_block line 3 at CALL
...
```
It appears to be adding to the output a 'CONTEXT' error somehow. I have exception handling in each procedure and it never gets hit even when run from pg_cron.
Why am I getting this logging to the postgresql log? Any ideas?
Contributor guide
No contributing guide indexed for this repository
Assessment
This issue has not been assessed yet.