test_fdw segfaults server on Postgres 11

[intgr]

Apparently this has never worked on my machine but I didn't pay attention to it because I wasn't using the FDW functionality... (I need to manually run drop function DefaultFDW() cascade; in the test database for the error to occur again, otherwise it just fails with foreign-data wrapper "defaultfdw" already exists.)

Arch Linux; PostgreSQL 11.3 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.3.0, 64-bit

May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.206 EEST [23832] LOG:  statement:
May 26 13:27:03 newn postgres[23742]:         CREATE SERVER df FOREIGN DATA WRAPPER defaultfdw;
May 26 13:27:03 newn postgres[23742]:         
May 26 13:27:03 newn postgres[23742]:         DROP SCHEMA IF EXISTS fdw_test_schema CASCADE;
May 26 13:27:03 newn postgres[23742]:         
May 26 13:27:03 newn postgres[23742]:         CREATE SCHEMA fdw_test_schema;
May 26 13:27:03 newn postgres[23742]:         
May 26 13:27:03 newn postgres[23742]:         IMPORT FOREIGN SCHEMA test
May 26 13:27:03 newn postgres[23742]:           FROM SERVER df
May 26 13:27:03 newn postgres[23742]:           INTO fdw_test_schema;
May 26 13:27:03 newn postgres[23742]:         
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.209 EEST [23832] LOG:  execute <unnamed>: SELECT * FROM fdw_test_schema.mytable
May 26 13:27:03 newn kernel: traps: postgres[23832] general protection fault ip:7fe2e1a4bea9 sp:7ffebb46df28 error:0 in libc-2.29.so[7fe2e19cb000+14c000]
May 26 13:27:03 newn systemd[1]: Started Process Core Dump (PID 23833/UID 0).
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23742] LOG:  server process (PID 23832) was terminated by signal 11: Segmentation fault
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23742] DETAIL:  Failed process was running: SELECT * FROM fdw_test_schema.mytable
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23742] LOG:  terminating any other active server processes
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23765] WARNING:  terminating connection because of crash of another server process
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23765] 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.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.750 EEST [23765] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23754] WARNING:  terminating connection because of crash of another server process
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23754] 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.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23754] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23747] WARNING:  terminating connection because of crash of another server process
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23747] 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.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.751 EEST [23747] HINT:  In a moment you should be able to reconnect to the database and repeat your command.
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.753 EEST [23742] LOG:  all server processes terminated; reinitializing
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.803 EEST [23836] LOG:  database system was interrupted; last known up at 2019-05-26 13:26:18 EEST
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.803 EEST [23836] LOG:  database system was not properly shut down; automatic recovery in progress
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.804 EEST [23836] LOG:  redo starts at 3/B1239818
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.805 EEST [23836] LOG:  invalid record length at 3/B123EA88: wanted 24, got 0
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.805 EEST [23836] LOG:  redo done at 3/B123E820
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.805 EEST [23836] LOG:  last completed transaction was at log time 2019-05-26 13:27:03.208861+03
May 26 13:27:03 newn postgres[23742]: 2019-05-26 13:27:03.812 EEST [23742] LOG:  database system is ready to accept connections
May 26 13:27:03 newn systemd-coredump[23834]: Process 23832 (postgres) of user 88 dumped core.
                                              
                                              Stack trace of thread 23832:
                                              #0  0x00007fe2e1a4bea9 __memcpy_sse2_unaligned_erms (libc.so.6)
                                              #1  0x00007fe2cd8c6324 _ZN9pg_extend6pg_fdw23ForeignWrapper$LT$T$GT$9get_field17h883b7931344fdea3E (libfdw.so)
                                              #2  0x00007fe2cd8c4642 _ZN9pg_extend6pg_fdw23ForeignWrapper$LT$T$GT$20iterate_foreign_scan17hd164e1283ebe0148E (libfdw.so)
                                              #3  0x000055b03bc5d333 n/a (postgres)
                                              #4  0x000055b03bc39cfa ExecScan (postgres)
                                              #5  0x000055b03bc310fd standard_ExecutorRun (postgres)
                                              #6  0x000055b03bd8781d n/a (postgres)
                                              #7  0x000055b03bd88cee PortalRun (postgres)
                                              #8  0x000055b03bd86106 PostgresMain (postgres)
                                              #9  0x000055b03bd10a92 n/a (postgres)
                                              #10 0x000055b03bd119d9 PostmasterMain (postgres)
                                              #11 0x000055b03ba9413a main (postgres)
                                              #12 0x00007fe2e19ccce3 __libc_start_main (libc.so.6)
                                              #13 0x000055b03ba941ee _start (postgres)
May 26 13:27:03 newn systemd[1]: systemd-coredump@12-23833-0.service: Succeeded.

[bluejekyll]

Yeah, I’ve noticed the fdw test isn’t properly cleaning up after it’s run.

As to the segfault, I haven’t noticed that on the travis runs. We might want to mark the fdw crate with a new feature, and disable it by default.

[intgr]

Apparently this is a compatibility issue with PostgreSQL 11. I tested with PG 10.8 and all tests passed without errors.

[Hywan]

Travis tests Pg 10. I also notice a segfault with Pg 11 on macOS.

2019-06-14 14:40:31.043 CEST [41687] LOG:  server process (PID 41755) was terminated by signal 11: Segmentation fault
2019-06-14 14:40:31.043 CEST [41687] DETAIL:  Failed process was running: SELECT * FROM fdw_test_schema.mytable;

[intgr]

Oops, sorry for the spam; I used commit --amend too many times. Anyway point being, as PR #89 is merged, the FDW feature is now disabled when building with PostgreSQL 11+