When ANALYZE a table that contains certains values on a geometry field, PostgreSQL crash

[zancos]

If during writing tables that contains PostGIS geometry fields AUTOVACUUM is launched, it crashes and force PostgreSQL to restart. If over the same table I execute VACUUM manually, it works fine with no issues.

Although it always happens when I try to insert data in the database that I am developing, I have also managed to reproduce it by inserting data in the following table:

CREATE TABLE "bug_schema"."bug_table" (
  "#tbl" int8 NOT NULL DEFAULT nextval('bug_schema."bug_table_#tbl_seq"'::regclass),
  "guid" uuid NOT NULL DEFAULT NULL,
  "text" varchar(255) COLLATE "pg_catalog"."default" NOT NULL DEFAULT NULL,
  "metadata" json NOT NULL DEFAULT NULL,
  "bounding_box" "bug_schema"."geometry" NOT NULL DEFAULT NULL,
  "flag" bool NOT NULL DEFAULT NULL,
  "pose" float8[] NOT NULL DEFAULT NULL
)
;

Tested versions:

• PostgreSQL 9.6.9 on x86_64-pc-linux-gnu (Debian 9.6.9-2.pgdg90+1), compiled by gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516, 64-bit POSTGIS="2.4.4 r16526" PGSQL="96" GEOS="3.5.1-CAPI-1.9.1 r4246" SFCGAL="1.3.0" PROJ="Rel. 4.9.3, 15 August 2016" GDAL="GDAL 2.1.2, released 2016/10/24" LIBXML="2.9.4" LIBJSON="0.12.1" LIBPROTOBUF="1.2.1" RASTER

• On both, Windows Server 2012 R2 and CentOS Linux release 7.5.1804

• Also tested with the last PostgreSQL 10.4 and PostGIS 2.4 via docker (only over linux)

Log record one, using our table structure (sorry, I cannot provide you the whole database design):

[unknown] 2018-08-08 15:20:07.228 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_be8 ('{55a7f8e7-781b-4b50-bb82-d2ed524be4a0}', '{fcce536f-c28f-4208-956b-de8c5d58070f}')
[unknown] 2018-08-08 15:20:07.228 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_be8 AS INSERT INTO "wdb"."jt_resource_link" ("FK_resource", "FK_link") VALUES ($1, $2)
[unknown] 2018-08-08 15:20:07.230 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_be8
[unknown] 2018-08-08 15:20:07.231 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_be9 AS INSERT INTO "wdb".resource (guid, "FK_resource_type", metadata, "FK_entity_owner", deleted) VALUES ($1, (SELECT "wdb"."resource_type"."guid" FROM "wdb"."resource_type" WHERE "resource_type"."resource_type" = $2), $3, $4, $5)
[unknown] 2018-08-08 15:20:07.232 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_be9 ('{51cabefc-86b0-42c5-8679-542f0fcafa7f}', 'Point Cloud', NULL, '{c746c96e-ff10-4eb4-aaeb-0c935f809558}', FALSE)
[unknown] 2018-08-08 15:20:07.232 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_be9 AS INSERT INTO "wdb".resource (guid, "FK_resource_type", metadata, "FK_entity_owner", deleted) VALUES ($1, (SELECT "wdb"."resource_type"."guid" FROM "wdb"."resource_type" WHERE "resource_type"."resource_type" = $2), $3, $4, $5)
[unknown] 2018-08-08 15:20:07.233 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_be9
[unknown] 2018-08-08 15:20:07.234 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_bea AS SELECT "wdb"."server".*, "wdb"."server_type"."server_type" FROM "wdb".server INNER JOIN "wdb"."server_type" ON "wdb"."server"."FK_server_type" = "wdb"."server_type"."guid" WHERE "wdb"."server"."name" = $1 AND "wdb"."server"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.235 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_bea ('CRASH')
[unknown] 2018-08-08 15:20:07.235 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_bea AS SELECT "wdb"."server".*, "wdb"."server_type"."server_type" FROM "wdb".server INNER JOIN "wdb"."server_type" ON "wdb"."server"."FK_server_type" = "wdb"."server_type"."guid" WHERE "wdb"."server"."name" = $1 AND "wdb"."server"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.236 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_bea
[unknown] 2018-08-08 15:20:07.237 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_beb AS SELECT * FROM "wdb".link_view WHERE "path" = $1
[unknown] 2018-08-08 15:20:07.238 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_beb ('\Scan\{c746c96e-ff10-4eb4-aaeb-0c935f809558}\20180612_Ed52_Outdoor_Z.C_Scan8.ply')
[unknown] 2018-08-08 15:20:07.238 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_beb AS SELECT * FROM "wdb".link_view WHERE "path" = $1
[unknown] 2018-08-08 15:20:07.239 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_beb
[unknown] 2018-08-08 15:20:07.240 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_bec AS SELECT "wdb"."resource".*, "wdb"."resource_type"."resource_type" FROM "wdb"."resource" INNER JOIN "wdb"."resource_type" ON "wdb"."resource"."FK_resource_type" = "wdb"."resource_type"."guid" INNER JOIN "wdb"."jt_resource_link" ON "wdb"."jt_resource_link"."FK_resource" = "wdb"."resource"."guid" WHERE "wdb"."jt_resource_link"."FK_link" = $1 AND "wdb"."resource"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.241 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_bec (NULL)
[unknown] 2018-08-08 15:20:07.241 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_bec AS SELECT "wdb"."resource".*, "wdb"."resource_type"."resource_type" FROM "wdb"."resource" INNER JOIN "wdb"."resource_type" ON "wdb"."resource"."FK_resource_type" = "wdb"."resource_type"."guid" INNER JOIN "wdb"."jt_resource_link" ON "wdb"."jt_resource_link"."FK_resource" = "wdb"."resource"."guid" WHERE "wdb"."jt_resource_link"."FK_link" = $1 AND "wdb"."resource"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.243 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_bec
[unknown] 2018-08-08 15:20:07.244 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_bed AS SELECT "wdb"."server".*, "wdb"."server_type"."server_type" FROM "wdb".server INNER JOIN "wdb"."server_type" ON "wdb"."server"."FK_server_type" = "wdb"."server_type"."guid" INNER JOIN "wdb"."jt_link_server" ON "wdb"."jt_link_server"."FK_server" = "wdb"."server"."guid" WHERE "wdb"."jt_link_server"."FK_link" = $1 AND "wdb"."server"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.244 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_bed (NULL)
[unknown] 2018-08-08 15:20:07.244 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_bed AS SELECT "wdb"."server".*, "wdb"."server_type"."server_type" FROM "wdb".server INNER JOIN "wdb"."server_type" ON "wdb"."server"."FK_server_type" = "wdb"."server_type"."guid" INNER JOIN "wdb"."jt_link_server" ON "wdb"."jt_link_server"."FK_server" = "wdb"."server"."guid" WHERE "wdb"."jt_link_server"."FK_link" = $1 AND "wdb"."server"."deleted" = FALSE
[unknown] 2018-08-08 15:20:07.246 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_bed
[unknown] 2018-08-08 15:20:07.247 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_bee AS INSERT INTO "wdb"."link" ("guid", "FK_link_type", "path", "deleted") VALUES ($1, (SELECT "wdb"."link_type"."guid" FROM "wdb"."link_type" WHERE "link_type"."link_type" = $2), $3, $4)
[unknown] 2018-08-08 15:20:07.248 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_bee ('{d816c240-95a0-40b8-b1cc-80626505e225}', 'Point Cloud Ply link', '\Scan\{c746c96e-ff10-4eb4-aaeb-0c935f809558}\20180612_Ed52_Outdoor_Z.C_Scan8.ply', FALSE)
[unknown] 2018-08-08 15:20:07.248 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_bee AS INSERT INTO "wdb"."link" ("guid", "FK_link_type", "path", "deleted") VALUES ($1, (SELECT "wdb"."link_type"."guid" FROM "wdb"."link_type" WHERE "link_type"."link_type" = $2), $3, $4)
[unknown] 2018-08-08 15:20:07.249 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_bee
[unknown] 2018-08-08 15:20:07.250 UTC 00000 451LOG:  statement: PREPARE qpsqlpstmt_bef AS INSERT INTO "wdb"."jt_link_server" ("FK_link", "FK_server") VALUES ($1, $2)
[unknown] 2018-08-08 15:20:07.251 UTC 00000 451LOG:  statement: EXECUTE qpsqlpstmt_bef ('{d816c240-95a0-40b8-b1cc-80626505e225}', '{c8f68af8-52e2-4e12-bcee-e810c5d1a5a5}')
[unknown] 2018-08-08 15:20:07.251 UTC 00000 451DETAIL:  prepare: PREPARE qpsqlpstmt_bef AS INSERT INTO "wdb"."jt_link_server" ("FK_link", "FK_server") VALUES ($1, $2)
[unknown] 2018-08-08 15:20:07.253 UTC 00000 451LOG:  statement: DEALLOCATE qpsqlpstmt_bef
 2018-08-08 15:20:08.801 UTC 00000 1LOG:  server process (PID 471) was terminated by signal 11: Segmentation fault
 2018-08-08 15:20:08.801 UTC 00000 1DETAIL:  Failed process was running: autovacuum: ANALYZE wdb.scan
 2018-08-08 15:20:08.801 UTC 00000 1LOG:  terminating any other active server processes
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 451WARNING:  terminating connection because of crash of another server process
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 451DETAIL:  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.
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 451HINT:  In a moment you should be able to reconnect to the database and repeat your command.
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 447WARNING:  terminating connection because of crash of another server process
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 447DETAIL:  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.
[unknown] 2018-08-08 15:20:08.801 UTC 57P02 447HINT:  In a moment you should be able to reconnect to the database and repeat your command.
App 2018-08-08 15:20:08.802 UTC 57P02 126WARNING:  terminating connection because of crash of another server process
App 2018-08-08 15:20:08.802 UTC 57P02 126DETAIL:  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.
App 2018-08-08 15:20:08.802 UTC 57P02 126HINT:  In a moment you should be able to reconnect to the database and repeat your command.
App 2018-08-08 15:20:08.803 UTC 57P02 31WARNING:  terminating connection because of crash of another server process
App 2018-08-08 15:20:08.803 UTC 57P02 31DETAIL:  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.
App 2018-08-08 15:20:08.803 UTC 57P02 31HINT:  In a moment you should be able to reconnect to the database and repeat your command.
App 2018-08-08 15:20:08.804 UTC 57P02 84WARNING:  terminating connection because of crash of another server process
App 2018-08-08 15:20:08.804 UTC 57P02 84DETAIL:  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.
App 2018-08-08 15:20:08.804 UTC 57P02 84HINT:  In a moment you should be able to reconnect to the database and repeat your command.
App 2018-08-08 15:20:08.805 UTC 57P02 28WARNING:  terminating connection because of crash of another server process
App 2018-08-08 15:20:08.805 UTC 57P02 28DETAIL:  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.
App 2018-08-08 15:20:08.805 UTC 57P02 28HINT:  In a moment you should be able to reconnect to the database and repeat your command.
 2018-08-08 15:20:08.807 UTC 57P02 25WARNING:  terminating connection because of crash of another server process
 2018-08-08 15:20:08.807 UTC 57P02 25DETAIL:  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.
 2018-08-08 15:20:08.807 UTC 57P02 25HINT:  In a moment you should be able to reconnect to the database and repeat your command.
 2018-08-08 15:20:08.812 UTC 00000 1LOG:  all server processes terminated; reinitializing
 2018-08-08 15:20:08.889 UTC 00000 472LOG:  database system was interrupted; last known up at 2018-08-08 14:48:13 UTC
 2018-08-08 15:20:10.214 UTC 00000 472LOG:  database system was not properly shut down; automatic recovery in progress
 2018-08-08 15:20:10.232 UTC 00000 472LOG:  redo starts at 0/D47FA430
 2018-08-08 15:20:10.249 UTC 00000 472LOG:  invalid record length at 0/D484D4C0: wanted 24, got 0
 2018-08-08 15:20:10.249 UTC 00000 472LOG:  redo done at 0/D484D498
 2018-08-08 15:20:10.249 UTC 00000 472LOG:  last completed transaction was at log time 2018-08-08 15:20:08.508645+00
 2018-08-08 15:20:10.274 UTC 00000 472LOG:  MultiXact member wraparound protections are now enabled
 2018-08-08 15:20:10.277 UTC 00000 476LOG:  autovacuum launcher started
 2018-08-08 15:20:10.277 UTC 00000 1LOG:  database system is ready to accept connections

Log record two (also attached the whole file)

LOG:  statement: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: EXECUTE qpsqlpstmt_1 ('{00000000-0000-0000-0000-000000000000}', 'text', '{ }', 'GEOMETRYCOLLECTION(POINT(0.0 0.0 0.0),POINT(0.0 0.0 0.0))', FALSE, '{0, 0, 0, 0, 0, 0}')
DETAIL:  prepare: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: DEALLOCATE qpsqlpstmt_1
LOG:  statement: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: EXECUTE qpsqlpstmt_1 ('{00000000-0000-0000-0000-000000000000}', 'text', '{ }', 'GEOMETRYCOLLECTION(POINT(0.0 0.0 0.0),POINT(0.0 0.0 0.0))', FALSE, '{0, 0, 0, 0, 0, 0}')
DETAIL:  prepare: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: DEALLOCATE qpsqlpstmt_1
LOG:  statement: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: EXECUTE qpsqlpstmt_1 ('{00000000-0000-0000-0000-000000000000}', 'text', '{ }', 'GEOMETRYCOLLECTION(POINT(0.0 0.0 0.0),POINT(0.0 0.0 0.0))', FALSE, '{0, 0, 0, 0, 0, 0}')
DETAIL:  prepare: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: DEALLOCATE qpsqlpstmt_1
LOG:  statement: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: EXECUTE qpsqlpstmt_1 ('{00000000-0000-0000-0000-000000000000}', 'text', '{ }', 'GEOMETRYCOLLECTION(POINT(0.0 0.0 0.0),POINT(0.0 0.0 0.0))', FALSE, '{0, 0, 0, 0, 0, 0}')
DETAIL:  prepare: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: DEALLOCATE qpsqlpstmt_1
LOG:  statement: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: EXECUTE qpsqlpstmt_1 ('{00000000-0000-0000-0000-000000000000}', 'text', '{ }', 'GEOMETRYCOLLECTION(POINT(0.0 0.0 0.0),POINT(0.0 0.0 0.0))', FALSE, '{0, 0, 0, 0, 0, 0}')
DETAIL:  prepare: PREPARE qpsqlpstmt_1 AS INSERT INTO "bug_database"."bug_schema"."bug_table" (guid, text, metadata, bounding_box, flag, pose) VALUES ($1, $2, $3, $4, $5, $6)
LOG:  statement: DEALLOCATE qpsqlpstmt_1
LOG:  server process (PID 28) was terminated by signal 11: Segmentation fault
DETAIL:  Failed process was running: autovacuum: ANALYZE bug_schema.bug_table
LOG:  terminating any other active server processes
WARNING:  terminating connection because of crash of another server process
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.
HINT:  In a moment you should be able to reconnect to the database and repeat your command.
WARNING:  terminating connection because of crash of another server process
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.
HINT:  In a moment you should be able to reconnect to the database and repeat your command.
LOG:  all server processes terminated; reinitializing
LOG:  database system was interrupted; last known up at 2018-08-07 14:18:12 UTC
LOG:  database system was not properly shut down; automatic recovery in progress
LOG:  redo starts at 0/CE894A60
LOG:  invalid record length at 0/CE8B5540: wanted 24, got 0
LOG:  redo done at 0/CE8B5518
LOG:  last completed transaction was at log time 2018-08-07 14:19:35.060534+00
LOG:  MultiXact member wraparound protections are now enabled
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started

I used for testing the following Dockerfile to build the testing platform:

FROM postgres:9.6

##Installation
RUN apt-get -y update && apt-get -y install postgresql-9.6-postgis-2.4 postgresql-9.6-postgis-2.4-scripts --no-install-recommends

## cleaning
RUN apt-get purge -y --auto-remove && apt-get -y autoclean && rm -fr /var/lib/apt/lists/*

Maybe could also be related with this reported bug: ​https://trac.osgeo.org/postgis/ticket/3550#no1

Disabling autovacuum, I have no issues inserting the same records in the same database structure. I'm not a PostgreSQL / Database expert, so please, let me know how could I provide you better information if needed.

[zancos]

Failure log

[Algunenano]

The crashed process is the one running: autovacuum: ANALYZE bug_schema.bug_table so it could be a bug in Postgres itself, but it's impossible to say without, at least, a backtrace. Could you please install symbols for both Postgis and Postgresql to get a trace of the process crashing.

Are you using indices, specifically in `"bounding_box"?

[zancos]

Whole database dump attached. There is no indexes at all.

In our final database we have indexes, but none of them are over geo fields. Only uuid and some text fields are indexed.

As I said, I'm not a database expert so I'm using postgresql/postgis binaries with no debug symbols; thus, I haven't backtrace at the moment. If you could not reproduce the problem, I could try to compile postgresql/postgis in debug mode, but probably will take me some time.

Please, let me know…

[zancos]

Database dump

[zancos]

I tried to obtain a BT, but there is no good news:

(gdb) cont
Continuing.

Program received signal SIGQUIT, Quit.
0x00007faa63ffe0a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
84       in ../sysdeps/unix/syscall-template.S
(gdb) bt
#0  0x00007faa63ffe0a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
Backtrace stopped: Cannot access memory at address 0x7ffd765ea418

[zancos]

I have tried to get some bt captures before the failure, but they are probably useless.

Continuing.

Program received signal SIGINT, Interrupt.
0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
84	in ../sysdeps/unix/syscall-template.S
#0  0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
#1  0x000055ebcdb5dcb9 in WaitEventSetWaitBlock (nevents=1, occurred_events=0x7ffe6ff53b10, cur_timeout=-1, set=0x55ebceb20ea8) at ./build/../src/backend/storage/ipc/latch.c:1053
#2  WaitEventSetWait (set=0x55ebceb20ea8, timeout=timeout@entry=-1, occurred_events=occurred_events@entry=0x7ffe6ff53b10, nevents=nevents@entry=1) at ./build/../src/backend/storage/ipc/latch.c:1007
#3  0x000055ebcda91e90 in secure_read (port=0x55ebceb5e540, ptr=0x55ebce0cffc0 <PqRecvBuffer>, len=8192) at ./build/../src/backend/libpq/be-secure.c:149
#4  0x000055ebcda9bdc3 in pq_recvbuf () at ./build/../src/backend/libpq/pqcomm.c:940
#5  0x000055ebcda9cc75 in pq_getbyte () at ./build/../src/backend/libpq/pqcomm.c:983
#6  0x000055ebcdb7fb1d in SocketBackend (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:326
#7  ReadCommand (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:499
#8  PostgresMain (argc=<optimized out>, argv=argv@entry=0x55ebceb690e0, dbname=<optimized out>, username=<optimized out>) at ./build/../src/backend/tcop/postgres.c:4017
#9  0x000055ebcd8f4bd8 in BackendRun (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4342
#10 BackendStartup (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4016
#11 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1721
#12 0x000055ebcdb1d492 in PostmasterMain (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/postmaster/postmaster.c:1329
#13 0x000055ebcd8f5f44 in main (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/main/main.c:228
Continuing.

Program received signal SIGINT, Interrupt.
0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
84	in ../sysdeps/unix/syscall-template.S
#0  0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
#1  0x000055ebcdb5dcb9 in WaitEventSetWaitBlock (nevents=1, occurred_events=0x7ffe6ff53b10, cur_timeout=-1, set=0x55ebceb20ea8) at ./build/../src/backend/storage/ipc/latch.c:1053
#2  WaitEventSetWait (set=0x55ebceb20ea8, timeout=timeout@entry=-1, occurred_events=occurred_events@entry=0x7ffe6ff53b10, nevents=nevents@entry=1) at ./build/../src/backend/storage/ipc/latch.c:1007
#3  0x000055ebcda91e90 in secure_read (port=0x55ebceb5e540, ptr=0x55ebce0cffc0 <PqRecvBuffer>, len=8192) at ./build/../src/backend/libpq/be-secure.c:149
#4  0x000055ebcda9bdc3 in pq_recvbuf () at ./build/../src/backend/libpq/pqcomm.c:940
#5  0x000055ebcda9cc75 in pq_getbyte () at ./build/../src/backend/libpq/pqcomm.c:983
#6  0x000055ebcdb7fb1d in SocketBackend (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:326
#7  ReadCommand (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:499
#8  PostgresMain (argc=<optimized out>, argv=argv@entry=0x55ebceb690e0, dbname=<optimized out>, username=<optimized out>) at ./build/../src/backend/tcop/postgres.c:4017
#9  0x000055ebcd8f4bd8 in BackendRun (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4342
#10 BackendStartup (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4016
#11 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1721
#12 0x000055ebcdb1d492 in PostmasterMain (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/postmaster/postmaster.c:1329
#13 0x000055ebcd8f5f44 in main (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/main/main.c:228
Breakpoint 1 at 0x55ebcdc87b40: file ./build/../src/backend/utils/error/elog.c, line 414.
Continuing.

Program received signal SIGINT, Interrupt.
0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
84	in ../sysdeps/unix/syscall-template.S
#0  0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
#1  0x000055ebcdb5dcb9 in WaitEventSetWaitBlock (nevents=1, occurred_events=0x7ffe6ff53b10, cur_timeout=-1, set=0x55ebceb20ea8) at ./build/../src/backend/storage/ipc/latch.c:1053
#2  WaitEventSetWait (set=0x55ebceb20ea8, timeout=timeout@entry=-1, occurred_events=occurred_events@entry=0x7ffe6ff53b10, nevents=nevents@entry=1) at ./build/../src/backend/storage/ipc/latch.c:1007
#3  0x000055ebcda91e90 in secure_read (port=0x55ebceb5e540, ptr=0x55ebce0cffc0 <PqRecvBuffer>, len=8192) at ./build/../src/backend/libpq/be-secure.c:149
#4  0x000055ebcda9bdc3 in pq_recvbuf () at ./build/../src/backend/libpq/pqcomm.c:940
#5  0x000055ebcda9cc75 in pq_getbyte () at ./build/../src/backend/libpq/pqcomm.c:983
#6  0x000055ebcdb7fb1d in SocketBackend (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:326
#7  ReadCommand (inBuf=0x7ffe6ff53d10) at ./build/../src/backend/tcop/postgres.c:499
#8  PostgresMain (argc=<optimized out>, argv=argv@entry=0x55ebceb690e0, dbname=<optimized out>, username=<optimized out>) at ./build/../src/backend/tcop/postgres.c:4017
#9  0x000055ebcd8f4bd8 in BackendRun (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4342
#10 BackendStartup (port=0x55ebceb5e540) at ./build/../src/backend/postmaster/postmaster.c:4016
#11 ServerLoop () at ./build/../src/backend/postmaster/postmaster.c:1721
#12 0x000055ebcdb1d492 in PostmasterMain (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/postmaster/postmaster.c:1329
#13 0x000055ebcd8f5f44 in main (argc=5, argv=0x55ebceb1ee10) at ./build/../src/backend/main/main.c:228
Continuing.

Program received signal SIGQUIT, Quit.
0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
84	in ../sysdeps/unix/syscall-template.S
#0  0x00007f67416570a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84
Backtrace stopped: Cannot access memory at address 0x7ffe6ff53a38
Detaching from program: /usr/lib/postgresql/9.6/bin/postgres, process 5678

[robe]

Why is this marked as PostGIS GDAL? raster isn't even at play here so GDAL in theory should not be involved unless the .so files are fighting with each other. Also at a glance at your bt I don't see any postgis components showing up as a culprit.

I wasn't able to make your example crash on

PostgreSQL 10.3, compiled by Visual C++ build 1800, 64-bit POSTGIS="2.4.4 r16526" PGSQL="100" GEOS="3.6.2-CAPI-1.10.2 4d2925d" PROJ="Rel. 4.9.3, 15 August 2016" GDAL="GDAL 2.2.4, released 2018/03/19" LIBXML="2.7.8" LIBJSON="0.12" LIBPROTOBUF="1.2.1" RASTER

or

PostgreSQL 10.3, compiled by Visual C++ build 1800, 64-bit POSTGIS="2.4.4 r16526" PGSQL="100" GEOS="3.6.2-CAPI-1.10.2 4d2925d" PROJ="Rel. 4.9.3, 15 August 2016" GDAL="GDAL 2.2.4, released 2018/03/19" LIBXML="2.7.8" LIBJSON="0.12" LIBPROTOBUF="1.2.1" RASTER

PostgreSQL 9.6.8, compiled by Visual C++ build 1800, 64-bit POSTGIS="2.4.4 r16526" PGSQL="96" GEOS="3.6.2-CAPI-1.10.2 4d2925d" PROJ="Rel. 4.9.3, 15 August 2016" GDAL="GDAL 2.2.4, released 2018/03/19" LIBXML="2.7.8" LIBJSON="0.12" LIBPROTOBUF="1.2.1" RASTER

I revised your example a bit - here is what I ran

CREATE SCHEMA IF NOT EXISTS bug_schema;
CREATE EXTENSION postgis SCHEMA bug_schema;
CREATE TABLE "bug_schema"."bug_table" (
  "#tbl" bigserial NOT NULL ,
  "guid" uuid NOT NULL DEFAULT NULL,
  "text" varchar(255) COLLATE "pg_catalog"."default" NOT NULL DEFAULT NULL,
  "metadata" json NOT NULL DEFAULT NULL,
  "bounding_box" "bug_schema"."geometry" NOT NULL DEFAULT NULL,
  "flag" bool NOT NULL DEFAULT NULL,
  "pose" float8[] NOT NULL DEFAULT NULL
)
;
INSERT INTO bug_schema.bug_table(guid, "text", "metadata",
           bounding_box, flag, pose  )
SELECT '28ef049e-9d36-11e8-80b0-00000a3a2e20'::uuid,
    'hello', '{"name": "hello", "age": 10}'::json,
    bug_schema.ST_MakeEnvelope(1,2,3,i, 4326),
    true, '{1908098080934,190808.2908}'::float8[]
   FROM generate_series(1,10) AS i;

vacuum analyze verbose;

Can you provide an example of an insert that triggers the error. Might have to do with play of NULLS and so forth.

[zancos]

Issue edited.

Trigger: when in a geometry field is pushed a GEOMETRYCOLLECTION with more than two points, and one of these points has, at least, one value containing a number smaller than -3.385894e+38 (which is not the limit) and then if ANALYSE the table, PostgreSQL crash and force the database engine to restart.

Due to ANALYSE is executed before vacuum tables when autovacuum is called, also PostgreSQL crash when inserting values into database and at least there is one of this fields filled in with this "problematic" value.

This code reproduce the error:

-- ----------------------------
-- Prepare schema and populate postgis extension
-- ----------------------------
CREATE SCHEMA bug_schema;
CREATE EXTENSION postgis SCHEMA bug_schema;

-- ----------------------------
-- Table structure for scan
-- ----------------------------
DROP TABLE IF EXISTS bug_schema.bug_table;
CREATE TABLE bug_schema.bug_table (
  "geometryField" bug_schema."geometry" NOT NULL DEFAULT NULL
)
;

PREPARE stmt AS INSERT INTO bug_schema.bug_table ("geometryField") VALUES ($1);
EXECUTE stmt ('GEOMETRYCOLLECTION(POINT(-3.385894e+38 0 0),POINT(0 0 0))');
DEALLOCATE stmt;

ANALYZE;

[zancos]

I observed that is not only happening with this condition:

"value containing a number smaller than -3.385894e+38"

Also pushing this value, when ANALYSE the table, postgreSQL crash. If ANALYSE is not executed, everything looks working fine.

POLYGON((-3.40282e+38 -3.40282e+38,3.40282e+38 -3.40282e+38,3.40282e+38 3.40282e+38,-3.40282e+38 3.40282e+38,-3.40282e+38 -3.40282e+38))

[komzpa]

This sounds like there is a cast to 32bit float in histogram build.

FLT_MAX      = 3.402823e+38

Out of curiosity, what is the data with this value? I expect that no normal projection will store such value on surface of the planet.

[zancos]

This "extreme" value is assigned only when initializing bounding_box to -infinity/+infinite

Only few fields takes this value, but believe me that this error got me crazy!

[pramsey]

Confirmed crasher on OSX as well

DROP TABLE IF EXISTS bug_table;
CREATE TABLE bug_table (
  geom geometry NOT NULL DEFAULT NULL
);

INSERT INTO bug_table (geom) 
  VALUES ('GEOMETRYCOLLECTION(POINT(-3.385894e+38 0 0),POINT(0 0 0))');

ANALYZE bug_table;

[pramsey]

In 16786:

Handle almost-infinite features when building table statistics in ANALYZE
References #4144

[pramsey]

In 16787:

Handle almost-infinite features when building table statistics in ANALYZE
References #4144

[pramsey]

In 16788:

Handle almost-infinite features when building table statistics in ANALYZE
Closes #4144