Arch Linux

gkrukar

Member

Registered: 2018-05-11

Posts: 7

Problem with starting postgresql after upgrade to 10.4-1

How can i fix this issue?

[gk@gk ~]$ sudo systemctl start postgresql
Job for postgresql.service failed because a timeout was exceeded.
See "systemctl status postgresql.service" and "journalctl -xe" for details.

[gk@gk ~]$ systemctl status postgresql.service
● postgresql.service - PostgreSQL database server
   Loaded: loaded (/usr/lib/systemd/system/postgresql.service; disabled; vendor preset: disabled)
   Active: failed (Result: timeout) since Fri 2018-05-11 10:56:29 CEST; 13s ago
  Process: 710 ExecStart=/usr/bin/pg_ctl -s -D ${PGROOT}/data start -w -t 120 (code=exited, status=0/SUCCESS)
  Process: 706 ExecStartPre=/usr/bin/postgresql-check-db-dir ${PGROOT}/data (code=exited, status=0/SUCCESS)
 Main PID: 710 (code=exited, status=0/SUCCESS)

May 11 10:54:30 gk postgres[708]: 2018-05-11 10:54:30.016 CEST [711] LOG:  database system was shut down at 2018-05-11 10:51:55 CEST
May 11 10:54:30 gk postgres[708]: 2018-05-11 10:54:30.037 CEST [710] LOG:  database system is ready to accept connections
May 11 10:54:30 gk systemd[1]: postgresql.service: Got notification message from PID 710, but reception only permitted for main PID 708
May 11 10:56:29 gk systemd[1]: postgresql.service: Start operation timed out. Terminating.
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.846 CEST [710] LOG:  received smart shutdown request
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.849 CEST [710] LOG:  worker process: logical replication launcher (PID 717) exited with exit code 1
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.849 CEST [712] LOG:  shutting down
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.877 CEST [710] LOG:  database system is shut down
May 11 10:56:29 gk systemd[1]: postgresql.service: Failed with result 'timeout'.
May 11 10:56:29 gk systemd[1]: Failed to start PostgreSQL database server.

[gk@gk ~]$ journalctl -xe
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit postgresql.service has begun starting up.
May 11 10:54:29 gk postgres[708]: 2018-05-11 10:54:29.930 CEST [710] LOG:  listening on IPv6 address "::1", port 5432
May 11 10:54:29 gk postgres[708]: 2018-05-11 10:54:29.931 CEST [710] LOG:  listening on IPv4 address "127.0.0.1", port 5432
May 11 10:54:29 gk postgres[708]: 2018-05-11 10:54:29.935 CEST [710] LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5432"
May 11 10:54:30 gk postgres[708]: 2018-05-11 10:54:30.016 CEST [711] LOG:  database system was shut down at 2018-05-11 10:51:55 CEST
May 11 10:54:30 gk postgres[708]: 2018-05-11 10:54:30.037 CEST [710] LOG:  database system is ready to accept connections
May 11 10:54:30 gk systemd[1]: postgresql.service: Got notification message from PID 710, but reception only permitted for main PID 708
May 11 10:54:30 gk systemd-timesyncd[326]: Synchronized to time server 91.232.160.1:123 (2.arch.pool.ntp.org).
May 11 10:56:29 gk systemd[1]: postgresql.service: Start operation timed out. Terminating.
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.846 CEST [710] LOG:  received smart shutdown request
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.849 CEST [710] LOG:  worker process: logical replication launcher (PID 717) exited with exit code 1
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.849 CEST [712] LOG:  shutting down
May 11 10:56:29 gk postgres[708]: 2018-05-11 10:56:29.877 CEST [710] LOG:  database system is shut down
May 11 10:56:29 gk systemd[1]: postgresql.service: Failed with result 'timeout'.
May 11 10:56:29 gk systemd[1]: Failed to start PostgreSQL database server.
-- Subject: Unit postgresql.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit postgresql.service has failed.
-- 
-- The result is RESULT.
May 11 10:56:29 gk sudo[703]: pam_unix(sudo:session): session closed for user root

serwiz

Member

Registered: 2014-08-22

Posts: 1

Re: Problem with starting postgresql after upgrade to 10.4-1

Add

NotifyAccess=all

after

Type=notify

in

/etc/systemd/system/multi-user.target.wants/postgresql.service

GeorgeTG

Member

Registered: 2016-05-02

Posts: 1

Re: Problem with starting postgresql after upgrade to 10.4-1

I have the exact same issue with the exact same journal/logs output
systemd[1]: postgresql.service: Got notification message from PID 710, but reception only permitted for main PID 708
Seems to be the culprit

EDIT:

Add

NotifyAccess=all

after

Type=notify

in

/etc/systemd/system/multi-user.target.wants/postgresql.service

Seems to fix the issue.

Last edited by GeorgeTG (2018-05-11 10:11:20)

nl6720

The Evil Wiki Admin

Registered: 2016-07-02

Posts: 714

Re: Problem with starting postgresql after upgrade to 10.4-1

For reference, the bug link: FS#58544.

amish

Member

Registered: 2014-05-10

Posts: 513

Re: Problem with starting postgresql after upgrade to 10.4-1

This feature request probably introduced the bug:
https://bugs.archlinux.org/task/55095

With due respect, I wonder if package maintainer actually uses the package?

Because if yes then maintainer must have come across the bug before releasing it.

If not, then we need to have policy in place where maintainer uses the package himself. Atleast for important packages which can be very critical.

amish

Member

Registered: 2014-05-10

Posts: 513

Re: Problem with starting postgresql after upgrade to 10.4-1

10.4-2 fixes it. (by reversing the unit file change)

Mardukas

Banned

From: Lithuania

Registered: 2007-08-05

Posts: 121

Re: Problem with starting postgresql after upgrade to 10.4-1

10.4-2 fixes it. (by reversing the unit file change)

10.4-3 broke it again? https://git.archlinux.org/svntogit/pack … 75011f9dc7
Update changed to `Type=notify` and now I get this:

Got notification message from PID 454, but reception only permitted for main PID 379

Changing Type back to forking or adding NotifyAccess=all fixes it.

---

Is this a problem because of my config or bug in package?

Last edited by Mardukas (2018-05-23 07:24:45)

amish

Member

Registered: 2014-05-10

Posts: 513

Re: Problem with starting postgresql after upgrade to 10.4-1

Pieces of the new postgresql.service seems to have been picked up from official documentation.

https://www.postgresql.org/docs/current … start.html (scroll down to word systemd)

Only difference in Timeout=120 is used instead of Timeout=0 (recommended by upstream for crash recovery)

So overall it should be fine unless there is some kind of crash recovery going on with your postgresql.

PS: I am yet to test latest package release.

twelveeighty

Member

Registered: 2011-09-04

Posts: 1,451

Re: Problem with starting postgresql after upgrade to 10.4-1

I wonder if this is caused by combining Type=notify and ExecStartPre, which is not mentioned in the official documentation's sample systemd config file.

@Mardukas: can you test it by setting back Type=notify, and remove the ExecStartPre line? Assuming that your database is fine, we should be able to safely remove that for testing purposes.

amish

Member

Registered: 2014-05-10

Posts: 513

Re: Problem with starting postgresql after upgrade to 10.4-1

If it happens due to ExecStartPre then it would be systemd bug.(but I doubt that is causing problem facec by @Mardukas)

Mardukas

Banned

From: Lithuania

Registered: 2007-08-05

Posts: 121

Re: Problem with starting postgresql after upgrade to 10.4-1

I wonder if this is caused by combining Type=notify and ExecStartPre, which is not mentioned in the official documentation's sample systemd config file.

@Mardukas: can you test it by setting back Type=notify, and remove the ExecStartPre line? Assuming that your database is fine, we should be able to safely remove that for testing purposes.

Remove ExecStartPre line, still same problems:

-- Unit postgresql.service has begun starting up.
May 23 20:18:54 gorgut.eu postgres[5963]: 2018-05-23 18:18:54 GMT [5965]: [1-1] user=,db=,app= LOG:  listening on IPv4 address "0.0.0.0", port 5136
May 23 20:18:54 gorgut.eu postgres[5963]: 2018-05-23 18:18:54 GMT [5965]: [2-1] user=,db=,app= LOG:  listening on IPv6 address "::", port 5136
May 23 20:18:54 gorgut.eu postgres[5963]: 2018-05-23 18:18:54 GMT [5965]: [3-1] user=,db=,app= LOG:  listening on Unix socket "/run/postgresql/.s.PGSQL.5136"
May 23 20:18:55 gorgut.eu postgres[5963]: 2018-05-23 18:18:55 GMT [5967]: [1-1] user=,db=,app= LOG:  database system was shut down at 2018-05-23 18:18:54 GMT
May 23 20:18:55 gorgut.eu postgres[5963]: 2018-05-23 18:18:55 GMT [5965]: [4-1] user=,db=,app= LOG:  database system is ready to accept connections
May 23 20:18:55 gorgut.eu systemd[1]: postgresql.service: Got notification message from PID 5965, but reception only permitted for main PID 5963
May 23 20:20:54 gorgut.eu systemd[1]: postgresql.service: Start operation timed out. Terminating.
May 23 20:20:54 gorgut.eu postgres[5963]: 2018-05-23 18:20:54 GMT [5965]: [5-1] user=,db=,app= LOG:  received fast shutdown request
May 23 20:20:54 gorgut.eu postgres[5963]: 2018-05-23 18:20:54 GMT [5965]: [6-1] user=,db=,app= LOG:  aborting any active transactions
May 23 20:20:54 gorgut.eu postgres[5963]: 2018-05-23 18:20:54 GMT [5965]: [7-1] user=,db=,app= LOG:  worker process: logical replication launcher (PID 5973) exited with exit code 1
May 23 20:20:54 gorgut.eu postgres[5963]: 2018-05-23 18:20:54 GMT [5968]: [1-1] user=,db=,app= LOG:  shutting down
May 23 20:20:55 gorgut.eu postgres[5963]: 2018-05-23 18:20:55 GMT [5965]: [8-1] user=,db=,app= LOG:  database system is shut down
May 23 20:20:55 gorgut.eu systemd[1]: postgresql.service: Failed with result 'timeout'.
May 23 20:20:55 gorgut.eu systemd[1]: Failed to start PostgreSQL database server.
-- Subject: Unit postgresql.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
--
-- Unit postgresql.service has failed.
--
-- The result is RESULT.

ATM running with

NotifyAccess=all

line added in [Service] and it works.

Last edited by Mardukas (2018-05-23 18:23:24)

amish

Member

Registered: 2014-05-10

Posts: 513

Re: Problem with starting postgresql after upgrade to 10.4-1

@Markdukas do u have any drop-in systemd files? (which uses pg_ctl) - they might be overriding settings.

If not then, exact 120 seconds have taken for triggering shutdown - which hints at introduction of the previous bug again!

Last edited by amish (2018-05-24 02:35:01)

Mardukas

Banned

From: Lithuania

Registered: 2007-08-05

Posts: 121

Re: Problem with starting postgresql after upgrade to 10.4-1

@Markdukas do u have any drop-in systemd files? (which uses pg_ctl) - they might be overriding settings.

If not then, exact 120 seconds have taken for triggering shutdown - which hints at introduction of the previous bug again!

Actually I do, forgot about override.conf, will investigate later.

EDIT: EVERYTHING'S FINE, had to update my override.conf file, problem was on my end. Thanks for the help.

Last edited by Mardukas (2018-05-24 07:36:53)