Message-ID: <4D2D6A56.9060808@enterprisedb.com>
Date: Wed, 12 Jan 2011 10:46:14 +0200
From: Heikki Linnakangas <heikki.linnakangas@enterprisedb.com>
User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; fi-FI;
	rv:1.9.1.15) Gecko/20101030 Icedove/3.0.10
MIME-Version: 1.0
To: Maxim Boguk <maxim.boguk@gmail.com>
CC: Fujii Masao <masao.fujii@gmail.com>, pgsql-admin@postgresql.org,
	PostgreSQL-development <pgsql-hackers@postgresql.org>
Subject: Re: [HACKERS] Re: PD_ALL_VISIBLE flag was incorrectly set
	happend during repeatable vacuum
References: <AANLkTino+Gc2vvOVdzCPRRXW-N7R5=ikYMnNKT5W=mk1@mail.gmail.com>
	<AANLkTikw==USr3+4Mt+w97P3ymux-Bhn0G7Ad0ZJHbqG@mail.gmail.com>
In-Reply-To: <AANLkTikw==USr3+4Mt+w97P3ymux-Bhn0G7Ad0ZJHbqG@mail.gmail.com>
Content-Type: multipart/mixed; boundary="------------080500090308060107000509"

This is a multi-part message in MIME format.
--------------080500090308060107000509
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 7bit

On 12.01.2011 06:21, Fujii Masao wrote:
> On Sat, Dec 25, 2010 at 2:09 PM, Maxim Boguk<maxim.boguk@gmail.com>  wrote:
>> While I trying create reproducible test case for BUG #5798 I
>> encountered very strange effect on two of my servers (both servers
>> have same hardware platform/OS (freebsd 7.2) and PostgreSQL 8.4.4).
>>
>> Very simple test table created as:
>> CREATE TABLE test (id integer);
>> INSERT INTO test select generate_series(0,10000);
>>
>> And I trying repeateble vacuum of that table with script:
>>   perl -e "foreach (1..100000) {system \"psql -d test -h -c 'vacuum test'\";}"
>>
>> And once per like an minute (really random intervals can be 5 minutes
>> without problems can be 3 vacuum in row show same error)  I getting
>> next errors:
>> WARNING:  PD_ALL_VISIBLE flag was incorrectly set in relation "test" page 1
>> ...
>> WARNING:  PD_ALL_VISIBLE flag was incorrectly set in relation "test"
>> page 30 for all pages of the relation.

Oh, interesting. This is the first time anyone can reliably reproducible 
that. I can't reproduce that on my laptop with that script, though, so 
I'm going to need your help to debug this.

Can you compile PostgreSQL with the attached patch, and rerun the test? 
It will dump the pages with incorrectly set flags to files in /tmp/, and 
adds a bit more detail in the WARNING.  Please run the test until you 
get those warnings, and tar up the the created "/tmp/pageimage*" files, 
and post them along with the warning generated.

We'll likely need to go back and forth a few times with various 
debugging patches until we get to the heart of this..

-- 
   Heikki Linnakangas
   EnterpriseDB   http://www.enterprisedb.com

--------------080500090308060107000509
Content-Type: text/x-diff;
 name="debug-pd_all_visible-1.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="debug-pd_all_visible-1.patch"

diff --git a/src/backend/commands/vacuumlazy.c b/src/backend/commands/vacuumlazy.c
index 67e0be9..0e88aa5 100644
--- a/src/backend/commands/vacuumlazy.c
+++ b/src/backend/commands/vacuumlazy.c
@@ -48,6 +48,7 @@
 #include "pgstat.h"
 #include "postmaster/autovacuum.h"
 #include "storage/bufmgr.h"
+#include "storage/fd.h"
 #include "storage/freespace.h"
 #include "storage/lmgr.h"
 #include "utils/inval.h"
@@ -668,13 +669,26 @@ lazy_scan_heap(Relation onerel, LVRelStats *vacrelstats,
 		/* Update the all-visible flag on the page */
 		if (!PageIsAllVisible(page) && all_visible)
 		{
+			elog(WARNING, "debugging: setting PD_ALL_VISIBLE in relation \"%s\" on page %u (OldestXmin %u)", relname, blkno, OldestXmin);
 			PageSetAllVisible(page);
 			SetBufferCommitInfoNeedsSave(buf);
 		}
 		else if (PageIsAllVisible(page) && !all_visible)
 		{
-			elog(WARNING, "PD_ALL_VISIBLE flag was incorrectly set in relation \"%s\" page %u",
-				 relname, blkno);
+			elog(WARNING, "PD_ALL_VISIBLE flag was incorrectly set in relation \"%s\" page %u (OldestXmin %u)",
+				 relname, blkno, OldestXmin);
+			{
+				char fname[MAXPGPATH];
+				FILE *fp;
+
+				/* dump the raw page to a file */
+				snprintf(fname, sizeof(fname), "/tmp/pageimage_%s_%d",
+						 relname, blkno);
+				fp = AllocateFile(fname, "wb");
+				fwrite(page, 1, BLCKSZ, fp);
+				FreeFile(fp);
+				
+			}
 			PageClearAllVisible(page);
 			SetBufferCommitInfoNeedsSave(buf);
 

--------------080500090308060107000509--