BUG #13472: VACUUM ANALYZE hangs on certain tables

Поиск
Список
Период
Сортировка
От matthew.seaman@adestra.com
Тема BUG #13472: VACUUM ANALYZE hangs on certain tables
Дата
Msg-id 20150626110830.3881.92624@wrigleys.postgresql.org
обсуждение исходный текст
Ответы Re: BUG #13472: VACUUM ANALYZE hangs on certain tables  (Andres Freund <andres@anarazel.de>)
Список pgsql-bugs
Дерево обсуждения 
The following bug has been logged on the website:

Bug reference:      13472
Logged by:          Matthew Seaman
Email address:      matthew.seaman@adestra.com
PostgreSQL version: 9.2.10
Operating system:   FreeBSD 10.1-RELEASE-p9
Description:

We have two tables which we have not been able to vacuum sucessfully on one
of our database servers.  The vacuum process just hangs almost
instantaneously after issuing the 'VACUUM ANALYZE' command.

Here's the result of truss'ing the psql process like so: db-21a:/tmp:# truss
-p 85976 -d -s 128 -f -o /tmp/postgres-vacuum.truss

db-21a:/tmp:# cat postgres-vacuum.truss
85976: -1435316384.769176354 SIGNAL 17 (SIGSTOP)
85976: 3.038535625 recvfrom(10,"Q\0\0\0\^_VACUUM ANALYZE page_tags
;\0",8192,0x0,NULL,0x0) = 32 (0x20)
85976: 3.038826780 open("pg_stat_tmp/pgstat.stat",O_RDONLY,0666) = 21
(0x15)
85976: 3.038891300 fstat(21,{ mode=-rw-------
,inode=7142821,size=862100,blksize=32768 }) = 0 (0x0)
85976: 3.039011646

read(21,"\M^Z\M-<\M-%\^A\M-*\M-}\M-_gh\M-<\^A\0+B\0\0\0\0\0\0#\^U\0\0\0\0\0\0o\M-2\M-\\M^F\0\0\0\0\M-)3;\0\0\0\0\0\M-g\^^`2\0\0\0\0\M-H"...,32768)
= 32768 (0x8000)
85976: 3.040517980 close(21)                     = 0 (0x0)
85976: 3.040590876
sendto(9,"\^A\0\0\0\^P\0\0\0g\M^H\^Xhh\M-<\^A\0",16,0x0,NULL,0x0) = 16
(0x10)
85976: 3.050990883 select(0,0x0,0x0,0x0,{0.010000 }) = 0 (0x0)
85976: 3.051077076 open("pg_stat_tmp/pgstat.stat",O_RDONLY,0666) = 21
(0x15)
85976: 3.051124309 fstat(21,{ mode=-rw-------
,inode=7142808,size=862100,blksize=32768 }) = 0 (0x0)
85976: 3.051211802 read(21,"\M^Z\M-<\M-%\^A\M-z0
hh\M-<\^A\0+B\0\0\0\0\0\0#\^U\0\0\0\0\0\0o\M-2\M-\\M^F\0\0\0\0\M-)3;\0\0\0\0\0\M-g\^^`2\0\0\0\0\M-H\M-V\M^P"...,32768)
= 32768 (0x8000)
85976: 3.052608356 close(21)                     = 0 (0x0)
85976: 3.052693536 open("pg_stat_tmp/pgstat.stat",O_RDONLY,0666) = 21
(0x15)
85976: 3.052743522 fstat(21,{ mode=-rw-------
,inode=7142808,size=862100,blksize=32768 }) = 0 (0x0)
85976: 3.052812245 read(21,"\M^Z\M-<\M-%\^A\M-z0
hh\M-<\^A\0+B\0\0\0\0\0\0#\^U\0\0\0\0\0\0o\M-2\M-\\M^F\0\0\0\0\M-)3;\0\0\0\0\0\M-g\^^`2\0\0\0\0\M-H\M-V\M^P"...,32768)
= 32768 (0x8000)
85976: 3.054225196

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M^D"...,32768)
= 32768 (0x8000)
85976: 3.055429568

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.056594506

read(21,"\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.057768974

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T\M-\\M-v%\0\0\0\0\0K\^B\0\0\0\0\0\0\^F\b\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.058982546

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T1\M-x%\0\0\0\0\0\^D\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.060145744

read(21,"\0O\M^V$\M--\\\M-<\^A\0:\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A\M-?$\M--\\\M-<\^A\0:\0\0\0\0\0\0\0\M-A8z\^S\M-O\M-7\^A"...,32768)
= 32768 (0x8000)
85976: 3.061483712

read(21,"\0\0\0\M-3\^_\0\0\0\0\0\0$\^]\0\0\0\0\0\0\M-e\M-oC\M--\\\M-<\^A\0:\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0@\M-sC\M--\\\M-<"...,32768)
= 32768 (0x8000)
85976: 3.062796877

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M-I\M-V\^P\M-0\\"...,32768)
= 32768 (0x8000)
85976: 3.064062535

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.065262827

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.066425202

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0T\M^@\n\0\0\0\0\0\0\^C\0\0\0\0\0\0\0\^C\0\0\0\0\0\0\0\^C\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.067633907

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T:\^C\0\0\0\0\0\0\^B\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.068792535

read(21,"\^A\08\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0>\M-K"\M-.\\\M-<\^A\08\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T\M^[_&"...,32768)
= 32768 (0x8000)
85976: 3.069993310

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\M-h\M^F\M-,\M--\\\M-<\^A\08\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M-k\M^G\M-,\M--\\\M-<\^A\08\0"...,32768)
= 32768 (0x8000)
85976: 3.071352321

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A\0\0\0\0\0\0\0\t\0\0\0\0\0\0\0\^E\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.072538236

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M^PI\M--\M-."...,32768)
= 32768 (0x8000)
85976: 3.073751354

read(21,"\0\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^A\0\0\0\0\0\0\0\b\0\0"...,32768)
= 32768 (0x8000)
85976: 3.074951546

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.076144411

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T\M-v\^P\M^N\0\0\0\0\0\^A\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.077484792

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0T\M-|\^]\M-!\0\0\0\0\0\M^L"...,32768)
= 32768 (0x8000)
85976: 3.078847630

read(21,"\0\0\0\0\0O"\M-$\M-:\\\M-<\^A\0005\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.080215317

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M-<\M-?}\M-a\\\M-<\^A\0/\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.081569181

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0{\^E\0\0\0\0\0\0B\^D\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 32768 (0x8000)
85976: 3.082836663

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M-_\M-+\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\^RL\0\0\0\0\0\0.\t\0\0\0\0\0\0^\M^N"...,32768)
= 32768 (0x8000)
85976: 3.084285987

read(21,"\0\0\0\0\0v+\^B\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0v+\^B\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\M-v\M-b"...,32768)
= 32768 (0x8000)
85976: 3.085686937

read(21,"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,32768)
= 10132 (0x2794)
85976: 3.086923792 close(21)                     = 0 (0x0)
85976: 3.087002286 lseek(11,0x0,SEEK_END)        = 8192 (0x2000)
85976: 3.087083538 lseek(17,0x0,SEEK_END)        = 483328 (0x76000)
85976: 3.088391400
madvise(0x80507c000,0x1000,0x5,0xaaaaaaaaaaaaaaab,0x805003eb8,0x802759be0) =
0 (0x0)
85976: 3.088444000
madvise(0x805217000,0x8000,0x5,0xaaaaaaaaaaaaaaab,0x805003eb8,0x802759be0) =
0 (0x0)
85976: 3.088511966
madvise(0x8052a1000,0x58000,0x5,0xaaaaaaaaaaaaaaab,0x805003eb8,0x802759be0)
= 0 (0x0)
85976: 3.088565242
madvise(0x805252000,0x2000,0x5,0xaaaaaaaaaaaaaaab,0x7fffffffcd00,0x802759be0)
= 0 (0x0)
85976: 3.088629049
madvise(0x805248000,0xa000,0x5,0xaaaaaaaaaaaaaaab,0x7fffffffcd00,0x802759be0)
= 0 (0x0)
85976: 3.088672235
madvise(0x805254000,0x4000,0x5,0xaaaaaaaaaaaaaaab,0x7fffffffcd00,0x802759be0)
= 0 (0x0)
85976: 3.088742918
madvise(0x805281000,0x20000,0x5,0xaaaaaaaaaaaaaaab,0x7fffffffcd00,0x802759be0)
= 0 (0x0)
85976: 3.088807845
madvise(0x80525f000,0x1c000,0x5,0xaaaaaaaaaaaaaaab,0x805003888,0x802759be0)
= 0 (0x0)
85976: 3.088875758 setitimer(0,{0.000000, 1.000000 },0x0) = 0 (0x0)
85976: 4.089210052 semop(0x3000b,0x7fffffffd550,0x1,0x0,0x20,0x1431e650f0)
ERR#4 'Interrupted system call'
85976: 4.089210052 SIGNAL 14 (SIGALRM)
85976: 4.089414257 sigprocmask(SIG_SETMASK,SIGALRM,0x0) = 0 (0x0)
85976: 4.089493593
semop(0x3000b,0x7fffffffcb28,0x1,0x0,0x6559a0,0x1431e650f0) = 0 (0x0)
85976: 4.089541500
sigreturn(0x7fffffffcb80,0x7fffffffcb80,0x301,0x0,0xfffffffffffffbc0,0x1431e650f0)
ERR#4 'Interrupted system call'
85976: 4.089594057 semop(0x3000b,0x7fffffffd550,0x1,0x0,0x20,0x1431e650f0) =
0 (0x0)
85976: 4.089914562 write(2,"\0\0N\^A\M-XO\^A\0t2015-06-26 11:59:47 BST 85976
pgsql [local] psql amf_more2 2015-06-26 11:38:43 BST [11]LOG:  process 85976
st"...,343) = 343 (0x157)

В списке pgsql-bugs по дате отправления:

Предыдущее
От: andomar@aule.net
Дата:
Сообщение: BUG #13471: Reload with include_dir results in incorrect "contains errors" message
Следующее
От: marco.nenciarini@2ndquadrant.it
Дата:
Сообщение: BUG #13473: VACUUM FREEZE mistakenly cancel standby sessions