[Pkg-systemd-maintainers] Bug#737825: Bug#737825: systemd: systemctl start php5-fpm hangs on systemd-tty-ask-password-agent

[Michael Stapelberg]

control: severity -1 normal

Hi Ondřej,

Ondřej Surý <ondrej at sury.org> writes:
> when installing php5-fpm on the headless KVM server the 'systemctl
> start php5-fpm' hangs with 'systemd-tty-ask-password-agent --watch'
> waiting for something (I guess user input?):
>
> root         1  0.0  0.1  45940  4256 ?        Ss   Feb05   0:07 /lib/systemd/systemd
> root       188  0.0  0.3 114764 14100 ?        Ss   Feb05   0:08 /lib/systemd/systemd-journald
> root       199  0.0  0.0  42380  1088 ?        Ss   Feb05   0:00 /lib/systemd/systemd-udevd
> root       649  0.0  0.0  28512  1052 ?        Ss   Feb05   0:00 /lib/systemd/systemd-logind
> message+   654  0.0  0.0  41380  1176 ?        Ss   Feb05   0:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation
> root      4952  0.0  0.0  15068   788 pts/0    S+   11:12   0:00
> /bin/systemd-tty-ask-password-agent --watch
While the PIDs suggest that systemd-tty-ask-password-agent (4952) was started
shortly before php5-fpm.service’s ExecStartPre (4953), I am not yet
convinced there is any causation here. Where do you gather the
information from that systemd-tty-ask-password-agent is hanging and/or
blocking the php5-fpm startup?

> Output of 'systemctl status php5-fpm.service':
>
> root at pagan:/etc/php5/fpm/pool.d# systemctl status php5-fpm.service 
> php5-fpm.service - The PHP FastCGI Process Manager
>    Loaded: loaded (/lib/systemd/system/php5-fpm.service; enabled)
>    Active: failed (Result: timeout) since Thu 2014-02-06 11:15:18 CET; 2min 24s ago
>   Process: 4953 ExecStartPre=/usr/lib/php5/php5-fpm-checkconf (code=exited, status=0/SUCCESS)
>  Main PID: 4524
Note that MainPID (4524) and the process that is logging the error
message below (4959) actually are different. Not sure if that is
expected.

>    CGroup: name=systemd:/system/php5-fpm.service
>
> Feb 06 11:12:18 pagan.rfc1925.org systemd[1]: Starting The PHP FastCGI Process Manager...
> Feb 06 11:12:18 pagan.rfc1925.org php5-fpm[4959]: [06-Feb-2014 11:12:18] ERROR: An another FPM instance seems to already listen on /var/run/php5-fpm.e-psychologie.cz.sock
> Feb 06 11:12:18 pagan.rfc1925.org php5-fpm[4959]: [06-Feb-2014 11:12:18] ERROR: FPM initialization failed
> Feb 06 11:13:48 pagan.rfc1925.org systemd[1]: php5-fpm.service operation timed out. Terminating.
> Feb 06 11:15:18 pagan.rfc1925.org systemd[1]: php5-fpm.service stopping timed out (2). Killing.
> Feb 06 11:15:18 pagan.rfc1925.org systemd[1]: Failed to start The PHP FastCGI Process Manager.
> Feb 06 11:15:18 pagan.rfc1925.org systemd[1]: Unit php5-fpm.service entered failed state.
>
> The php5-fpm.service job is quite simple:
>
> # cat /lib/systemd/system/php5-fpm.service
> [Unit]
> Description=The PHP FastCGI Process Manager
> After=network.target
>
> [Service] 
> Type=notify
I think this may be the problem. systemd expects an sd_notify() call,
but doesn’t get one. I haven’t verified if php5-fpm actually supports
that. But this explains why the unit state is “timeout”.

> PIDFile=/var/run/php5-fpm.pid
> ExecStartPre=/usr/lib/php5/php5-fpm-checkconf
> ExecStart=/usr/sbin/php5-fpm --nodaemonize --fpm-config /etc/php5/fpm/php-fpm.conf
> ExecReload=/bin/kill -USR2 $MAINPID
>
> [Install]
> WantedBy=multi-user.target
>
> *** *** ***
>
> I see two problems here:
>
> * There was a monit job monitoring php5-fpm and starting it with
>   "/etc/init.d/php5-fpm start" when the service was not running.  Thus
>   the php5-fpm failed to start because there was already some other
>   process listening to the socket.
>
>   SO - it seems there's some bad interaction between running the old
>   shell script and the new php5-fpm.service.
Note that /etc/init.d/php5-fpm, when running on a machine with systemd
as PID 1, will just divert any invocations to systemctl. I.e., there is
no inherent conflict between monit interacting with the init script and
using systemd.

So, in conclusion, I think we should gather some more information here,
but I don’t have time to reproduce the bug right now.

-- 
Best regards,
Michael