Re: Hot Standby: too many KnownAssignedXids

On 24.11.2010 06:56, Joachim Wieland wrote:
> On Tue, Nov 23, 2010 at 8:45 AM, Heikki Linnakangas
> <heikki.linnakangas@enterprisedb.com>  wrote:
>> On 19.11.2010 23:46, Joachim Wieland wrote:
>>>
>>> FATAL:  too many KnownAssignedXids. head: 0, tail: 0, nxids: 9978,
>>> pArray->maxKnownAssignedXids: 6890
>>
>> Hmm, that's a lot of entries in KnownAssignedXids.
>>
>> Can you recompile with WAL_DEBUG, and run the recovery again with
>> wal_debug=on ? That will print all the replayed WAL records, which is a lot
>> of data, but it might give a hint what's going on.
>
> Sure, but this gives me only one more line:
>
> [...]
> LOG:  redo starts at 1F8/FC00E978
> LOG:  REDO @ 1F8/FC00E978; LSN 1F8/FC00EE90: prev 1F8/FC00E930; xid
> 385669; len 21; bkpb1: Heap - insert: rel 1663/16384/18373; tid
> 3829898/23
> FATAL:  too many KnownAssignedXids
> CONTEXT:  xlog redo insert: rel 1663/16384/18373; tid 3829898/23
> LOG:  startup process (PID 4587) exited with exit code 1
> LOG:  terminating any other active server processes

Thanks, I can reproduce this now. This happens when you have a wide gap 
between the oldest still active xid and the latest xid.

When recovery starts, we fetch the oldestActiveXid from the checkpoint 
record. Let's say that it's 100. We then start replaying WAL records 
from the Redo pointer, and the first record (heap insert in your case) 
contains an Xid that's much larger than 100, say 10000. We call 
RecordKnownAssignedXids() to make note that all xids between that range 
are in-progress, but there isn't enough room in the array for that.

We normally get away with a smallish array because the array is trimmed 
at commit and abort records, and the special xid-assignment record to 
handle the case of a lot of subtransactions. We initialize the array 
from the running-xacts record that's written at a checkpoint. That 
mechanism fails in this case because the heap insert record is seen 
before the running-xacts record, causing all those xids in the range 
100-10000 to be considered in-progress. The running-xacts record that 
comes later would prune them, but we don't have enough slots to hold 
them until that.

Hmm. I'm not sure off the top of my head how to fix that. Perhaps stash 
the xids we see during WAL replay in private memory instead of putting 
them in the KnownAssignedXids array until we see the running-xacts record.

To reproduce this, I did this in the master:

postgres=# CREATE FUNCTION insertfunc(n integer) RETURNS VOID AS $$
declare  i integer;
begin  FOR i IN 1..n LOOP    BEGIN      INSERT INTO foo VALUES (1);    EXCEPTION WHEN division_by_zero THEN RAISE
NOTICE'divbyzero';    END;  END LOOP;
 
end;
$$ LANGUAGE plpgsql;
postgres=# SELECT insertfunc(100000000);

After letting that run for a while, so that a couple of checkpoints have 
occurred, kill the master and start standby to recover that from 
archive. After it has replayed all the WAL, stop the standby and restart it.

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