Re: BUG #14195: "MultiXactId XXXXXX has not been created yet -- apparent wraparound" after upgrade from 9.2

>>>>> "sean" == sean hope <sean.hope@eroad.com> writes:

 sean> The following bug has been logged on the website:
 sean> Bug reference:      14195
 sean> Logged by:          Sean Hope
 sean> Email address:      sean.hope@eroad.com
 sean> PostgreSQL version: 9.4.7
 sean> Operating system:   Ubuntu 12.04 LTS
 sean> Description:

 sean> Hi,

 sean> We're having issues with 'MultiXactId xxxxxxxxx has not been
 sean> created yet -- apparent wraparound' log messages upon table
 sean> vacuums. The vacuums are cancelled by the system after this
 sean> message is issued.

 sean> These messages have only been seen since upgrading from 9.2.x to
 sean> 9.4.7 via pg_upgrade about a month ago. This is a large / high
 sean> transaction rate (1120 tps) database. We are unable to vacuum the
 sean> affected tables (5 of them) currently due to this issue.

This one came up on the IRC channel and I did some analysis there.

What it seems to boil down to is that, faced with a tuple with a
pre-upgrade mxid, we get this call path:

vacuum calls heap_prepare_freeze_tuple

heap_prepare_freeze_tuple calls FreezeMultiXactId
 (because HEAP_XMAX_IS_MULTI)

FreezeMultiXactId checks if the mxid is older than the cutoff, but
because this is a pre-upgrade mxid it can be literally anything, and in
this case it's in the future not the past, so that check is skipped

FreezeMultiXactId calls GetMultiXactIdMembers with allow_old=true

GetMultiXactIdMembers checks for wraparound, but while it downgrades the
error to DEBUG1 if allow_old is true and the mxid is in the past, it
unconditionally errors if the mxid is in the future.

From pageinspect output this is one of the failing tuples:

blk: 291;
lp: 35;
lp_off: 7992;
lp_flags: 1;
lp_len: 196;
t_xmin: 2;
t_xmax: 197529992;
t_field3: 21;
t_ctid: (291,35);
t_infomask2: 32791;
t_infomask: 14723;  (0x3983)
t_hoff: 32;
bits: "111111111111111111111100000000000000000000000000000000000000000000000000";

(note: the pageinspect output was all absolutely consistent, there were
no signs of any data corruption of any kind)

from pg_controldata:

Latest checkpoint's NextMultiXactId:  3125330305
Latest checkpoint's NextMultiOffset:  2217410182
Latest checkpoint's oldestMultiXid:   2741572175

--
Andrew (irc:RhodiumToad)