Thread: server process exited with code 1

On Fri, Apr 23, 2021 at 03:58:32PM +0000, Eric Hill wrote:
> Hey,
> 
> We are experiencing a periodic PostgreSQL crash. It happens overnight when automated processes are updating content
onour website.  My PostgreSQL version information is:
 
> 
> PostgreSQL 11.10, compiled by Visual C++ build 1914, 64-bit
> 
> It is running on Windows Server 2019 Standard.  We were having this same crash on PostgreSQL 9.6, also running on
WindowsServer, I believe 2012, before a recent upgrade.  Here is the relevant part of the log:
 
> 
> 2021-04-23 03:20:57 EDT [5324]: LOG:  connection received: host=10.120.80.162 port=54017
> 2021-04-23 03:20:57 EDT [5324]: LOG:  connection authorized: user=dba_webjmp database=webjmp
> 2021-04-23 03:21:00 EDT [15776]: LOG:  server process (PID 14820) exited with exit code 1
> 2021-04-23 03:21:00 EDT [15776]: DETAIL:  Failed process was running: SET client_min_messages TO warning;SET TIME
ZONEINTERVAL '+00:00' HOUR TO MINUTE;
 
> 2021-04-23 03:21:00 EDT [15776]: LOG:  terminating any other active server processes
> 2021-04-23 03:21:00 EDT [5324]: WARNING:  terminating connection because of crash of another server process
> 2021-04-23 03:21:00 EDT [5324]: DETAIL:  The postmaster has commanded this server process to roll back the current
transactionand exit, because another server process exited abnormally and possibly corrupted shared memory.
 
> 2021-04-23 03:21:00 EDT [5324]: HINT:  In a moment you should be able to reconnect to the database and repeat your
command.
> 
> I would really like for PostgreSQL to produce a crashdump of this crash but one is not produced.  I made a crashdumps
folderin the data directory and gave it every permission I could think of, but no joy there.
 

The mentioned query works just fine for me, so I doubt we could help without a
core dump.  Did you check the instructions at

https://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQL_backend_on_Windows#Using_crash_dumps_to_debug_random_and_unpredictable_backend_crashes?

Eric Hill <Eric.Hill@jmp.com> writes:
> 2021-04-23 03:20:57 EDT [5324]: LOG:  connection received: host=10.120.80.162 port=54017
> 2021-04-23 03:20:57 EDT [5324]: LOG:  connection authorized: user=dba_webjmp database=webjmp
> 2021-04-23 03:21:00 EDT [15776]: LOG:  server process (PID 14820) exited with exit code 1
> 2021-04-23 03:21:00 EDT [15776]: DETAIL:  Failed process was running: SET client_min_messages TO warning;SET TIME
ZONEINTERVAL '+00:00' HOUR TO MINUTE; 
> 2021-04-23 03:21:00 EDT [15776]: LOG:  terminating any other active server processes

Hm.  That's fairly odd.  Exit code 1 ordinarily means that the backend
hit a "FATAL" error, which is one that causes process termination but
*not* a database-wide restart.  The fact that the postmaster is treating
it that way anyway implies that the backend failed to disarm the "dead
man switch" mechanism that exists to check that backends cleaned up
their shared-memory state before exiting.  Another thing that doesn't
square with this being an ordinary FATAL exit is that there's no message
visible in the log.

(I wonder what this looks like from the client's end --- is it getting
any sort of termination message, or just a lost network connection?)

The implication is that something in the backend did _exit(1) to force
process termination without any of the normal atexit cleanup.  There
is not, or at least isn't supposed to be, anything in Postgres proper
that does that.  So I'm wondering if you have any nonstandard code
in there, such as unusual extensions.  A badly-written event trigger
could perhaps do it too.

This being Windows, a certain amount of suspicion has to be directed
towards bogus antivirus code, too.

            regards, tom lane

Eric Hill <Eric.Hill@jmp.com> writes:
> I don’t believe we have any unusual extensions.  We do have triggers, and the VM does have antivirus protection.
I’llwork on exclusions for the AV, and we’ll look into our triggers a bit. 

BTW, I happened to check in our commit log to see when we installed the
dead man switch I referred to, and the commit message is quite
interesting:

Author: Tom Lane <tgl@sss.pgh.pa.us>
Branch: master Release: REL8_4_BR [969d7cd43] 2009-05-05 19:59:00 +0000

    Install a "dead man switch" to allow the postmaster to detect cases where
    a backend has done exit(0) or exit(1) without having disengaged itself
    from shared memory.  We are at risk for this whenever third-party code is
    loaded into a backend, since such code might not know it's supposed to go
    through proc_exit() instead.  Also, it is reported that under Windows
    there are ways to externally kill a process that cause the status code
    returned to the postmaster to be indistinguishable from a voluntary exit
    (thank you, Microsoft).  If this does happen then the system is probably
    hosed --- for instance, the dead session might still be holding locks.
    So the best recovery method is to treat this like a backend crash.

    The dead man switch is armed for a particular child process when it
    acquires a regular PGPROC, and disarmed when the PGPROC is released;
    these should be the first and last touches of shared memory resources
    in a backend, or close enough anyway.  This choice means there is no
    coverage for auxiliary processes, but I doubt we need that, since they
    shouldn't be executing any user-provided code anyway.


So it seems like you'd better be looking into the possibility that
something entirely external to Postgres is causing that backend process
to quit with what looks like _exit(1).  Unfortunately, this commit is
from before we had a habit of including links to mailing list
discussions in commit messages; but if you dig around in the pghackers
archives near that date you can probably find the thread, and maybe
there will be more info about the Windows aspect.  (I'm not a Windows
guy, so this was purely hearsay on my part.)

            regards, tom lane