From: | "Sahagian, David" <david(dot)sahagian(at)emc(dot)com> |
---|---|
To: | "pgsql-general(at)postgresql(dot)org" <pgsql-general(at)postgresql(dot)org> |
Subject: | help with log entries during restart |
Date: | 2013-05-07 21:03:16 |
Message-ID: | F3CBFBA88397EA498B22A05FFA9EC49D0124DE7B89@MX22A.corp.emc.com |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-general |
log_line_prefix = '%m %a %u %c %v %x '
# %m Time stamp with milliseconds
# %a Application name
# %u User name
# %c emits a quasi-unique Session ID,
# consisting of two 4-byte hexadecimal numbers (without leading zeros) separated by a dot.
# The numbers are the "Process start time" and the "Process ID".
# %v Virtual transaction ID (backendID/localXID)
# %x Transaction ID (0 if none is assigned)
This was logged by a 9.1.8 Postgres server in a testing-environment:
17:19:01.825 EDT 517a97eb.5081 0 LOG: received fast shutdown request
17:19:01.825 EDT 517a97eb.5081 0 LOG: aborting any active transactions
. . . . . . . . . . . . .
17:19:03.137 EDT 517a97f1.5084 0 LOG: shutting down
17:19:03.839 EDT [unknown] user1 51881e47.6e6f 0 FATAL: the database system is shutting down
17:19:05.187 EDT [unknown] [unknown] 51881e49.6e70 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.193 EDT [unknown] [unknown] 51881e49.6e71 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.198 EDT [unknown] [unknown] 51881e49.6e72 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.202 EDT [unknown] [unknown] 51881e49.6e73 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.207 EDT [unknown] [unknown] 51881e49.6e74 0 LOG: PID 26897 in cancel request did not match any process
. . . about 85 more . . .
17:19:05.952 EDT [unknown] [unknown] 51881e49.6ecb 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.959 EDT [unknown] [unknown] 51881e49.6ecc 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.964 EDT [unknown] [unknown] 51881e49.6ecd 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.970 EDT [unknown] [unknown] 51881e49.6ece 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.975 EDT [unknown] [unknown] 51881e49.6ecf 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.977 EDT 517a97f1.5084 0 LOG: database system is shut down
17:19:05.980 EDT [unknown] [unknown] 51881e49.6ed0 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.985 EDT [unknown] [unknown] 51881e49.6ed1 0 LOG: PID 26897 in cancel request did not match any process
17:19:05.994 EDT [unknown] [unknown] 51881e49.6ed2 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.000 EDT [unknown] [unknown] 51881e4a.6ed3 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.023 EDT [unknown] [unknown] 51881e4a.6ed4 0 LOG: PID 26897 in cancel request did not match any process
. . . about 20 more . . .
17:19:06.225 EDT [unknown] [unknown] 51881e4a.6eea 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.232 EDT [unknown] [unknown] 51881e4a.6eeb 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.240 EDT [unknown] [unknown] 51881e4a.6eec 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.245 EDT [unknown] [unknown] 51881e4a.6eed 0 LOG: PID 26897 in cancel request did not match any process
17:19:06.249 EDT [unknown] [unknown] 51881e4a.6eee 0 LOG: PID 26897 in cancel request did not match any process
17:19:09.489 EDT 51881e4d.6efc 0 LOG: database system was shut down at 17:19:05 EDT
17:19:09.528 EDT [unknown] user2 51881e4d.6efd 0 FATAL: the database system is starting up
17:19:09.530 EDT [unknown] user2 51881e4d.6eff 0 FATAL: the database system is starting up
17:19:09.534 EDT [unknown] user2 51881e4d.6efe 0 FATAL: the database system is starting up
17:19:09.602 EDT 51881e4b.6efa 0 LOG: database system is ready to accept connections
17:19:09.603 EDT 51881e4d.6f02 0 LOG: autovacuum launcher started
(1)
Does this prove or strongly indicate that somebody did a [pg_ctl_restart] ?
(2)
Can you explain/speculate the meaning of the ~100 "PID 26897 in cancel request did not match any process" entries,
logged between
"the database system is shutting down"
and
"database system is shut down" ?
(3)
Can you explain/speculate the meaning of the ~30 "PID 26897 in cancel request did not match any process" entries,
logged between
"database system is shut down"
and
"database system was shut down at 17:19:05 EDT" ?
(4)
Can you explain/speculate the meaning of the 3 "FATAL: the database system is starting up" entries,
logged between
"database system was shut down at 17:19:05 EDT"
and
"database system is ready to accept connections" ?
Thank you,
-dvs-
From | Date | Subject | |
---|---|---|---|
Next Message | Alan Nilsson | 2013-05-08 01:53:47 | Need an explanation |
Previous Message | Tom Lane | 2013-05-07 16:19:35 | Re: replication breaks with CentOS 6.4 upgrade |