Обсуждение: wal_consistency_checking reports an inconsistency on master branch
Running "make installcheck" with wal_consistency_checking='all' on the master branch shows the follow failure on a streaming replica: 19696/2018-04-12 11:35:29 PDT FATAL: inconsistent page found, rel 1663/50192/66636, forknum 0, blkno 0 19696/2018-04-12 11:35:29 PDT CONTEXT: WAL redo at 2/6D8411F8 for Heap/DELETE: off 4 KEYS_UPDATED 19695/2018-04-12 11:35:29 PDT LOG: startup process (PID 19696) exited with exit code 1 19695/2018-04-12 11:35:29 PDT LOG: terminating any other active server processes 19695/2018-04-12 11:35:29 PDT LOG: database system is shut down I can correlate it with this wal_debug output on the primary: 18713/2018-04-12 11:20:40 PDT ERROR: new row violates check option for view "upview" 18713/2018-04-12 11:20:40 PDT DETAIL: Failing row contains (a, 4, 120, 1, 1). 18713/2018-04-12 11:20:40 PDT STATEMENT: UPDATE upview set c = 120 WHERE b = 4; 18713/2018-04-12 11:20:40 PDT LOG: INSERT @ 2/6D8411F8: - Transaction/ABORT: 2018-04-12 11:20:40.085145-07 18073/2018-04-12 11:20:40 PDT LOG: xlog bg flush request write 2/6D840000; flush: 0/0, current is write 2/6D840000; flush 2/6D7B40B0 18713/2018-04-12 11:20:40 PDT LOG: INSERT @ 2/6D841378: - Heap/DELETE: off 4 KEYS_UPDATED 18713/2018-04-12 11:20:40 PDT STATEMENT: UPDATE upview set a = 'b', b = 15, c = 120 WHERE b = 4; 18713/2018-04-12 11:20:40 PDT LOG: INSERT @ 2/6D8415F0: - Heap/INSERT: off 10 18713/2018-04-12 11:20:40 PDT STATEMENT: UPDATE upview set a = 'b', b = 15, c = 120 WHERE b = 4; 18713/2018-04-12 11:20:40 PDT ERROR: new row violates check option for view "upview" 18713/2018-04-12 11:20:40 PDT DETAIL: Failing row contains (b, 15, 120, 1, 1). 18713/2018-04-12 11:20:40 PDT STATEMENT: UPDATE upview set a = 'b', b = 15, c = 120 WHERE b = 4; In short, it looks like the tests added to update.sql by commit 2f178441 ("Allow UPDATE to move rows between partitions") lead to this failure, since I always hit a problem when update.sql is reached. I haven't gone to the trouble of digging any deeper than that just yet. -- Peter Geoghegan
On Thu, Apr 12, 2018 at 11:47 AM, Peter Geoghegan <pg@bowt.ie> wrote: > In short, it looks like the tests added to update.sql by commit > 2f178441 ("Allow UPDATE to move rows between partitions") lead to this > failure, since I always hit a problem when update.sql is reached. I > haven't gone to the trouble of digging any deeper than that just yet. Without having looked at it in much detail, this seems rather more likely to be the fault of 2f178441. That was recent enough that it's easy to believe that I'd be the first to notice it, and actually has on-disk changes, in the form of ItemPointerSetMovedPartitions(). -- Peter Geoghegan
On Thu, Apr 12, 2018 at 03:36:12PM -0700, Peter Geoghegan wrote: > Without having looked at it in much detail, this seems rather more > likely to be the fault of 2f178441. That was recent enough that it's > easy to believe that I'd be the first to notice it, and actually has > on-disk changes, in the form of ItemPointerSetMovedPartitions(). Since f16241be the following comment has been added to heap_mask(): /* * NB: Not ignoring ctid changes due to the tuple having moved * (i.e. HeapTupleHeaderIndicatesMovedPartitions), because that's * important information that needs to be in-sync between primary * and standby, and thus is WAL logged. */ And actually, if you remove this query from update.sql, then the consistency checks are able to finish: UPDATE upview set c = 120 WHERE b = 4; This triggers in the test suite a CHECK violation but this should not result in a row being moved as even c is updated it would remain on the same child partition so no rows are moved across partitions here. Could this be pointing to an older issue? -- Michael
Вложения
On 2018/04/13 7:36, Peter Geoghegan wrote: > On Thu, Apr 12, 2018 at 11:47 AM, Peter Geoghegan <pg@bowt.ie> wrote: >> In short, it looks like the tests added to update.sql by commit >> 2f178441 ("Allow UPDATE to move rows between partitions") lead to this >> failure, since I always hit a problem when update.sql is reached. I >> haven't gone to the trouble of digging any deeper than that just yet. > > Without having looked at it in much detail, this seems rather more > likely to be the fault of 2f178441. That was recent enough that it's > easy to believe that I'd be the first to notice it, and actually has > on-disk changes, in the form of ItemPointerSetMovedPartitions(). I think you meant f16241bef7cc2 (Raise error when affecting tuple moved into different partition), because it's the one that adds ItemPointerSetMovedPartitions. Commit 2f178441 you quoted added the test that triggered the failure. Thanks, Amit
On 2018-04-13 12:29:21 +0900, Amit Langote wrote: > On 2018/04/13 7:36, Peter Geoghegan wrote: > > On Thu, Apr 12, 2018 at 11:47 AM, Peter Geoghegan <pg@bowt.ie> wrote: > >> In short, it looks like the tests added to update.sql by commit > >> 2f178441 ("Allow UPDATE to move rows between partitions") lead to this > >> failure, since I always hit a problem when update.sql is reached. I > >> haven't gone to the trouble of digging any deeper than that just yet. > > > > Without having looked at it in much detail, this seems rather more > > likely to be the fault of 2f178441. That was recent enough that it's > > easy to believe that I'd be the first to notice it, and actually has > > on-disk changes, in the form of ItemPointerSetMovedPartitions(). > > I think you meant f16241bef7cc2 (Raise error when affecting tuple moved > into different partition), because it's the one that adds > ItemPointerSetMovedPartitions. Commit 2f178441 you quoted added the test > that triggered the failure. Right. Amul, have you looked at this? Greetings, Andres Freund
Will look into this, thanks.
Regards,
Amul
----------------------------------------------------------------------------------------------------
Sent from a mobile device. Please excuse brevity and tpyos.
Amul
----------------------------------------------------------------------------------------------------
Sent from a mobile device. Please excuse brevity and tpyos.
On Fri, Apr 13, 2018, 9:06 AM Andres Freund <andres@anarazel.de> wrote:
On 2018-04-13 12:29:21 +0900, Amit Langote wrote:
> On 2018/04/13 7:36, Peter Geoghegan wrote:
> > On Thu, Apr 12, 2018 at 11:47 AM, Peter Geoghegan <pg@bowt.ie> wrote:
> >> In short, it looks like the tests added to update.sql by commit
> >> 2f178441 ("Allow UPDATE to move rows between partitions") lead to this
> >> failure, since I always hit a problem when update.sql is reached. I
> >> haven't gone to the trouble of digging any deeper than that just yet.
> >
> > Without having looked at it in much detail, this seems rather more
> > likely to be the fault of 2f178441. That was recent enough that it's
> > easy to believe that I'd be the first to notice it, and actually has
> > on-disk changes, in the form of ItemPointerSetMovedPartitions().
>
> I think you meant f16241bef7cc2 (Raise error when affecting tuple moved
> into different partition), because it's the one that adds
> ItemPointerSetMovedPartitions. Commit 2f178441 you quoted added the test
> that triggered the failure.
Right. Amul, have you looked at this?
Greetings,
Andres Freund
On Fri, Apr 13, 2018 at 9:06 AM, Andres Freund <andres@anarazel.de> wrote: > On 2018-04-13 12:29:21 +0900, Amit Langote wrote: >> On 2018/04/13 7:36, Peter Geoghegan wrote: >> > On Thu, Apr 12, 2018 at 11:47 AM, Peter Geoghegan <pg@bowt.ie> wrote: >> >> In short, it looks like the tests added to update.sql by commit >> >> 2f178441 ("Allow UPDATE to move rows between partitions") lead to this >> >> failure, since I always hit a problem when update.sql is reached. I >> >> haven't gone to the trouble of digging any deeper than that just yet. >> > >> > Without having looked at it in much detail, this seems rather more >> > likely to be the fault of 2f178441. That was recent enough that it's >> > easy to believe that I'd be the first to notice it, and actually has >> > on-disk changes, in the form of ItemPointerSetMovedPartitions(). >> >> I think you meant f16241bef7cc2 (Raise error when affecting tuple moved >> into different partition), because it's the one that adds >> ItemPointerSetMovedPartitions. Commit 2f178441 you quoted added the test >> that triggered the failure. > > Right. Amul, have you looked at this? > I have looked into this and found that the issue is in heap_xlog_delete -- we have missed to set the correct offset number from the target_tid when XLH_DELETE_IS_PARTITION_MOVE flag is set. Please find the attached patch does the correction and a big thanks to Peter for the bug report. Regards, Amul
Вложения
On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: > I have looked into this and found that the issue is in heap_xlog_delete -- we > have missed to set the correct offset number from the target_tid when > XLH_DELETE_IS_PARTITION_MOVE flag is set. Oh, this looks good to me. So when a row was moved across partitions this could have caused incorrect tuple references on a standby, which could have caused corruptions. wal_consistency_checking is proving to be worth its cost here... -- Michael
Вложения
On 2018/04/13 19:08, Michael Paquier wrote: > On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: >> I have looked into this and found that the issue is in heap_xlog_delete -- we >> have missed to set the correct offset number from the target_tid when >> XLH_DELETE_IS_PARTITION_MOVE flag is set. > > Oh, this looks good to me. So when a row was moved across partitions > this could have caused incorrect tuple references on a standby, which > could have caused corruptions. > > wal_consistency_checking is proving to be worth its cost here... +1 Thanks, Amit
On 13/04/18 13:08, Michael Paquier wrote: > On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: >> I have looked into this and found that the issue is in heap_xlog_delete -- we >> have missed to set the correct offset number from the target_tid when >> XLH_DELETE_IS_PARTITION_MOVE flag is set. > > Oh, this looks good to me. So when a row was moved across partitions > this could have caused incorrect tuple references on a standby, which > could have caused corruptions. Hmm. So, the problem was that HeapTupleHeaderSetMovedPartitions() only sets the block number to InvalidBlockNumber, and leaves the offset number unchanged. WAL replay didn't preserve the offset number, so the master and the standby had a different offset number in the ctid. Why does HeapTupleHeaderSetMovedPartitions() leave the offset number unchanged? The old offset number is meaningless without the block number. Also, bits and magic values in the tuple header are scarce. We're squandering a whole range of values in the ctid, everything with ip_blkid==InvalidBlockNumber, to mean "moved to different partition", when a single value would suffice. Let's tighten that up. In the attached (untested) patch, I changed the macros so that "moved to different partition" is indicated by the magic TID (InvalidBlockNumber, 0xfffd). Offset number 0xfffe was already used for speculative insertion tokens, so this follows that precedent. I kept using InvalidBlockNumber there, so ItemPointerIsValid() still considers those item pointers as invalid. But my gut feeling is actually that it would be better to use e.g. 0 as the block number, so that these item pointers would appear valid. Again, to follow the precedent of speculative insertion tokens. But I'm not sure if there was some well-thought-out reason to make them appear invalid. A comment on that would be nice, at least. (Amit hinted at this in https://www.postgresql.org/message-id/CAA4eK1KtsTqsGDggDCrz2O9Jgo7ma-Co-B8%2Bv3L2zWMA2NHm6A%40mail.gmail.com. He was OK with the current approach, but I feel pretty strongly that we should also set the offset number.) - Heikki
Вложения
On 2018-04-23 13:22:21 +0300, Heikki Linnakangas wrote: > On 13/04/18 13:08, Michael Paquier wrote: > > On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: > > > I have looked into this and found that the issue is in heap_xlog_delete -- we > > > have missed to set the correct offset number from the target_tid when > > > XLH_DELETE_IS_PARTITION_MOVE flag is set. > > > > Oh, this looks good to me. So when a row was moved across partitions > > this could have caused incorrect tuple references on a standby, which > > could have caused corruptions. > > Hmm. So, the problem was that HeapTupleHeaderSetMovedPartitions() only sets > the block number to InvalidBlockNumber, and leaves the offset number > unchanged. WAL replay didn't preserve the offset number, so the master and > the standby had a different offset number in the ctid. Right. > Why does HeapTupleHeaderSetMovedPartitions() leave the offset number > unchanged? The old offset number is meaningless without the block number. > Also, bits and magic values in the tuple header are scarce. We're > squandering a whole range of values in the ctid, everything with > ip_blkid==InvalidBlockNumber, to mean "moved to different partition", when a > single value would suffice. Yes, I agree on that. > I kept using InvalidBlockNumber there, so ItemPointerIsValid() still > considers those item pointers as invalid. But my gut feeling is actually > that it would be better to use e.g. 0 as the block number, so that these > item pointers would appear valid. Again, to follow the precedent of > speculative insertion tokens. But I'm not sure if there was some > well-thought-out reason to make them appear invalid. A comment on that would > be nice, at least. That seems risky to me. We want something that stops EPQ style chasing without running into asserts for invalid offsets... Greetings, Andres Freund
On Mon, Apr 23, 2018 at 07:58:30AM -0700, Andres Freund wrote: > On 2018-04-23 13:22:21 +0300, Heikki Linnakangas wrote: >> Why does HeapTupleHeaderSetMovedPartitions() leave the offset number >> unchanged? The old offset number is meaningless without the block number. >> Also, bits and magic values in the tuple header are scarce. We're >> squandering a whole range of values in the ctid, everything with >> ip_blkid==InvalidBlockNumber, to mean "moved to different partition", when a >> single value would suffice. > > Yes, I agree on that. True that the spculative inserts and the partition move are handled in inconsistent ways now. >> I kept using InvalidBlockNumber there, so ItemPointerIsValid() still >> considers those item pointers as invalid. But my gut feeling is actually >> that it would be better to use e.g. 0 as the block number, so that these >> item pointers would appear valid. Again, to follow the precedent of >> speculative insertion tokens. But I'm not sure if there was some >> well-thought-out reason to make them appear invalid. A comment on that would >> be nice, at least. > > That seems risky to me. We want something that stops EPQ style chasing > without running into asserts for invalid offsets... -/* - * Special value used in t_ctid.ip_posid, to indicate that it holds a - * speculative insertion token rather than a real TID. This must be -higher - * than MaxOffsetNumber, so that it can be distinguished from a valid - * offset number in a regular item pointer. - */ -#define SpecTokenOffsetNumber 0xfff Moving those definitions from htup_details.h to itemptr.h seems confusing for me. As those are heap-related operations, I would recommend to keep them where they are, and also move those two ones to htup_details.h, renaming them on the way so as they are more -consistent: - ItemPointerIndicatesMovedPartitions - ItemPointerSetMovedPartitions -- Michael
Вложения
As a general note on this thread, we should try to get this cleared up as soon as possible, since it involves an on-disk format change. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
On 2018-04-23 07:58:30 -0700, Andres Freund wrote: > On 2018-04-23 13:22:21 +0300, Heikki Linnakangas wrote: > > On 13/04/18 13:08, Michael Paquier wrote: > > > On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: > > > > I have looked into this and found that the issue is in heap_xlog_delete -- we > > > > have missed to set the correct offset number from the target_tid when > > > > XLH_DELETE_IS_PARTITION_MOVE flag is set. > > > > > > Oh, this looks good to me. So when a row was moved across partitions > > > this could have caused incorrect tuple references on a standby, which > > > could have caused corruptions. > > > > Hmm. So, the problem was that HeapTupleHeaderSetMovedPartitions() only sets > > the block number to InvalidBlockNumber, and leaves the offset number > > unchanged. WAL replay didn't preserve the offset number, so the master and > > the standby had a different offset number in the ctid. > > Right. > > > Why does HeapTupleHeaderSetMovedPartitions() leave the offset number > > unchanged? The old offset number is meaningless without the block number. > > Also, bits and magic values in the tuple header are scarce. We're > > squandering a whole range of values in the ctid, everything with > > ip_blkid==InvalidBlockNumber, to mean "moved to different partition", when a > > single value would suffice. > > Yes, I agree on that. > > > > I kept using InvalidBlockNumber there, so ItemPointerIsValid() still > > considers those item pointers as invalid. But my gut feeling is actually > > that it would be better to use e.g. 0 as the block number, so that these > > item pointers would appear valid. Again, to follow the precedent of > > speculative insertion tokens. But I'm not sure if there was some > > well-thought-out reason to make them appear invalid. A comment on that would > > be nice, at least. > > That seems risky to me. We want something that stops EPQ style chasing > without running into asserts for invalid offsets... Heikki, would you rather apply this yourself or have me do it? Greetings, Andres Freund
On 2018-04-30 22:08:46 -0700, Andres Freund wrote: > On 2018-04-23 07:58:30 -0700, Andres Freund wrote: > > On 2018-04-23 13:22:21 +0300, Heikki Linnakangas wrote: > > > On 13/04/18 13:08, Michael Paquier wrote: > > > > On Fri, Apr 13, 2018 at 02:15:35PM +0530, amul sul wrote: > > > > > I have looked into this and found that the issue is in heap_xlog_delete -- we > > > > > have missed to set the correct offset number from the target_tid when > > > > > XLH_DELETE_IS_PARTITION_MOVE flag is set. > > > > > > > > Oh, this looks good to me. So when a row was moved across partitions > > > > this could have caused incorrect tuple references on a standby, which > > > > could have caused corruptions. > > > > > > Hmm. So, the problem was that HeapTupleHeaderSetMovedPartitions() only sets > > > the block number to InvalidBlockNumber, and leaves the offset number > > > unchanged. WAL replay didn't preserve the offset number, so the master and > > > the standby had a different offset number in the ctid. > > > > Right. > > > > > Why does HeapTupleHeaderSetMovedPartitions() leave the offset number > > > unchanged? The old offset number is meaningless without the block number. > > > Also, bits and magic values in the tuple header are scarce. We're > > > squandering a whole range of values in the ctid, everything with > > > ip_blkid==InvalidBlockNumber, to mean "moved to different partition", when a > > > single value would suffice. > > > > Yes, I agree on that. > > > > > > > I kept using InvalidBlockNumber there, so ItemPointerIsValid() still > > > considers those item pointers as invalid. But my gut feeling is actually > > > that it would be better to use e.g. 0 as the block number, so that these > > > item pointers would appear valid. Again, to follow the precedent of > > > speculative insertion tokens. But I'm not sure if there was some > > > well-thought-out reason to make them appear invalid. A comment on that would > > > be nice, at least. > > > > That seems risky to me. We want something that stops EPQ style chasing > > without running into asserts for invalid offsets... > > Heikki, would you rather apply this yourself or have me do it? I pushed that now. Greetings, Andres Freund