Horton

Thread

Commits

  1. Avoid duplicate XIDs at recovery when building initial snapshot

  1. out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-05T07:06:45Z

    Hi hackers,

Looks like there is a bug with logging running transactions XIDs and 
prepared transactions.
One of our customers get error "FATAL: out-of-order XID insertion in 
KnownAssignedXids"
trying to apply backup.
WAL contains the following record:

rmgr: Standby     len (rec/tot):     98/    98, tx: 0, lsn: 
1418/A9A76C90, prev 1418/A9A76C48, desc: RUNNING_XACTS nextXid 
2004495309 latestCompletedXid 2004495307 oldestRunningXid 2004495290; 3 
xacts: 2004495290 2004495308 2004495308

As you can notice, XID 2004495308 is encountered twice which cause error 
in KnownAssignedXidsAdd:

     if (head > tail &&
         TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1], 
from_xid))
     {
         KnownAssignedXidsDisplay(LOG);
         elog(ERROR, "out-of-order XID insertion in KnownAssignedXids");
     }

The probability of this error is very small but it can quite easily 
reproduced: you should just set breakpoint in debugger after calling 
MarkAsPrepared in twophase.c and then try to prepare any transaction.
MarkAsPrepared  will add GXACT to proc array and at this moment there 
will be two entries in procarray with the same XID:

(gdb) p procArray->numProcs
$2 = 4
(gdb) p allPgXact[procArray->pgprocnos[0]]
$4 = {xid = 513976717, xmin = 0, vacuumFlags = 0 '\000', overflowed = 0 
'\000', delayChkpt = 1 '\001', nxids = 0 '\000',
   used = 0 '\000', parent = 0x0}
(gdb) p allPgXact[procArray->pgprocnos[1]]
$5 = {xid = 0, xmin = 0, vacuumFlags = 0 '\000', overflowed = 0 '\000', 
delayChkpt = 0 '\000', nxids = 0 '\000',
   used = 0 '\000', parent = 0x0}
(gdb) p allPgXact[procArray->pgprocnos[2]]
$6 = {xid = 0, xmin = 0, vacuumFlags = 0 '\000', overflowed = 0 '\000', 
delayChkpt = 0 '\000', nxids = 0 '\000',
   used = 0 '\000', parent = 0x0}
(gdb) p allPgXact[procArray->pgprocnos[3]]
$7 = {xid = 513976717, xmin = 0, vacuumFlags = 0 '\000', overflowed = 0 
'\000', delayChkpt = 0 '\000', nxids = 0 '\000',
   used = 0 '\000', parent = 0x0}

Then you should just wait for sometime until checkpoint timeout is 
triggered and it  logs snapshot:

(gdb) bt
#0  0x00000000007f3dab in GetRunningTransactionData () at procarray.c:2240
#1  0x00000000007fab22 in LogStandbySnapshot () at standby.c:943
#2  0x000000000077cde8 in BackgroundWriterMain () at bgwriter.c:331
#3  0x00000000005377f3 in AuxiliaryProcessMain (argc=2, 
argv=0x7ffe00aa00e0) at bootstrap.c:446
#4  0x000000000078e07e in StartChildProcess (type=BgWriterProcess) at 
postmaster.c:5323
#5  0x000000000078b6f0 in reaper (postgres_signal_arg=17) at 
postmaster.c:2948
#6  <signal handler called>
#7  0x00007f1356d665b3 in __select_nocancel () at 
../sysdeps/unix/syscall-template.S:84
#8  0x0000000000789931 in ServerLoop () at postmaster.c:1765
#9  0x000000000078906c in PostmasterMain (argc=3, argv=0x1902640) at 
postmaster.c:1406
#10 0x00000000006d0e4f in main (argc=3, argv=0x1902640) at main.c:228

Now generated RUNNING_XACTS record contains duplicated XIDs.

I want to ask opinion of community about the best way of fixing this 
problem.
Should we avoid storing duplicated XIDs in procarray (by invalidating 
XID in original pgaxct)
or eliminate/change check for duplicate in KnownAssignedXidsAdd (for 
example just ignore duplicates)?

  2. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-05T08:04:22Z

    On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
> As you can notice, XID 2004495308 is encountered twice which cause error in
> KnownAssignedXidsAdd:
> 
>     if (head > tail &&
>         TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1], from_xid))
>     {
>         KnownAssignedXidsDisplay(LOG);
>         elog(ERROR, "out-of-order XID insertion in KnownAssignedXids");
>     }
> 
> The probability of this error is very small but it can quite easily
> reproduced: you should just set breakpoint in debugger after calling
> MarkAsPrepared in twophase.c and then try to prepare any transaction.
> MarkAsPrepared  will add GXACT to proc array and at this moment there will
> be two entries in procarray with the same XID:
>
> [snip]
>
> Now generated RUNNING_XACTS record contains duplicated XIDs.

So, I have been doing exactly that, and if you trigger a manual
checkpoint then things happen quite correctly if you let the first
session finish:
rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606

If you still maintain the debugger after calling MarkAsPrepared, then
the manual checkpoint would block.  Now if you actually keep the
debugger, and wait for a checkpoint timeout to happen, then I can see
the incorrect record.  It is impressive that your customer has been able
to see that first, and then that you have been able to get into that
state with simple steps.

> I want to ask opinion of community about the best way of fixing this
> problem.  Should we avoid storing duplicated XIDs in procarray (by
> invalidating XID in original pgaxct) or eliminate/change check for
> duplicate in KnownAssignedXidsAdd (for example just ignore
> duplicates)?

Hmmmmm...  Please let me think through that first.  It seems to me that
the record should not be generated to begin with.  At least I am able to
confirm what you see.
--
Michael

  3. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-05T08:33:08Z

    
On 05.10.2018 11:04, Michael Paquier wrote:
> On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
>> As you can notice, XID 2004495308 is encountered twice which cause error in
>> KnownAssignedXidsAdd:
>>
>>      if (head > tail &&
>>          TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1], from_xid))
>>      {
>>          KnownAssignedXidsDisplay(LOG);
>>          elog(ERROR, "out-of-order XID insertion in KnownAssignedXids");
>>      }
>>
>> The probability of this error is very small but it can quite easily
>> reproduced: you should just set breakpoint in debugger after calling
>> MarkAsPrepared in twophase.c and then try to prepare any transaction.
>> MarkAsPrepared  will add GXACT to proc array and at this moment there will
>> be two entries in procarray with the same XID:
>>
>> [snip]
>>
>> Now generated RUNNING_XACTS record contains duplicated XIDs.
> So, I have been doing exactly that, and if you trigger a manual
> checkpoint then things happen quite correctly if you let the first
> session finish:
> rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
> 0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
> latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606
>
> If you still maintain the debugger after calling MarkAsPrepared, then
> the manual checkpoint would block.  Now if you actually keep the
> debugger, and wait for a checkpoint timeout to happen, then I can see
> the incorrect record.  It is impressive that your customer has been able
> to see that first, and then that you have been able to get into that
> state with simple steps.


There are about 1000 active clients performing 2PC transactions, so if 
you perform backup (which does checkpoint)
then probability seems to be large enough.

I have reproduced this problem without using gdb by just running in 
parallel many 2PC transactions and checkpoints:

for ((i=1;i<10;i++))
do
     pgbench -n -T 300000 -M prepared -f t$i.sql postgres > t$i.log &
done

pgbench -n -T 300000 -f checkpoint.sql postgres > checkpoint.log &
wait
------------------------------

tN.sql:

begin;
update t set val=val+1 where pk=N;
prepare transaction 'tN';
commit prepared 'tN';

------------------------------

checkpoint.sql:

checkpoint;



>
>> I want to ask opinion of community about the best way of fixing this
>> problem.  Should we avoid storing duplicated XIDs in procarray (by
>> invalidating XID in original pgaxct) or eliminate/change check for
>> duplicate in KnownAssignedXidsAdd (for example just ignore
>> duplicates)?
> Hmmmmm...  Please let me think through that first.  It seems to me that
> the record should not be generated to begin with.  At least I am able to
> confirm what you see.
> --
> Michael

-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  4. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-08T09:04:28Z

    
On 05.10.2018 11:04, Michael Paquier wrote:
> On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
>> As you can notice, XID 2004495308 is encountered twice which cause error in
>> KnownAssignedXidsAdd:
>>
>>      if (head > tail &&
>>          TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1], from_xid))
>>      {
>>          KnownAssignedXidsDisplay(LOG);
>>          elog(ERROR, "out-of-order XID insertion in KnownAssignedXids");
>>      }
>>
>> The probability of this error is very small but it can quite easily
>> reproduced: you should just set breakpoint in debugger after calling
>> MarkAsPrepared in twophase.c and then try to prepare any transaction.
>> MarkAsPrepared  will add GXACT to proc array and at this moment there will
>> be two entries in procarray with the same XID:
>>
>> [snip]
>>
>> Now generated RUNNING_XACTS record contains duplicated XIDs.
> So, I have been doing exactly that, and if you trigger a manual
> checkpoint then things happen quite correctly if you let the first
> session finish:
> rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
> 0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
> latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606
>
> If you still maintain the debugger after calling MarkAsPrepared, then
> the manual checkpoint would block.  Now if you actually keep the
> debugger, and wait for a checkpoint timeout to happen, then I can see
> the incorrect record.  It is impressive that your customer has been able
> to see that first, and then that you have been able to get into that
> state with simple steps.
>
>> I want to ask opinion of community about the best way of fixing this
>> problem.  Should we avoid storing duplicated XIDs in procarray (by
>> invalidating XID in original pgaxct) or eliminate/change check for
>> duplicate in KnownAssignedXidsAdd (for example just ignore
>> duplicates)?
> Hmmmmm...  Please let me think through that first.  It seems to me that
> the record should not be generated to begin with.  At least I am able to
> confirm what you see.

The simplest way to fix the problem is to ignore duplicates before 
adding them to KnownAssignedXids.
We in any case perform sort i this place...



-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  5. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-08T09:14:51Z

    On Mon, Oct 08, 2018 at 12:04:28PM +0300, Konstantin Knizhnik wrote:
> The simplest way to fix the problem is to ignore duplicates before adding
> them to KnownAssignedXids.
> We in any case perform sort i this place...

I may of course be missing something, but shouldn't we not have
duplicates in the first place?
--
Michael

  6. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-08T09:33:20Z

    
On 08.10.2018 12:14, Michael Paquier wrote:
> On Mon, Oct 08, 2018 at 12:04:28PM +0300, Konstantin Knizhnik wrote:
>> The simplest way to fix the problem is to ignore duplicates before adding
>> them to KnownAssignedXids.
>> We in any case perform sort i this place...
> I may of course be missing something, but shouldn't we not have
> duplicates in the first place?
The reason of appearing duplicated XIDs in case of 2PC seems to be clear.
It may be possible to eliminate it by clearing XID of MyPgxact for 
prepared transaction.
But there are two problems with it:
1. I am not sure that it will not break something
2. There is obvious race condition between adding GXACT to ProcArrayAdd 
and invalidating XID of current transaction.
If it is cleared before calling ProcArrayAdd, then there will be some 
moment when XID is not present in procarray.
If it is done after calling ProcArrayAdd, then still it is possible to 
see duplicated XID in procarray.

 From my point of view it is easier and less invasive to exclude 
duplicates while replaying RUNNING_XIDS record.




-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  7. Re: out-of-order XID insertion in KnownAssignedXids

    Andres Freund <andres@anarazel.de> — 2018-10-08T15:24:25Z

    
On October 8, 2018 2:04:28 AM PDT, Konstantin Knizhnik <k.knizhnik@postgrespro.ru> wrote:
>
>
>On 05.10.2018 11:04, Michael Paquier wrote:
>> On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
>>> As you can notice, XID 2004495308 is encountered twice which cause
>error in
>>> KnownAssignedXidsAdd:
>>>
>>>      if (head > tail &&
>>>          TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1],
>from_xid))
>>>      {
>>>          KnownAssignedXidsDisplay(LOG);
>>>          elog(ERROR, "out-of-order XID insertion in
>KnownAssignedXids");
>>>      }
>>>
>>> The probability of this error is very small but it can quite easily
>>> reproduced: you should just set breakpoint in debugger after calling
>>> MarkAsPrepared in twophase.c and then try to prepare any
>transaction.
>>> MarkAsPrepared  will add GXACT to proc array and at this moment
>there will
>>> be two entries in procarray with the same XID:
>>>
>>> [snip]
>>>
>>> Now generated RUNNING_XACTS record contains duplicated XIDs.
>> So, I have been doing exactly that, and if you trigger a manual
>> checkpoint then things happen quite correctly if you let the first
>> session finish:
>> rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
>> 0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
>> latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606
>>
>> If you still maintain the debugger after calling MarkAsPrepared, then
>> the manual checkpoint would block.  Now if you actually keep the
>> debugger, and wait for a checkpoint timeout to happen, then I can see
>> the incorrect record.  It is impressive that your customer has been
>able
>> to see that first, and then that you have been able to get into that
>> state with simple steps.
>>
>>> I want to ask opinion of community about the best way of fixing this
>>> problem.  Should we avoid storing duplicated XIDs in procarray (by
>>> invalidating XID in original pgaxct) or eliminate/change check for
>>> duplicate in KnownAssignedXidsAdd (for example just ignore
>>> duplicates)?
>> Hmmmmm...  Please let me think through that first.  It seems to me
>that
>> the record should not be generated to begin with.  At least I am able
>to
>> confirm what you see.
>
>The simplest way to fix the problem is to ignore duplicates before 
>adding them to KnownAssignedXids.
>We in any case perform sort i this place...

I vehemently object to that as the proper course.

Andres
-- 
Sent from my Android device with K-9 Mail. Please excuse my brevity.

  8. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-08T15:28:52Z

    
On 08.10.2018 18:24, Andres Freund wrote:
>
> On October 8, 2018 2:04:28 AM PDT, Konstantin Knizhnik <k.knizhnik@postgrespro.ru> wrote:
>>
>> On 05.10.2018 11:04, Michael Paquier wrote:
>>> On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
>>>> As you can notice, XID 2004495308 is encountered twice which cause
>> error in
>>>> KnownAssignedXidsAdd:
>>>>
>>>>       if (head > tail &&
>>>>           TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1],
>> from_xid))
>>>>       {
>>>>           KnownAssignedXidsDisplay(LOG);
>>>>           elog(ERROR, "out-of-order XID insertion in
>> KnownAssignedXids");
>>>>       }
>>>>
>>>> The probability of this error is very small but it can quite easily
>>>> reproduced: you should just set breakpoint in debugger after calling
>>>> MarkAsPrepared in twophase.c and then try to prepare any
>> transaction.
>>>> MarkAsPrepared  will add GXACT to proc array and at this moment
>> there will
>>>> be two entries in procarray with the same XID:
>>>>
>>>> [snip]
>>>>
>>>> Now generated RUNNING_XACTS record contains duplicated XIDs.
>>> So, I have been doing exactly that, and if you trigger a manual
>>> checkpoint then things happen quite correctly if you let the first
>>> session finish:
>>> rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
>>> 0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
>>> latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606
>>>
>>> If you still maintain the debugger after calling MarkAsPrepared, then
>>> the manual checkpoint would block.  Now if you actually keep the
>>> debugger, and wait for a checkpoint timeout to happen, then I can see
>>> the incorrect record.  It is impressive that your customer has been
>> able
>>> to see that first, and then that you have been able to get into that
>>> state with simple steps.
>>>
>>>> I want to ask opinion of community about the best way of fixing this
>>>> problem.  Should we avoid storing duplicated XIDs in procarray (by
>>>> invalidating XID in original pgaxct) or eliminate/change check for
>>>> duplicate in KnownAssignedXidsAdd (for example just ignore
>>>> duplicates)?
>>> Hmmmmm...  Please let me think through that first.  It seems to me
>> that
>>> the record should not be generated to begin with.  At least I am able
>> to
>>> confirm what you see.
>> The simplest way to fix the problem is to ignore duplicates before
>> adding them to KnownAssignedXids.
>> We in any case perform sort i this place...
> I vehemently object to that as the proper course.
And what about adding qsort to GetRunningTransactionData or 
LogCurrentRunningXacts and excluding duplicates here?


> Andres

-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  9. Re: out-of-order XID insertion in KnownAssignedXids

    Andres Freund <andres@anarazel.de> — 2018-10-08T16:30:49Z

    On 2018-10-08 18:28:52 +0300, Konstantin Knizhnik wrote:
> 
> 
> On 08.10.2018 18:24, Andres Freund wrote:
> > 
> > On October 8, 2018 2:04:28 AM PDT, Konstantin Knizhnik <k.knizhnik@postgrespro.ru> wrote:
> > > 
> > > On 05.10.2018 11:04, Michael Paquier wrote:
> > > > On Fri, Oct 05, 2018 at 10:06:45AM +0300, Konstantin Knizhnik wrote:
> > > > > As you can notice, XID 2004495308 is encountered twice which cause
> > > error in
> > > > > KnownAssignedXidsAdd:
> > > > > 
> > > > >       if (head > tail &&
> > > > >           TransactionIdFollowsOrEquals(KnownAssignedXids[head - 1],
> > > from_xid))
> > > > >       {
> > > > >           KnownAssignedXidsDisplay(LOG);
> > > > >           elog(ERROR, "out-of-order XID insertion in
> > > KnownAssignedXids");
> > > > >       }
> > > > > 
> > > > > The probability of this error is very small but it can quite easily
> > > > > reproduced: you should just set breakpoint in debugger after calling
> > > > > MarkAsPrepared in twophase.c and then try to prepare any
> > > transaction.
> > > > > MarkAsPrepared  will add GXACT to proc array and at this moment
> > > there will
> > > > > be two entries in procarray with the same XID:
> > > > > 
> > > > > [snip]
> > > > > 
> > > > > Now generated RUNNING_XACTS record contains duplicated XIDs.
> > > > So, I have been doing exactly that, and if you trigger a manual
> > > > checkpoint then things happen quite correctly if you let the first
> > > > session finish:
> > > > rmgr: Standby     len (rec/tot):     58/    58, tx:          0, lsn:
> > > > 0/016150F8, prev 0/01615088, desc: RUNNING_XACTS nextXid 608
> > > > latestCompletedXid 605 oldestRunningXid 606; 2 xacts: 607 606
> > > > 
> > > > If you still maintain the debugger after calling MarkAsPrepared, then
> > > > the manual checkpoint would block.  Now if you actually keep the
> > > > debugger, and wait for a checkpoint timeout to happen, then I can see
> > > > the incorrect record.  It is impressive that your customer has been
> > > able
> > > > to see that first, and then that you have been able to get into that
> > > > state with simple steps.
> > > > 
> > > > > I want to ask opinion of community about the best way of fixing this
> > > > > problem.  Should we avoid storing duplicated XIDs in procarray (by
> > > > > invalidating XID in original pgaxct) or eliminate/change check for
> > > > > duplicate in KnownAssignedXidsAdd (for example just ignore
> > > > > duplicates)?
> > > > Hmmmmm...  Please let me think through that first.  It seems to me
> > > that
> > > > the record should not be generated to begin with.  At least I am able
> > > to
> > > > confirm what you see.
> > > The simplest way to fix the problem is to ignore duplicates before
> > > adding them to KnownAssignedXids.
> > > We in any case perform sort i this place...
> > I vehemently object to that as the proper course.
> And what about adding qsort to GetRunningTransactionData or
> LogCurrentRunningXacts and excluding duplicates here?

Sounds less terrible, but still pretty bad.  I think we should fix the
underlying data inconsistency, not paper over it a couple hundred meters
away.

Greetings,

Andres Freund

  10. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-09T05:59:00Z

    On Mon, Oct 08, 2018 at 09:30:49AM -0700, Andres Freund wrote:
> Sounds less terrible, but still pretty bad.  I think we should fix the
> underlying data inconsistency, not paper over it a couple hundred meters
> away.

+1.  I am looking at how to make that possible.
--
Michael

  11. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-09T07:52:58Z

    On Tue, Oct 09, 2018 at 02:59:00PM +0900, Michael Paquier wrote:
> +1.  I am looking at how to make that possible.

And so...  Going through a bit of investigation the problem is that each
2PC transaction preparing finishes by putting the procarray in a state
where there are two entries referring to the same transaction running as
MarkAsPrepared adds an extra entry on the top of the one already
existing.  This is expected though per the comments in
ProcArrayClearTransaction(), as it assumes that MyProc can be safely
cleaned and it assumes that there is a duplicated entry.  Then,
GetRunningTransactionData() ignores the assumption that those duplicate
entries can exist, which makes the snapshot data taken as incorrect,
generating those incorrect XLOG_RUNNING_XACT records.

The most simple fix I can think of first is to tweak the origin of the
problem in GetRunningTransactionData() so as those duplicate XIDs are
ignored if found as there has to be a state between the time
MarkAsPrepared() inserted the 2PC entry in the procarray and the time
ProcArrayClearTransaction() gets called.
--
Michael

  12. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-09T14:26:49Z

    
On 09.10.2018 10:52, Michael Paquier wrote:
> On Tue, Oct 09, 2018 at 02:59:00PM +0900, Michael Paquier wrote:
>> +1.  I am looking at how to make that possible.
> And so...  Going through a bit of investigation the problem is that each
> 2PC transaction preparing finishes by putting the procarray in a state
> where there are two entries referring to the same transaction running as
> MarkAsPrepared adds an extra entry on the top of the one already
> existing.  This is expected though per the comments in
> ProcArrayClearTransaction(), as it assumes that MyProc can be safely
> cleaned and it assumes that there is a duplicated entry.  Then,
> GetRunningTransactionData() ignores the assumption that those duplicate
> entries can exist, which makes the snapshot data taken as incorrect,
> generating those incorrect XLOG_RUNNING_XACT records.
>
> The most simple fix I can think of first is to tweak the origin of the
> problem in GetRunningTransactionData() so as those duplicate XIDs are
> ignored if found as there has to be a state between the time
> MarkAsPrepared() inserted the 2PC entry in the procarray and the time
> ProcArrayClearTransaction() gets called.
> --
> Michael

Right now GetRunningTransactionData is used only once in Postgres code - in LogStandbySnapshot to log RUNNING_XACTS record.
So if this situation is not changed, there will be no difference whether to perform sort and exclude duplicates in LogStandbySnapsho
or GetRunningTransactionData.

But GetRunningTransactionData may be used in some other cases... For example I have used it in my snapfs Postgres extensions (fast file-level snapshots)
to check if there are no more active transactions in the system. In my case presence of duplicates is not important and ordering of XIDs is not needed.
But performance of GetRunningTransactionData is also not critical. But I can suspect that there can be cases when it is critical and doing unneeded qsort is not desired.
There may be thousands of active transactions and sorting their XIDs is notinstantaneous.

Also please take in account that in most cases XIDs in RUNNINGS_XACTS record are not processed at all (only if we perform recovery from backup and do not reach consistent point yet). This is why this bug was not detected before.

So I completely understand the argument that it is better to eliminate source of the problem (presence of duplicates in RUNNING_XACTS record)
but not sure that in this particular case it is really the best solution. If presence of duplicates is considered to be acceptable for procarray, why we
can not accept it for RUNNING_XACTS record?

I am not insisting that skipping duplicates in 
ProcArrayApplyRecoveryInfo is the right place (but at least is seems to 
be the most efficient alternative). But I also do not fill that moving 
sort to GetRunningTransactionData and elimination of duplicates here 
(requires one more scan and copying of the whole array) is principally 
better...


-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  13. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-10T02:22:45Z

    On Tue, Oct 09, 2018 at 05:26:49PM +0300, Konstantin Knizhnik wrote:
> But GetRunningTransactionData may be used in some other cases... For
> example I have used it in my snapfs Postgres extensions (fast
> file-level snapshots) to check if there are no more active
> transactions in the system. In my case presence of duplicates is not
> important and ordering of XIDs is not needed.  But performance of
> GetRunningTransactionData is also not critical. But I can suspect that
> there can be cases when it is critical and doing unneeded qsort is not
> desired.  There may be thousands of active transactions and sorting
> their XIDs is notinstantaneous.

I am not sure if the performance argument is actually this much
sensible, it could be as you say, but another thing that we could argue
about is that the presence of duplicate entries in
GetRunningTransactionData() can be used as a point to understand that
2PC transactions are running, and that among the two, one of them is a
dummy entry while the other is pending for being cleared.

> So I completely understand the argument that it is better to eliminate
> source of the problem (presence of duplicates in RUNNING_XACTS record)
> but not sure that in this particular case it is really the best
> solution. If presence of duplicates is considered to be acceptable for
> procarray, why we can not accept it for RUNNING_XACTS record?

This won't solve the case where records have already been generated and
won't be processed correctly, but based on the chances this can happen
we can rather safely say that fixing only the source would be fine.

> I am not insisting that skipping duplicates in ProcArrayApplyRecoveryInfo is
> the right place (but at least is seems to be the most efficient
> alternative). But I also do not fill that moving sort to
> GetRunningTransactionData and elimination of duplicates here (requires one
> more scan and copying of the whole array) is principally better...

Making recovery a couple of instructions shorter is always a good thing
in my opinion.  Users don't care much if backups take a long time, ans
sweat less if restores take a shorter time.

Hence what about doing roughly the following:

1) Document that GetRunningTransactionData() fetches information also
about 2PC entries, like that:
  * GetRunningTransactionData -- returns information about running transactions.
  *
  * Similar to GetSnapshotData but returns more information. We include
- * all PGXACTs with an assigned TransactionId, even VACUUM processes.
+ * all PGXACTs with an assigned TransactionId, even VACUUM processes and
+ * dummy two-phase related entries created when preparing the transaction.

2) Update LogStandbySnapshot so as the list of XIDs fetched is sorted
and ordered.  This can be used as a sanity check for recovery via
ProcArrayApplyRecoveryInfo().
--
Michael

  14. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-11T09:06:11Z

    On Wed, Oct 10, 2018 at 11:22:45AM +0900, Michael Paquier wrote:
> I am not sure if the performance argument is actually this much
> sensible, it could be as you say, but another thing that we could argue
> about is that the presence of duplicate entries in
> GetRunningTransactionData() can be used as a point to understand that
> 2PC transactions are running, and that among the two, one of them is a
> dummy entry while the other is pending for being cleared.

Actually there would be a performance impact for any deployments if we
were to do so, as ProcArrayLock is hold and we would need to scan 4
times procArray instead of twice.  Many people already complain (justly)
that ProcArray is a performance bottleneck, it would be a bad idea to
make things worse...

> 1) Document that GetRunningTransactionData() fetches information also
> about 2PC entries, like that:
>   * GetRunningTransactionData -- returns information about running transactions.
>   *
>   * Similar to GetSnapshotData but returns more information. We include
> - * all PGXACTs with an assigned TransactionId, even VACUUM processes.
> + * all PGXACTs with an assigned TransactionId, even VACUUM processes and
> + * dummy two-phase related entries created when preparing the transaction.
> 
> 2) Update LogStandbySnapshot so as the list of XIDs fetched is sorted
> and ordered.  This can be used as a sanity check for recovery via
> ProcArrayApplyRecoveryInfo().

This also would increase the pressure on ProcArrayLock with wal_level =
logical as the WAL record needs to be included while holding the lock.
So let's do as Konstantin is suggesting by skipping duplicated XIDs
after applying the qsort().  The current code is also doing a bad
documentation job, so we should mentioned that GetRunningTransactionData
may return duplicated XIDs because of the dummy 2PC entries which
overlap with the active ones, and also add a proper comment in
ProcArrayApplyRecoveryInfo().  Konstantin, do you want to give it a try
with a patch?  Or should I?
--
Michael

  15. Re: out-of-order XID insertion in KnownAssignedXids

    Konstantin Knizhnik <k.knizhnik@postgrespro.ru> — 2018-10-11T17:04:11Z

    
On 11.10.2018 12:06, Michael Paquier wrote:
> On Wed, Oct 10, 2018 at 11:22:45AM +0900, Michael Paquier wrote:
>> I am not sure if the performance argument is actually this much
>> sensible, it could be as you say, but another thing that we could argue
>> about is that the presence of duplicate entries in
>> GetRunningTransactionData() can be used as a point to understand that
>> 2PC transactions are running, and that among the two, one of them is a
>> dummy entry while the other is pending for being cleared.
> Actually there would be a performance impact for any deployments if we
> were to do so, as ProcArrayLock is hold and we would need to scan 4
> times procArray instead of twice.  Many people already complain (justly)
> that ProcArray is a performance bottleneck, it would be a bad idea to
> make things worse...
>
>> 1) Document that GetRunningTransactionData() fetches information also
>> about 2PC entries, like that:
>>    * GetRunningTransactionData -- returns information about running transactions.
>>    *
>>    * Similar to GetSnapshotData but returns more information. We include
>> - * all PGXACTs with an assigned TransactionId, even VACUUM processes.
>> + * all PGXACTs with an assigned TransactionId, even VACUUM processes and
>> + * dummy two-phase related entries created when preparing the transaction.
>>
>> 2) Update LogStandbySnapshot so as the list of XIDs fetched is sorted
>> and ordered.  This can be used as a sanity check for recovery via
>> ProcArrayApplyRecoveryInfo().
> This also would increase the pressure on ProcArrayLock with wal_level =
> logical as the WAL record needs to be included while holding the lock.
> So let's do as Konstantin is suggesting by skipping duplicated XIDs
> after applying the qsort().  The current code is also doing a bad
> documentation job, so we should mentioned that GetRunningTransactionData
> may return duplicated XIDs because of the dummy 2PC entries which
> overlap with the active ones, and also add a proper comment in
> ProcArrayApplyRecoveryInfo().  Konstantin, do you want to give it a try
> with a patch?  Or should I?
> --
> Michael

Proposed patch is attached.


-- 
Konstantin Knizhnik
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company

  16. Re: out-of-order XID insertion in KnownAssignedXids

    Michael Paquier <michael@paquier.xyz> — 2018-10-12T02:49:01Z

    On Thu, Oct 11, 2018 at 08:04:11PM +0300, Konstantin Knizhnik wrote:
> Proposed patch is attached.

The problem I have with this patch doing the duplication removal and
qsort work in LogCurrentRunningXacts is that it would still lock
ProcArrayLock until the WAL record has been written with wal_level =
logical.  With many sessions and 2PC transactions running around, this
would be a performance impact for any deployments every time a
checkpoint happens or every time the bgwriter decide to log a standby
snapshot.  Hence I would go instead with the attached, which does the
legwork at recovery, which is a one-time code path as you mentioned.
Okay, this makes the recovery a bit longer but that's way better than
impacting all deployments of Postgres, even those not using 2PC when
normally running.  And as the sorting phase already happens we just need
to do something like the attached.

One thing that we could also do for HEAD is to add in
RunningTransactionsData if the transaction comes from a 2PC entry, and
allow recovery to do more sanity checks.  This would require a WAL
format change.  The proposed patch needs to be back-patched down to
9.3.
--
Michael