Postgres service stops when I kill client backend on Windows
I’ve started PostgreSQL server on Windows and then I kill client
backend’s process by taskkill the service was stopped:
postgres=# select pg_backend_pid();
pg_backend_pid
----------------
1976
postgres=# \! taskkill /pid 1976 /f
SUCCESS: The process with PID 1976 has been terminated.
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>
If I kill backend’s process on Linux then service not failing. So
what’s the problem? Why PostgreSQL is so strange on Windows?
------
Dmitry Vasilyev
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Hello Dmitry
-----Original Message-----
From: pgsql-hackers-owner@postgresql.org [mailto:pgsql-hackers-owner@postgresql.org] On Behalf Of Dmitry Vasilyev
Sent: Freitag, 9. Oktober 2015 11:52
To: pgsql-hackers@postgresql.org
Subject: [HACKERS] Postgres service stops when I kill client backend on WindowsI’ve started PostgreSQL server on Windows and then I kill client
backend’s process by taskkill the service was stopped:postgres=# select pg_backend_pid();
pg_backend_pid
----------------
1976postgres=# \! taskkill /pid 1976 /f
SUCCESS: The process with PID 1976 has been terminated.
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>If I kill backend’s process on Linux then service not failing. So
what’s the problem? Why PostgreSQL is so strange on Windows?
I can't say what happens on windows, but I don't undestand either why you want to kill the session you are in.
Besides that why don't you use pg_terminate_backend?
db=> select pg_backend_pid();
pg_backend_pid
----------------
8808
(1 row)
db=> select pg_terminate_backend(8808);
FATAL: terminating connection due to administrator command
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
db=> select pg_backend_pid();
pg_backend_pid
----------------
8500
(1 row)
Regards
Charles
------
Dmitry Vasilyev
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
This code stoped server too:
postgres=# do $$ unpack p,1x8 $$ language plperlu;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>
------> >
Hello Dmitry
-----Original Message-----
From: pgsql-hackers-owner@postgresql.org [mailto:pgsql-hackers-owne
r@postgresql.org] On Behalf Of Dmitry Vasilyev
Sent: Freitag, 9. Oktober 2015 11:52
To: pgsql-hackers@postgresql.org
Subject: [HACKERS] Postgres service stops when I kill client
backend on WindowsI’ve started PostgreSQL server on Windows and then I kill client
backend’s process by taskkill the service was stopped:postgres=# select pg_backend_pid();
pg_backend_pid
----------------
1976postgres=# \! taskkill /pid 1976 /f
SUCCESS: The process with PID 1976 has been terminated.
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>If I kill backend’s process on Linux then service not failing. So
what’s the problem? Why PostgreSQL is so strange on Windows?I can't say what happens on windows, but I don't undestand either why
you want to kill the session you are in.
Besides that why don't you use pg_terminate_backend?db=> select pg_backend_pid();
pg_backend_pid
----------------
8808
(1 row)db=> select pg_terminate_backend(8808);
FATAL: terminating connection due to administrator command
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
db=> select pg_backend_pid();
pg_backend_pid
----------------
8500
(1 row)Regards
Charles------
Dmitry Vasilyev
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Fri, Oct 9, 2015 at 5:52 AM, Dmitry Vasilyev
<d.vasilyev@postgrespro.ru> wrote:
I’ve started PostgreSQL server on Windows and then I kill client
backend’s process by taskkill the service was stopped:postgres=# select pg_backend_pid();
pg_backend_pid
----------------
1976postgres=# \! taskkill /pid 1976 /f
SUCCESS: The process with PID 1976 has been terminated.
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>If I kill backend’s process on Linux then service not failing. So
what’s the problem? Why PostgreSQL is so strange on Windows?
Hmm. I'd expect that to cause a crash-and-restart cycle, just like a
SIGQUIT would cause a crash-and-restart cycle on Linux. But I would
expect the server to end up running again at the end, not stopped.
--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Robert Haas <robertmhaas@gmail.com> writes:
On Fri, Oct 9, 2015 at 5:52 AM, Dmitry Vasilyev
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
Hmm. I'd expect that to cause a crash-and-restart cycle, just like a
SIGQUIT would cause a crash-and-restart cycle on Linux. But I would
expect the server to end up running again at the end, not stopped.
It *is* a crash and restart cycle, or at least no evidence to the
contrary has been provided.
Whether psql's attempt to do an immediate reconnect succeeds or not is
very strongly timing-dependent, on both Linux and Windows. It's easy
for it to attempt the reconnection before crash recovery is complete,
and then you get the above symptom. Personally I get a "Failed" result
more often than not, regardless of platform.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
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.
On Сб, 2015-10-10 at 10:23 -0500, Tom Lane wrote:
Robert Haas <robertmhaas@gmail.com> writes:
On Fri, Oct 9, 2015 at 5:52 AM, Dmitry Vasilyev
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.Hmm. I'd expect that to cause a crash-and-restart cycle, just like
a
SIGQUIT would cause a crash-and-restart cycle on Linux. But I
would
expect the server to end up running again at the end, not stopped.It *is* a crash and restart cycle, or at least no evidence to the
contrary has been provided.Whether psql's attempt to do an immediate reconnect succeeds or not
is
very strongly timing-dependent, on both Linux and Windows. It's easy
for it to attempt the reconnection before crash recovery is complete,
and then you get the above symptom. Personally I get a "Failed"
result
more often than not, regardless of platform.regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
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
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/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)
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
2015-10-10 18:04 GMT+02:00 Dmitry Vasilyev <d.vasilyev@postgrespro.ru>:
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)
so it is expected behave. After any unexpected client fails, the server is
restarted
Regards
Pavel
Show quoted text
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 STOPPEDThe 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)--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Greetings,
2015-10-11 0:18 GMT+07:00 Pavel Stehule <pavel.stehule@gmail.com>:
2015-10-10 18:04 GMT+02:00 Dmitry Vasilyev <d.vasilyev@postgrespro.ru>:
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.so it is expected behave. After any unexpected client fails, the server is
restarted
I can confirm this too. In linux (i use Fedora 22), this is what happens
when a server is killed:
=== 1. before:
$ sudo systemctl status postgresql.service
postgresql.service - PostgreSQL database server
Loaded: loaded (/usr/lib/systemd/system/postgresql.service; enabled)
Active: active (running) since Jum 2015-10-09 16:25:43 WIB; 1 day 14h ago
Process: 778 ExecStart=/usr/bin/pg_ctl start -D ${PGDATA} -s -o -p
${PGPORT} -w -t 300 (code=exited, status=0/SUCCESS)
Process: 747 ExecStartPre=/usr/bin/postgresql-check-db-dir ${PGDATA}
(code=exited, status=0/SUCCESS)
Main PID: 783 (postgres)
CGroup: /system.slice/postgresql.service
├─ 783 /usr/bin/postgres -D /var/lib/pgsql/data -p 5432
├─ 812 postgres: logger process
├─ 821 postgres: checkpointer process
├─ 822 postgres: writer process
├─ 823 postgres: wal writer process
├─ 824 postgres: autovacuum launcher process
├─ 825 postgres: stats collector process
└─17181 postgres: postgres test [local] idle
=== 2. killing and attempt to reconnect:
$ sudo kill 17181
test=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
=== 3. service status after:
$ sudo systemctl status postgresql.service
postgresql.service - PostgreSQL database server
Loaded: loaded (/usr/lib/systemd/system/postgresql.service; enabled)
Active: active (running) since Jum 2015-10-09 16:25:43 WIB; 1 day 14h ago
Process: 778 ExecStart=/usr/bin/pg_ctl start -D ${PGDATA} -s -o -p
${PGPORT} -w -t 300 (code=exited, status=0/SUCCESS)
Process: 747 ExecStartPre=/usr/bin/postgresql-check-db-dir ${PGDATA}
(code=exited, status=0/SUCCESS)
Main PID: 783 (postgres)
CGroup: /system.slice/postgresql.service
├─ 783 /usr/bin/postgres -D /var/lib/pgsql/data -p 5432
├─ 812 postgres: logger process
├─ 821 postgres: checkpointer process
├─ 822 postgres: writer process
├─ 823 postgres: wal writer process
├─ 824 postgres: autovacuum launcher process
├─ 825 postgres: stats collector process
└─17422 postgres: postgres test [local] idle
===
The service status is still active (running), and new process 17422 handles
the client.
But this is what happens in Windows (win 7 32 bit, postgres 9.4):
=== 1. before:
C:\Windows\system32>sc queryex postgresql-9.4
SERVICE_NAME: postgresql-9.4
TYPE : 10 WIN32_OWN_PROCESS
STATE : 4 RUNNING
(STOPPABLE, PAUSABLE, ACCEPTS_SHUTDOWN)
WIN32_EXIT_CODE : 0 (0x0)
SERVICE_EXIT_CODE : 0 (0x0)
CHECKPOINT : 0x0
WAIT_HINT : 0x0
PID : 3716
FLAGS :
=== 2. killing & attempt to reconnect:
postgres=# select pg_backend_pid();
pg_backend_pid
----------------
2080
(1 row)
C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.
postgres=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!>
=== 3. service status after:
C:\Windows\system32>sc query postgresql-9.4
SERVICE_NAME: postgresql-9.4
TYPE : 10 WIN32_OWN_PROCESS
STATE : 1 STOPPED
WIN32_EXIT_CODE : 0 (0x0)
SERVICE_EXIT_CODE : 0 (0x0)
CHECKPOINT : 0x0
WAIT_HINT : 0x0
===
The client cannot reconnect. The service is dead. This is nasty, because
any client can exploit some segfault bug like the one in perl Dmitry
mentoined upthread, and the postgresql service is down.
Note: killing the server process with pg_terminate_backend isn't causing
this behavior to happen. The client reconnects normally, and the service is
still running.
Regards,
Ali Akbar
On Sun, Oct 11, 2015 at 8:54 AM, Ali Akbar <the.apaan@gmail.com> wrote:
C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.
taskkill /f *forcefully* terminates the process targeted [1]http://www.microsoft.com/resources/documentation/windows/xp/all/proddocs/en-us/taskkill.mspx?mfr=true -- Michael. Isn't
that equivalent to a kill -9? If you headshot a backend process on
Linux with kill -9, an instance won't restart either.
[1]: http://www.microsoft.com/resources/documentation/windows/xp/all/proddocs/en-us/taskkill.mspx?mfr=true -- Michael
--
Michael
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Dmitry Vasilyev <d.vasilyev@postgrespro.ru> writes:
On Сб, 2015-10-10 at 10:55 -0500, Tom Lane wrote:
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.
The log you can see bellow:
...
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.
Thanks for providing some detail! It's clear from the above log excerpt
that we're timing out after 10 seconds in win32_shmem.c's version of
PGSharedMemoryCreate, because CreateFileMapping is still reporting that
the old shared memory segment still exists. When we last discussed this
sort of problem in
/messages/by-id/49FA3B6F.6080906@dunslane.net
there was no evidence that such a failure could persist for longer than a
second or two. Now it seems that on your machine the failure state can
persist for at least 10 seconds, but I don't know why.
If I had to guess, on the basis of no evidence, I'd wonder whether the
DSM code broke it; there is evidently at least one DSM segment in play
in your use-case. But that's only a guess.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Sun, Oct 11, 2015 at 10:09 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Dmitry Vasilyev <d.vasilyev@postgrespro.ru> writes:
The log you can see bellow:
...
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.
..
If I had to guess, on the basis of no evidence, I'd wonder whether the
DSM code broke it; there is evidently at least one DSM segment in play
in your use-case. But that's only a guess.
There is some possibility based on the above DEBUG messages that
DSM could cause this problem, but I think the last message (pre-existing
shared memory block is still in use) won't be logged for DSM. We create
the new dsm segment in below code dsm_postmaster_startup()->
dsm_impl_op()->dsm_impl_windows()
dsm_impl_windows()
{
..
if (op == DSM_OP_CREATE)
..
}
Basically in this path, we try to recreate the dsm with different name if it
fails with ALREADY_EXIST error.
To diagnose the reason of problem, I think we can write a diagnostic
patch which would do below 2 points:
1. Increase the below loop count 10 to 50 or 100 in win32_shmem.c
or instead of loop count, we can increase the sleep time as well.
PGSharedMemoryCreate()
{
..
for (i = 0; i < 10; i++)
..
if (GetLastError() == ERROR_ALREADY_EXISTS)
{
..
Sleep(1000);
continue;
}
..
}
2. Increase the log messages both in win32_shmem.c and dsm related
code which can help us in narrowing down the problem.
If you find this as reasonable approach to diagnose the root cause
of problem, I can work on writing a diagnostic patch.
With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com
On Sun, Oct 11, 2015 at 5:55 AM, Michael Paquier <michael.paquier@gmail.com>
wrote:
On Sun, Oct 11, 2015 at 8:54 AM, Ali Akbar <the.apaan@gmail.com> wrote:
C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.taskkill /f *forcefully* terminates the process targeted [1]. Isn't
that equivalent to a kill -9? If you headshot a backend process on
Linux with kill -9, an instance won't restart either.
[1]:
http://www.microsoft.com/resources/documentation/windows/xp/all/proddocs/en-us/taskkill.mspx?mfr=true
It does. If you want a "gracefull kill" on Windows, you must use "pg_ctl
kill" which can send an "emulated term-signal".
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
On 10/11/2015 05:58 AM, Magnus Hagander wrote:
On Sun, Oct 11, 2015 at 5:55 AM, Michael Paquier
<michael.paquier@gmail.com <mailto:michael.paquier@gmail.com>> wrote:On Sun, Oct 11, 2015 at 8:54 AM, Ali Akbar <the.apaan@gmail.com
<mailto:the.apaan@gmail.com>> wrote:C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.taskkill /f *forcefully* terminates the process targeted [1]. Isn't
that equivalent to a kill -9? If you headshot a backend process on
Linux with kill -9, an instance won't restart either.
[1]:
http://www.microsoft.com/resources/documentation/windows/xp/all/proddocs/en-us/taskkill.mspx?mfr=trueIt does. If you want a "gracefull kill" on Windows, you must use
"pg_ctl kill" which can send an "emulated term-signal".
Nevertheless, we'd like a hard crash of a backend other than the
postmaster not to have worse effects than on *nix, where killing a
backend even with SIGKILL doesn't halt the server:
andrew=# select pg_backend_pid();
pg_backend_pid
----------------
24359
(1 row)
andrew=# \! kill -9 24359
andrew=# select 1;
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Succeeded.
andrew=#
Amit's proposals elsewhere to increase the shmem timeout and increase
logging seem reasonable.
cheers
andrew
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
Andrew Dunstan <andrew@dunslane.net> writes:
Amit's proposals elsewhere to increase the shmem timeout and increase
logging seem reasonable.
I'm back to the position I had in the previous thread, which is that
we don't really understand why any delay is needed here at all, and
we ought to try to remedy that lack rather than just hoping that more
and more delay will fix it. It may be that there's some proactive
measure we can take to improve matters.
I'm a bit suspicious that we may have leaked a handle to the shared
memory block someplace, for example. That would explain why this
symptom is visible now when it was not in 2009. Or maybe it's dependent
on some feature that we didn't test back then --- for instance, if
the logging collector is in use, could it have inherited a handle and
not closed it?
One thing I noticed in the CreateFileMapping docs is that Windows
apparently implements the sort of anonymous mapping we're doing as
a mapping of part of the "system paging file". I wonder if it's too
dumb (perhaps in only some releases) to realize that it doesn't
really need to flush dirty pages to disk when the last reference
to the mapping is abandoned. In that case maybe an explicit flush
request would move things along.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Sun, Oct 11, 2015 at 4:32 PM, Andrew Dunstan <andrew@dunslane.net> wrote:
On 10/11/2015 05:58 AM, Magnus Hagander wrote:
On Sun, Oct 11, 2015 at 5:55 AM, Michael Paquier <
michael.paquier@gmail.com <mailto:michael.paquier@gmail.com>> wrote:On Sun, Oct 11, 2015 at 8:54 AM, Ali Akbar <the.apaan@gmail.com
<mailto:the.apaan@gmail.com>> wrote:C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.taskkill /f *forcefully* terminates the process targeted [1]. Isn't
that equivalent to a kill -9? If you headshot a backend process on
Linux with kill -9, an instance won't restart either.
[1]:It does. If you want a "gracefull kill" on Windows, you must use "pg_ctl
kill" which can send an "emulated term-signal".Nevertheless, we'd like a hard crash of a backend other than the
postmaster not to have worse effects than on *nix, where killing a backend
even with SIGKILL doesn't halt the server:
Oh, absolutely. I was just pointing out that something like taskill
*should* result in a hard restart of *all* backends, and if you want to
kill off just the one you should never use it, you should instead use
pg_ctl kill. But of course, none of those two should lead to the scenario
explained here where it does not come back up again.
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
On Sun, Oct 11, 2015 at 5:22 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
Andrew Dunstan <andrew@dunslane.net> writes:
Amit's proposals elsewhere to increase the shmem timeout and increase
logging seem reasonable.I'm back to the position I had in the previous thread, which is that
we don't really understand why any delay is needed here at all, and
we ought to try to remedy that lack rather than just hoping that more
and more delay will fix it. It may be that there's some proactive
measure we can take to improve matters.I'm a bit suspicious that we may have leaked a handle to the shared
memory block someplace, for example. That would explain why this
symptom is visible now when it was not in 2009. Or maybe it's dependent
on some feature that we didn't test back then --- for instance, if
the logging collector is in use, could it have inherited a handle and
not closed it?
Even if we leaked it, it should go away when the other processes died.
What would be interesting to know is if there at this point is *any*
postgres.exe process still running, and in that case what it is. It should
then be possible to use Process Explorer to figure out which process it is
(by looking at the "fake title"), and probably also which shared memory
handles it has open (even though they don't have a name, their info might
explain things).
So if someone with a reproducible case could check that as well, I think it
woudl be valuable information.
One thing I noticed in the CreateFileMapping docs is that Windows
apparently implements the sort of anonymous mapping we're doing as
a mapping of part of the "system paging file". I wonder if it's too
dumb (perhaps in only some releases) to realize that it doesn't
really need to flush dirty pages to disk when the last reference
to the mapping is abandoned. In that case maybe an explicit flush
request would move things along.
First of all, note that "system paging file" is exactly the same as "swap
file" or "swap partition" on Unix. Just in case there is any unclearness
there.
And I'm pretty sure it doesn't do that. Surely we would've seen performance
issues from that before in that case. But I don't really have any facts to
back that up :)
We do get, AIUI, the SEC_COMMIT behaviour which commits the pages initially
to make sure there is actually space for them. I don't believe that one
specifically says anything about when you close it.
--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/
Magnus Hagander <magnus@hagander.net> writes:
On Sun, Oct 11, 2015 at 5:22 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
I'm a bit suspicious that we may have leaked a handle to the shared
memory block someplace, for example. That would explain why this
symptom is visible now when it was not in 2009. Or maybe it's dependent
on some feature that we didn't test back then --- for instance, if
the logging collector is in use, could it have inherited a handle and
not closed it?
Even if we leaked it, it should go away when the other processes died.
I'm fairly certain that we do not kill/restart the logging collector
during a database restart (because it's impossible to reproduce the
original stderr destination if we do). Not sure if any other postmaster
children are allowed to survive.
regards, tom lane
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
On Sun, Oct 11, 2015 at 5:55 AM, Michael Paquier wrote:
On Sun, Oct 11, 2015 at 8:54 AM, Ali Akbar <the.apaan@gmail.com> wrote:
C:\Windows\system32>taskkill /F /PID 2080
SUCCESS: The process with PID 2080 has been terminated.taskkill /f *forcefully* terminates the process targeted [1]. Isn't
that equivalent to a kill -9? If you headshot a backend process on
Linux with kill -9, an instance won't restart either.
[1]:
http://www.microsoft.com/resources/documentation/windows/xp/all/proddocs/en-us/taskkill.mspx?mfr=trueIt does. If you want a "gracefull kill" on Windows, you must use "pg_ctl
kill" which can send an "emulated term-signal".
Ah, yes. Sure. I had restart_after_crash = off on this instance...
--
Michael
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers