git.8kb.co.uk Git - postgresql/pg_log_long_xact/blob - README.md

   1 pg_log_long_xact
   2 ================
   3
   4 Pl/pgsql function to log long running transactions in PostgreSQL, can optionally output details of any blocking statements and cancel/terminate problematic statements/transactions.
   5
   6 Schedule with cron or similar if required.
   7
   8 Use the cancel/terminate functionality with care, and see notes about better alternatives for some use cases built into postgres.
   9
  10 Usage
  11 ---------
  12
  13 To simply log long running transactions just call the function passing the shortest duration to start logging at:
  14
  15 ```sql
  16 TEST=# SELECT public.pg_log_long_xact('1s');
  17 NOTICE:  long_xact pid: 4465 duration: 431.325747 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  18 NOTICE:  long_xact pid: 16532 duration: 327.438302 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  19  pg_log_long_xact
  20 ---------------
  21 (0 rows)
  22 ```
  23
  24 To log extra information about locks the long running transactions might be waiting on, supply the second argument as true (although you could log similar information by just enabling log_lock_waits):
  25
  26 ```sql
  27 TEST=# SELECT public.pg_log_long_xact('1s', true);
  28 NOTICE:  long_xact pid: 4465 duration: 471.885373 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  29 NOTICE:  long_xact pid: 16532 duration: 367.997928 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  30 NOTICE:  long_xact waiter pid: 16532 blocker detail is; pid: 4465 duration: 471.885373 ms relation: any (public.balls (RowExclusiveLock)) lock type: transaction id 311824482 user: glyn application: psql client: [local] statement: <IDLE> in transaction
  31  pg_log_long_xact
  32 ---------------
  33 (0 rows)
  34 ```
  35
  36 To set the level of raise used pass a third argument which can be any of 'debug','log','info','notice','warning' or 'text' to output as a text resultset.
  37 (in hindsight the default should probably have been 'log')
  38
  39 ```sql
  40 TEST=# \t off
  41 Showing only tuples.
  42 TEST=# SELECT public.pg_log_long_xact('1s', true, 'text');
  43  long_xact pid: 4465 duration: 574.477076 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  44  long_xact pid: 16532 duration: 470.589631 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  45  long_xact waiter pid: 16532 blocker detail is; pid: 4465 duration: 574.477076 ms relation: any (public.balls (RowExclusiveLock)) lock type: transaction id 311824482 user: glyn application: psql client: [local] statement: <IDLE> in transaction
  46 ```
  47
  48 To make it start cancelling statements exceeding a specific duration we pass a duration as the fourth argument; the first transaction exceeding this will be cancelled
  49 on each run, with blocking statements prioritised.
  50
  51  (As of pg 9.3 there's a lock_timeout parameter that will abort any statement waiting longer than the specified number of milliseconds, which is much better.  Note that the difference here is that this function will attempt to abort the blocking transaction rather than the waiting statement, or if there is no locking just the longest transaction.)
  52
  53 ```sql
  54 TEST=# SELECT public.pg_log_long_xact('1s', true, 'text', '10 minutes');
  55  long_xact pid: 4465 duration: 895.57988 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  56  long_xact unable to cancel backend with pid: 4465
  57  long_xact pid: 16532 duration: 791.692435 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  58  long_xact waiter pid: 16532 blocker detail is; pid: 4465 duration: 895.57988 ms relation: any (public.balls (RowExclusiveLock)) lock type: transaction id 31182
  59 4482 user: glyn application: psql client: [local] statement: <IDLE> in transaction
  60 ```
  61
  62 We can also provide a duration as the fith argument to terminate backends with transactions exceeding this, with prioritisation as per cancelling:
  63
  64 ```sql
  65 TEST=# SELECT public.pg_log_long_xact('1s', true, 'text', '10 minutes', '15 minutes');
  66  long_xact pid: 4465 duration: 1026.90736 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  67  long_xact terminated backend with pid: 4465
  68  long_xact pid: 16532 duration: 923.019915 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  69 ```
  70
  71 By default the function only cancels/terminates the longest running blocker, or longest running transaction, we can be more forceful than that
  72 by passing an extra parameter to tell it to cancel statements/terminate backlends of all long running transactions it finds:
  73
  74 ```sql
  75 TEST=#\t off
  76 TEST=# SELECT public.pg_log_long_xact('1s', true, 'text', '2 minutes', '3 minutes', true);
  77  long_xact pid: 19065 duration: 187.279089 ms user: glyn application: psql client: [local] statement: <IDLE> in transaction
  78  long_xact terminated backend with pid: 19065
  79  long_xact pid: 16532 duration: 184.251569 ms user: glyn application: psql client: [local] statement: UPDATE balls SET description = 'TEST' WHERE id = 5;
  80  long_xact cancelled backend with pid: 16532
  81 (4 rows)
  82 ```