pg.ddx.io  pgsql-bugs@postgresql.org mailing list archive  
help / color / mirror / Atom feed
The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
7+ messages / 3 participants
[nested] [flat]

Commits from this thread:
  2019-11-07 a0c96856e8 e5cfb8cbbe fb53c4c07f 127ad57f5d aa7cd6a8e7 b1bebc2cee 1accf99748  Fix assertion failure when running pgbench -s.
* The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-06 02:40  Andrey Lepikhov <a.lepikhov@postgrespro.ru>
  0 siblings, 1 reply; 7+ messages in thread

From: Andrey Lepikhov @ 2019-11-06 02:40 UTC (permalink / raw)
  To: PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

I found this in our multimaster project on PostgreSQL 11.5. It is 
difficult to reproduce this error, but I will try to do it if necessary.

The rest of a continuation WAL-record can exactly match the block size. 
In this case, we need to switch targetPagePtr to the next block before 
calculating the starting point of the next WAL-record.
See the patch in attachment for the bug fix.

-- 
Andrey Lepikhov
Postgres Professional
https://postgrespro.com
The Russian Postgres Company

Attachments:

  0001-Correct-the-algorithm-of-definition-of-WAL-record-st.patch (text/x-patch, 0B) download

^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-06 04:41  Michael Paquier <michael@paquier.xyz>
  parent: Andrey Lepikhov <a.lepikhov@postgrespro.ru>
  0 siblings, 1 reply; 7+ messages in thread

From: Michael Paquier @ 2019-11-06 04:41 UTC (permalink / raw)
  To: Andrey Lepikhov <a.lepikhov@postgrespro.ru>; +Cc: PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

On Wed, Nov 06, 2019 at 07:40:48AM +0500, Andrey Lepikhov wrote:
> I found this in our multimaster project on PostgreSQL 11.5. It is difficult
> to reproduce this error, but I will try to do it if necessary.
> 
> The rest of a continuation WAL-record can exactly match the block size. In
> this case, we need to switch targetPagePtr to the next block before
> calculating the starting point of the next WAL-record.
> See the patch in attachment for the bug fix.

What's the error you actually saw after reading the record in
xlogreader.c?  If you have past WAL archives, perhaps you are able to
reproduce the problem with a given WAL segment and pg_waldump?

This code rings a bell as of this thread which led to commit bab7823:
https://www.postgresql.org/message-id/CABOikdPsPByMiG6J01DKq6om2+BNkxHTPkOyqHM2a4oYwGKsqQ@mail.gmail...

Reminds me as well of the following:
https://www.postgresql.org/message-id/CAOR=d=16x+jKM=00AoEZEKU9RJDwjU9E2bUnFBpX_HrGjkMHXg@mail.gmail...
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-06 05:06  Andrey Lepikhov <a.lepikhov@postgrespro.ru>
  parent: Michael Paquier <michael@paquier.xyz>
  0 siblings, 1 reply; 7+ messages in thread

From: Andrey Lepikhov @ 2019-11-06 05:06 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; +Cc: PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>



On 06/11/2019 09:41, Michael Paquier wrote:
> On Wed, Nov 06, 2019 at 07:40:48AM +0500, Andrey Lepikhov wrote:
>> I found this in our multimaster project on PostgreSQL 11.5. It is difficult
>> to reproduce this error, but I will try to do it if necessary.
>>
>> The rest of a continuation WAL-record can exactly match the block size. In
>> this case, we need to switch targetPagePtr to the next block before
>> calculating the starting point of the next WAL-record.
>> See the patch in attachment for the bug fix.
> 
> What's the error you actually saw after reading the record in
> xlogreader.c?  If you have past WAL archives, perhaps you are able to
> reproduce the problem with a given WAL segment and pg_waldump?

I saw the message:
pg_waldump: xlogreader.c:264: XLogReadRecord: <Text in russian> 
"((RecPtr) % 8192 >= (((uintptr_t) ((sizeof(XLogPageHeaderData))) + ((8) 
- 1)) & ~((uintptr_t) ((8) - 1))))" <Text in russian>

Yes, I reproduced error with pg_waldump too. The patch in previous 
letter fixed this problem.

some details:
I have the record:
rmgr: Transaction len (rec/tot): 86/ 86, tx: 0, lsn: 0/11FFFF98, prev 
0/11FFFDA8, desc: COMMIT_PREPARED

The next record occupied the rest of segment No.11 and 8151 bytes of the 
first block of the segment No.12, i.e. its size is 8167 bytes.

Problematic record (I got it by pg_waldump after applying the patch) is:
rmgr: Heap len (rec/tot): 71/ 8167, tx: 1249835485258, lsn: 0/11FFFFF0, 
prev 0/11FFFF98, desc: LOCK off 8: xid 1249835485258: flags 0 LOCK_ONLY 
EXCL_LOCK KEYS_UPDATED , blkref #0: rel 1663/13121/16474 blk 10880 FPW

-- 
Andrey Lepikhov
Postgres Professional
https://postgrespro.com
The Russian Postgres Company





^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-06 17:41  Fujii Masao <masao.fujii@gmail.com>
  parent: Andrey Lepikhov <a.lepikhov@postgrespro.ru>
  0 siblings, 1 reply; 7+ messages in thread

From: Fujii Masao @ 2019-11-06 17:41 UTC (permalink / raw)
  To: Andrey Lepikhov <a.lepikhov@postgrespro.ru>; +Cc: Michael Paquier <michael@paquier.xyz>; PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

On Wed, Nov 6, 2019 at 2:07 PM Andrey Lepikhov
<a.lepikhov@postgrespro.ru> wrote:
>
>
>
> On 06/11/2019 09:41, Michael Paquier wrote:
> > On Wed, Nov 06, 2019 at 07:40:48AM +0500, Andrey Lepikhov wrote:
> >> I found this in our multimaster project on PostgreSQL 11.5. It is difficult
> >> to reproduce this error, but I will try to do it if necessary.
> >>
> >> The rest of a continuation WAL-record can exactly match the block size. In
> >> this case, we need to switch targetPagePtr to the next block before
> >> calculating the starting point of the next WAL-record.
> >> See the patch in attachment for the bug fix.

Good catch!

> > What's the error you actually saw after reading the record in
> > xlogreader.c?  If you have past WAL archives, perhaps you are able to
> > reproduce the problem with a given WAL segment and pg_waldump?
>
> I saw the message:
> pg_waldump: xlogreader.c:264: XLogReadRecord: <Text in russian>
> "((RecPtr) % 8192 >= (((uintptr_t) ((sizeof(XLogPageHeaderData))) + ((8)
> - 1)) & ~((uintptr_t) ((8) - 1))))" <Text in russian>

I created the problematic WAL file artificially by using
pg_logical_emit_message() and sucessfully reproduced
the error. I attached the WAL file that I created. You can
reproduce the issue by

    pg_waldump 000000010000000000000008 -s 0/08002028

> Yes, I reproduced error with pg_waldump too. The patch in previous
> letter fixed this problem.

The patch looks good to me. Barrying any objection, I will commit it.
XLogFindNextRecord() must return the valid record starting position,
but currently could return the starting position of WAL page
(not valid WAL record) in the case that you described. This is
the cause of the issue.

Regards,

-- 
Fujii Masao

Attachments:

  000000010000000000000008.tar.bz2 (application/x-bzip2, 315B) download

^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-07 03:41  Michael Paquier <michael@paquier.xyz>
  parent: Fujii Masao <masao.fujii@gmail.com>
  0 siblings, 1 reply; 7+ messages in thread

From: Michael Paquier @ 2019-11-07 03:41 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@gmail.com>; +Cc: Andrey Lepikhov <a.lepikhov@postgrespro.ru>; PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

On Thu, Nov 07, 2019 at 02:41:29AM +0900, Fujii Masao wrote:
> I created the problematic WAL file artificially by using
> pg_logical_emit_message() and sucessfully reproduced
> the error.

Good idea.  I didn't know this one.

> I attached the WAL file that I created. You can
> reproduce the issue by
> 
>     pg_waldump 000000010000000000000008 -s 0/08002028

Assertion failure reproduced here.

> The patch looks good to me. Barrying any objection, I will commit it.
> XLogFindNextRecord() must return the valid record starting position,
> but currently could return the starting position of WAL page
> (not valid WAL record) in the case that you described. This is
> the cause of the issue.

No issues from here, thanks for taking care of it.
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-07 07:37  Fujii Masao <masao.fujii@gmail.com>
  parent: Michael Paquier <michael@paquier.xyz>
  0 siblings, 1 reply; 7+ messages in thread

From: Fujii Masao @ 2019-11-07 07:37 UTC (permalink / raw)
  To: Michael Paquier <michael@paquier.xyz>; +Cc: Andrey Lepikhov <a.lepikhov@postgrespro.ru>; PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

On Thu, Nov 7, 2019 at 12:41 PM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Thu, Nov 07, 2019 at 02:41:29AM +0900, Fujii Masao wrote:
> > I created the problematic WAL file artificially by using
> > pg_logical_emit_message() and sucessfully reproduced
> > the error.
>
> Good idea.  I didn't know this one.
>
> > I attached the WAL file that I created. You can
> > reproduce the issue by
> >
> >     pg_waldump 000000010000000000000008 -s 0/08002028
>
> Assertion failure reproduced here.
>
> > The patch looks good to me. Barrying any objection, I will commit it.
> > XLogFindNextRecord() must return the valid record starting position,
> > but currently could return the starting position of WAL page
> > (not valid WAL record) in the case that you described. This is
> > the cause of the issue.
>
> No issues from here, thanks for taking care of it.

Thanks for the check! I committed the patch!

Regards,

-- 
Fujii Masao





^ permalink  raw  reply  [nested|flat] 7+ messages in thread

* Re: The XLogFindNextRecord() routine find incorrect record start point after a long continuation record
@ 2019-11-07 07:52  Michael Paquier <michael@paquier.xyz>
  parent: Fujii Masao <masao.fujii@gmail.com>
  0 siblings, 0 replies; 7+ messages in thread

From: Michael Paquier @ 2019-11-07 07:52 UTC (permalink / raw)
  To: Fujii Masao <masao.fujii@gmail.com>; +Cc: Andrey Lepikhov <a.lepikhov@postgrespro.ru>; PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>

On Thu, Nov 07, 2019 at 04:37:00PM +0900, Fujii Masao wrote:
> Thanks for the check! I committed the patch!

Thanks Fujii-san.
--
Michael

Attachments:

  signature.asc (application/pgp-signature, 832B) download

^ permalink  raw  reply  [nested|flat] 7+ messages in thread


end of thread, other threads:[~2019-11-07 07:52 UTC | newest]

Thread overview: 7+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2019-11-06 02:40 The XLogFindNextRecord() routine find incorrect record start point after a long continuation record Andrey Lepikhov <a.lepikhov@postgrespro.ru>
2019-11-06 04:41 ` Michael Paquier <michael@paquier.xyz>
2019-11-06 05:06   ` Andrey Lepikhov <a.lepikhov@postgrespro.ru>
2019-11-06 17:41     ` Fujii Masao <masao.fujii@gmail.com>
2019-11-07 03:41       ` Michael Paquier <michael@paquier.xyz>
2019-11-07 07:37         ` Fujii Masao <masao.fujii@gmail.com>
2019-11-07 07:52           ` Michael Paquier <michael@paquier.xyz>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox