Hi,
I can reproduce a segmentation fault when creating a BRIN concurrently
with set pages_per_range and autosummarize.
# Reproduce
CREATE TABLE brin_test AS
SELECT
series AS id,
MD5(series::TEXT) AS VALUE,
'2015-10-31 13:37:00.313370+01'::TIMESTAMP + (series::TEXT || '
Minute')::INTERVAL AS TIME
FROM
GENERATE_SERIES(0,10000) AS series;
CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin
(TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:08:59.451 CEST [20689] LOG: server process (PID 20881)
was terminated by signal 11: Segmentation fault
2017-05-30 16:08:59.451 CEST [20689] DETAIL: Failed process was
running: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test
USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:08:59.451 CEST [20689] LOG: terminating any other active
server processes
2017-05-30 16:08:59.451 CEST [20806] WARNING: terminating connection
because of crash of another server process
2017-05-30 16:08:59.451 CEST [20806] DETAIL: The postmaster has
commanded this server process to roll back the current transaction and
exit, because another server process exited abnormally and possibly
corrupted shared memory.
2017-05-30 16:08:59.451 CEST [20806] HINT: In a moment you should be
able to reconnect to the database and repeat your command.
2017-05-30 16:08:59.452 CEST [21204] postgres@postgres FATAL: the
database system is in recovery mode
The debian packages where used, version "PostgreSQL 10beta1 on
x86_64-pc-linux-gnu, compiled by gcc (Debian 6.3.0-18) 6.3.0 20170516,
64-bit".
I also tested the latest git commit
d5cb3bab564e0927ffac7c8729eacf181a12dd40 with the same result.
A more detailed log (debug5) can be found attached.
Kind regards,
Alexander Sosna
2017-05-30 16:19:27.374 CEST [22160] postgres@postgres DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.374 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.375 CEST [22160] postgres@postgres DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 591/1/2
2017-05-30 16:19:27.375 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.382 CEST [22160] postgres@postgres DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.382 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.382 CEST [22160] postgres@postgres DEBUG: building index "brin_test_time_abrin_8" on table "brin_test"
2017-05-30 16:19:27.382 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.384 CEST [22160] postgres@postgres DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/1 (used)
2017-05-30 16:19:27.384 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.384 CEST [22160] postgres@postgres DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.384 CEST [22160] postgres@postgres STATEMENT: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.386 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.386 CEST [22059] DEBUG: server process (PID 22160) was terminated by signal 11: Segmentation fault
2017-05-30 16:19:27.386 CEST [22059] DETAIL: Failed process was running: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.386 CEST [22059] LOG: server process (PID 22160) was terminated by signal 11: Segmentation fault
2017-05-30 16:19:27.386 CEST [22059] DETAIL: Failed process was running: CREATE INDEX CONCURRENTLY brin_test_time_abrin_8 ON brin_test USING brin (TIME) WITH (pages_per_range=8, autosummarize=true);
2017-05-30 16:19:27.386 CEST [22059] LOG: terminating any other active server processes
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22066
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22062
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22061
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22063
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22064
2017-05-30 16:19:27.386 CEST [22059] DEBUG: sending SIGQUIT to process 22065
2017-05-30 16:19:27.386 CEST [22064] WARNING: terminating connection because of crash of another server process
2017-05-30 16:19:27.386 CEST [22064] DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2017-05-30 16:19:27.386 CEST [22064] HINT: In a moment you should be able to reconnect to the database and repeat your command.
2017-05-30 16:19:27.386 CEST [22065] DEBUG: writing stats file "pg_stat/global.stat"
2017-05-30 16:19:27.386 CEST [22065] DEBUG: writing stats file "pg_stat/db_12873.stat"
2017-05-30 16:19:27.387 CEST [22065] DEBUG: removing temporary stats file "/var/run/postgresql/10-main.pg_stat_tmp/db_12873.stat"
2017-05-30 16:19:27.387 CEST [22064] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22061] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22064] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22061] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22064] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22061] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22065] DEBUG: writing stats file "pg_stat/db_0.stat"
2017-05-30 16:19:27.387 CEST [22066] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22066] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22066] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22065] DEBUG: removing temporary stats file "/var/run/postgresql/10-main.pg_stat_tmp/db_0.stat"
2017-05-30 16:19:27.387 CEST [22063] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22063] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22063] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22062] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22059] DEBUG: forked new backend, pid=22223 socket=11
2017-05-30 16:19:27.387 CEST [22062] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22062] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres FATAL: the database system is in recovery mode
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: shmem_exit(1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: proc_exit(1): 1 callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: exit(1)
2017-05-30 16:19:27.387 CEST [22065] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22065] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22065] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.387 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.387 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.387 CEST [22223] postgres@postgres DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.388 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.388 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.388 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.388 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.388 CEST [22059] DEBUG: server process (PID 22223) exited with exit code 1
2017-05-30 16:19:27.388 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.388 CEST [22059] LOG: all server processes terminated; reinitializing
2017-05-30 16:19:27.388 CEST [22059] DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.388 CEST [22059] DEBUG: shmem_exit(1): 5 on_shmem_exit callbacks to make
2017-05-30 16:19:27.388 CEST [22059] DEBUG: cleaning up orphaned dynamic shared memory with ID 1908602242
2017-05-30 16:19:27.388 CEST [22059] DEBUG: cleaning up dynamic shared memory control segment with ID 727641219
2017-05-30 16:19:27.390 CEST [22059] DEBUG: invoking IpcMemoryCreate(size=148529152)
2017-05-30 16:19:27.390 CEST [22059] DEBUG: mmap(148897792) with MAP_HUGETLB failed, huge pages disabled: Cannot allocate memory
2017-05-30 16:19:27.398 CEST [22059] DEBUG: SlruScanDirectory invoking callback on pg_notify/0000
2017-05-30 16:19:27.398 CEST [22059] DEBUG: removing file "pg_notify/0000"
2017-05-30 16:19:27.398 CEST [22059] DEBUG: dynamic shared memory system will support 288 segments
2017-05-30 16:19:27.398 CEST [22059] DEBUG: created dynamic shared memory control segment 1908602242 (6928 bytes)
2017-05-30 16:19:27.399 CEST [22224] LOG: database system was interrupted; last known up at 2017-05-30 16:17:56 CEST
2017-05-30 16:19:27.467 CEST [22224] DEBUG: checkpoint record is at 5/629516C8
2017-05-30 16:19:27.468 CEST [22224] DEBUG: redo record is at 5/629516C8; shutdown TRUE
2017-05-30 16:19:27.468 CEST [22224] DEBUG: next transaction ID: 0:589; next OID: 73728
2017-05-30 16:19:27.468 CEST [22224] DEBUG: next MultiXactId: 1; next MultiXactOffset: 0
2017-05-30 16:19:27.468 CEST [22224] DEBUG: oldest unfrozen transaction ID: 548, in database 1
2017-05-30 16:19:27.468 CEST [22224] DEBUG: oldest MultiXactId: 1, in database 1
2017-05-30 16:19:27.468 CEST [22224] DEBUG: commit timestamp Xid oldest/newest: 0/0
2017-05-30 16:19:27.468 CEST [22224] DEBUG: transaction ID wrap limit is 2147484195, limited by database with OID 1
2017-05-30 16:19:27.468 CEST [22224] DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2017-05-30 16:19:27.468 CEST [22224] DEBUG: starting up replication slots
2017-05-30 16:19:27.468 CEST [22224] DEBUG: starting up replication origin progress state
2017-05-30 16:19:27.468 CEST [22224] LOG: database system was not properly shut down; automatic recovery in progress
2017-05-30 16:19:27.471 CEST [22224] DEBUG: resetting unlogged relations: cleanup 1 init 0
2017-05-30 16:19:27.472 CEST [22224] LOG: redo starts at 5/62951738
2017-05-30 16:19:27.485 CEST [22224] LOG: invalid record length at 5/62A6ECB0: wanted 24, got 0
2017-05-30 16:19:27.485 CEST [22224] LOG: redo done at 5/62A6EC00
2017-05-30 16:19:27.485 CEST [22224] LOG: last completed transaction was at log time 2017-05-30 16:19:27.375409+02
2017-05-30 16:19:27.485 CEST [22224] DEBUG: resetting unlogged relations: cleanup 0 init 1
2017-05-30 16:19:27.500 CEST [22224] DEBUG: performing replication slot checkpoint
2017-05-30 16:19:27.521 CEST [22224] DEBUG: attempting to remove WAL segments older than log file 000000000000000500000061
2017-05-30 16:19:27.521 CEST [22224] DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1
2017-05-30 16:19:27.521 CEST [22224] DEBUG: MultiXact member stop limit is now 4294914944 based on MultiXact 1
2017-05-30 16:19:27.525 CEST [22224] DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make
2017-05-30 16:19:27.525 CEST [22224] DEBUG: shmem_exit(0): 4 on_shmem_exit callbacks to make
2017-05-30 16:19:27.525 CEST [22224] DEBUG: proc_exit(0): 2 callbacks to make
2017-05-30 16:19:27.525 CEST [22224] DEBUG: exit(0)
2017-05-30 16:19:27.525 CEST [22224] DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2017-05-30 16:19:27.525 CEST [22224] DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2017-05-30 16:19:27.525 CEST [22224] DEBUG: proc_exit(-1): 0 callbacks to make
2017-05-30 16:19:27.526 CEST [22059] DEBUG: reaping dead processes
2017-05-30 16:19:27.527 CEST [22225] DEBUG: checkpointer updated shared memory configuration values
2017-05-30 16:19:27.527 CEST [22228] DEBUG: autovacuum launcher started
2017-05-30 16:19:27.527 CEST [22228] DEBUG: InitPostgres
2017-05-30 16:19:27.527 CEST [22228] DEBUG: my backend ID is 1
2017-05-30 16:19:27.527 CEST [22059] DEBUG: starting background worker process "logical replication launcher"
2017-05-30 16:19:27.527 CEST [22228] DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22059] LOG: database system is ready to accept connections
2017-05-30 16:19:27.528 CEST [22228] DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22229] DEBUG: received inquiry for database 0
2017-05-30 16:19:27.528 CEST [22229] DEBUG: writing stats file "/var/run/postgresql/10-main.pg_stat_tmp/global.stat"
2017-05-30 16:19:27.528 CEST [22230] DEBUG: logical replication launcher started
2017-05-30 16:19:27.528 CEST [22230] DEBUG: InitPostgres
2017-05-30 16:19:27.528 CEST [22230] DEBUG: my backend ID is 2
2017-05-30 16:19:27.528 CEST [22230] DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22230] DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22230] DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22230] DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22230] DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.528 CEST [22230] DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.538 CEST [22228] DEBUG: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0
2017-05-30 16:19:27.538 CEST [22228] DEBUG: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
