Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1qGJ8D-000064-6A for pgsql-bugs@arkaria.postgresql.org; Mon, 03 Jul 2023 12:58:17 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1qGJ8A-0005Wh-Kx for pgsql-bugs@arkaria.postgresql.org; Mon, 03 Jul 2023 12:58:14 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1qGJ8A-0005WL-2t for pgsql-bugs@lists.postgresql.org; Mon, 03 Jul 2023 12:58:14 +0000 Received: from lana.depesz.com ([88.198.49.178] helo=depesz.com) by makus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qGJ86-001nqT-Bk for pgsql-bugs@postgresql.org; Mon, 03 Jul 2023 12:58:12 +0000 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=depesz.com; s=20170201; h=In-Reply-To:Content-Type:MIME-Version:References:Reply-To: Message-ID:Subject:To:Sender:From:Date:Cc:Content-Transfer-Encoding: Content-ID:Content-Description:Resent-Date:Resent-From:Resent-Sender: Resent-To:Resent-Cc:Resent-Message-ID:List-Id:List-Help:List-Unsubscribe: List-Subscribe:List-Post:List-Owner:List-Archive; bh=lfqQxXnbJXredxyMinU9Lvpzss4xGBa8BH80HgkaV2k=; b=pm/VUx1PRYAg01JyAfNdUP/rTH 41jeGEJBXS6Rilzl8HB66EJEeEapyMIhyt/Zq33giGQ003vRhlMTf+M4JB0rBbu+2E6FyiPY0xwXR KCjaE5fqNq9XN3g/fTX72NGJFZ8lsoPOrbBjhXhXdEuwLi8Nb1z8SSmIBHdxQCdo6oqU=; Received: from depesz by depesz.com with local (Exim 4.94.2) (envelope-from ) id 1qGJ84-00FS1x-01 for pgsql-bugs@postgresql.org; Mon, 03 Jul 2023 14:58:08 +0200 Date: Mon, 3 Jul 2023 14:58:07 +0200 From: hubert depesz lubaczewski Sender: depesz@depesz.com To: pgsql-bugs mailing list Subject: Re: Backend handling replication slot stuck using 100% cpu, unkillable Message-ID: Reply-To: depesz@depesz.com References: MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline In-Reply-To: List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk On Mon, Jul 03, 2023 at 01:36:32PM +0200, hubert depesz lubaczewski wrote: > Hi, > we are using debezium to get change data from Pg. > > This particular pg is 12.9, and will be soon upgrade to 14.something > (this thursday). So, i installed dbgsym for this pg, and this bny accident upgraded pg to 12.14. Now I do have debug symbols, though, so backtrace can be more informative. I ran: for i in 1 2 3; do date; sudo gdb -batch -p 8938 -ex bt; sleep 30; echo; done And got this: #v+ Mon Jul 3 12:50:14 UTC 2023 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1". hash_seq_search (status=status@entry=0xfffff0173f40) at ./build/../src/backend/utils/hash/dynahash.c:1439 1439 ./build/../src/backend/utils/hash/dynahash.c: No such file or directory. #0 hash_seq_search (status=status@entry=0xfffff0173f40) at ./build/../src/backend/utils/hash/dynahash.c:1439 #1 0x0000ffffa1bc8714 in rel_sync_cache_publication_cb (arg=, cacheid=, hashvalue=) at ./build/../src/backend/replication/pgoutput/pgoutput.c:665 #2 0x0000aaaab4bfcef4 in CallSyscacheCallbacks (cacheid=47, hashvalue=1542357812) at ./build/../src/backend/utils/cache/inval.c:1520 #3 0x0000aaaab4a91884 in ReorderBufferExecuteInvalidations (rb=0xffffa4ac5308 , txn=0xfffff0174240, txn=0xfffff0174240) at ./build/../src/backend/replication/logical/reorderbuffer.c:2187 #4 ReorderBufferCommit (rb=0xffffa4ac5308 , xid=xid@entry=2741814901, commit_lsn=187650155969544, end_lsn=, commit_time=commit_time@entry=741514150878208, origin_id=origin_id@entry=0, origin_lsn=origin_lsn@entry=0) at ./build/../src/backend/replication/logical/reorderbuffer.c:1816 #5 0x0000aaaab4a869bc in DecodeCommit (xid=2741814901, parsed=0xfffff0174390, buf=0xfffff0174510, ctx=0xaaaad5e1df00) at ./build/../src/backend/replication/logical/decode.c:654 #6 DecodeXactOp (ctx=ctx@entry=0xaaaad5e1df00, buf=0xfffff0174510, buf@entry=0xfffff0174570) at ./build/../src/backend/replication/logical/decode.c:249 #7 0x0000aaaab4a86ad4 in LogicalDecodingProcessRecord (ctx=0xaaaad5e1df00, record=0xaaaad5e1e198) at ./build/../src/backend/replication/logical/decode.c:117 #8 0x0000aaaab4a996ec in XLogSendLogical () at ./build/../src/backend/replication/walsender.c:2883 #9 0x0000aaaab4a9bbb0 in WalSndLoop (send_data=send_data@entry=0xaaaab4a99688 ) at ./build/../src/backend/replication/walsender.c:2232 #10 0x0000aaaab4a9c674 in StartLogicalReplication (cmd=0xaaaad5e47f90) at ./build/../src/backend/replication/walsender.c:1134 #11 exec_replication_command (cmd_string=cmd_string@entry=0xaaaad5d1db00 "START_REPLICATION SLOT \"slot_name\" LOGICAL 1D6C/92965050 (\"proto_version\" '1', \"publication_names\" 'xxx')") at ./build/../src/backend/replication/walsender.c:1602 #12 0x0000aaaab4af0c08 in PostgresMain (argc=, argv=argv@entry=0xaaaad5d7aaf8, dbname=, username=) at ./build/../src/backend/tcop/postgres.c:4289 #13 0x0000aaaab4a759a8 in BackendRun (port=0xaaaad5d76150, port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4517 #14 BackendStartup (port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4200 #15 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1725 #16 0x0000aaaab4a769d4 in PostmasterMain (argc=, argv=) at ./build/../src/backend/postmaster/postmaster.c:1398 #17 0x0000aaaab480355c in main (argc=5, argv=0xaaaad5d16720) at ./build/../src/backend/main/main.c:228 Mon Jul 3 12:50:45 UTC 2023 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1". 0x0000aaaab4c1e11c in hash_search_with_hash_value (hashp=0xaaaad5dea900, keyPtr=0xfffff0173f5c, keyPtr@entry=0xfffff0173f7c, hashvalue=1107843932, action=action@entry=HASH_FIND, foundPtr=foundPtr@entry=0x0) at ./build/../src/backend/utils/hash/dynahash.c:949 949 ./build/../src/backend/utils/hash/dynahash.c: No such file or directory. #0 0x0000aaaab4c1e11c in hash_search_with_hash_value (hashp=0xaaaad5dea900, keyPtr=0xfffff0173f5c, keyPtr@entry=0xfffff0173f7c, hashvalue=1107843932, action=action@entry=HASH_FIND, foundPtr=foundPtr@entry=0x0) at ./build/../src/backend/utils/hash/dynahash.c:949 #1 0x0000aaaab4c1e79c in hash_search (hashp=, keyPtr=keyPtr@entry=0xfffff0173f7c, action=action@entry=HASH_FIND, foundPtr=foundPtr@entry=0x0) at ./build/../src/backend/utils/hash/dynahash.c:911 #2 0x0000aaaab4c07180 in RelationCacheInvalidateEntry (relationId=) at ./build/../src/backend/utils/cache/relcache.c:2820 #3 0x0000aaaab4bfcfe0 in LocalExecuteInvalidationMessage (msg=0xffffa033ab88) at ./build/../src/backend/utils/cache/inval.c:603 #4 0x0000aaaab4a91884 in ReorderBufferExecuteInvalidations (rb=0xffffa4ac5308 , txn=0xfffff0174240, txn=0xfffff0174240) at ./build/../src/backend/replication/logical/reorderbuffer.c:2187 #5 ReorderBufferCommit (rb=0xffffa4ac5308 , xid=xid@entry=2741814901, commit_lsn=187650155969544, end_lsn=, commit_time=commit_time@entry=741514150878208, origin_id=origin_id@entry=0, origin_lsn=origin_lsn@entry=0) at ./build/../src/backend/replication/logical/reorderbuffer.c:1816 #6 0x0000aaaab4a869bc in DecodeCommit (xid=2741814901, parsed=0xfffff0174390, buf=0xfffff0174510, ctx=0xaaaad5e1df00) at ./build/../src/backend/replication/logical/decode.c:654 #7 DecodeXactOp (ctx=ctx@entry=0xaaaad5e1df00, buf=0xfffff0174510, buf@entry=0xfffff0174570) at ./build/../src/backend/replication/logical/decode.c:249 #8 0x0000aaaab4a86ad4 in LogicalDecodingProcessRecord (ctx=0xaaaad5e1df00, record=0xaaaad5e1e198) at ./build/../src/backend/replication/logical/decode.c:117 #9 0x0000aaaab4a996ec in XLogSendLogical () at ./build/../src/backend/replication/walsender.c:2883 #10 0x0000aaaab4a9bbb0 in WalSndLoop (send_data=send_data@entry=0xaaaab4a99688 ) at ./build/../src/backend/replication/walsender.c:2232 #11 0x0000aaaab4a9c674 in StartLogicalReplication (cmd=0xaaaad5e47f90) at ./build/../src/backend/replication/walsender.c:1134 #12 exec_replication_command (cmd_string=cmd_string@entry=0xaaaad5d1db00 "START_REPLICATION SLOT \"slot_name\" LOGICAL 1D6C/92965050 (\"proto_version\" '1', \"publication_names\" 'xxx')") at ./build/../src/backend/replication/walsender.c:1602 #13 0x0000aaaab4af0c08 in PostgresMain (argc=, argv=argv@entry=0xaaaad5d7aaf8, dbname=, username=) at ./build/../src/backend/tcop/postgres.c:4289 #14 0x0000aaaab4a759a8 in BackendRun (port=0xaaaad5d76150, port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4517 #15 BackendStartup (port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4200 #16 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1725 #17 0x0000aaaab4a769d4 in PostmasterMain (argc=, argv=) at ./build/../src/backend/postmaster/postmaster.c:1398 #18 0x0000aaaab480355c in main (argc=5, argv=0xaaaad5d16720) at ./build/../src/backend/main/main.c:228 Mon Jul 3 12:51:16 UTC 2023 [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1". hash_seq_search (status=status@entry=0xfffff0173f40) at ./build/../src/backend/utils/hash/dynahash.c:1439 1439 ./build/../src/backend/utils/hash/dynahash.c: No such file or directory. #0 hash_seq_search (status=status@entry=0xfffff0173f40) at ./build/../src/backend/utils/hash/dynahash.c:1439 #1 0x0000ffffa1bc8714 in rel_sync_cache_publication_cb (arg=, cacheid=, hashvalue=) at ./build/../src/backend/replication/pgoutput/pgoutput.c:665 #2 0x0000aaaab4bfcef4 in CallSyscacheCallbacks (cacheid=47, hashvalue=3011071378) at ./build/../src/backend/utils/cache/inval.c:1520 #3 0x0000aaaab4a91884 in ReorderBufferExecuteInvalidations (rb=0xffffa4ac5308 , txn=0xfffff0174240, txn=0xfffff0174240) at ./build/../src/backend/replication/logical/reorderbuffer.c:2187 #4 ReorderBufferCommit (rb=0xffffa4ac5308 , xid=xid@entry=2741814901, commit_lsn=187650155969544, end_lsn=, commit_time=commit_time@entry=741514150878208, origin_id=origin_id@entry=0, origin_lsn=origin_lsn@entry=0) at ./build/../src/backend/replication/logical/reorderbuffer.c:1816 #5 0x0000aaaab4a869bc in DecodeCommit (xid=2741814901, parsed=0xfffff0174390, buf=0xfffff0174510, ctx=0xaaaad5e1df00) at ./build/../src/backend/replication/logical/decode.c:654 #6 DecodeXactOp (ctx=ctx@entry=0xaaaad5e1df00, buf=0xfffff0174510, buf@entry=0xfffff0174570) at ./build/../src/backend/replication/logical/decode.c:249 #7 0x0000aaaab4a86ad4 in LogicalDecodingProcessRecord (ctx=0xaaaad5e1df00, record=0xaaaad5e1e198) at ./build/../src/backend/replication/logical/decode.c:117 #8 0x0000aaaab4a996ec in XLogSendLogical () at ./build/../src/backend/replication/walsender.c:2883 #9 0x0000aaaab4a9bbb0 in WalSndLoop (send_data=send_data@entry=0xaaaab4a99688 ) at ./build/../src/backend/replication/walsender.c:2232 #10 0x0000aaaab4a9c674 in StartLogicalReplication (cmd=0xaaaad5e47f90) at ./build/../src/backend/replication/walsender.c:1134 #11 exec_replication_command (cmd_string=cmd_string@entry=0xaaaad5d1db00 "START_REPLICATION SLOT \"slot_name\" LOGICAL 1D6C/92965050 (\"proto_version\" '1', \"publication_names\" 'xxx')") at ./build/../src/backend/replication/walsender.c:1602 #12 0x0000aaaab4af0c08 in PostgresMain (argc=, argv=argv@entry=0xaaaad5d7aaf8, dbname=, username=) at ./build/../src/backend/tcop/postgres.c:4289 #13 0x0000aaaab4a759a8 in BackendRun (port=0xaaaad5d76150, port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4517 #14 BackendStartup (port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4200 #15 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1725 #16 0x0000aaaab4a769d4 in PostmasterMain (argc=, argv=) at ./build/../src/backend/postmaster/postmaster.c:1398 #17 0x0000aaaab480355c in main (argc=5, argv=0xaaaad5d16720) at ./build/../src/backend/main/main.c:228 #v- Based on suggestion from IRC, i tried "return 0" and contiunue in gdb session. backtrace changed to: #v+ [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1". 0x0000aaaab4bfcf84 in LocalExecuteInvalidationMessage (msg=0xffff9ff33e18) at ./build/../src/backend/utils/cache/inval.c:578 578 ./build/../src/backend/utils/cache/inval.c: No such file or directory. #0 0x0000aaaab4bfcf84 in LocalExecuteInvalidationMessage (msg=0xffff9ff33e18) at ./build/../src/backend/utils/cache/inval.c:578 #1 0x0000aaaab4a91884 in ReorderBufferExecuteInvalidations (rb=0xffffa4ac5308 , txn=0xfffff0174240, txn=0xfffff0174240) at ./build/../src/backend/replication/logical/reorderbuffer.c:2187 #2 ReorderBufferCommit (rb=0xffffa4ac5308 , xid=xid@entry=2741814901, commit_lsn=187650155969544, end_lsn=, commit_time=commit_time@entry=741514150878208, origin_id=origin_id@entry=0, origin_lsn=origin_lsn@entry=0) at ./build/../src/backend/replication/logical/reorderbuffer.c:1816 #3 0x0000aaaab4a869bc in DecodeCommit (xid=2741814901, parsed=0xfffff0174390, buf=0xfffff0174510, ctx=0xaaaad5e1df00) at ./build/../src/backend/replication/logical/decode.c:654 #4 DecodeXactOp (ctx=ctx@entry=0xaaaad5e1df00, buf=0xfffff0174510, buf@entry=0xfffff0174570) at ./build/../src/backend/replication/logical/decode.c:249 #5 0x0000aaaab4a86ad4 in LogicalDecodingProcessRecord (ctx=0xaaaad5e1df00, record=0xaaaad5e1e198) at ./build/../src/backend/replication/logical/decode.c:117 #6 0x0000aaaab4a996ec in XLogSendLogical () at ./build/../src/backend/replication/walsender.c:2883 #7 0x0000aaaab4a9bbb0 in WalSndLoop (send_data=send_data@entry=0xaaaab4a99688 ) at ./build/../src/backend/replication/walsender.c:2232 #8 0x0000aaaab4a9c674 in StartLogicalReplication (cmd=0xaaaad5e47f90) at ./build/../src/backend/replication/walsender.c:1134 #9 exec_replication_command (cmd_string=cmd_string@entry=0xaaaad5d1db00 "START_REPLICATION SLOT \"data_access_platform_cdc\" LOGICAL 1D6C/92965050 (\"proto_version\" '1', \"publication_names\" 'cdc')") at ./build/../src/backend/replication/walsender.c:1602 #10 0x0000aaaab4af0c08 in PostgresMain (argc=, argv=argv@entry=0xaaaad5d7aaf8, dbname=, username=) at ./build/../src/backend/tcop/postgres.c:4289 #11 0x0000aaaab4a759a8 in BackendRun (port=0xaaaad5d76150, port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4517 #12 BackendStartup (port=0xaaaad5d76150) at ./build/../src/backend/postmaster/postmaster.c:4200 #13 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1725 #14 0x0000aaaab4a769d4 in PostmasterMain (argc=, argv=) at ./build/../src/backend/postmaster/postmaster.c:1398 #15 0x0000aaaab480355c in main (argc=5, argv=0xaaaad5d16720) at ./build/../src/backend/main/main.c:228 #v- and then it went back to hash_seq_search :( Anything I can do about it? Best regards, depesz