Re: Postgres service stops when I kill client backend on Windows - Mailing list pgsql-hackers
| From | Dmitry Vasilyev |
|---|---|
| Subject | Re: Postgres service stops when I kill client backend on Windows |
| Date | |
| Msg-id | 1444493043.9569.16.camel@postgrespro.ru Whole thread Raw |
| In response to | Re: Postgres service stops when I kill client backend on Windows (Tom Lane <tgl@sss.pgh.pa.us>) |
| Responses |
Re: Postgres service stops when I kill client backend on Windows
(Pavel Stehule <pavel.stehule@gmail.com>)
Re: Postgres service stops when I kill client backend on Windows (Tom Lane <tgl@sss.pgh.pa.us>) |
| List | pgsql-hackers |
Hello Tom! On Сб, 2015-10-10 at 10:55 -0500, Tom Lane wrote: > Dmitry Vasilyev <d.vasilyev@postgrespro.ru> writes: > > I have written, what service stopped. This action is repeatable. > > You can run command 'psql -c "do $$ unpack p,1x8 $$ language > > plperlu;"' > > and after this windows service will stop. > > Well, (a) that probably means that your plperl installation is > broken, > and (b) you still haven't convinced me that you had an actual service > stop, and not just that the recovery time was longer than psql would > wait before retrying the connection. Can you start a fresh psql > session after waiting a few seconds? > > regards, tom lane This is knowned bug of perl: perl -e ' unpack p,1x8' Segmentation fault (core dumped) backend of postgres is crashed, and windows service is stopped: C:\Users\vadv>sc query postgresql-X64-9.4 | findstr /i "STATE" S TATE : 1 STOPPED The log you can see bellow: 2015-10-10 19:00:13 AST LOG: database system was interrupted; last known up at 2015-10-10 18:54:47 AST 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: checkpoint record is at 0/16A01C8 2015-10-10 19:00:13 AST DEBUG: redo record is at 0/16A01C8; shutdown TRUE 2015-10-10 19:00:13 AST DEBUG: next transaction ID: 0/678; next OID: 16393 2015-10-10 19:00:13 AST DEBUG: next MultiXactId: 1; next MultiXactOffset: 0 2015-10-10 19:00:13 AST DEBUG: oldest unfrozen transaction ID: 667, in database 1 2015-10-10 19:00:13 AST DEBUG: oldest MultiXactId: 1, in database 1 2015-10-10 19:00:13 AST DEBUG: transaction ID wrap limit is 2147484314, limited by database with OID 1 2015-10-10 19:00:13 AST DEBUG: MultiXactId wrap limit is 2147483648, limited by database with OID 1 2015-10-10 19:00:13 AST DEBUG: starting up replication slots 2015-10-10 19:00:13 AST LOG: database system was not properly shut down; automatic recovery in progress 2015-10-10 19:00:13 AST DEBUG: resetting unlogged relations: cleanup 1 init 0 2015-10-10 19:00:13 AST LOG: redo starts at 0/16A0230 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12057; tid 0/3 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12059; tid 1/3 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12060; tid 1/2 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11979; tid 31/63 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11984; tid 16/34 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11889; tid 67/5 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11894; tid 9/132 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11895; tid 18/81 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12003; tid 48/62 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12005; tid 28/16 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/12006; tid 27/24 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11950; tid 0/5 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11952; tid 1/3 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 80 to 17 2015-10-10 19:00:13 AST CONTEXT: xlog redo insert: rel 1663/12135/11953; tid 1/5 2015-10-10 19:00:13 AST LOG: record with zero length at 0/16AB308 2015-10-10 19:00:13 AST LOG: redo done at 0/16AB2D8 2015-10-10 19:00:13 AST LOG: last completed transaction was at log time 2015-10-10 18:55:09.464+03 2015-10-10 19:00:13 AST DEBUG: resetting unlogged relations: cleanup 0 init 1 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 5 to 13 2015-10-10 19:00:13 AST DEBUG: performing replication slot checkpoint 2015-10-10 19:00:13 AST DEBUG: attempting to remove WAL segments older than log file 000000000000000000000000 2015-10-10 19:00:13 AST DEBUG: SlruScanDirectory invoking callback on pg_multixact/offsets/0000 2015-10-10 19:00:13 AST DEBUG: SlruScanDirectory invoking callback on pg_multixact/members/0000 2015-10-10 19:00:13 AST DEBUG: SlruScanDirectory invoking callback on pg_multixact/offsets/0000 2015-10-10 19:00:13 AST DEBUG: oldest MultiXactId member is at offset 0 2015-10-10 19:00:13 AST LOG: MultiXact member wraparound protections are now enabled 2015-10-10 19:00:13 AST DEBUG: MultiXact member stop limit is now 4294914944 based on MultiXact 1 2015-10-10 19:00:13 AST DEBUG: shmem_exit(0): 1 before_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: shmem_exit(0): 3 on_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: proc_exit(0): 2 callbacks to make 2015-10-10 19:00:13 AST DEBUG: exit(0) 2015-10-10 19:00:13 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:13 AST DEBUG: reaping dead processes 2015-10-10 19:00:13 AST LOG: database system is ready to accept connections 2015-10-10 19:00:13 AST LOG: autovacuum launcher started 2015-10-10 19:00:13 AST DEBUG: InitPostgres 2015-10-10 19:00:13 AST DEBUG: my backend ID is 1 2015-10-10 19:00:13 AST DEBUG: checkpointer updated shared memory configuration values 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: forked new backend, pid=3432 socket=1288 2015-10-10 19:00:13 AST DEBUG: StartTransaction 2015-10-10 19:00:13 AST DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:13 AST DEBUG: CommitTransaction 2015-10-10 19:00:13 AST DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: received inquiry for database 0 2015-10-10 19:00:13 AST DEBUG: writing stats file "pg_stat_tmp/global.stat" 2015-10-10 19:00:13 AST DEBUG: postgres child[3432]: starting with ( 2015-10-10 19:00:13 AST DEBUG: postgres 2015-10-10 19:00:13 AST DEBUG: ) 2015-10-10 19:00:13 AST DEBUG: InitPostgres 2015-10-10 19:00:13 AST DEBUG: my backend ID is 2 2015-10-10 19:00:13 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:13 AST DEBUG: StartTransaction 2015-10-10 19:00:13 AST DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:13 AST FATAL: role "WIN-TDLBFCTPHT0$" does not exist 2015-10-10 19:00:13 AST DEBUG: shmem_exit(1): 1 before_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: shmem_exit(1): 6 on_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: proc_exit(1): 3 callbacks to make 2015-10-10 19:00:13 AST DEBUG: exit(1) 2015-10-10 19:00:13 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:13 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:13 AST DEBUG: reaping dead processes 2015-10-10 19:00:13 AST DEBUG: server process (PID 3432) exited with exit code 1 2015-10-10 19:00:16 AST DEBUG: forked new backend, pid=148 socket=1288 2015-10-10 19:00:16 AST DEBUG: postgres child[148]: starting with ( 2015-10-10 19:00:16 AST DEBUG: postgres 2015-10-10 19:00:16 AST DEBUG: ) 2015-10-10 19:00:16 AST DEBUG: InitPostgres 2015-10-10 19:00:16 AST DEBUG: my backend ID is 2 2015-10-10 19:00:16 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:16 AST DEBUG: StartTransaction 2015-10-10 19:00:16 AST DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:16 AST FATAL: role "vadv" does not exist 2015-10-10 19:00:16 AST DEBUG: shmem_exit(1): 1 before_shmem_exit callbacks to make 2015-10-10 19:00:16 AST DEBUG: shmem_exit(1): 6 on_shmem_exit callbacks to make 2015-10-10 19:00:16 AST DEBUG: proc_exit(1): 3 callbacks to make 2015-10-10 19:00:16 AST DEBUG: exit(1) 2015-10-10 19:00:16 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:16 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:16 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:16 AST DEBUG: reaping dead processes 2015-10-10 19:00:16 AST DEBUG: server process (PID 148) exited with exit code 1 2015-10-10 19:00:20 AST DEBUG: forked new backend, pid=5024 socket=1288 2015-10-10 19:00:20 AST DEBUG: postgres child[5024]: starting with ( 2015-10-10 19:00:20 AST DEBUG: postgres 2015-10-10 19:00:20 AST DEBUG: ) 2015-10-10 19:00:20 AST DEBUG: InitPostgres 2015-10-10 19:00:20 AST DEBUG: my backend ID is 2 2015-10-10 19:00:20 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:20 AST DEBUG: StartTransaction 2015-10-10 19:00:20 AST DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:20 AST DEBUG: mapped win32 error code 2 to 2 2015-10-10 19:00:20 AST DEBUG: CommitTransaction 2015-10-10 19:00:20 AST DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:32 AST DEBUG: StartTransactionCommand 2015-10-10 19:00:32 AST STATEMENT: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST DEBUG: StartTransaction 2015-10-10 19:00:32 AST STATEMENT: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children: 2015-10-10 19:00:32 AST STATEMENT: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST DEBUG: ProcessUtility 2015-10-10 19:00:32 AST STATEMENT: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST DEBUG: server process (PID 5024) was terminated by exception 0xC0000005 2015-10-10 19:00:32 AST DETAIL: Failed process was running: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST HINT: See C include file "ntstatus.h" for a description of the hexadecimal value. 2015-10-10 19:00:32 AST LOG: server process (PID 5024) was terminated by exception 0xC0000005 2015-10-10 19:00:32 AST DETAIL: Failed process was running: do $$ unpack p,1x8 $$ language plperlu; 2015-10-10 19:00:32 AST HINT: See C include file "ntstatus.h" for a description of the hexadecimal value. 2015-10-10 19:00:32 AST LOG: terminating any other active server processes 2015-10-10 19:00:32 AST DEBUG: sending SIGQUIT to process 1848 2015-10-10 19:00:32 AST DEBUG: sending SIGQUIT to process 968 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: sending SIGQUIT to process 1100 2015-10-10 19:00:32 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:32 AST DEBUG: sending SIGQUIT to process 1856 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:32 AST DEBUG: sending SIGQUIT to process 1104 2015-10-10 19:00:32 AST WARNING: terminating connection because of crash of another server process 2015-10-10 19:00:32 AST 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. 2015-10-10 19:00:32 AST HINT: In a moment you should be able to reconnect to the database and repeat your command. 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:32 AST DEBUG: writing stats file "pg_stat/global.stat" 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST DEBUG: writing stats file "pg_stat/db_12135.stat" 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST DEBUG: removing temporary stats file "pg_stat_tmp/db_12135.stat" 2015-10-10 19:00:32 AST DEBUG: writing stats file "pg_stat/db_0.stat" 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST DEBUG: removing temporary stats file "pg_stat_tmp/db_0.stat" 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST DEBUG: reaping dead processes 2015-10-10 19:00:32 AST LOG: all server processes terminated; reinitializing 2015-10-10 19:00:32 AST DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: shmem_exit(1): 3 on_shmem_exit callbacks to make 2015-10-10 19:00:32 AST DEBUG: cleaning up dynamic shared memory control segment with ID 851401618 2015-10-10 19:00:32 AST DEBUG: invoking IpcMemoryCreate(size=290095104) 2015-10-10 19:00:42 AST FATAL: pre-existing shared memory block is still in use 2015-10-10 19:00:42 AST HINT: Check if there are any old server processes still running, and terminate them. 2015-10-10 19:00:42 AST DEBUG: shmem_exit(1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: shmem_exit(1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: proc_exit(1): 2 callbacks to make 2015-10-10 19:00:42 AST DEBUG: exit(1) 2015-10-10 19:00:42 AST DEBUG: shmem_exit(-1): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: shmem_exit(-1): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: proc_exit(-1): 0 callbacks to make 2015-10-10 19:00:42 AST DEBUG: logger shutting down 2015-10-10 19:00:42 AST DEBUG: shmem_exit(0): 0 before_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: shmem_exit(0): 0 on_shmem_exit callbacks to make 2015-10-10 19:00:42 AST DEBUG: proc_exit(0): 0 callbacks to make 2015-10-10 19:00:42 AST DEBUG: exit(0)
pgsql-hackers by date: