Re: autovacuum hung? - Mailing list pgsql-performance

Tom Lane [tgl@sss.pgh.pa.us] wrote:
> Oh, and don't forget the more-complete pg_locks state.  We'll want all
> the columns of pg_locks, not just the ones you showed before.
auto vacuum of ts_user_sessions_map has been running for > 17 hours.
This table has 2,204,488 rows. I hope that I've captured enough info.

Thanks,
Brian


cemdb=# select procpid,current_query,query_start from pg_stat_activity;
  procpid |                          current_query
     |          query_start
---------+-----------------------------------------------------------------+-------------------------------
     8817 | <IDLE>
     | 2009-07-09 16:48:12.656419-07
     8818 | autovacuum: VACUUM public.ts_user_sessions_map
     | 2009-07-09 16:48:18.873677-07


cemdb=# select
l.pid,c.relname,l.mode,l.granted,l.virtualxid,l.virtualtransaction from
pg_locks l left outer join pg_class c on c.oid=l.relation order by l.pid;
   pid  |                  relname                   |           mode
         | granted | virtualxid | virtualtransaction

-------+--------------------------------------------+--------------------------+---------+------------+--------------------

  8818 | ts_user_sessions_map_interimsessionidindex | RowExclusiveLock
        | t       |            | 2/3
   8818 | ts_user_sessions_map_appindex              | RowExclusiveLock
         | t       |            | 2/3
   8818 | ts_user_sessions_map_sessionidindex        | RowExclusiveLock
         | t       |            | 2/3
   8818 | ts_user_sessions_map                       |
ShareUpdateExclusiveLock | t       |            | 2/3
   8818 |                                            | ExclusiveLock
         | t       | 2/3        | 2/3
   8818 | ts_user_sessions_map_pkey                  | RowExclusiveLock
         | t       |            | 2/3
  13706 |                                            | ExclusiveLock
         | t       | 6/50       | 6/50
  13706 | pg_class_oid_index                         | AccessShareLock
         | t       |            | 6/50
  13706 | pg_class_relname_nsp_index                 | AccessShareLock
         | t       |            | 6/50
  13706 | pg_locks                                   | AccessShareLock
         | t       |            | 6/50
  13706 | pg_class                                   | AccessShareLock
         | t       |            | 6/50
(11 rows)


[root@rdl64xeoserv01 log]# strace -p 8818 -o /tmp/strace.log
Process 8818 attached - interrupt to quit
Process 8818 detached
[root@rdl64xeoserv01 log]# more /tmp/strace.log
select(0, NULL, NULL, NULL, {0, 13000}) = 0 (Timeout)
read(36, "`\0\0\0\370\354\250u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0\340\f\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\300,\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0(L\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0\264"...,
8192) = 8192
read(36, "`\0\0\0|M\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0\264"...,
8192) = 8192
read(36, "`\0\0\0\\~\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0\264"...,
8192) = 8192
read(36, "`\0\0\0D\234\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\34\255\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\4\315\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\234\2334x\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\354\354\251u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0\324\f\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\274,\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\244L\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0008^\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0,\233\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\370\330\252u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0000\371\252u\1\0\0\0\34\0\270\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\364\30\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\2448\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
select(0, NULL, NULL, NULL, {0, 20000}) = 0 (Timeout)
read(36, "`\0\0\0dX\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0\264"...,
8192) = 8192
read(36, "`\0\0\0X\216\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\10\256\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\300\315\253u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0\304\f\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\354=\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\254]\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0d}\254u\1\0\0\0\34\0\270\37\360\37\4 \0\0\0\0\270"...,
8192) = 8192
read(36, "`\0\0\0\24\235\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\314\274\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0\314\330\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0"...,
8192) = 8192
read(36, "`\0\0\0X\354\254u\1\0\0\0\34\0\264\37\360\37\4 \0\0\0\0"...,
8192) = 8192
read(36, "`\0\0\0\350\253\30x\1\0\0\0\34\0\264\37\360\37\4 \0\0\0"...,
8192) = 8192
_llseek(36, 1068474368, [1068474368], SEEK_SET) = 0
read(36, "`\0\0\0\350\253\30x\1\0\0\0\24\1h\21\360\37\4 \0\0\0\0"...,
8192) = 8192
_llseek(36, 1068220416, [1068220416], SEEK_SET) = 0
read(36, "`\0\0\0P\356\254u\1\0\0\0\34\0\270\37\360\37\4 \0\0\0\0"...,
8192) = 8192