Received: from maia.hub.org (maia-2.hub.org [200.46.204.251]) by mail.postgresql.org (Postfix) with ESMTP id 65E766327A7 for ; Mon, 16 Aug 2010 15:25:12 -0300 (ADT) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.251]) (amavisd-maia, port 10024) with ESMTP id 16150-02 for ; Mon, 16 Aug 2010 18:25:04 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from glacier.frostconsultingllc.com (glacier.frostconsultingllc.com [69.36.227.170]) by mail.postgresql.org (Postfix) with ESMTP id 0C5F6632591 for ; Mon, 16 Aug 2010 15:25:05 -0300 (ADT) Received: from dsl081-245-111.sfo1.dsl.speakeasy.net ([64.81.245.111] helo=Sidney-Stratton.local) by glacier.frostconsultingllc.com with esmtpsa (TLSv1:CAMELLIA256-SHA:256) (Exim 4.69) (envelope-from ) id 1Ol4Ml-000280-79 for pgsql-hackers@postgreSQL.org; Mon, 16 Aug 2010 11:25:02 -0700 Message-ID: <4C69827A.409@agliodbs.com> Date: Mon, 16 Aug 2010 11:24:58 -0700 From: Josh Berkus User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.1b3pre) Gecko/20090223 Thunderbird/3.0b2 MIME-Version: 1.0 To: PostgreSQL-development Subject: Return of the Solaris vacuum polling problem -- anyone remember this? Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-1.9 tagged_above=-5 required=5 tests=BAYES_00=-1.9 X-Spam-Level: X-Archive-Number: 201008/1125 X-Sequence-Number: 167928 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