backend crash on DELETE, reproducible locally

Dear list members !

I am running this delete statement via psql

DELETE FROM ref.auto_hint WHERE title = 'Kontraindikation: ACE/Sartan <-> Schwangerschaft';

against a

name | server_version
setting | 11.0 (Debian 11.0-1)

postgres(at)hermes:~$ psql -d gnumed_v21
Ausgabeformat ist »wrapped«.
psql (11.0 (Debian 11.0-1))

on Debian

Distributor ID: Debian
Description: Debian GNU/Linux testing (buster)
Release: testing
Codename: buster

postgresql-11:
Installiert: 11.0-1
Installationskandidat: 11.0-1
Versionstabelle:
*** 11.0-1 990
990 http://httpredir.debian.org/debian buster/main i386 Packages
500 http://httpredir.debian.org/debian unstable/main i386 Packages

and it crashes the backend it is running on.

The DELETE is part of a lengthy database upgrade process. If
I comment out that statement the entire process runs find
start to end (there are - succeeding - SQL statements after
the failing DELETE).

The cluster in question

Ver Cluster Port Status Owner Data directory Log file
10 main 5433 down postgres /var/lib/postgresql/10/main /var/log/postgresql/postgresql-10-main.log
11 main 5432 online postgres /var/lib/postgresql/11/main /var/log/postgresql/postgresql-11-main.log

was upgraded from PG10 to PG11 without a hitch earlier today
using pg_upgrade through Debian's pg_upgradecluster
(dump/restore method).

The backend crash is reproducible each time I run the above
DELETE. If I bump log_min_messages to debug5 the following
ensues:

2018-11-01 13:09:55 GMT LOG: 00000: Datenbanksystem ist bereit, um Verbindungen anzunehmen
2018-11-01 13:09:55 GMT ORT: reaper, postmaster.c:2888
2018-11-01 13:19:03 GMT LOG: 00000: SIGHUP empfangen, Konfigurationsdateien werden neu geladen
2018-11-01 13:19:03 GMT ORT: SIGHUP_handler, postmaster.c:2529
2018-11-01 13:19:04 GMT LOG: 00000: Parameter »log_min_messages« auf »debug5« gesetzt
2018-11-01 13:19:04 GMT ORT: ProcessConfigFileInternal, guc-file.l:456
2018-11-01 13:19:04 GMT DEBUG: 00000: sending signal 1 to process 5703
2018-11-01 13:19:04 GMT ORT: SignalSomeChildren, postmaster.c:3920
2018-11-01 13:19:04 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:04 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:04 GMT DEBUG: 00000: checkpointer updated shared memory configuration values
2018-11-01 13:19:04 GMT ORT: UpdateSharedMemoryConfig, checkpointer.c:1362
2018-11-01 13:19:04 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:04 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:04 GMT DEBUG: 00000: received inquiry for database 0
2018-11-01 13:19:04 GMT ORT: pgstat_recv_inquiry, pgstat.c:5640
2018-11-01 13:19:04 GMT DEBUG: 00000: writing stats file "/run/postgresql/global.stat"
2018-11-01 13:19:04 GMT ORT: pgstat_write_statsfiles, pgstat.c:4684
2018-11-01 13:19:04 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:04 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:04 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT DEBUG: 00000: forked new backend, pid=6264 socket=13
2018-11-01 13:19:25 GMT ORT: BackendStartup, postmaster.c:4055
2018-11-01 13:19:25 GMT LOG: 00000: Verbindung empfangen: Host=[local]
2018-11-01 13:19:25 GMT ORT: BackendInitialize, postmaster.c:4209
2018-11-01 13:19:25 GMT DEBUG: 00000: postgres child[6264]: starting with (
2018-11-01 13:19:25 GMT ORT: BackendRun, postmaster.c:4348
2018-11-01 13:19:25 GMT DEBUG: 00000: postgres
2018-11-01 13:19:25 GMT ORT: BackendRun, postmaster.c:4351
2018-11-01 13:19:25 GMT DEBUG: 00000: )
2018-11-01 13:19:25 GMT ORT: BackendRun, postmaster.c:4353
2018-11-01 13:19:25 GMT DEBUG: 00000: InitPostgres
2018-11-01 13:19:25 GMT ORT: InitPostgres, postinit.c:573
2018-11-01 13:19:25 GMT DEBUG: 00000: my backend ID is 3
2018-11-01 13:19:25 GMT ORT: SharedInvalBackendInit, sinvaladt.c:324
2018-11-01 13:19:25 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:25 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT DEBUG: 00000: snapshot of 0+0 running transaction ids (lsn 0/46947AC4 oldest xid 128763 latest complete 128762 next xid 128763)
2018-11-01 13:19:25 GMT ORT: LogCurrentRunningXacts, standby.c:1000
2018-11-01 13:19:25 GMT DEBUG: 00000: rehashing catalog cache id 8 for pg_auth_members; 17 tups, 8 buckets
2018-11-01 13:19:25 GMT ORT: RehashCatCache, catcache.c:883
2018-11-01 13:19:25 GMT DEBUG: 00000: received password packet
2018-11-01 13:19:25 GMT ORT: recv_password_packet, auth.c:718
2018-11-01 13:19:25 GMT LOG: 00000: Verbindung autorisiert: Benutzer=gm-dbo Datenbank=gnumed_v21
2018-11-01 13:19:25 GMT ORT: PerformAuthentication, postinit.c:279
2018-11-01 13:19:25 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:25 GMT LOCATION: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:25 GMT LOCATION: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT LOG: 00000: statement: set default_transaction_read_only to off;
2018-11-01 13:19:25 GMT LOCATION: exec_simple_query, postgres.c:952
2018-11-01 13:19:25 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:25 GMT LOCATION: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:25 GMT LOCATION: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:25 GMT LOG: 00000: statement: DELETE FROM ref.auto_hint WHERE title = 'Kontraindikation: ACE/Sartan <-> Schwangerschaft';
2018-11-01 13:19:25 GMT LOCATION: exec_simple_query, postgres.c:952
2018-11-01 13:19:26 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:26 GMT ORT: reaper, postmaster.c:2781
2018-11-01 13:19:26 GMT DEBUG: 00000: Serverprozess (PID 6264) wurde von Signal 11 beendet: Segmentation fault
2018-11-01 13:19:26 GMT DETAIL: Der fehlgeschlagene Prozess führte aus: DELETE FROM ref.auto_hint WHERE title = 'Kontraindikation: ACE/Sartan <-> Schwangerschaft';
2018-11-01 13:19:26 GMT ORT: LogChildExit, postmaster.c:3579
2018-11-01 13:19:26 GMT LOG: 00000: Serverprozess (PID 6264) wurde von Signal 11 beendet: Segmentation fault
2018-11-01 13:19:26 GMT DETAIL: Der fehlgeschlagene Prozess führte aus: DELETE FROM ref.auto_hint WHERE title = 'Kontraindikation: ACE/Sartan <-> Schwangerschaft';
2018-11-01 13:19:26 GMT ORT: LogChildExit, postmaster.c:3579
2018-11-01 13:19:26 GMT LOG: 00000: aktive Serverprozesse werden abgebrochen
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3299
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5703
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3344
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5699
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3426
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5698
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3438
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5700
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3450
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5701
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3474
2018-11-01 13:19:26 GMT DEBUG: 00000: sending SIGQUIT to process 5702
2018-11-01 13:19:26 GMT ORT: HandleChildCrash, postmaster.c:3504
2018-11-01 13:19:26 GMT DEBUG: 00000: writing stats file "pg_stat/global.stat"
2018-11-01 13:19:26 GMT ORT: pgstat_write_statsfiles, pgstat.c:4684
2018-11-01 13:19:26 GMT DEBUG: 00000: writing stats file "pg_stat/db_139580.stat"
2018-11-01 13:19:26 GMT ORT: pgstat_write_db_statsfile, pgstat.c:4841
2018-11-01 13:19:26 GMT DEBUG: 00000: removing temporary stats file "/run/postgresql/db_139580.stat"
2018-11-01 13:19:26 GMT ORT: pgstat_write_db_statsfile, pgstat.c:4922
2018-11-01 13:19:26 GMT DEBUG: 00000: writing stats file "pg_stat/db_0.stat"
2018-11-01 13:19:26 GMT ORT: pgstat_write_db_statsfile, pgstat.c:4841
2018-11-01 13:19:26 GMT DEBUG: 00000: removing temporary stats file "/run/postgresql/db_0.stat"
2018-11-01 13:19:26 GMT ORT: pgstat_write_db_statsfile, pgstat.c:4922
2018-11-01 13:19:26 GMT DEBUG: 00000: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2018-11-01 13:19:26 GMT ORT: shmem_exit, ipc.c:237
2018-11-01 13:19:26 GMT DEBUG: 00000: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2018-11-01 13:19:26 GMT ORT: shmem_exit, ipc.c:270
2018-11-01 13:19:26 GMT DEBUG: 00000: proc_exit(-1): 0 callbacks to make
2018-11-01 13:19:26 GMT ORT: proc_exit_prepare, ipc.c:197
2018-11-01 13:19:26 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:26 GMT ORT: reaper, postmaster.c:2781
2018-11-01 13:19:26 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:26 GMT ORT: reaper, postmaster.c:2781
2018-11-01 13:19:26 GMT WARNUNG: 57P02: Verbindung wird abgebrochen wegen Absturz eines anderen Serverprozesses
2018-11-01 13:19:26 GMT DETAIL: Der Postmaster hat diesen Serverprozess angewiesen, die aktuelle Transaktion zurückzurollen und die Sitzung zu beenden, weil ein anderer Serverprozess abnormal beendet wurde und möglicherweise das Shared Memory verfälscht hat.
2018-11-01 13:19:26 GMT TIPP: In einem Moment sollten Sie wieder mit der Datenbank verbinden und Ihren Befehl wiederholen können.
2018-11-01 13:19:26 GMT ORT: quickdie, postgres.c:2640
2018-11-01 13:19:26 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:26 GMT ORT: reaper, postmaster.c:2781
2018-11-01 13:19:26 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:26 GMT ORT: reaper, postmaster.c:2781

And the backends restart automatically:

2018-11-01 13:19:26 GMT LOG: 00000: alle Serverprozesse beendet; initialisiere neu
2018-11-01 13:19:26 GMT ORT: PostmasterStateMachine, postmaster.c:3823
2018-11-01 13:19:26 GMT DEBUG: 00000: shmem_exit(1): 0 before_shmem_exit callbacks to make
2018-11-01 13:19:26 GMT ORT: shmem_exit, ipc.c:237
2018-11-01 13:19:26 GMT DEBUG: 00000: shmem_exit(1): 5 on_shmem_exit callbacks to make
2018-11-01 13:19:26 GMT ORT: shmem_exit, ipc.c:270
2018-11-01 13:19:26 GMT DEBUG: 00000: cleaning up dynamic shared memory control segment with ID 1958734660
2018-11-01 13:19:26 GMT ORT: dsm_postmaster_shutdown, dsm.c:377
2018-11-01 13:19:26 GMT DEBUG: 00000: invoking IpcMemoryCreate(size=33415168)
2018-11-01 13:19:26 GMT ORT: CreateSharedMemoryAndSemaphores, ipci.c:164
2018-11-01 13:19:26 GMT DEBUG: 00000: mmap(33554432) with MAP_HUGETLB failed, huge pages disabled: Nicht genügend Hauptspeicher verfügbar
2018-11-01 13:19:26 GMT ORT: CreateAnonymousSegment, pg_shmem.c:485
2018-11-01 13:19:26 GMT DEBUG: 00000: SlruScanDirectory invoking callback on pg_notify/0000
2018-11-01 13:19:26 GMT ORT: SlruScanDirectory, slru.c:1398
2018-11-01 13:19:26 GMT DEBUG: 00000: entferne Datei »pg_notify/0000«
2018-11-01 13:19:26 GMT ORT: SlruInternalDeleteSegment, slru.c:1253
2018-11-01 13:19:26 GMT DEBUG: 00000: dynamic shared memory system will support 158 segments
2018-11-01 13:19:26 GMT ORT: dsm_postmaster_startup, dsm.c:170
2018-11-01 13:19:26 GMT DEBUG: 00000: created dynamic shared memory control segment 156941574 (2540 bytes)
2018-11-01 13:19:26 GMT ORT: dsm_postmaster_startup, dsm.c:195
2018-11-01 13:19:26 GMT LOG: 00000: Datenbanksystem wurde unterbrochen; letzte bekannte Aktion am 2018-11-01 13:09:54 GMT
2018-11-01 13:19:26 GMT ORT: StartupXLOG, xlog.c:6388
2018-11-01 13:19:40 GMT DEBUG: 00000: Checkpoint-Eintrag ist bei 0/46946098
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6646
2018-11-01 13:19:40 GMT DEBUG: 00000: redo record is at 0/46946098; shutdown true
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6724
2018-11-01 13:19:40 GMT DEBUG: 00000: next transaction ID: 0:128763; next OID: 147771
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6728
2018-11-01 13:19:40 GMT DEBUG: 00000: next MultiXactId: 1; next MultiXactOffset: 0
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6731
2018-11-01 13:19:40 GMT DEBUG: 00000: oldest unfrozen transaction ID: 561, in database 1
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6734
2018-11-01 13:19:40 GMT DEBUG: 00000: oldest MultiXactId: 1, in database 1
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6737
2018-11-01 13:19:40 GMT DEBUG: 00000: commit timestamp Xid oldest/newest: 15720/128762
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6741
2018-11-01 13:19:40 GMT DEBUG: 00000: Grenze für Transaktionsnummernüberlauf ist 2147484208, begrenzt durch Datenbank mit OID 1
2018-11-01 13:19:40 GMT ORT: SetTransactionIdLimit, varsup.c:368
2018-11-01 13:19:40 GMT DEBUG: 00000: Grenze für MultiXactId-Überlauf ist 2147483648, begrenzt durch Datenbank mit OID 1
2018-11-01 13:19:40 GMT ORT: SetMultiXactIdLimit, multixact.c:2269
2018-11-01 13:19:40 GMT DEBUG: 00000: starting up replication slots
2018-11-01 13:19:40 GMT ORT: StartupReplicationSlots, slot.c:1110
2018-11-01 13:19:40 GMT DEBUG: 00000: starting up replication origin progress state
2018-11-01 13:19:40 GMT ORT: StartupReplicationOrigin, origin.c:699
2018-11-01 13:19:40 GMT LOG: 00000: Datenbanksystem wurde nicht richtig heruntergefahren; automatische Wiederherstellung läuft
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:6879
2018-11-01 13:19:40 GMT DEBUG: 00000: resetting unlogged relations: cleanup 1 init 0
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelations, reinit.c:57
2018-11-01 13:19:40 GMT DEBUG: 00000: unlinked file "base/33083/34131"
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:258
2018-11-01 13:19:40 GMT DEBUG: 00000: unlinked file "base/33083/35593"
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:258
2018-11-01 13:19:40 GMT DEBUG: 00000: unlinked file "base/33083/35594"
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:258
2018-11-01 13:19:40 GMT LOG: 00000: Redo beginnt bei 0/46946100
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:7150
2018-11-01 13:19:40 GMT LOG: 00000: Redo fertig bei 0/4699B5A0
2018-11-01 13:19:40 GMT ORT: StartupXLOG, xlog.c:7422
2018-11-01 13:19:40 GMT DEBUG: 00000: resetting unlogged relations: cleanup 0 init 1
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelations, reinit.c:57
2018-11-01 13:19:40 GMT DEBUG: 00000: copying base/33083/34131_init to base/33083/34131
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:307
2018-11-01 13:19:40 GMT DEBUG: 00000: copying base/33083/35594_init to base/33083/35594
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:307
2018-11-01 13:19:40 GMT DEBUG: 00000: copying base/33083/35593_init to base/33083/35593
2018-11-01 13:19:40 GMT ORT: ResetUnloggedRelationsInDbspaceDir, reinit.c:307
2018-11-01 13:19:40 GMT DEBUG: 00000: performing replication slot checkpoint
2018-11-01 13:19:40 GMT ORT: CheckPointReplicationSlots, slot.c:1074
2018-11-01 13:19:41 GMT DEBUG: 00000: attempting to remove WAL segments older than log file 000000000000000000000045
2018-11-01 13:19:41 GMT ORT: RemoveOldXlogFiles, xlog.c:3909
2018-11-01 13:19:41 GMT DEBUG: 00000: Grenze für MultiXactId-Überlauf ist 2147483648, begrenzt durch Datenbank mit OID 1
2018-11-01 13:19:41 GMT ORT: SetMultiXactIdLimit, multixact.c:2269
2018-11-01 13:19:41 GMT DEBUG: 00000: MultiXact-Member-Stopp-Limit ist jetzt 4294914944, basierend auf MultiXact 1
2018-11-01 13:19:41 GMT ORT: SetOffsetVacuumLimit, multixact.c:2632
2018-11-01 13:19:41 GMT DEBUG: 00000: shmem_exit(0): 1 before_shmem_exit callbacks to make
2018-11-01 13:19:41 GMT ORT: shmem_exit, ipc.c:237
2018-11-01 13:19:41 GMT DEBUG: 00000: shmem_exit(0): 4 on_shmem_exit callbacks to make
2018-11-01 13:19:41 GMT ORT: shmem_exit, ipc.c:270
2018-11-01 13:19:41 GMT DEBUG: 00000: proc_exit(0): 2 callbacks to make
2018-11-01 13:19:41 GMT ORT: proc_exit_prepare, ipc.c:197
2018-11-01 13:19:41 GMT DEBUG: 00000: exit(0)
2018-11-01 13:19:41 GMT ORT: proc_exit, ipc.c:150
2018-11-01 13:19:41 GMT DEBUG: 00000: shmem_exit(-1): 0 before_shmem_exit callbacks to make
2018-11-01 13:19:41 GMT ORT: shmem_exit, ipc.c:237
2018-11-01 13:19:41 GMT DEBUG: 00000: shmem_exit(-1): 0 on_shmem_exit callbacks to make
2018-11-01 13:19:41 GMT ORT: shmem_exit, ipc.c:270
2018-11-01 13:19:41 GMT DEBUG: 00000: proc_exit(-1): 0 callbacks to make
2018-11-01 13:19:41 GMT ORT: proc_exit_prepare, ipc.c:197
2018-11-01 13:19:41 GMT DEBUG: 00000: reaping dead processes
2018-11-01 13:19:41 GMT ORT: reaper, postmaster.c:2781
2018-11-01 13:19:41 GMT DEBUG: 00000: Autovacuum-Launcher startet
2018-11-01 13:19:41 GMT ORT: AutoVacLauncherMain, autovacuum.c:442
2018-11-01 13:19:41 GMT DEBUG: 00000: starte Background-Worker-Prozess »logical replication launcher«
2018-11-01 13:19:41 GMT ORT: do_start_bgworker, postmaster.c:5656
2018-11-01 13:19:41 GMT DEBUG: 00000: InitPostgres
2018-11-01 13:19:41 GMT ORT: InitPostgres, postinit.c:573
2018-11-01 13:19:41 GMT DEBUG: 00000: my backend ID is 1
2018-11-01 13:19:41 GMT ORT: SharedInvalBackendInit, sinvaladt.c:324
2018-11-01 13:19:41 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT LOG: 00000: Datenbanksystem ist bereit, um Verbindungen anzunehmen
2018-11-01 13:19:41 GMT ORT: reaper, postmaster.c:2888
2018-11-01 13:19:41 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: Logical-Replication-Launcher startet
2018-11-01 13:19:41 GMT ORT: ApplyLauncherMain, launcher.c:988
2018-11-01 13:19:41 GMT DEBUG: 00000: InitPostgres
2018-11-01 13:19:41 GMT ORT: InitPostgres, postinit.c:573
2018-11-01 13:19:41 GMT DEBUG: 00000: my backend ID is 2
2018-11-01 13:19:41 GMT ORT: SharedInvalBackendInit, sinvaladt.c:324
2018-11-01 13:19:41 GMT DEBUG: 00000: received inquiry for database 0
2018-11-01 13:19:41 GMT ORT: pgstat_recv_inquiry, pgstat.c:5640
2018-11-01 13:19:41 GMT DEBUG: 00000: writing stats file "/run/postgresql/global.stat"
2018-11-01 13:19:41 GMT ORT: pgstat_write_statsfiles, pgstat.c:4684
2018-11-01 13:19:41 GMT DEBUG: 00000: checkpointer updated shared memory configuration values
2018-11-01 13:19:41 GMT ORT: UpdateSharedMemoryConfig, checkpointer.c:1362
2018-11-01 13:19:41 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: StartTransaction(1) name: unnamed; blockState: DEFAULT; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:41 GMT DEBUG: 00000: CommitTransaction(1) name: unnamed; blockState: STARTED; state: INPROGRESS, xid/subid/cid: 0/1/0
2018-11-01 13:19:41 GMT ORT: ShowTransactionStateRec, xact.c:5151
2018-11-01 13:19:56 GMT DEBUG: 00000: snapshot of 0+0 running transaction ids (lsn 0/4699D564 oldest xid 128764 latest complete 128763 next xid 128764)
2018-11-01 13:19:56 GMT ORT: LogCurrentRunningXacts, standby.c:1000
2018-11-01 13:20:19 GMT LOG: 00000: SIGHUP empfangen, Konfigurationsdateien werden neu geladen
2018-11-01 13:20:19 GMT ORT: SIGHUP_handler, postmaster.c:2529
2018-11-01 13:20:19 GMT LOG: 00000: Parameter »log_min_messages« auf »notice« gesetzt
2018-11-01 13:20:19 GMT ORT: ProcessConfigFileInternal, guc-file.l:456

What else can I provide/test/look into ?

(In case anyone remembers: GNUmed uses psycopg2 for upgrades
and its databases default to default_transaction_read_only=true
but I have taken both aspects out of the loop manually for
the above test.)

Thanks for any hints,
Karsten
--
GPG 40BE 5B0E C98E 1713 AFA6 5BC0 3BEA AC80 7D4F C89B