View Issue Details

IDProjectCategoryView StatusLast Update
0000051Pgpool-IIBugpublic2013-03-15 20:40
ReporterandreasAssigned Tot-ishii 
PrioritynormalSeveritycrashReproducibilityalways
Status resolvedResolutionopen 
PlatformOSLinux x86_64OS Version3.7.9
Product Version 
Target VersionFixed in Version 
Summary0000051: pgpool crashes on DDL statements
DescriptionWhen sending a few DDL statements pgpool segfaults.
Tested and reproduced for versions 3.1-3.2.3
Steps To ReproduceQueries in attached log should suffice.
Additional Informationpostgresql-9.2.3

Also reproduced on a debian system
TagsNo tags attached.

Activities

andreas

2013-03-05 01:04

reporter  

pgpool-log (9,049 bytes)
Feb 20 18:23:00 vm-lbl pgpool[10513]: pgpool-II successfully started. version 3.2.3 (namameboshi)
Feb 20 18:39:25 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 8374 statement: CREATE TABLE databasechangeloglock (ID INT NOT NULL, 
LOCKED BOOLEAN NOT NULL, LOCKGRANTED TIMESTAMP WITH TIME ZONE, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DATABASECHANGELOGLOCK PRIMARY KEY (ID)) message: CREATE TABLE / PRIMARY KEY will create implic
it index "pk_databasechangeloglock" for table "databasechangeloglock"
Feb 20 18:39:25 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 7949 statement: CREATE TABLE databasechangeloglock (ID INT NOT NULL, 
LOCKED BOOLEAN NOT NULL, LOCKGRANTED TIMESTAMP WITH TIME ZONE, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DATABASECHANGELOGLOCK PRIMARY KEY (ID)) message: CREATE TABLE / PRIMARY KEY will create implic
it index "pk_databasechangeloglock" for table "databasechangeloglock"
Feb 20 18:39:25 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 8374 statement: CREATE TABLE databasechangelog (ID VARCHAR(63) NOT NU
LL, AUTHOR VARCHAR(63) NOT NULL, FILENAME VARCHAR(200) NOT NULL, DATEEXECUTED TIMESTAMP WITH TIME ZONE NOT NULL, ORDEREXECUTED INT NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DE
SCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONSTRAINT PK_DATABASECHANGELOG PRIMARY KEY (ID, AUTHOR, FILENAME)) message: CREATE TABLE / PRIMARY KEY wi
ll create implicit index "pk_databasechangelog" for table "databasechangelog"
Feb 20 18:39:25 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 7949 statement: CREATE TABLE databasechangelog (ID VARCHAR(63) NOT NU
LL, AUTHOR VARCHAR(63) NOT NULL, FILENAME VARCHAR(200) NOT NULL, DATEEXECUTED TIMESTAMP WITH TIME ZONE NOT NULL, ORDEREXECUTED INT NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DE
SCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONSTRAINT PK_DATABASECHANGELOG PRIMARY KEY (ID, AUTHOR, FILENAME)) message: CREATE TABLE / PRIMARY KEY wi
ll create implicit index "pk_databasechangelog" for table "databasechangelog"
Feb 20 18:39:26 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 8374 statement: CREATE TABLE attributeDefinition (id BYTEA NOT NULL, 
attributeType VARCHAR(255), description VARCHAR(16384), filterable BOOLEAN, name VARCHAR(255) NOT NULL, visible BOOLEAN, catalogId BYTEA, CONSTRAINT CONSTRAINT_C PRIMARY KEY (id)) message: CREAT
E TABLE / PRIMARY KEY will create implicit index "constraint_c" for table "attributedefinition"
Feb 20 18:39:26 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 7949 statement: CREATE TABLE attributeDefinition (id BYTEA NOT NULL, 
attributeType VARCHAR(255), description VARCHAR(16384), filterable BOOLEAN, name VARCHAR(255) NOT NULL, visible BOOLEAN, catalogId BYTEA, CONSTRAINT CONSTRAINT_C PRIMARY KEY (id)) message: CREAT
E TABLE / PRIMARY KEY will create implicit index "constraint_c" for table "attributedefinition"
Feb 20 18:39:26 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 8374 statement: CREATE TABLE category (id BYTEA NOT NULL, externalId 
VARCHAR(255) NOT NULL, name VARCHAR(255), parentId BYTEA, treeDepth INT NOT NULL, treeLeft INT NOT NULL, treeRight INT NOT NULL, catalogId BYTEA, CONSTRAINT CONSTRAINT_3 PRIMARY KEY (id)) messag
e: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_3" for table "category"
Feb 20 18:39:26 vm-lbl pgpool[10540]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 7949 statement: CREATE TABLE category (id BYTEA NOT NULL, externalId 
VARCHAR(255) NOT NULL, name VARCHAR(255), parentId BYTEA, treeDepth INT NOT NULL, treeLeft INT NOT NULL, treeRight INT NOT NULL, catalogId BYTEA, CONSTRAINT CONSTRAINT_3 PRIMARY KEY (id)) messag
e: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_3" for table "category"
Feb 20 18:39:26 vm-lbl kernel: [ 2702.621443] pgpool[10540]: segfault at 7f4e00000100 ip 0000000000471384 sp 00007fffbf830680 error 4 in pgpool[400000+f1000]
Feb 20 18:39:26 vm-lbl pgpool[10513]: Child process 10540 was terminated by segmentation fault
Feb 20 18:39:26 vm-lbl systemd-coredump[14435]: Process 10540 (pgpool) dumped core.

----
Feb 20 18:48:57 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 11186 statement: CREATE TABLE databasechangeloglock (ID INT NOT NULL,
 LOCKED BOOLEAN NOT NULL, LOCKGRANTED TIMESTAMP WITH TIME ZONE, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DATABASECHANGELOGLOCK PRIMARY KEY (ID)) message: CREATE TABLE / PRIMARY KEY will create impli
cit index "pk_databasechangeloglock" for table "databasechangeloglock"
Feb 20 18:48:57 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 10733 statement: CREATE TABLE databasechangeloglock (ID INT NOT NULL,
 LOCKED BOOLEAN NOT NULL, LOCKGRANTED TIMESTAMP WITH TIME ZONE, LOCKEDBY VARCHAR(255), CONSTRAINT PK_DATABASECHANGELOGLOCK PRIMARY KEY (ID)) message: CREATE TABLE / PRIMARY KEY will create implicit index "pk_databasechangeloglock" for table "databasechangeloglock"
Feb 20 18:48:57 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 11186 statement: CREATE TABLE databasechangelog (ID VARCHAR(63) NOT NULL, AUTHOR VARCHAR(63) NOT NULL, FILENAME VARCHAR(200) NOT NULL, DATEEXECUTED TIMESTAMP WITH TIME ZONE NOT NULL, ORDEREXECUTED INT NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DESCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONSTRAINT PK_DATABASECHANGELOG PRIMARY KEY (ID, AUTHOR, FILENAME)) message: CREATE TABLE / PRIMARY KEY will create implicit index "pk_databasechangelog" for table "databasechangelog"
Feb 20 18:48:57 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 10733 statement: CREATE TABLE databasechangelog (ID VARCHAR(63) NOT NULL, AUTHOR VARCHAR(63) NOT NULL, FILENAME VARCHAR(200) NOT NULL, DATEEXECUTED TIMESTAMP WITH TIME ZONE NOT NULL, ORDEREXECUTED INT NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DESCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONSTRAINT PK_DATABASECHANGELOG PRIMARY KEY (ID, AUTHOR, FILENAME)) message: CREATE TABLE / PRIMARY KEY will create implicit index "pk_databasechangelog" for table "databasechangelog"
Feb 20 18:48:58 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 11186 statement: CREATE TABLE attributeDefinition (id BYTEA NOT NULL, attributeType VARCHAR(255), description VARCHAR(16384), filterable BOOLEAN, name VARCHAR(255) NOT NULL, visible BOOLEAN, catalogId BYTEA, CONSTRAINT CONSTRAINT_C PRIMARY KEY (id)) message: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_c" for table "attributedefinition"
Feb 20 18:48:58 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 10733 statement: CREATE TABLE attributeDefinition (id BYTEA NOT NULL, attributeType VARCHAR(255), description VARCHAR(16384), filterable BOOLEAN, name VARCHAR(255) NOT NULL, visible BOOLEAN, catalogId BYTEA, CONSTRAINT CONSTRAINT_C PRIMARY KEY (id)) message: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_c" for table "attributedefinition"
Feb 20 18:48:58 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 0 backend pid: 11186 statement: CREATE TABLE category (id BYTEA NOT NULL, externalId VARCHAR(255) NOT NULL, name VARCHAR(255), parentId BYTEA, treeDepth INT NOT NULL, treeLeft INT NOT NULL, treeRight INT NOT NULL, catalogId BYTEA, CONSTRAINT CONSTRAINT_3 PRIMARY KEY (id)) message: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_3" for table "category"
Feb 20 18:48:58 vm-lbl pgpool[15429]: pool_send_and_wait: Error or notice message from backend: : DB node id: 1 backend pid: 10733 statement: CREATE TABLE category (id BYTEA NOT NULL, externalId VARCHAR(255) NOT NULL, name VARCHAR(255), parentId BYTEA, treeDepth INT NOT NULL, treeLeft INT NOT NULL, treeRight INT NOT NULL, catalogId BYTEA, CONSTRAINT CONSTRAINT_3 PRIMARY KEY (id)) message: CREATE TABLE / PRIMARY KEY will create implicit index "constraint_3" for table "category"
Feb 20 18:48:58 vm-lbl kernel: [ 3274.701157] traps: pgpool[15429] general protection ip:7fa282164461 sp:7fffa24a5370 error:0 in libc-2.17.so[7fa2820e8000+1a4000]
Feb 20 18:48:58 vm-lbl systemd-coredump[16679]: Process 15429 (pgpool) dumped core.
pgpool-log (9,049 bytes)

t-ishii

2013-03-05 08:24

developer   ~0000233

To make sure what series of DDLs causes the problem, can you please attach the DDLs, rather than pgpool log file.

andreas

2013-03-06 23:37

reporter   ~0000235

Sorry, I made a wrong presumption.
I thought the crash was because of the DDLs since it always occurred on DB migration.
I tried exporting the DDLs and ran them with psql, but couldn't reproduce the crash that way.

I'm currently debugging, so far I at least have a stacktrace for you:
#0 pool_memory_alloc (pool=0x23fbad0, size=size@entry=32) at pool_memory.c:99
0000001 0x0000000000470443 in pool_memory_alloc_zero (pool=<optimized out>, size=size@entry=32) at pool_memory.c:144
0000002 0x0000000000445541 in rewrite_timestamp (backend=backend@entry=0x23e6670, node=node@entry=0x2417958, rewrite_to_params=0 '\000', message=message@entry=0x23fbc38) at pool_timestamp.c:620
0000003 0x000000000044c46d in Parse (frontend=frontend@entry=0x23f3050, backend=backend@entry=0x23e6670, len=459, contents=<optimized out>, contents@entry=0x2402190 "") at pool_proto_modules.c:1024
0000004 0x000000000044cbd0 in ProcessFrontendResponse (frontend=frontend@entry=0x23f3050, backend=backend@entry=0x23e6670) at pool_proto_modules.c:2475
0000005 0x00000000004195a7 in pool_process_query (frontend=frontend@entry=0x23f3050, backend=backend@entry=0x23e6670, reset_request=reset_request@entry=0) at pool_process_query.c:231
0000006 0x000000000040b4ef in do_child (unix_fd=unix_fd@entry=5, inet_fd=inet_fd@entry=6) at child.c:371
0000007 0x0000000000404e1c in fork_a_child (unix_fd=5, inet_fd=6, id=id@entry=62) at main.c:1243
0000008 0x0000000000407f4d in main (argc=<optimized out>, argv=<optimized out>) at main.c:661

andreas

2013-03-07 00:09

reporter  

pgpool.conf (24,909 bytes)

andreas

2013-03-07 00:11

reporter  

core.pgpool.2987.vm-lbl.1362579912.xz (85,372 bytes)

andreas

2013-03-07 00:12

reporter  

pgpool-ii-3.2.3-1-x86_64.pkg.tar.xz (1,257,184 bytes)

andreas

2013-03-07 00:14

reporter   ~0000236

conf, coredump and binary attached

andreas

2013-03-07 00:58

reporter  

pgpool.log.xz (7,024 bytes)

andreas

2013-03-07 00:59

reporter  

statements.sql (10,366 bytes)

andreas

2013-03-07 01:00

reporter   ~0000237

tried extracting all statements from the verbose log, but pgpool probably crashes before the last statement is logged

t-ishii

2013-03-14 20:23

developer   ~0000243

A user from pgpool comunity in Japan found a bug which might be related to your problem. According to him, the bug is triggered by 1) replication mode 2) queries are using now() or current_timestamp things which envoke time stamp rewriting code. It seems the backtrace includes rewirte_timestamp() call and I suspect yours is the case. Can you please try attached patch? It was created by the user.

t-ishii

2013-03-14 20:24

developer  

pool_proto_modules.patch (601 bytes)
--- pool_proto_modules.c	2013-03-08 20:58:26.301071849 +0900
+++ pool_proto_modules.c.new	2013-03-08 20:58:14.439445873 +0900
@@ -771,7 +771,8 @@
 			if (rewrite_query != NULL)
 			{
 				int alloc_len = len - strlen(stmt) + strlen(rewrite_query);
-				contents = palloc(alloc_len);
+				contents = pool_memory_realloc(session_context->memory_context,
+                                                                      msg->contents, alloc_len);
 				strcpy(contents, name);
 				strcpy(contents + strlen(name) + 1, rewrite_query);
 				memcpy(contents + strlen(name) + strlen(rewrite_query) + 2,

andreas

2013-03-15 03:37

reporter   ~0000244

Thank you, the first tests were successful.
I'm going to do more testing tomorrow.
(Applied against 3.2.3)

andreas

2013-03-15 19:24

reporter   ~0000247

Can't reproduce the crash with the patch applied :)

t-ishii

2013-03-15 20:39

developer   ~0000248

Glad to hear that! Will commit to master and 3.x-stable branches.

Issue History

Date Modified Username Field Change
2013-03-05 01:04 andreas New Issue
2013-03-05 01:04 andreas File Added: pgpool-log
2013-03-05 08:24 t-ishii Note Added: 0000233
2013-03-06 23:37 andreas Note Added: 0000235
2013-03-07 00:09 andreas File Added: pgpool.conf
2013-03-07 00:11 andreas File Added: core.pgpool.2987.vm-lbl.1362579912.xz
2013-03-07 00:12 andreas File Added: pgpool-ii-3.2.3-1-x86_64.pkg.tar.xz
2013-03-07 00:14 andreas Note Added: 0000236
2013-03-07 00:58 andreas File Added: pgpool.log.xz
2013-03-07 00:59 andreas File Added: statements.sql
2013-03-07 01:00 andreas Note Added: 0000237
2013-03-14 20:23 t-ishii Note Added: 0000243
2013-03-14 20:24 t-ishii File Added: pool_proto_modules.patch
2013-03-15 03:37 andreas Note Added: 0000244
2013-03-15 07:30 t-ishii Assigned To => t-ishii
2013-03-15 07:30 t-ishii Status new => assigned
2013-03-15 19:24 andreas Note Added: 0000247
2013-03-15 20:39 t-ishii Note Added: 0000248
2013-03-15 20:40 t-ishii Status assigned => resolved