Is it possible to get the full log/DBMSOutput from failed Postgres procs?

Many of my stored procedures are doing ETL style transformation. As such it is important to see the full series of debug messaging on procedure failure during development to see what the heck happened. I don't know if this is possible but can we get the full log/DBMS output for failed procedures in Postgres (currently only the final exception/DBMSError is returned).

Hi Shaun, Can you please clarify a bit. Are you using some standard PostgreSQL logging procedure in your stored procedures, and it is this log output you want to see? Can you please give a simple example? Best Regards, Hans

Correct. I'm using standard postgres RAISE INFO commands to log where I am at and other information for debug. During successful execution I get the full log output (such as below), but if the procedure fails I only get the final SQLERROR message: SUCCESS OUTPUT: 15:02:49 [SELECT - 1 row(s), 277.024 secs] Result set fetched Code: 0 SQL State: 00000 --- 2012-12-04 20:58:12.652871+00 : START usp_pop_raw_mp_order_attr Code: 0 SQL State: 00000 --- Processing raw_mp_order_attr for requested date range: 2012-04-01 to 2012-06-30 Code: 0 SQL State: 00000 --- Processing raw_mp_order_attr for date range: 2012-04-01 to 2012-06-30 Code: 0 SQL State: 00000 --- No new partitions needed. Code: 0 SQL State: 00000 --- Created 0 new partitions. Code: 0 SQL State: 00000 --- Creating order input table Code: 0 SQL State: 00000 --- table "raw_mp_order_trans_temp" does not exist, skipping Code: 0 SQL State: 00000 --- table "order_trans_temp" does not exist, skipping Code: 0 SQL State: 00000 --- 2012-12-04 20:58:41.558373+00 : Temp table created : order_trans_temp : Number of Rows: 2325016 : Elapsed Time : 00:00:19.934823 Code: 0 SQL State: 00000 --- table "order_trans_master_profile_temp" does not exist, skipping Code: 0 SQL State: 00000 --- 2012-12-04 20:58:52.329795+00 : Temp table created : order_trans_master_profile_temp : Number of Rows: 2318798 : Elapsed Time : 00:00:05.304842 Code: 0 SQL State: 00000 --- 2012-12-04 20:58:55.143809+00 : MP Order eligible rows inserted : raw_mp_order_trans_temp : Number of Rows: 1932349 : Elapsed Time : 00:00:02.341535 Code: 0 SQL State: 00000 --- 2012-12-04 20:59:12.669978+00: Creating impression input table Code: 0 SQL State: 00000 --- Running attribution proc: usp_pop_raw_mp_order_attr_001_last_touch Code: 0 SQL State: 00000 --- table "msg_cmpgn_type_90_days_temp" does not exist, skipping Code: 0 SQL State: 00000 --- Temp table msg_cmpgn_type_90_days_temp created. Number of Rows: 400775 Code: 0 SQL State: 00000 --- table "order_attr_temp" does not exist, skipping Code: 0 SQL State: 00000 --- Temp table order_attr_temp created. Number of Rows: 1932349 Code: 0 SQL State: 00000 --- Temp table raw_mp_order_attr_temp created. Number of rows: 21831 Code: 0 SQL State: 00000 --- raw_mp_order_attr_temp: Number of rows inserted: 224016 Code: 0 SQL State: 00000 --- raw_order_attr_temp: Number of rows inserted: 6814 Code: 0 SQL State: 00000 --- Inserted data to date: 2012-12-03 - Number of Rows: 6814 Code: 0 SQL State: 00000 --- Backing up other companies data Code: 0 SQL State: 00000 --- Backup appended. Retained raw mp order attribution number of rows: 21823380 ... 1 statement(s) executed, 1 row(s) affected, exec/fetch time: 277.024/0.000 sec [1 successful, 0 warnings, 0 errors] FAIL OUTPUT (all other logging doesn't show up): 15:05:46 [SELECT - 0 row(s), 0.000 secs] [Error Code: 0, SQL State: P0001] ERROR: Error during transaction of raw_mp_order_attr start date end date 2012-06-30. Error code raised P0001. Description: Error: Invalid force flag specified: 3

Hi Shaun, Thanks for the clarification. I'll have a look at it. Best Regards, Hans

Hi Shaun, I believe I have a solution for this, to be included in the next maintenance release. You ail then get something like this for a failure: 15:05:46 [SELECT - 0 row(s), 0.000 secs] [Error Code: 0, SQL State: P0001] ERROR: Error during transaction of raw_mp_order_attr start date end date 2012-06-30. Error code raised P0001. Description: Error: Invalid force flag specified: 3 Code: 0 SQL State: 00000 --- 2012-12-04 20:58:12.652871+00 : START usp_pop_raw_mp_order_attr Code: 0 SQL State: 00000 --- Processing raw_mp_order_attr for requested date range: 2012-04-01 to 2012-06-30 Code: 0 SQL State: 00000 --- Processing raw_mp_order_attr for date range: 2012-04-01 to 2012-06-30 Code: 0 SQL State: 00000 --- No new partitions needed. Code: 0 SQL State: 00000 --- Created 0 new partitions. Code: 0 SQL State: 00000 --- Creating order input table Code: 0 SQL State: 00000 --- table "raw_mp_order_trans_temp" does not exist, skipping ... 1 statement(s) executed, 1 row(s) affected, exec/fetch time: 277.024/0.000 sec [1 successful, 0 warnings, 0 errors] In other words, the ERROR line will be followed by all output produced by RAISE INFO upto the point where RAISE EXCEPTION is called. I hope this is what you're looking for. Best Regards, Hans

perfect

Awesome. Thanks for the quick response.