Segfault on join's

[kataev]

Stable debian & postgres 9.6 from http://apt.postgresql.org/pub/repos/apt/

postgres@filter:~$ /usr/lib/postgresql/9.6/bin/postgres -D /etc/postgresql/9.6/main/ 
2016-12-14 09:25:43 UTC [681-1] LOG:  database system was interrupted; last known up at 2016-12-14 09:23:09 UTC
2016-12-14 09:25:43 UTC [686-1] postgres@postgres FATAL:  the database system is starting up
2016-12-14 09:25:43 UTC [687-1] postgres@postgres FATAL:  the database system is starting up
2016-12-14 09:25:44 UTC [681-2] LOG:  database system was not properly shut down; automatic recovery in progress
2016-12-14 09:25:44 UTC [681-3] LOG:  invalid record length at 80/697694D8: wanted 24, got 0
2016-12-14 09:25:44 UTC [681-4] LOG:  redo is not required
2016-12-14 09:25:44 UTC [681-5] LOG:  MultiXact member wraparound protections are now enabled
2016-12-14 09:25:44 UTC [680-1] LOG:  database system is ready to accept connections
2016-12-14 09:25:44 UTC [691-1] LOG:  autovacuum launcher started
2016-12-14 09:26:58 UTC [680-2] LOG:  server process (PID 739) was terminated by signal 11: Segmentation fault
2016-12-14 09:26:58 UTC [680-3] DETAIL:  Failed process was running: select * from content join build_source using(source_id) where build_id = 123 limit 10;
2016-12-14 09:26:58 UTC [680-4] LOG:  terminating any other active server processes
2016-12-14 09:26:58 UTC [698-1] postgres@postgres WARNING:  terminating connection because of crash of another server process
2016-12-14 09:26:58 UTC [698-2] postgres@postgres 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.
2016-12-14 09:26:58 UTC [698-3] postgres@postgres HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2016-12-14 09:26:58 UTC [691-2] WARNING:  terminating connection because of crash of another server process
2016-12-14 09:26:58 UTC [691-3] 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.
2016-12-14 09:26:58 UTC [691-4] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2016-12-14 09:26:58 UTC [853-1] postgres@skydns-mkfilter WARNING:  terminating connection because of crash of another server process
2016-12-14 09:26:58 UTC [853-2] postgres@skydns-mkfilter 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.
2016-12-14 09:26:58 UTC [853-3] postgres@skydns-mkfilter HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2016-12-14 09:26:58 UTC [697-1] postgres@postgres WARNING:  terminating connection because of crash of another server process
2016-12-14 09:26:58 UTC [697-2] postgres@postgres 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.
2016-12-14 09:26:58 UTC [697-3] postgres@postgres HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2016-12-14 09:26:58 UTC [680-5] LOG:  all server processes terminated; reinitializing
2016-12-14 09:26:59 UTC [1024-1] LOG:  database system was interrupted; last known up at 2016-12-14 09:25:44 UTC
2016-12-14 09:26:59 UTC [1024-2] LOG:  database system was not properly shut down; automatic recovery in progress
2016-12-14 09:26:59 UTC [1024-3] LOG:  invalid record length at 80/69769548: wanted 24, got 0
2016-12-14 09:26:59 UTC [1024-4] LOG:  redo is not required
2016-12-14 09:27:00 UTC [1024-5] LOG:  MultiXact member wraparound protections are now enabled
2016-12-14 09:27:00 UTC [680-6] LOG:  database system is ready to accept connections
2016-12-14 09:27:00 UTC [1032-1] LOG:  autovacuum launcher started

Where content - table with range partition key on source_id, and build_source simple table.

[local] postgres@skydns-mkfilter=# select * from content join build_source using(source_id) where build_id = 123 limit 10;
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.
Time: 25689.742 ms

But if disable pg_pathman, query work well.

[local] postgres@filter=# set pg_pathman.enable = f;
NOTICE:  00000: RuntimeAppend, RuntimeMergeAppend and PartitionFilter nodes and some other options have been disabled
LOCATION:  pg_pathman_enable_assign_hook, hooks.c:450
SET
Time: 1.633 ms
[local] postgres@filter=# select source_id from content join build_source using(source_id) where build_id = 123 limit 1;
source_id
142
(1 row)
Time: 12032.605 ms

Enable pathman crash backend again.

[local] postgres@filter=# set pg_pathman.enable = t;                                                                                                                                                                                                              
NOTICE:  00000: RuntimeAppend, RuntimeMergeAppend and PartitionFilter nodes and some other options have been enabled
LOCATION:  pg_pathman_enable_assign_hook, hooks.c:450
SET
Time: 0.211 ms
[local] postgres@filter=# select source_id from content join build_source using(source_id) where build_id = 123 limit 1;
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.
Time: 26965.025 ms

Also sometimes query produce empty result with enabled pg_pathman, but after disable yield rows.

[kataev]

pg_pathman builded from https://github.com/postgrespro/pg_pathman/tree/1.2.1

[funbringer]

Could you provide a DB scheme? I couldn't reproduce a segfault using your query.

[kataev]

Dump content 3 files, dump.sql and some real random ordered data with limit 5000.

Next some commands https://gist.github.com/kataev/65efa9a3b252befb228a3412126396c1

dump.zip

[kataev]

Data at last query from psql -c return no result, but sometimes query crash

kataev@filter:~/pg_pathman$ sudo -u postgres psql debug 

Welcome, my magistrate

psql (9.6.1)
Type "help" for help.

[local] postgres@debug=# select * from content join build_source using(source_id) limit 10;
┌───────────┬────┬───────────┬────────┬─────────┬───────┬────────┬──────────┬────────┬──────────┐
│ source_id │ id │ domain_id │ dog_id │ path_id │ depth │ active │ build_id │ weight │ map_type │
├───────────┼────┼───────────┼────────┼─────────┼───────┼────────┼──────────┼────────┼──────────┤
└───────────┴────┴───────────┴────────┴─────────┴───────┴────────┴──────────┴────────┴──────────┘
(0 rows)

Time: 5.589 ms
[local] postgres@debug=# select * from content join build_source using(source_id) limit 10;
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.
Time: 2.681 ms
 @!> 

[funbringer]

I'm sorry, it still works fine for me:

select * from content join build_source using(source_id) limit 10;
 source_id |   id    | domain_id | dog_id | path_id | depth | active | build_id | weight | map_type 
-----------+---------+-----------+--------+---------+-------+--------+----------+--------+----------
         1 |   67846 |    267400 |  90774 |       1 |     0 | t      |        1 |     80 |        1
         5 |  133098 |   2135262 | 116869 |       1 |     0 | t      |        1 |    120 |        1
         5 |  133897 |   7168956 | 116869 |       1 |     0 | t      |        1 |    120 |        1
         6 |  188154 |   9969453 | 586951 |       1 |     0 | t      |        1 |      5 |        1
         6 |  216475 |  10036843 | 586951 |       1 |     0 | t      |        1 |      5 |        1
         6 |  164851 |  10450596 | 586951 |       1 |     0 | t      |        1 |      5 |        1
         7 |  970755 |    485290 | 110014 |       1 |     0 | t      |        1 |    110 |        1
         7 | 1571069 |    506661 | 452454 |       1 |     0 | t      |        1 |    110 |        1
         7 | 1634811 |    723259 | 487965 |       1 |     0 | t      |        1 |    110 |        1
         7 |  822686 |    921832 | 110014 |       1 |     0 | t      |        1 |    110 |        1
(10 rows)

explain analyze select * from content join build_source using(source_id) limit 10;
                                                                                  QUERY PLAN                                                                 
                  
-------------------------------------------------------------------------------------------------------------------------------------------------------------
------------------
 Limit  (cost=0.16..0.46 rows=10 width=53) (actual time=0.073..0.173 rows=10 loops=1)
   ->  Nested Loop  (cost=0.16..2124.80 rows=71424 width=53) (actual time=0.072..0.171 rows=10 loops=1)
         ->  Seq Scan on build_source  (cost=0.00..11.06 rows=706 width=16) (actual time=0.013..0.015 rows=7 loops=1)
         ->  Custom Scan (RuntimeAppend)  (cost=0.16..1.98 rows=101 width=41) (actual time=0.006..0.007 rows=1 loops=7)
               ->  Index Scan using content_1_source_id_domain_id_path_id_depth_idx on content_1  (cost=0.12..0.16 rows=1 width=41) (actual time=0.003..0.003
 rows=0 loops=4)
                     Index Cond: (source_id = build_source.source_id)
               ->  Index Scan using content_2_source_id_domain_id_path_id_depth_idx on content_2  (cost=0.14..0.42 rows=15 width=41) (actual time=0.006..0.00
9 rows=3 loops=3)
                     Index Cond: (source_id = build_source.source_id)
 Planning time: 4.170 ms
 Execution time: 0.253 ms
(10 rows)

Do you use any extensions apart from pg_pathman?

[maksm90]

Hi, @kataev !

I also tried to reproduce your bug and failed to do it. Could you show stack trace under database crash gotten, for example, through core dump and gdb?

Previously you have to configure and rebuild PostgreSQL and pg_pathman with options --enable-debug and --enable-cassert.

[kataev]

Yep, i also tried reproduce this bug on fresh created vm. And all work pretty well.

I find one problem in my pipe line. I build pg_pathman using checkinstall

sudo checkinstall make install USE_PGXS=1

And i found what checkinstall don't rebuild between runs, and after i am clone repo again, and build new package, problem has gone.

Thank you for everything

[funbringer]

[didn't refresh my page]