From: ocean_li_996 <ocean_li_996@163.com>
To: pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>
Cc: pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>
Subject: Re: BUG #18055: logical decoding core on AllocateSnapshotBuilder()
Date: Tue, 15 Aug 2023 01:03:52 +0800 (GMT+08:00)
Message-ID: <12586894.d69f.189f501073a.Coremail.ocean_li_996@163.com> (raw)
In-Reply-To: <18055-ab3beed9f4b7b7d6@postgresql.org>
References: <18055-ab3beed9f4b7b7d6@postgresql.org>
By applying the test.patch in attachment, I got similar core stacks following the procedureļ¼
==>
postgres=# alter system set wal_level to 'logical';
-- restart server
postgres=# set statement_timeout to 1000;
SET
postgres=# select pg_create_logical_replication_slot('test', 'test_decoding', 0);
WARNING: NInitialRunningXacts is 0 , InitialRunningXacts is (nil)
pg_create_logical_replication_slot
------------------------------------
(test,0/423999D8)
(1 row)
postgres=# select pg_logical_slot_get_changes('test', NULL, NULL);
WARNING: NInitialRunningXacts is 0 , InitialRunningXacts is (nil)
ERROR: canceling statement due to statement timeout
postgres=# select pg_logical_slot_get_changes('test', NULL, NULL);
WARNING: NInitialRunningXacts is 3 , InitialRunningXacts is 0x373bc18
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: Succeeded.
==>
And core stacks got above are
==>
(gdb) bt
#0 0x00007fbf2c987277 in raise () from /lib64/libc.so.6
#1 0x00007fbf2c988968 in abort () from /lib64/libc.so.6
#2 0x0000000000deb38e in ExceptionalCondition (
conditionName=0x11f5d70 "!(NInitialRunningXacts == 0 && InitialRunningXacts == ((void *)0))",
errorType=0x11f5d60 "FailedAssertion", fileName=0x11f5d00 "snapbuild.c", lineNumber=385)
at assert.c:46
#3 0x0000000000b5d7d2 in AllocateSnapshotBuilder (reorder=0x35795d8, xmin_horizon=0,
start_lsn=1111114144, need_full_snapshot=false) at snapbuild.c:385
#4 0x0000000000b4d4c2 in StartupDecodingContext (output_plugin_options=0x0, start_lsn=1111114144,
xmin_horizon=0, need_full_snapshot=false, fast_forward=false,
read_page=0xb4f5a5 ,
prepare_write=0xb4f378 , do_write=0xb4f3a6 ,
update_progress=0x0) at logical.c:191
#5 0x0000000000b4de0a in CreateDecodingContext (start_lsn=1111114144, output_plugin_options=0x0,
fast_forward=false, read_page=0xb4f5a5 ,
prepare_write=0xb4f378 , do_write=0xb4f3a6 ,
update_progress=0x0) at logical.c:486
#6 0x0000000000b4fcb7 in pg_logical_slot_get_changes_guts (fcinfo=0x344fbe8, confirm=true, binary=false)
at logicalfuncs.c:260
#7 0x0000000000b500b1 in pg_logical_slot_get_changes (fcinfo=0x344fbe8) at logicalfuncs.c:395
==>
In my view, this bug can be fix by using fix.patch in attachment.
Regards.
| |
ocean_li_996
|
|
ocean_li_996@163.com
|
---- Replied Message ----
| From | PG Bug reporting form<noreply@postgresql.org> |
| Date | 8/15/2023 00:05 |
| To | <pgsql-bugs@lists.postgresql.org> |
| Cc | <ocean_li_996@163.com> |
| Subject | BUG #18055: logical decoding core on AllocateSnapshotBuilder() |
The following bug has been logged on the website:
Bug reference: 18055
Logged by: ocean li
Email address: ocean_li_996@163.com
PostgreSQL version: 11.9
Operating system: centos7 5.10.84 x86_64
Description:
For testing logical decoding module, *pg_logical_slot_get_changes* function
is used. Sometimes i got an core whose stack was like that:
==>
#0 0x00007f744a7b9277 in raise () from /lib64/libc.so.6
#1 0x00007f744a7ba968 in abort () from /lib64/libc.so.6
#2 0x00000000010edd37 in ExceptionalCondition (conditionName=0x17e2b58
"!(NInitialRunningXacts == 0 && InitialRunningXacts == ((void *)0))",
errorType=0x17e2b45 "FailedAssertion", fileName=0x17e2b39 "snapbuild.c",
lineNumber=381) at assert.c:46
#3 0x0000000000e60b46 in AllocateSnapshotBuilder (reorder=0x551ea98,
xmin_horizon=0, start_lsn=1267160216, need_full_snapshot=false) at
snapbuild.c:381
#4 0x0000000000e50f70 in StartupDecodingContext (output_plugin_options=0x0,
start_lsn=1267160216, xmin_horizon=0, need_full_snapshot=false,
fast_forward=false, read_page=0xe53023 <logical_read_local_xlog_page>,
prepare_write=0xe52df6 <LogicalOutputPrepareWrite>, do_write=0xe52e24
<LogicalOutputWrite>, update_progress=0x0) at logical.c:191
#5 0x0000000000e518b8 in CreateDecodingContext (start_lsn=1267160216,
output_plugin_options=0x0, fast_forward=false, read_page=0xe53023
<logical_read_local_xlog_page>, prepare_write=0xe52df6
<LogicalOutputPrepareWrite>, do_write=0xe52e24 <LogicalOutputWrite>,
update_progress=0x0) at logical.c:486
#6 0x0000000000e53735 in pg_logical_slot_get_changes_guts
(fcinfo=0x7ffcd879e3d0, confirm=true, binary=false) at logicalfuncs.c:259
#7 0x0000000000e53b1c in pg_logical_slot_get_changes
(fcinfo=0x7ffcd879e3d0) at logicalfuncs.c:393
#8 0x00000000010ff89e in FunctionCallInvokeCheckSPL (fcinfo=0x7ffcd879e3d0)
at fmgr.c:2262
...
==>
And in level #3 of stack above, NInitialRunningXacts is 2 and
InitialRunningXacts is not NULL observed in one of cores.
Using of NInitialRunningXacts and InitialRunningXacts are clear. Currently,
the core, as far as i know, maybe caused by this way: an ERROR raised when
calling *pg_logical_slot_get_changes_guts* function. The code part of
PG_CATCH() doses not reset NInitialRunningXacts and InitialRunningXacts.
Then, calling pg_logical_slot_get_changes_guts again, the core may occur.
Unfortunately, I couldn't find a minimal reproduction case. However, I
observed an *ERROR: canceling statement due to statement timeout* logged
before each core occurred. (For some reason, I can't provide the information
of log)
Attachments:download all (2 files, .tar.gz)test.patch (application/octet-stream, 2.2K) downloaddiff --git a/src/backend/replication/logical/logicalfuncs.c b/src/backend/replication/logical/logicalfuncs.cindex 4d355b1f976..5670e6f3111 100644--- a/src/backend/replication/logical/logicalfuncs.c+++ b/src/backend/replication/logical/logicalfuncs.c@@ -49,6 +49,7 @@
#include "storage/fd.h"
#include "polar_dma/polar_dma.h"
+#include "replication/snapbuild.h"
/* private date for writing out data */
typedef struct DecodingOutputState
@@ -335,6 +336,7 @@ pg_logical_slot_get_changes_guts(FunctionCallInfo fcinfo, bool confirm, bool bin
if (upto_nchanges != 0 &&
upto_nchanges <= p->returned_rows)
break;
+ IncreaseNInitialRunningXacts(ctx->snapshot_builder);
CHECK_FOR_INTERRUPTS();
}
diff --git a/src/backend/replication/logical/snapbuild.c b/src/backend/replication/logical/snapbuild.cindex b6866cc9b23..7c429af2614 100644--- a/src/backend/replication/logical/snapbuild.c+++ b/src/backend/replication/logical/snapbuild.c@@ -354,6 +354,8 @@ AllocateSnapshotBuilder(ReorderBuffer *reorder,
MemoryContext oldcontext;
SnapBuild *builder;
+ ereport(WARNING, (errmsg("NInitialRunningXacts is %u , InitialRunningXacts is %p", + NInitialRunningXacts, InitialRunningXacts)));
/* allocate memory in own context, to have better accountability */
context = AllocSetContextCreate(CurrentMemoryContext,
"snapshot builder context",
@@ -385,6 +387,14 @@ AllocateSnapshotBuilder(ReorderBuffer *reorder,
return builder;
}
+void+IncreaseNInitialRunningXacts(SnapBuild *builder)+{+ NInitialRunningXacts = 3;+ InitialRunningXacts = MemoryContextAlloc(builder->context, sizeof(TransactionId) * 3);+ sleep(5);+}+
/*
* Free a snapshot builder.
*/
diff --git a/src/include/replication/snapbuild.h b/src/include/replication/snapbuild.hindex 4df3c3f2f73..e56ab99ba49 100644--- a/src/include/replication/snapbuild.h+++ b/src/include/replication/snapbuild.h@@ -58,6 +58,7 @@ struct xl_heap_new_cid;
struct xl_running_xacts;
extern void CheckPointSnapBuild(void);
+extern void IncreaseNInitialRunningXacts(SnapBuild *builder);
extern SnapBuild *AllocateSnapshotBuilder(struct ReorderBuffer *cache,
TransactionId xmin_horizon, XLogRecPtr start_lsn,
fix.patch (application/octet-stream, 1.0K) download
From d8c3c6a59593227957ce5deb99fffdb4b47534e8 Mon Sep 17 00:00:00 2001
From: "mohen.lhy"
Date: Fri, 4 Aug 2023 16:52:28 +0800
Subject: [PATCH] [Bug] to fix AllocateSnapbuilder core
---
src/backend/replication/logical/logicalfuncs.c | 11 +++++++++++
1 file changed, 11 insertions(+)
diff --git a/src/backend/replication/logical/logicalfuncs.c b/src/backend/replication/logical/logicalfuncs.cindex 4d355b1f976..1ee9193f105 100644--- a/src/backend/replication/logical/logicalfuncs.c+++ b/src/backend/replication/logical/logicalfuncs.c@@ -374,6 +374,17 @@ pg_logical_slot_get_changes_guts(FunctionCallInfo fcinfo, bool confirm, bool bin
}
PG_CATCH();
{
+ /*+ * When an error raised, Clean-up work should be needed.+ * Otherwise, residual influence can make a crash,+ * such as Assert(NInitialRunningXacts == 0).+ */++ /* free context, call shutdown callback */+ FreeDecodingContext(ctx);++ ReplicationSlotRelease();+
/* clear all timetravel entries */
InvalidateSystemCaches();
--
2.32.0.3.g01195cf9f
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-bugs@postgresql.org
Cc: ocean_li_996@163.com, pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #18055: logical decoding core on AllocateSnapshotBuilder()
In-Reply-To: <12586894.d69f.189f501073a.Coremail.ocean_li_996@163.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox