Re: 13.4 on RDS, SSL SYSCALL EOF on restore

Dug out some more logging:

2021-10-08 20:18:46 UTC::@:[27842]:LOG: checkpoint complete: wrote 43719
buffers (8.3%); 0 WAL file(s) added, 0 removed, 842 recycled;
write=3239.859 s, sync=0.560 s, total=3242.821 s; sync files=67,
longest=0.050 s, average=0.008 s; distance=55175592 kB, estimate=55185037 kB
2021-10-08 20:24:44 UTC::@:[27842]:LOG: checkpoint starting: time
2021-10-08 20:35:08 UTC::@:[12682]:LOG: server process (PID 3970) was
terminated by signal 9: Killed
2021-10-08 20:35:08 UTC::@:[12682]:DETAIL: Failed process was running:
CREATE INDEX ...

2021-10-08 20:35:08 UTC::@:[12682]:LOG: terminating any other active
server processes
2021-10-08 20:35:08 UTC::@:[12682]:LOG: archiver process (PID 27845)
exited with exit code 2

2021-10-08 20:35:08 UTC:172.31.3.72(46884):postgres(at)dbname:[3969]:WARNING:
terminating connection because of crash of another server process
2021-10-08 20:35:08 UTC:172.31.3.72(46884):postgres(at)dbname:[3969]: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-10-08 20:35:08 UTC:172.31.3.72(46884):postgres(at)dbname:[3969]:HINT: In
a moment you should be able to reconnect to the database and repeat your
command.

That block of 3 lines i repeated several times, and then:

2021-10-08 20:35:08 UTC:172.31.3.72(46978):[unknown](at)[unknown]:[22197]:LOG:
PID 3970 in cancel request did not match any process
2021-10-08 20:35:09 UTC:172.31.3.72(46984):postgres(at)dbname:[22202]:FATAL:
the database system is in recovery mode
2021-10-08 20:35:09 UTC:172.31.3.72(46986):postgres(at)dbname:[22203]:FATAL:
the database system is in recovery mode
2021-10-08 20:35:09 UTC:172.31.3.72(46988):postgres(at)dbname:[22207]:FATAL:
the database system is in recovery mode
2021-10-08 20:35:09 UTC:172.31.3.72(46990):postgres(at)dbname:[22208]:FATAL:
the database system is in recovery mode
2021-10-08 20:35:09 UTC::@:[12682]:LOG: all server processes terminated;
reinitializing
2021-10-08 20:35:09 UTC::@:[22209]:LOG: database system was interrupted;
last known up at 2021-10-08 20:18:43 UTC
2021-10-08 20:35:09 UTC::@:[22209]:LOG: database system was not properly
shut down; automatic recovery in progress
2021-10-08 20:35:09 UTC::@:[22209]:LOG: redo starts at 144/14652BF0
2021-10-08 20:35:20 UTC:127.0.0.1(27834):rdsadmin(at)rdsadmin:[22478]:FATAL:
the database system is in recovery mode

Repeat that last line _several_ times and then:

2021-10-08 20:37:48 UTC::@:[22209]:LOG: redo done at 14B/5D9DF848
2021-10-08 20:37:48 UTC::@:[22209]:LOG: checkpoint starting:
end-of-recovery immediate
2021-10-08 20:37:51 UTC:127.0.0.1(28136):rdsadmin(at)rdsadmin:[25911]:FATAL:
the database system is in recovery mode
2021-10-08 20:37:53 UTC:127.0.0.1(28138):rdsadmin(at)rdsadmin:[26058]:FATAL:
the database system is in recovery mode
2021-10-08 20:37:53 UTC:127.0.0.1(28140):rdsadmin(at)rdsadmin:[26059]:FATAL:
the database system is in recovery mode
2021-10-08 20:38:00 UTC::@:[22209]:LOG: checkpoint complete: wrote 524188
buffers (100.0%); 0 WAL file(s) added, 434 removed, 0 recycled;
write=10.006 s, sync=0.007 s, total=11.772 s; sync files=77, longest=0.007
s, average=0.001 s; distance=30559795 kB, estimate=30559795 kB
2021-10-08 20:38:00 UTC::@:[12682]:LOG: database system is ready to accept
connections

On Fri, Oct 8, 2021 at 3:16 PM Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote:

> Wells Oliver <wells(dot)oliver(at)gmail(dot)com> writes:
> > The only thing I see in the RDS log are:
>
> > 2021-10-06 16:36:05 UTC::@:[5035]:LOG: redirecting log output to
> logging
> > collector process
> > 2021-10-06 16:36:05 UTC::@:[5035]:HINT: Future log output will appear
> in
> > directory "/rdsdbdata/log/error".
>
> So what's in /rdsdbdata/log/error ?
>
> regards, tom lane
>

--
Wells Oliver
wells(dot)oliver(at)gmail(dot)com <wellsoliver(at)gmail(dot)com>