Subject: Re: ERROR: multixact X from before cutoff Y found to be still running
To: "pgsql-bugs@postgresql.org" <pgsql-bugs@postgresql.org>,
	PostgreSQL-development <pgsql-hackers@postgresql.org>
References: <DAFB8AFF-2F05-4E33-AD7F-FF8B0F760C17@amazon.com>
From: Jeremy Schneider <schnjere@amazon.com>
CC: "Bossart, Nathan" <bossartn@amazon.com>, "Nasby, Jim" <nasbyj@amazon.com>
Message-ID: <be665139-6bdc-9535-eaa6-c3c84d3900c7@amazon.com>
Date: Wed, 4 Sep 2019 18:01:05 -0700
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.12; rv:60.0)
 Gecko/20100101 Thunderbird/60.8.0
MIME-Version: 1.0
In-Reply-To: <DAFB8AFF-2F05-4E33-AD7F-FF8B0F760C17@amazon.com>
Content-Type: multipart/mixed;
	boundary="------------C3E0BEF037202CC57E7D4DCC"
Content-Language: en-US
Precedence: Bulk
Precedence: bulk

--------------C3E0BEF037202CC57E7D4DCC
Content-Type: multipart/alternative;
	boundary="------------7C1B62C7D08B7F60DD54EB2D"

--------------7C1B62C7D08B7F60DD54EB2D
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: 8bit

On 9/4/19 17:37, Nathan Bossart wrote:
> Hi,
>
> Currently, if you hold a multixact open long enough to generate an
> "oldest multixact is far in the past" message during VACUUM, you may
> see the following ERROR:
>
>         WARNING:  oldest multixact is far in the past
>         HINT:  Close open transactions with multixacts soon to avoid wraparound problems.
>         ERROR:  multixact X from before cutoff Y found to be still running
>
> Upon further inspection, I found that this is because the multixact
> limit used in this case is the threshold for which we emit the "oldest
> multixact" message.  Instead, I think the multixact limit should be
> set to the result of GetOldestMultiXactId(), effectively forcing a
> minimum freeze age of zero.  The ERROR itself is emitted by
> FreezeMultiXactId() and appears to be a safeguard against problems
> like this.
>
> I've attached a patch to set the limit to the oldest multixact instead
> of the "safeMxactLimit" in this case.  I'd like to credit Jeremy
> Schneider as the original reporter.


This was fun (sortof) - and a good part of the afternoon for Nathan,
Nasby and myself today.  A rather large PostgreSQL database with default
autovacuum settings had a large table that started getting behind on
Sunday.  The server has a fairly large number of CPUs and a respectable
workload.  We realized today that with their XID generation they would
go read-only to prevent wraparound tomorrow.  (And perfectly healthy XID
age on Sunday - that's wraparound in four days! Did I mention that I'm
excited for the default limit GUC change in pg12?)  To make matters more
interesting, whenever we attempted to run a VACUUM command we
encountered the ERROR message that Nate quoted on every single attempt! 
There was a momentary mild panic based on the "ERRCODE_DATA_CORRUPTED"
message parameter in heapam.c FreezeMultiXactId() ... but as we looked
closer we're now thinking there might just be an obscure bug in the code
that sets vacuum limits.

Nathan and Nasby and myself have been chatting about this for quite
awhile but the vacuum code isn't exactly the simplest thing in the world
to reason about.  :)  Anyway, it looks to me like
MultiXactMemberFreezeThreshold() is intended to progressively reduce the
vacuum multixact limits across multiple vacuum runs on the same table,
as pressure on the members space increases.  I'm thinking there was just
a small oversight in writing the formula where under the most aggressive
circumstances, vacuum could actually be instructed to delete multixacts
that are still in use by active transactions and trigger the failure we
observed.

Nate put together an initial patch (attached to the previous email,
which was sent only to the bugs list). We couldn't quite come to a
consensus and on the best approach, but we decided that he'd kick of the
thread and I'd throw out an alternative version of the patch that might
be worth discussion.  [Attached to this email.]  Curious what others think!

-Jeremy

-- 
Jeremy Schneider
Database Engineer
Amazon Web Services


--------------7C1B62C7D08B7F60DD54EB2D
Content-Type: text/html; charset="utf-8"
Content-Transfer-Encoding: 8bit

<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    <div class="moz-cite-prefix">On 9/4/19 17:37, Nathan Bossart wrote:<br>
      <blockquote type="cite"
        cite="mid:DAFB8AFF-2F05-4E33-AD7F-FF8B0F760C17@amazon.com">
        <pre class="moz-quote-pre" wrap="">Hi,

Currently, if you hold a multixact open long enough to generate an
"oldest multixact is far in the past" message during VACUUM, you may
see the following ERROR:

        WARNING:  oldest multixact is far in the past
        HINT:  Close open transactions with multixacts soon to avoid wraparound problems.
        ERROR:  multixact X from before cutoff Y found to be still running

Upon further inspection, I found that this is because the multixact
limit used in this case is the threshold for which we emit the "oldest
multixact" message.  Instead, I think the multixact limit should be
set to the result of GetOldestMultiXactId(), effectively forcing a
minimum freeze age of zero.  The ERROR itself is emitted by
FreezeMultiXactId() and appears to be a safeguard against problems
like this.

I've attached a patch to set the limit to the oldest multixact instead
of the "safeMxactLimit" in this case.  I'd like to credit Jeremy
Schneider as the original reporter.</pre>
      </blockquote>
      <br>
      <br>
      This was fun (sortof) - and a good part of the afternoon for
      Nathan, Nasby and myself today.  A rather large PostgreSQL
      database with default autovacuum settings had a large table that
      started getting behind on Sunday.  The server has a fairly large
      number of CPUs and a respectable workload.  We realized today that
      with their XID generation they would go read-only to prevent
      wraparound tomorrow.  (And perfectly healthy XID age on Sunday -
      that's wraparound in four days! Did I mention that I'm excited for
      the default limit GUC change in pg12?)  To make matters more
      interesting, whenever we attempted to run a VACUUM command we
      encountered the ERROR message that Nate quoted on every single
      attempt!  There was a momentary mild panic based on the
      "ERRCODE_DATA_CORRUPTED" message parameter in heapam.c <span
        class="pl-en">FreezeMultiXactId() ... but as we looked closer
        we're now thinking there might just be an obscure bug in the
        code that sets vacuum limits.<br>
        <br>
      </span>Nathan and Nasby and myself have been chatting about this
      for quite awhile but the vacuum code isn't exactly the simplest
      thing in the world to reason about.  :)  Anyway, it looks to me
      like <span class="pl-en">MultiXactMemberFreezeThreshold() is
        intended to progressively reduce the vacuum multixact limits
        across multiple vacuum runs on the same table, as pressure on
        the members space increases.  I'm thinking there was just a
        small oversight in writing the formula where under the most
        aggressive circumstances, vacuum could actually be instructed to
        delete multixacts that are still in use by active transactions
        and trigger the failure we observed.</span><br>
      <br>
      Nate put together an initial patch (attached to the previous
      email, which was sent only to the bugs list). We couldn't quite
      come to a consensus and on the best approach, but we decided that
      he'd kick of the thread and I'd throw out an alternative version
      of the patch that might be worth discussion.  [Attached to this
      email.]  Curious what others think!<br>
      <br>
      -Jeremy<br>
    </div>
    <br>
    <pre class="moz-signature" cols="72">-- 
Jeremy Schneider
Database Engineer
Amazon Web Services</pre>
  </body>
</html>

--------------7C1B62C7D08B7F60DD54EB2D--

--------------C3E0BEF037202CC57E7D4DCC
Content-Type: text/plain; charset="UTF-8"; x-mac-type=0; x-mac-creator=0;
	name="fix_multixact_limit_v2.patch"
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="fix_multixact_limit_v2.patch"

ZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL2NvbW1hbmRzL3ZhY3V1bS5jIGIvc3JjL2JhY2tl
bmQvY29tbWFuZHMvdmFjdXVtLmMKaW5kZXggZTE1NDUwN2VjZC4uZjA5OTEyNzUxMCAxMDA2
NDQKLS0tIGEvc3JjL2JhY2tlbmQvY29tbWFuZHMvdmFjdXVtLmMKKysrIGIvc3JjL2JhY2tl
bmQvY29tbWFuZHMvdmFjdXVtLmMKQEAgLTg5Myw2ICs4OTMsNyBAQCB2YWN1dW1fc2V0X3hp
ZF9saW1pdHMoUmVsYXRpb24gcmVsLAogCWludAkJCWVmZmVjdGl2ZV9tdWx0aXhhY3RfZnJl
ZXplX21heF9hZ2U7CiAJVHJhbnNhY3Rpb25JZCBsaW1pdDsKIAlUcmFuc2FjdGlvbklkIHNh
ZmVMaW1pdDsKKwlNdWx0aVhhY3RJZCBvbGRlc3RNeGFjdDsKIAlNdWx0aVhhY3RJZCBteGFj
dExpbWl0OwogCU11bHRpWGFjdElkIHNhZmVNeGFjdExpbWl0OwogCkBAIC05NzAsNyArOTcx
LDggQEAgdmFjdXVtX3NldF94aWRfbGltaXRzKFJlbGF0aW9uIHJlbCwKIAlBc3NlcnQobXhp
ZF9mcmVlemVtaW4gPj0gMCk7CiAKIAkvKiBjb21wdXRlIHRoZSBjdXRvZmYgbXVsdGksIGJl
aW5nIGNhcmVmdWwgdG8gZ2VuZXJhdGUgYSB2YWxpZCB2YWx1ZSAqLwotCW14YWN0TGltaXQg
PSBHZXRPbGRlc3RNdWx0aVhhY3RJZCgpIC0gbXhpZF9mcmVlemVtaW47CisJb2xkZXN0TXhh
Y3QgPSBHZXRPbGRlc3RNdWx0aVhhY3RJZCgpOworCW14YWN0TGltaXQgPSBvbGRlc3RNeGFj
dCAtIG14aWRfZnJlZXplbWluOwogCWlmIChteGFjdExpbWl0IDwgRmlyc3RNdWx0aVhhY3RJ
ZCkKIAkJbXhhY3RMaW1pdCA9IEZpcnN0TXVsdGlYYWN0SWQ7CiAKQEAgLTk4NCw3ICs5ODYs
MTQgQEAgdmFjdXVtX3NldF94aWRfbGltaXRzKFJlbGF0aW9uIHJlbCwKIAkJZXJlcG9ydChX
QVJOSU5HLAogCQkJCShlcnJtc2coIm9sZGVzdCBtdWx0aXhhY3QgaXMgZmFyIGluIHRoZSBw
YXN0IiksCiAJCQkJIGVycmhpbnQoIkNsb3NlIG9wZW4gdHJhbnNhY3Rpb25zIHdpdGggbXVs
dGl4YWN0cyBzb29uIHRvIGF2b2lkIHdyYXBhcm91bmQgcHJvYmxlbXMuIikpKTsKLQkJbXhh
Y3RMaW1pdCA9IHNhZmVNeGFjdExpbWl0OworCQlpZiAoTXVsdGlYYWN0SWRQcmVjZWRlcyhv
bGRlc3RNeGFjdCwgc2FmZU14YWN0TGltaXQpKQorCQl7CisJCQlteGFjdExpbWl0ID0gb2xk
ZXN0TXhhY3Q7CisJCX0KKwkJZWxzZQorCQl7CisJCQlteGFjdExpbWl0ID0gc2FmZU14YWN0
TGltaXQ7CisJCX0KIAl9CiAKIAkqbXVsdGlYYWN0Q3V0b2ZmID0gbXhhY3RMaW1pdDsK
--------------C3E0BEF037202CC57E7D4DCC--