Re: BUG #16811: Severe reproducible server backend crash

From: James Inform <james(dot)inform(at)pharmapp(dot)de>
To: pgsql-bugs(at)lists(dot)postgresql(dot)org, james(dot)inform(at)pharmapp(dot)de
Subject: Re: BUG #16811: Severe reproducible server backend crash
Date: 2021-01-07 01:05:45
Message-ID: ef767fe3-2a39-697f-937f-c115f74dbd0f@pharmapp.de
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

Well, so here is the core dump in zip format.

> Bug reference: 16811
> Logged by: James Inform
> Email address: james(dot)inform(at)pharmapp(dot)de
> PostgreSQL version: 13.1
> Operating system: Ubuntu 18.04 LTS AND macOS Catalina 10.15.7
> Description:
>
> First things first: Happy new year to all of you and stay healthy during
> these days.
>
> I have run into a severe backend crash that makes the whole PostgreSQL
> shutting down and restart with recovering message.
>
> This is reproducible on Mac using the latest version of the Postgresapp
> (www.postgresapp.com) which comes with PG13.1 as well as on Ubuntu with a
> self build PG 13.1 and also with the latest version from REL_13_STABLE
> branch.
>
> The issue doesn't exist on PG 12.5. Wether on Mac nor on Ubuntu.
>
> It's very severe because with the steps for reproduction it seems that you
> can tear down every PostgreSQL 13 server you have access to.
>
> It's enough to run the following simple anonymous block with an appropriate
> db tool:
>
> do
> $$
> begin
> rollback;
> end
> $$
> ;
>
> This works fine in psql or from python using psycopg2.
>
> But when using the DBeaver tool (www.dbeaver.io / Verson 7.3.2) to run the
> command, the whole PostgreSQL is teared down. It is not only with DBeaver,
> it is also reproducible with Lazarus/Delphi [yes, I am still using good old
> pascal :)] on Linux and Windows. With Lazarus I am using components that
> have a pg client library compiled into while DBeaver uses java libraries. I
> can reproduce the behaviour with these two tools and I would bet that there
> are many more tools out there that deliver the same result.
>
> Steps to reproduce:
> 1. Install or build PostgreSQL 13.1 on Ubuntu or use the Postgresapp on
> Mac.
> 2. Init a new PG13 cluster (initdb)
> 3. Download and install DBeaver on Linux, Mac or Windows
> 4. Connect to PostgreSQL using the postgres superuser
> 5. Execute the anonymous block from above
> 6. Voila ... you have forced PostgreSQL to shutdown and recover
>
> I have started postgres with core dump option: pg_ctl start -D /opt/data13
> -c
> So I have a core dump at hand. But using the bug form on www.postgresql.org
> I am not able to add an attachment. How can I provide you with such an
> attachment.
>
> Cheers, James
>
> --################################################################################
> -- Now the relevant log entries
> -- You can see that the server starts
> -- And just after executing the command from (in this case) DBeaver the
> corresponding error is logged
> --################################################################################
>
> pglinux(at)aggaserv:/opt/data13$ pg_ctl start -D /opt/data13/ -c
> waiting for server to start....2021-01-06 22:36:18.375 UTC [38787] LOG:
> starting PostgreSQL 13.1 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu
> 7.5.0-3ubuntu1~18.04) 7.5.0, 64-bit
> 2021-01-06 22:36:18.375 UTC [38787] LOG: listening on IPv6 address "::1",
> port 5432
> 2021-01-06 22:36:18.375 UTC [38787] LOG: listening on IPv4 address
> "127.0.0.1", port 5432
> 2021-01-06 22:36:18.386 UTC [38787] LOG: listening on Unix socket
> "/tmp/.s.PGSQL.5432"
> 2021-01-06 22:36:18.405 UTC [38788] LOG: database system was shut down at
> 2021-01-06 22:26:20 UTC
> 2021-01-06 22:36:18.417 UTC [38787] LOG: database system is ready to accept
> connections
> done
> server started
> pglinux(at)aggaserv:/opt/data13$ 2021-01-06 22:36:30.022 UTC [38787] LOG:
> server process (PID 38881) was terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:30.022 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:30.022 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:30.022 UTC [38792] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:30.022 UTC [38792] 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.
> 2021-01-06 22:36:30.022 UTC [38792] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:30.023 UTC [38880] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:30.023 UTC [38880] 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.
> 2021-01-06 22:36:30.023 UTC [38880] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:30.024 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:30.043 UTC [38884] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:18 UTC
> 2021-01-06 22:36:30.088 UTC [38884] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:30.095 UTC [38884] LOG: invalid record length at
> 0/1693F78: wanted 24, got 0
> 2021-01-06 22:36:30.095 UTC [38884] LOG: redo is not required
> 2021-01-06 22:36:30.144 UTC [38787] LOG: database system is ready to accept
> connections
> 2021-01-06 22:36:30.686 UTC [38787] LOG: server process (PID 38977) was
> terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:30.686 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:30.686 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:30.686 UTC [38906] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:30.686 UTC [38906] 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.
> 2021-01-06 22:36:30.686 UTC [38906] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:30.686 UTC [38976] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:30.686 UTC [38976] 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.
> 2021-01-06 22:36:30.686 UTC [38976] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:30.688 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:30.695 UTC [38979] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:30 UTC
> 2021-01-06 22:36:30.702 UTC [38979] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:30.709 UTC [38979] LOG: invalid record length at
> 0/1693FF0: wanted 24, got 0
> 2021-01-06 22:36:30.709 UTC [38979] LOG: redo is not required
> 2021-01-06 22:36:30.748 UTC [38787] LOG: database system is ready to accept
> connections
> 2021-01-06 22:36:31.894 UTC [38787] LOG: server process (PID 39159) was
> terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:31.894 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:31.894 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:31.894 UTC [39158] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:31.894 UTC [39158] 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.
> 2021-01-06 22:36:31.894 UTC [39158] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:31.894 UTC [38986] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:31.894 UTC [38986] 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.
> 2021-01-06 22:36:31.894 UTC [38986] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:31.895 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:31.905 UTC [39161] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:30 UTC
> 2021-01-06 22:36:31.912 UTC [39161] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:31.919 UTC [39161] LOG: invalid record length at
> 0/1694080: wanted 24, got 0
> 2021-01-06 22:36:31.919 UTC [39161] LOG: redo is not required
> 2021-01-06 22:36:31.958 UTC [38787] LOG: database system is ready to accept
> connections
> 2021-01-06 22:36:32.561 UTC [38787] LOG: server process (PID 39253) was
> terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:32.561 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:32.561 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:32.562 UTC [39252] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:32.562 UTC [39252] 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.
> 2021-01-06 22:36:32.562 UTC [39252] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:32.562 UTC [39167] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:32.562 UTC [39167] 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.
> 2021-01-06 22:36:32.562 UTC [39167] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:32.562 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:32.569 UTC [39255] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:31 UTC
> 2021-01-06 22:36:32.576 UTC [39255] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:32.583 UTC [39255] LOG: invalid record length at
> 0/16940F8: wanted 24, got 0
> 2021-01-06 22:36:32.583 UTC [39255] LOG: redo is not required
> 2021-01-06 22:36:32.621 UTC [38787] LOG: database system is ready to accept
> connections
> s was running: do
> 976] 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.
> 2021-01-06 22:36:30.686 UTC [38976] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:30.688 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:30.695 UTC [38979] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:30 UTC
> 2021-01-06 22:36:30.702 UTC [38979] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:30.709 UTC [38979] LOG: invalid record length at
> 0/1693FF0: wanted 24, got 0
> 2021-01-06 22:36:30.709 UTC [38979] LOG: redo is not required
> 2021-01-06 22:36:30.748 UTC [38787] LOG: database system is ready to accept
> connections
> 2021-01-06 22:36:31.894 UTC [38787] LOG: server process (PID 39159) was
> terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:31.894 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:31.894 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:31.894 UTC [39158] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:31.894 UTC [39158] 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.
> 2021-01-06 22:36:31.894 UTC [39158] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:31.894 UTC [38986] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:31.894 UTC [38986] 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.
> 2021-01-06 22:36:31.894 UTC [38986] HINT: In a moment you should be able to
> reconnect to the database and repeat your command.
> 2021-01-06 22:36:31.895 UTC [38787] LOG: all server processes terminated;
> reinitializing
> 2021-01-06 22:36:31.905 UTC [39161] LOG: database system was interrupted;
> last known up at 2021-01-06 22:36:30 UTC
> 2021-01-06 22:36:31.912 UTC [39161] LOG: database system was not properly
> shut down; automatic recovery in progress
> 2021-01-06 22:36:31.919 UTC [39161] LOG: invalid record length at
> 0/1694080: wanted 24, got 0
> 2021-01-06 22:36:31.919 UTC [39161] LOG: redo is not required
> 2021-01-06 22:36:31.958 UTC [38787] LOG: database system is ready to accept
> connections
> 2021-01-06 22:36:32.561 UTC [38787] LOG: server process (PID 39253) was
> terminated by signal 11: Segmentation fault
> 2021-01-06 22:36:32.561 UTC [38787] DETAIL: Failed process was running:
> do
> $$
> begin
> rollback;
> end
> $$
>
> 2021-01-06 22:36:32.561 UTC [38787] LOG: terminating any other active
> server processes
> 2021-01-06 22:36:32.562 UTC [39252] WARNING: terminating connection because
> of crash of another server process
> 2021-01-06 22:36:32.562 UTC [39252] DETAIL: The postmaster has commanded
> this server process to roll back the current transaction and exit, because
> another server procs: command not found
>

Attachment Content-Type Size
core.zip application/zip 1.1 MB

In response to

Browse pgsql-bugs by date

  From Date Subject
Next Message Kämpf 2021-01-07 07:09:37 AW: BUG #16806: postgresql10 rpm is installed in the wrong directory
Previous Message PG Bug reporting form 2021-01-06 23:25:01 BUG #16811: Severe reproducible server backend crash