Re: autovacuum hung?

Tom Lane [tgl(at)sss(dot)pgh(dot)pa(dot)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(at)rdl64xeoserv01 log]# strace -p 8818 -o /tmp/strace.log
Process 8818 attached - interrupt to quit
Process 8818 detached
[root(at)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