Re: [Proposal] Fully WAL logged CREATE DATABASE - No Checkpoints - Mailing list pgsql-hackers

From Justin Pryzby
Subject Re: [Proposal] Fully WAL logged CREATE DATABASE - No Checkpoints
Date
Msg-id 20220803170118.GG19644@telsasoft.com
Whole thread Raw
In response to Re: [Proposal] Fully WAL logged CREATE DATABASE - No Checkpoints  (Justin Pryzby <pryzby@telsasoft.com>)
Responses Re: [Proposal] Fully WAL logged CREATE DATABASE - No Checkpoints
List pgsql-hackers
On Wed, Aug 03, 2022 at 11:02:00AM -0500, Justin Pryzby wrote:
> But I reproduced the first problem with a handful of tries interrupting the
> while loop:
> 
> 2022-08-03 10:39:50.129 CDT client backend[5530] [unknown] PANIC:  could not open critical system index 2662
...
> So far, I haven't succeeded in eliciting anything useful from valgrind.

Now, I've reproduced the problem under valgrind, but it doesn't show anything
useful:

pryzbyj@pryzbyj:~$ while :; do psql -h /tmp template1 -c "DROP DATABASE a" -c "CREATE DATABASE a TEMPLATE postgres
STRATEGYwal_log"; done
 
ERROR:  database "a" does not exist
CREATE DATABASE
^CCancel request sent
ERROR:  canceling statement due to user request
ERROR:  database "a" already exists
^C
pryzbyj@pryzbyj:~$ ^C
pryzbyj@pryzbyj:~$ ^C
pryzbyj@pryzbyj:~$ ^C
pryzbyj@pryzbyj:~$ psql -h /tmp a -c ''
2022-08-03 11:57:39.178 CDT client backend[31321] [unknown] PANIC:  could not open critical system index 2662
psql: error: falló la conexión al servidor en el socket «/tmp/.s.PGSQL.5432»: PANIC:  could not open critical system
index2662
 


On the server process, nothing interesting but the backtrace (the error was
before this, while writing the relation file, but there's nothing suspicious).

2022-08-03 11:08:06.628 CDT client backend[2841] [unknown] PANIC:  could not open critical system index 2662
==2841==
==2841== Process terminating with default action of signal 6 (SIGABRT)
==2841==    at 0x5FBBE97: raise (raise.c:51)
==2841==    by 0x5FBD800: abort (abort.c:79)
==2841==    by 0x2118DEF: errfinish (elog.c:675)
==2841==    by 0x20F6002: load_critical_index (relcache.c:4328)
==2841==    by 0x20F727A: RelationCacheInitializePhase3 (relcache.c:4103)
==2841==    by 0x213DFA5: InitPostgres (postinit.c:1087)
==2841==    by 0x1D20D72: PostgresMain (postgres.c:4081)
==2841==    by 0x1B15CFD: BackendRun (postmaster.c:4490)
==2841==    by 0x1B1D6E1: BackendStartup (postmaster.c:4218)
==2841==    by 0x1B1DD59: ServerLoop (postmaster.c:1808)
==2841==    by 0x1B1F86D: PostmasterMain (postmaster.c:1480)
==2841==    by 0x17B7150: main (main.c:197)

Below, I reproduced it without valgrind (and without LANG):

pryzbyj@pryzbyj:~/src/postgres$ while :; do psql -qh /tmp template1 -c "DROP DATABASE a" -c "CREATE DATABASE a TEMPLATE
postgresSTRATEGY wal_log"; done
 
2022-08-03 11:59:52.675 CDT checkpointer[1881] LOG:  checkpoint starting: immediate force wait
2022-08-03 11:59:52.862 CDT checkpointer[1881] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added,
0removed, 0 recycled; write=0.045 s, sync=0.038 s, total=0.188 s; sync files=3, longest=0.019 s, average=0.013 s;
distance=3kB, estimate=3 kB; lsn=0/24862508, redo lsn=0/248624D0
 
2022-08-03 11:59:53.213 CDT checkpointer[1881] LOG:  checkpoint starting: immediate force wait
2022-08-03 11:59:53.409 CDT checkpointer[1881] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added,
0removed, 0 recycled; write=0.030 s, sync=0.054 s, total=0.196 s; sync files=4, longest=0.029 s, average=0.014 s;
distance=4042kB, estimate=4042 kB; lsn=0/24C54D88, redo lsn=0/24C54D50
 
^CCancel request sent
2022-08-03 11:59:53.750 CDT checkpointer[1881] LOG:  checkpoint starting: immediate force wait
2022-08-03 11:59:53.930 CDT checkpointer[1881] LOG:  checkpoint complete: wrote 4 buffers (0.0%); 0 WAL file(s) added,
0removed, 1 recycled; write=0.029 s, sync=0.027 s, total=0.181 s; sync files=4, longest=0.022 s, average=0.007 s;
distance=4042kB, estimate=4042 kB; lsn=0/250476D0, redo lsn=0/25047698
 
2022-08-03 11:59:54.270 CDT checkpointer[1881] LOG:  checkpoint starting: immediate force wait
^C2022-08-03 11:59:54.294 CDT client backend[1903] psql ERROR:  canceling statement due to user request
2022-08-03 11:59:54.294 CDT client backend[1903] psql STATEMENT:  DROP DATABASE a
Cancel request sent
ERROR:  canceling statement due to user request
2022-08-03 11:59:54.296 CDT client backend[1903] psql ERROR:  database "a" already exists
2022-08-03 11:59:54.296 CDT client backend[1903] psql STATEMENT:  CREATE DATABASE a TEMPLATE postgres STRATEGY wal_log
ERROR:  database "a" already exists
^C
pryzbyj@pryzbyj:~/src/postgres$ ^C
pryzbyj@pryzbyj:~/src/postgres$ ^C
pryzbyj@pryzbyj:~/src/postgres$ 2022-08-03 11:59:54.427 CDT checkpointer[1881] LOG:  checkpoint complete: wrote 4
buffers(0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.024 s, sync=0.036 s, total=0.158 s; sync files=4,
longest=0.027s, average=0.009 s; distance=4042 kB, estimate=4042 kB; lsn=0/2543A108, redo lsn=0/2543A0A8
 
^C
pryzbyj@pryzbyj:~/src/postgres$ ^C
pryzbyj@pryzbyj:~/src/postgres$ ^C
pryzbyj@pryzbyj:~/src/postgres$ psql -h /tmp a -c ''
                                                                                          2022-08-03 11:59:56.617 CDT
clientbackend[1914] [unknown] PANIC:  could not open critical system index 2662
 



pgsql-hackers by date:

Previous
From: Robert Treat
Date:
Subject: Re: [doc] fix a potential grammer mistake
Next
From: Julien Rouhaud
Date:
Subject: Re: [PATCH] CF app: add "Returned: Needs more interest"