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

[sean...@eroad.com]

The following bug has been logged on the website:

Bug reference: 14195
Logged by: Sean Hope
Email address: sean...@eroad.com
PostgreSQL version: 9.4.7
Operating system: Ubuntu 12.04 LTS
Description:

Hi,

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

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

Any help most welcome.

Regards,
Sean

--
Sent via pgsql-bugs mailing list (pgsql...@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-bugs

[Andrew Gierth]

>>>>> "sean" == sean hope <sean...@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...@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)

[Alvaro Herrera]

Andrew Gierth wrote:

> 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.

I was in the middle of writing up this in another thread, and your
analysis in spot on.

https://www.postgresql.org/message-id/20160615233...@alvherre.pgsql

--
Álvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

[Alvaro Herrera]

sean...@eroad.com wrote:

> Hi,
>
> We're having issues with 'MultiXactId xxxxxxxxx has not been created yet --
> apparent wraparound' log messages upon table vacuums. The vacuums are
> cancelled by the system after this message is issued.
>
> These messages have only been seen since upgrading from 9.2.x to 9.4.7 via
> pg_upgrade about a month ago. This is a large / high transaction rate (1120
> tps) database. We are unable to vacuum the affected tables (5 of them)

> currently due to this issue.

This is fixed now, finally.
https://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=61b24fef89a9f7e381e6d83029b63e062d32812b
The other thread I linked to earlier has more discussion.

[caj...@gmail.com]

суббота, 25 июня 2016 г., 2:00:29 UTC+3 пользователь Alvaro Herrera написал:

Hello, i have same problem 'MultiXactId 2908840 has not been created yet', but i found 3 rows where i see problem:

select * from xxx where id = 9083638
select * from xxx where id = 9083640
select * from xxx where id = 9083642

only them give this problem. Do you have possible remove this rows without DELETE command? Because delete and select this rows give same error. Thanks

I did have psql 9.4.8, now i have 9.4.20. i thought the error will go away after update

Thanks