PostgreSQL 11 can not restart after an unexpected shutdown
Hi,
Sporadically the PostgreSQL 11 server can not be restarted when an
unexpected restart occurs with user defined table spaces.
Unexpected shutdown:
[image: systemrebootunexp.PNG]
Event logs:
After restart the postgresql does the following based on the event logs:
1. "Wating for server startup..."
2. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv6 address
"::", port 5432"
3. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv4 address
"0.0.0.0", port 5432"
4. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory"
5. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211349/PG_11_201809051": No such file or directory"
... (Plenty of this kind of logs about could not open directory pg_tblspc)
6. "2019-07-05 16:15:23.618 CEST [4608] LOG: redirecting log output to
logging collector process
2019-07-05 16:15:23.618 CEST [4608] HINT: Future log output will
appear in directory "log"."
7. ERROR level: "Timed out waiting for server startup"
8. Waiting for server startup...
9. ERROR level: "2019-07-05 16:17:50.381 CEST [10168] FATAL: lock file
"postmaster.pid" already exists
2019-07-05 16:17:50.381 CEST [10168] HINT: Is another postmaster (PID
4608) running in data directory "C:/Program Files/PostgreSQL/11/data"?"
10. ERROR level: "Timed out waiting for server startup"
Then it keeps trying without a success:
[image: image.png]
Boot time:
[image: image.png]
Postgresql Logs:
2019-07-05 16:15:24.153 CEST [6668] LOG: database system was interrupted;
last known up at 2019-07-05 16:09:51 CEST
2019-07-05 16:18:04.155 CEST [6668] LOG: could not stat file
"./pg_tblspc/211347": No such file or directory
.."Plenty of logs about this "could not stat file..."...
2019-07-05 16:18:30.623 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
*2019-07-05 16:18:30.632 CEST [6668] LOG: database system was not properly
shut down; automatic recovery in progress*
2019-07-05 16:18:31.209 CEST [6668] LOG: redo starts at A/1CC62250
2019-07-05 16:18:31.210 CEST [6668] WARNING: could not open directory
"pg_tblspc/310943/PG_11_201809051/310944": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] WARNING: some useless files may be
left behind in old database directory
"pg_tblspc/310943/PG_11_201809051/310944"
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310810": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC63348 for
Tablespace/DROP: 310810
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310943": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC633E8 for
Tablespace/DROP: 310943
2019-07-05 16:18:32.542 CEST [6668] LOG: invalid record length at
A/1CC696A8: wanted 24, got 0
2019-07-05 16:18:32.542 CEST [6668] LOG: redo done at A/1CC69670
2019-07-05 16:18:32.690 CEST [6668] LOG: last completed transaction was at
log time 2019-07-05 16:09:53.420563+02
2019-07-05 16:18:32.693 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
2019-07-05 16:18:35.488 CEST [4608] LOG: database system is ready to
accept connections
*(^But the pg_ctl does not running therefore in the eventlogs it can be
seen that:*
[image: image.png]
In the services window it looks like that the postgresql does not running
but it is running without the pg_ctl:
[image: image.png]
So in case i want to start the postgresql manually in the services it does
not allow me, so I have to kill these processes and restart the Postgresql.
Configuration: Windows 10
Version: "PostgreSQL 11.1, compiled by Visual C++ build 1914, 64-bit"
Note: MS SQL Server is also installed on the device.
Best Regards,
Adam Maracska
Hi,
I would like to republish my previous bug report, because the pictures were
eliminated and it made harder to understand the problem.
Link to the previous post:
/messages/by-id/CAJtpbKT6U91U7-zTRpSpp9T0nXB+xdJcR8gSTYVzGs7Eb0Svaw@mail.gmail.com
Sporadically the PostgreSQL 11 server can not be restarted when an
unexpected restart occurs with user defined table spaces.
Unexpected shutdown:
Picture: https://i.imgur.com/c7QM120.png
Event logs:
After restart the postgresql does the following based on the event logs:
1. "Wating for server startup..."
2. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv6 address
"::", port 5432"
3. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv4 address
"0.0.0.0", port 5432"
4. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory"
5. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211349/PG_11_201809051": No such file or directory"
... (Plenty of this kind of logs about could not open directory pg_tblspc)
6. "2019-07-05 16:15:23.618 CEST [4608] LOG: redirecting log output to
logging collector process
2019-07-05 16:15:23.618 CEST [4608] HINT: Future log output will
appear in directory "log"."
7. ERROR level: "Timed out waiting for server startup"
8. Waiting for server startup...
9. ERROR level: "2019-07-05 16:17:50.381 CEST [10168] FATAL: lock file
"postmaster.pid" already exists
2019-07-05 16:17:50.381 CEST [10168] HINT: Is another postmaster (PID
4608) running in data directory "C:/Program Files/PostgreSQL/11/data"?"
10. ERROR level: "Timed out waiting for server startup"
Then it keeps trying without a success:
Picture:
https://i.imgur.com/YQ74JGx.png
Boot time:
Picture: https://i.imgur.com/M5qwy7H.png
Postgresql Logs:
2019-07-05 16:15:24.153 CEST [6668] LOG: database system was interrupted;
last known up at 2019-07-05 16:09:51 CEST
2019-07-05 16:18:04.155 CEST [6668] LOG: could not stat file
"./pg_tblspc/211347": No such file or directory
.."Plenty of logs about this "could not stat file..."...
2019-07-05 16:18:30.623 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
*2019-07-05 16:18:30.632 CEST [6668] LOG: database system was not properly
shut down; automatic recovery in progress*
2019-07-05 16:18:31.209 CEST [6668] LOG: redo starts at A/1CC62250
2019-07-05 16:18:31.210 CEST [6668] WARNING: could not open directory
"pg_tblspc/310943/PG_11_201809051/310944": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] WARNING: some useless files may be
left behind in old database directory
"pg_tblspc/310943/PG_11_201809051/310944"
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310810": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC63348 for
Tablespace/DROP: 310810
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310943": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC633E8 for
Tablespace/DROP: 310943
2019-07-05 16:18:32.542 CEST [6668] LOG: invalid record length at
A/1CC696A8: wanted 24, got 0
2019-07-05 16:18:32.542 CEST [6668] LOG: redo done at A/1CC69670
2019-07-05 16:18:32.690 CEST [6668] LOG: last completed transaction was at
log time 2019-07-05 16:09:53.420563+02
2019-07-05 16:18:32.693 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
2019-07-05 16:18:35.488 CEST [4608] LOG: database system is ready to
accept connections
*(^But the pg_ctl does not running therefore in the eventlogs it can be
seen that:*
Picture: https://i.imgur.com/TKrulAa.png
In the services window it looks like that the postgresql does not running
but it is running without the pg_ctl:
Picture: https://i.imgur.com/3jA4Mc5.png
So in case i want to start the postgresql manually in the services it does
not allow me, so I have to kill these processes and restart the Postgresql.
Configuration: Windows 10
Version: "PostgreSQL 11.1, compiled by Visual C++ build 1914, 64-bit"
Note: MS SQL Server is also installed on the device.
Best Regards,
Adam Maracska
Ádám Maracska <csusza@gmail.com> ezt írta (időpont: 2019. júl. 8., H, 9:45):
Show quoted text
Hi,
Sporadically the PostgreSQL 11 server can not be restarted when an
unexpected restart occurs with user defined table spaces.Unexpected shutdown:
[image: systemrebootunexp.PNG]
Event logs:
After restart the postgresql does the following based on the event logs:
1. "Wating for server startup..."
2. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv6 address
"::", port 5432"
3. "2019-07-05 16:15:22.661 CEST [4608] LOG: listening on IPv4 address
"0.0.0.0", port 5432"
4. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory"
5. "2019-07-05 16:15:23.548 CEST [4608] LOG: could not open directory
"pg_tblspc/211349/PG_11_201809051": No such file or directory"
... (Plenty of this kind of logs about could not open directory pg_tblspc)
6. "2019-07-05 16:15:23.618 CEST [4608] LOG: redirecting log output to
logging collector process
2019-07-05 16:15:23.618 CEST [4608] HINT: Future log output will
appear in directory "log"."
7. ERROR level: "Timed out waiting for server startup"
8. Waiting for server startup...
9. ERROR level: "2019-07-05 16:17:50.381 CEST [10168] FATAL: lock file
"postmaster.pid" already exists
2019-07-05 16:17:50.381 CEST [10168] HINT: Is another postmaster (PID
4608) running in data directory "C:/Program Files/PostgreSQL/11/data"?"
10. ERROR level: "Timed out waiting for server startup"Then it keeps trying without a success:
[image: image.png]Boot time:
[image: image.png]Postgresql Logs:
2019-07-05 16:15:24.153 CEST [6668] LOG: database system was interrupted;
last known up at 2019-07-05 16:09:51 CEST
2019-07-05 16:18:04.155 CEST [6668] LOG: could not stat file
"./pg_tblspc/211347": No such file or directory
.."Plenty of logs about this "could not stat file..."...
2019-07-05 16:18:30.623 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
*2019-07-05 16:18:30.632 CEST [6668] LOG: database system was not
properly shut down; automatic recovery in progress*
2019-07-05 16:18:31.209 CEST [6668] LOG: redo starts at A/1CC62250
2019-07-05 16:18:31.210 CEST [6668] WARNING: could not open directory
"pg_tblspc/310943/PG_11_201809051/310944": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] WARNING: some useless files may be
left behind in old database directory
"pg_tblspc/310943/PG_11_201809051/310944"
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC622F8 for
Database/DROP: dir 310944/310943
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310810": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC63348 for
Tablespace/DROP: 310810
2019-07-05 16:18:31.210 CEST [6668] LOG: could not stat file
"pg_tblspc/310943": No such file or directory
2019-07-05 16:18:31.210 CEST [6668] CONTEXT: WAL redo at A/1CC633E8 for
Tablespace/DROP: 310943
2019-07-05 16:18:32.542 CEST [6668] LOG: invalid record length at
A/1CC696A8: wanted 24, got 0
2019-07-05 16:18:32.542 CEST [6668] LOG: redo done at A/1CC69670
2019-07-05 16:18:32.690 CEST [6668] LOG: last completed transaction was
at log time 2019-07-05 16:09:53.420563+02
2019-07-05 16:18:32.693 CEST [6668] LOG: could not open directory
"pg_tblspc/211347/PG_11_201809051": No such file or directory
.."Plenty of logs about this "could not open directory"...
2019-07-05 16:18:35.488 CEST [4608] LOG: database system is ready to
accept connections
*(^But the pg_ctl does not running therefore in the eventlogs it can be
seen that:*
[image: image.png]In the services window it looks like that the postgresql does not running
but it is running without the pg_ctl:
[image: image.png]So in case i want to start the postgresql manually in the services it does
not allow me, so I have to kill these processes and restart the Postgresql.Configuration: Windows 10
Version: "PostgreSQL 11.1, compiled by Visual C++ build 1914, 64-bit"Note: MS SQL Server is also installed on the device.
Best Regards,
Adam Maracska