To: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
CC: Amit Kapila <amit.kapila16@gmail.com>, "Schneider (AWS), Jeremy"
	<schnjere@amazon.com>
From: "Drouvot, Bertrand" <bdrouvot@amazon.com>
Subject: [bug] Logical Decoding of relation rewrite with toast does not reset
 toast_hash
Message-ID: <b5146fb1-ad9e-7d6e-f980-98ed68744a7c@amazon.com>
Date: Fri, 9 Jul 2021 08:51:34 +0200
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:78.0)
 Gecko/20100101 Thunderbird/78.11.0
MIME-Version: 1.0
Content-Type: multipart/mixed;
	boundary="------------22A5DB197C6CBD50E990D3A7"
Content-Language: en-US
Archived-At: 
 <https://www.postgresql.org/message-id/b5146fb1-ad9e-7d6e-f980-98ed68744a7c%40amazon.com>
Precedence: bulk

--------------22A5DB197C6CBD50E990D3A7
Content-Type: multipart/alternative;
	boundary="------------A2EA60988BD48073FE3EA4EE"

--------------A2EA60988BD48073FE3EA4EE
Content-Type: text/plain; charset="utf-8"; format=flowed
Content-Transfer-Encoding: 8bit

Hi hackers,

During logical decoding, we have recently observed (and reported in [1]) 
errors like:

ERROR:  could not open relation with OID 0

After investigating a recent issue on a PostgreSQL database that was 
encountering this error, we found that the logical decoding of relation 
rewrite with toast could produce this error without resetting the 
toast_hash.

We were able to create this repro of the error:

postgres=# \! cat bdt_repro.sql
select pg_create_logical_replication_slot('bdt_slot','test_decoding');
CREATE TABLE tbl1 (a INT, b TEXT);
CREATE TABLE tbl2 (a INT);
ALTER TABLE tbl1 ALTER COLUMN b SET STORAGE EXTERNAL;
BEGIN;
INSERT INTO tbl1 VALUES(1, repeat('a', 4000)) ;
ALTER TABLE tbl1 ADD COLUMN id serial primary key;
INSERT INTO tbl2 VALUES(1);
commit;
select * from pg_logical_slot_get_changes('bdt_slot', null, null);

That ends up on 12.5 with:

ERROR:  could not open relation with OID 0

And on current master with:

server closed the connection unexpectedly
     This probably means the server terminated abnormally
     before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.

The issue has been introduced by 325f2ec555 (and more precisely by its 
change in reorderbuffer.c), so it does affect pre v11 versions:

git branch -r --contains 325f2ec555
   origin/HEAD -> origin/master
   origin/REL_11_STABLE
   origin/REL_12_STABLE
   origin/REL_13_STABLE
   origin/REL_14_STABLE
   origin/master

The fact that current master is producing a different behavior than 12.5 
(for example) is due to 4daa140a2f that generates a failed assertion in 
such a case (after going to the code path that should print out the ERROR):

#2  0x0000000000b29fab in ExceptionalCondition (conditionName=0xce6850 
"(rb->size >= sz) && (txn->size >= sz)", errorType=0xce5f84 
"FailedAssertion", fileName=0xce5fd0 "reorderbuffer.c", lineNumber=3141) 
at assert.c:69
#3  0x00000000008ff1fb in ReorderBufferChangeMemoryUpdate (rb=0x11a7a40, 
change=0x11c94b8, addition=false) at reorderbuffer.c:3141
#4  0x00000000008fab27 in ReorderBufferReturnChange (rb=0x11a7a40, 
change=0x11c94b8, upd_mem=true) at reorderbuffer.c:477
#5  0x0000000000902ec1 in ReorderBufferToastReset (rb=0x11a7a40, 
txn=0x11b1998) at reorderbuffer.c:4799
#6  0x00000000008faaa2 in ReorderBufferReturnTXN (rb=0x11a7a40, 
txn=0x11b1998) at reorderbuffer.c:448
#7  0x00000000008fc95b in ReorderBufferCleanupTXN (rb=0x11a7a40, 
txn=0x11b1998) at reorderbuffer.c:1540

I am adding Amit to this thread to make him aware than this is related 
to the recent issue Jeremy and I were talking about in [1] - which we 
now believe is not linked to the logical decoding and speculative insert 
bug fixed in 4daa140a2f but likely to this new toast rewrite bug.

Please find enclosed a patch proposal to:

* Avoid the failed assertion on current master and generate the error 
message instead (should the code reach that stage).
* Reset the toast_hash in case of relation rewrite with toast (so that 
the logical decoding in the above repro is working).

I am adding this patch to the next commitfest.

Thanks
Bertrand

[1]: 
https://www.postgresql.org/message-id/CAA4eK1KcUPwwhDVhJmdQExc09AzEBZMGbOa-u3DYaJs1zzfEnA%40mail.gmail.com 


--------------A2EA60988BD48073FE3EA4EE
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>
    <div class="moz-text-html" lang="x-unicode">
      <p>Hi hackers,<br>
      </p>
      <p>During logical decoding, we have recently observed (and
        reported in [1]) errors like:</p>
      <p><font face="Courier New">ERROR:  could not open relation with
          OID 0</font><br>
      </p>
      After investigating a recent issue on a PostgreSQL database that
      was encountering this error, we found that the logical decoding of
      relation rewrite with toast could produce this error without
      resetting the toast_hash.<br>
      <br>
      We were able to create this repro of the error:<br>
      <br>
      <font face="Courier New">postgres=# \! cat bdt_repro.sql<br>
        select
        pg_create_logical_replication_slot('bdt_slot','test_decoding');<br>
        CREATE TABLE tbl1 (a INT, b TEXT);<br>
        CREATE TABLE tbl2 (a INT);<br>
        ALTER TABLE tbl1 ALTER COLUMN b SET STORAGE EXTERNAL;<br>
        BEGIN;<br>
        INSERT INTO tbl1 VALUES(1, repeat('a', 4000)) ;<br>
        ALTER TABLE tbl1 ADD COLUMN id serial primary key;<br>
        INSERT INTO tbl2 VALUES(1);<br>
        commit;<br>
        select * from pg_logical_slot_get_changes('bdt_slot', null,
        null);</font><br>
      <p>That ends up on 12.5 with:</p>
      <p><font face="Courier New">ERROR:  could not open relation with
          OID 0<br>
        </font></p>
      <p>And on current master with:</p>
      <font face="Courier New">server closed the connection unexpectedly<br>
            This probably means the server terminated abnormally</font><br>
      <font face="Courier New">     before or while processing the
        request.</font><br>
      <font face="Courier New"> </font> <font face="Courier New">The
        connection to the server was lost. Attempting reset: Failed.</font><br>
      <p>The issue has been introduced by 325f2ec555 (and more precisely
        by its change in reorderbuffer.c), so it does affect pre v11
        versions:</p>
      <p><font face="Courier New">git branch -r --contains 325f2ec555<br>
            origin/HEAD -&gt; origin/master<br>
            origin/REL_11_STABLE<br>
            origin/REL_12_STABLE<br>
            origin/REL_13_STABLE<br>
            origin/REL_14_STABLE<br>
            origin/master</font><br>
      </p>
      <p>The fact that current master is producing a different behavior
        than 12.5 (for example) is due to 4daa140a2f that generates a
        failed assertion in such a case (after going to the code path
        that should print out the ERROR):</p>
      <font face="Courier New">#2  0x0000000000b29fab in
        ExceptionalCondition (conditionName=0xce6850 "(rb-&gt;size &gt;=
        sz) &amp;&amp; (txn-&gt;size &gt;= sz)", errorType=0xce5f84
        "FailedAssertion", fileName=0xce5fd0 "reorderbuffer.c",
        lineNumber=3141) at assert.c:69</font><font face="Courier New"><br>
      </font><font face="Courier New">#3  0x00000000008ff1fb in
        ReorderBufferChangeMemoryUpdate (rb=0x11a7a40, change=0x11c94b8,
        addition=false) at reorderbuffer.c:3141</font><br>
      <font face="Courier New">#4  0x00000000008fab27 in
        ReorderBufferReturnChange (rb=0x11a7a40, change=0x11c94b8,
        upd_mem=true) at reorderbuffer.c:477</font><br>
      <font face="Courier New">#5  0x0000000000902ec1 in
        ReorderBufferToastReset (rb=0x11a7a40, txn=0x11b1998) at
        reorderbuffer.c:4799</font><br>
      <font face="Courier New">#6  0x00000000008faaa2 in
        ReorderBufferReturnTXN (rb=0x11a7a40, txn=0x11b1998) at
        reorderbuffer.c:448</font><font face="Courier New"><br>
      </font><font face="Courier New">#7  0x00000000008fc95b in
        ReorderBufferCleanupTXN (rb=0x11a7a40, txn=0x11b1998) at
        reorderbuffer.c:1540</font><br>
      <font face="Courier New"><br>
      </font>I am adding Amit to this thread to make him aware than this
      is related to the recent issue Jeremy and I were talking about in
      [1] - which we now believe is not linked to the logical decoding
      and speculative insert bug fixed in 4daa140a2f but likely to this
      new toast rewrite bug.<br>
      <br>
      <p>Please find enclosed a patch proposal to:</p>
      * Avoid the failed assertion on current master and generate the
      error message instead (should the code reach that stage).<br>
      * Reset the toast_hash in case of relation rewrite with toast (so
      that the logical decoding in the above repro is working).<br>
      <br>
      I am adding this patch to the next commitfest.<br>
      <br>
      Thanks<br>
      Bertrand<br>
      <br>
      [1]: <a class="moz-txt-link-freetext"
href="https://www.postgresql.org/message-id/CAA4eK1KcUPwwhDVhJmdQExc09AzEBZMGbOa-u3DYaJs1zzfEnA%40mail.gmail.com">https://www.postgresql.org/message-id/CAA4eK1KcUPwwhDVhJmdQExc09AzEBZMGbOa-u3DYaJs1zzfEnA%40mail.gmail.com</a>
    </div>
  </body>
</html>

--------------A2EA60988BD48073FE3EA4EE--

--------------22A5DB197C6CBD50E990D3A7
Content-Type: text/plain; charset="UTF-8"; x-mac-type=0; x-mac-creator=0;
	name="v1-0001-toast-rewrite.patch"
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="v1-0001-toast-rewrite.patch"

ZGlmZiAtLWdpdCBhL3NyYy9iYWNrZW5kL3JlcGxpY2F0aW9uL2xvZ2ljYWwvcmVvcmRlcmJ1
ZmZlci5jIGIvc3JjL2JhY2tlbmQvcmVwbGljYXRpb24vbG9naWNhbC9yZW9yZGVyYnVmZmVy
LmMKaW5kZXggMWI0ZjRhNTI4YS4uZjFhODlhM2Q4NSAxMDA2NDQKLS0tIGEvc3JjL2JhY2tl
bmQvcmVwbGljYXRpb24vbG9naWNhbC9yZW9yZGVyYnVmZmVyLmMKKysrIGIvc3JjL2JhY2tl
bmQvcmVwbGljYXRpb24vbG9naWNhbC9yZW9yZGVyYnVmZmVyLmMKQEAgLTIxNzAsNyArMjE3
MCwxNyBAQCBSZW9yZGVyQnVmZmVyUHJvY2Vzc1RYTihSZW9yZGVyQnVmZmVyICpyYiwgUmVv
cmRlckJ1ZmZlclRYTiAqdHhuLAogCQkJCQkgKiBwbHVnaW4gaGFzIGFza2VkIGZvciB0aGVt
LgogCQkJCQkgKi8KIAkJCQkJaWYgKHJlbGF0aW9uLT5yZF9yZWwtPnJlbHJld3JpdGUgJiYg
IXJiLT5vdXRwdXRfcmV3cml0ZXMpCisJCQkJCXsKKwkJCQkJCS8qIENsZWFyIHJlYXNzZW1i
bGVkIHRvYXN0IGNodW5rcyBpZiB3ZSdyZSBzdXJlCisJCQkJCQkgKiB0aGV5J3JlIG5vdCBy
ZXF1aXJlZCBhbnltb3JlLiBUaGUgY3JlYXRvciBvZiB0aGUKKwkJCQkJCSAqIHR1cGxlIHRl
bGxzIHVzLgorCQkJCQkJICovCisJCQkJCQlpZiAoIUlzVG9hc3RSZWxhdGlvbihyZWxhdGlv
bikgJiYKKwkJCQkJCQljaGFuZ2UtPmRhdGEudHAuY2xlYXJfdG9hc3RfYWZ0ZXJ3YXJkcykK
KwkJCQkJCQlSZW9yZGVyQnVmZmVyVG9hc3RSZXNldChyYiwgdHhuKTsKKwogCQkJCQkJZ290
byBjaGFuZ2VfZG9uZTsKKwkJCQkJfQogCiAJCQkJCS8qCiAJCQkJCSAqIEZvciBub3cgaWdu
b3JlIHNlcXVlbmNlIGNoYW5nZXMgZW50aXJlbHkuIE1vc3Qgb2YgdGhlCkBAIC00NjA5LDYg
KzQ2MTksMTEgQEAgUmVvcmRlckJ1ZmZlclRvYXN0UmVwbGFjZShSZW9yZGVyQnVmZmVyICpy
YiwgUmVvcmRlckJ1ZmZlclRYTiAqdHhuLAogCWlmICh0eG4tPnRvYXN0X2hhc2ggPT0gTlVM
TCkKIAkJcmV0dXJuOwogCisJdG9hc3RfcmVsID0gUmVsYXRpb25JZEdldFJlbGF0aW9uKHJl
bGF0aW9uLT5yZF9yZWwtPnJlbHRvYXN0cmVsaWQpOworCWlmICghUmVsYXRpb25Jc1ZhbGlk
KHRvYXN0X3JlbCkpCisJCWVsb2coRVJST1IsICJjb3VsZCBub3Qgb3BlbiByZWxhdGlvbiB3
aXRoIE9JRCAldSIsCisJCQkgcmVsYXRpb24tPnJkX3JlbC0+cmVsdG9hc3RyZWxpZCk7CisK
IAkvKgogCSAqIFdlJ3JlIGdvaW5nIHRvIG1vZGlmeSB0aGUgc2l6ZSBvZiB0aGUgY2hhbmdl
LCBzbyB0byBtYWtlIHN1cmUgdGhlCiAJICogYWNjb3VudGluZyBpcyBjb3JyZWN0IHdlJ2xs
IG1ha2UgaXQgbG9vayBsaWtlIHdlJ3JlIHJlbW92aW5nIHRoZSBjaGFuZ2UKQEAgLTQ2MjMs
MTEgKzQ2MzgsNiBAQCBSZW9yZGVyQnVmZmVyVG9hc3RSZXBsYWNlKFJlb3JkZXJCdWZmZXIg
KnJiLCBSZW9yZGVyQnVmZmVyVFhOICp0eG4sCiAKIAlkZXNjID0gUmVsYXRpb25HZXREZXNj
cihyZWxhdGlvbik7CiAKLQl0b2FzdF9yZWwgPSBSZWxhdGlvbklkR2V0UmVsYXRpb24ocmVs
YXRpb24tPnJkX3JlbC0+cmVsdG9hc3RyZWxpZCk7Ci0JaWYgKCFSZWxhdGlvbklzVmFsaWQo
dG9hc3RfcmVsKSkKLQkJZWxvZyhFUlJPUiwgImNvdWxkIG5vdCBvcGVuIHJlbGF0aW9uIHdp
dGggT0lEICV1IiwKLQkJCSByZWxhdGlvbi0+cmRfcmVsLT5yZWx0b2FzdHJlbGlkKTsKLQog
CXRvYXN0X2Rlc2MgPSBSZWxhdGlvbkdldERlc2NyKHRvYXN0X3JlbCk7CiAKIAkvKiBzaG91
bGQgd2UgYWxsb2NhdGUgZnJvbSBzdGFjayBpbnN0ZWFkPyAqLwo=
--------------22A5DB197C6CBD50E990D3A7--