BUG #16811: Severe reproducible server backend crash

Поиск
Список
Период
Сортировка
От PG Bug reporting form
Тема BUG #16811: Severe reproducible server backend crash
Дата
Msg-id 16811-c1b599b2c6c2d622@postgresql.org
обсуждение исходный текст
Ответы Re: BUG #16811: Severe reproducible server backend crash  (James Inform <james.inform@pharmapp.de>)
Re: BUG #16811: Severe reproducible server backend crash  (Thomas Munro <thomas.munro@gmail.com>)
Список pgsql-bugs
The following bug has been logged on the website:

Bug reference:      16811
Logged by:          James Inform
Email address:      james.inform@pharmapp.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@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@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


В списке pgsql-bugs по дате отправления:

Предыдущее
От: Devrim Gündüz
Дата:
Сообщение: Re: BUG #16806: postgresql10 rpm is installed in the wrong directory
Следующее
От: James Inform
Дата:
Сообщение: Re: BUG #16811: Severe reproducible server backend crash