0

I'm using Azure PostgreSQL server to store data in my application hosted on Azure App Service.

Yesterday, at some point application started to throw exceptions with connection closed and broken pipes.

At first glance it looked like a problem with wait_time property of datasource that was longer then the Database.

However when I looked in database and went through logs, I've found the following logs. I'm mostly interested to the cause of this issue with archiver and could it be related that my connections were "dropped" so app stopped working?

2020-07-11 22:43:42 UTC-5f0866f0.f0-LOG:  checkpoint complete (240): wrote 16 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=2.046 s, sync=0.031 s, total=2.390 s; sync files=13, longest=0.005 s, average=0.001 s; distance=77 kB, estimate=14627 kB
2020-07-11 22:47:06 UTC-5f0a416a.891c-LOG:  connection received: host=127.0.0.1 port=49431 pid=35100
2020-07-11 22:47:06 UTC-5f0a416a.891c-LOG:  connection authorized: user=azure_superuserdatabase=azure_sys SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, compression=off)
2020-07-11 22:48:07 UTC-5f0a41a7.8924-LOG:  connection received: host=127.0.0.1 port=49689 pid=35108
2020-07-11 22:48:07 UTC-5f0a41a7.8924-LOG:  connection authorized: user=azure_superuserdatabase=postgres SSL enabled (protocol=TLSv1.2, cipher=ECDHE-RSA-AES256-GCM-SHA384, compression=off)
2020-07-11 22:48:09 UTC-5f0866f0.f0-LOG:  checkpoint starting: immediate force wait
2020-07-11 22:48:10 UTC-5f0866f0.f0-LOG:  checkpoint complete (240): wrote 30 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.046 s, sync=0.046 s, total=0.437 s; sync files=13, longest=0.009 s, average=0.003 s; distance=163 kB, estimate=13180 kB
2020-07-11 22:48:10 UTC-5f0866ee.68-LOG:  received immediate shutdown request
2020-07-11 22:48:10 UTC-5f0a3f41.8914-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3f41.8914-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.
2020-07-11 22:48:10 UTC-5f0a3f41.8914-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3f35.8918-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3f35.8918-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.
2020-07-11 22:48:10 UTC-5f0a3f35.8918-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3f2b.8784-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3f2b.8784-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.
2020-07-11 22:48:10 UTC-5f0a3f2b.8784-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3f0d.8780-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3f0d.8780-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.
2020-07-11 22:48:10 UTC-5f0a3f0d.8780-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3ef1.8778-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3ef1.8778-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.
2020-07-11 22:48:10 UTC-5f0a3ef1.8778-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3ee7.8770-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3ee7.8770-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.
2020-07-11 22:48:10 UTC-5f0a3ee7.8770-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3eda.8774-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3eda.8774-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.
2020-07-11 22:48:10 UTC-5f0a3eda.8774-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3ece.8730-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3ece.8730-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.
2020-07-11 22:48:10 UTC-5f0a3ece.8730-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3ec6.872c-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3ec6.872c-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.
2020-07-11 22:48:10 UTC-5f0a3ec6.872c-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a3ea9.8728-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a3ea9.8728-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.
2020-07-11 22:48:10 UTC-5f0a3ea9.8728-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0a1412.7acc-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0a1412.7acc-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.
2020-07-11 22:48:10 UTC-5f0a1412.7acc-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f09f8a7.72a8-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f09f8a7.72a8-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.
2020-07-11 22:48:10 UTC-5f09f8a7.72a8-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0866f2.7c-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0866f2.7c-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.
2020-07-11 22:48:10 UTC-5f0866f2.7c-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0866ee.68-LOG:  src/port/kill.c(84): Process (272) exited OOB of pgkill.
2020-07-11 22:48:10 UTC-5f0866f1.fc-WARNING:  terminating connection because of crash of another server process
2020-07-11 22:48:10 UTC-5f0866f1.fc-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.
2020-07-11 22:48:10 UTC-5f0866f1.fc-HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2020-07-11 22:48:10 UTC-5f0866ee.68-LOG:  archiver process (PID 256) exited with exit code 1
2020-07-11 22:48:11 UTC-5f0866ee.68-LOG:  database system is shut down
ashur
  • 103
  • 2

1 Answers1

1

Th answer is right at the beginning:

2020-07-11 22:48:10 UTC-5f0866ee.68-LOG:  received immediate shutdown request

An immediate shutdown effectively crashes the server, killing all processes as fast as possible and leaving the database cluster in an unclean state. Such a cluster will require crash recovery upon restart.

If you want a shutdown that does not terminate client connections, use the “smart” shutdown mode: that will wait until the last client connection has terminated before shutting down the server.

If it wasn't you that crashed the server, you'll have to investigate who or what did. It may have been a high-availability software gone berserk.

Laurenz Albe
  • 61,070
  • 4
  • 55
  • 90