Return of the Solaris vacuum polling problem -- anyone remember this?

All,

This is something I'd swear we fixed around 8.3.2. However, I'm seeing
it again in production, and was wondering if anyone could remember what
the root cause was and how we fixed it.

The problem is that sometimes (but not the majority of times) autovaccum
with cost_delay is going into a pathological cycle where it polls the
system clock after reading every single disk page of a table. On large
tables, this results in vacuum not completing within the lifetime of the
server.  In most cases, killing autovaccuum and restarting it will cause
it to behave normally.

The below is the truss from the exhibited issue on 8.3.11 on Solaris
10u7, compiled with sun cc:

pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
lseek(39, 0x28F88000, SEEK_SET)                 = 0x28F88000
write(39, "0E10\0\0E0 CB5C101\001\0".., 8192)   = 8192
lseek(39, 0x28FCA000, SEEK_SET)                 = 0x28FCA000
read(39, " q\r\0\0 `9CD2B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " F0E\0\090A888 H01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q\r\0\0C819D3B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
lseek(39, 0x28F90000, SEEK_SET)                 = 0x28F90000
write(39, "0E10\0\0 0 gB7C101\001\0".., 8192)   = 8192
lseek(39, 0x28FD0000, SEEK_SET)                 = 0x28FD0000
read(39, " q\r\0\0 X 8D3B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " t0F\0\0 H +8F !01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q\r\0\0F0 sD3B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " F0E\0\0 0C888 H01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
lseek(39, 0x28FDA000, SEEK_SET)                 = 0x28FDA000
read(39, " q\r\0\0C0D1D3B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q\r\0\0D8F0D3B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " F0E\0\0800189 H01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q0F\0\0D0 ^A9F701\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " F0E\0\010 ?89 H01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q\r\0\0 x mD4B001\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " F0E\0\0 X _89 H01\001\0".., 8192)    = 8192
pollsys(0xFFFFFD7FFFDF9030, 0, 0xFFFFFD7FFFDF90C0, 0x00000000) = 0
read(39, " q\r\0\0 @ADD4B001\001\0".., 8192)    = 8192

For contrast, this is normal behavior:

read(10, " }\0\0\0 X82 >E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\018 4 ME301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0E881 NE301\0\0\0".., 8192)    = 8192
semop(16777221, 0xFFFFFD7FFFDF8FB8, 1)          = 0
read(10, " }\0\0\0 PEE \E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0\b k ^E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 8E0 jE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 P07 nE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0D885 xE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0  8D }E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 xD280E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\010DF8CE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0E09E8EE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0C8E29CE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\080889EE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0B0 UADE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0C0E4BCE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0   !C0E301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\010 UCDE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0F8EBCEE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\08092DDE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0A8 QDFE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 x cEDE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0D8 "EFE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 P15FAE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0C8C0FDE301\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 PFC\tE401\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 8C3\rE401\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0 @890FE401\0\0\0".., 8192)    = 8192
read(10, " }\0\0\0   r11E401\0\0\0".., 8192)    = 8192


--                                  -- Josh Berkus                                    PostgreSQL Experts Inc.
                        http://www.pgexperts.com