Willy, William, Vincent,

apparently systemd's behaviour changed regarding reloads. When one of the
reload commands fails it apparently starts stopping the service.

At first I thought it was some bad systemd configuration on my end, but
after seeing HAProxy die on me for the bazillionth time because of a bad
configuration I started investigating.

I cannot reproduce the issue on my Ubuntu 16.04 with systemd 229. I can
reproduce it on a Debian Buster machine with systemd 232.

I'm not fully convinced that this patch:

- is correct, because I am not sure whether "waitpid" mode is doing
  something bad. That's why I Cc William.
- is the best solution. It certainly isn't because the `reload` succeeds,
  while actually it does not. Maybe there's some systemd knob that
  improves on that behaviour. I Cc Vincent as the Debian maintainer of
  HAProxy, because that's the thing I run in production.

So basically this email is to bring attention to the issue and to confirm
it's not just me who is holding systemd wrong (I'm seeing that same issue
with Debian's nginx package, though). This patch is absolutely RFC only
and probably should not be merged as is without some discussion. It's
certainly the longest commit message I ever wrote ...

Best regards
Tim Düsterhus

Apply with `git am --scissors` to automatically cut the commit message.
-- >8 --
Subject: [RFC PATCH] BUG/MINOR: systemd: Remove configuration check for reloads

Apparently newer systemd versions kill the service when one of the
`ExecReload=` commands fails instead of just failing the reload.

See the following example with `haproxy.service` being as provided by
the Debian project.

Note the "Active: failed" after the first bad reload. After adjusting
the unit file HAProxy continues running in "waitpid" mode when the config
is bad, systemd does not return an error though. Thus the admin might not
notice that there was an issue.

Good config
===========

root@example:~# systemctl start haproxy
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: active (running) since Mon 2019-09-30 22:17:18 UTC; 2s ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16227 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=0/SUCCESS)
 Main PID: 16228 (haproxy)
    Tasks: 2 (limit: 2301)
   Memory: 6.8M
   CGroup: /system.slice/haproxy.service
           ├─16228 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock
           └─16229 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock

Sep 30 22:17:18 example.com systemd[1]: Starting HAProxy Load Balancer...
Sep 30 22:17:18 example.com haproxy[16228]: Proxy http started.
Sep 30 22:17:18 example.com haproxy[16228]: Proxy https started.
Sep 30 22:17:18 example.com haproxy[16228]: [NOTICE] 272/221718 (16228) : New 
worker #1 (16229) forked
Sep 30 22:17:18 example.com systemd[1]: Started HAProxy Load Balancer.

Reload with bad config
======================

root@example:~# echo 'foo' >> /etc/haproxy/haproxy.cfg
root@example:~# systemctl reload haproxy
Job for haproxy.service failed because the control process exited with error 
code.
See "systemctl status haproxy.service" and "journalctl -xe" for details.
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: failed (Result: exit-code) since Mon 2019-09-30 22:17:45 UTC; 315ms 
ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16255 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=1/FAILURE)

Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Control process 
exited, code=exited, status=1/FAILURE
Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Failed with result 
'exit-code'.
Sep 30 22:17:45 example.com systemd[1]: Failed to start HAProxy Load Balancer.
Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Service 
RestartSec=100ms expired, scheduling restart.
Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Scheduled restart job, 
restart counter is at 6.
Sep 30 22:17:45 example.com systemd[1]: Stopped HAProxy Load Balancer.
Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Start request repeated 
too quickly.
Sep 30 22:17:45 example.com systemd[1]: haproxy.service: Failed with result 
'exit-code'.
Sep 30 22:17:45 example.com systemd[1]: Failed to start HAProxy Load Balancer.

Fix config
==========

root@example:~# sed -i '/foo/d' /etc/haproxy/haproxy.cfg
root@example:~# systemctl restart haproxy
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: active (running) since Mon 2019-09-30 22:18:05 UTC; 2s ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16261 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=0/SUCCESS)
 Main PID: 16262 (haproxy)
    Tasks: 2 (limit: 2301)
   Memory: 6.8M
   CGroup: /system.slice/haproxy.service
           ├─16262 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock
           └─16263 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock

Sep 30 22:18:05 example.com systemd[1]: Starting HAProxy Load Balancer...
Sep 30 22:18:05 example.com haproxy[16262]: Proxy http started.
Sep 30 22:18:05 example.com haproxy[16262]: Proxy https started.
Sep 30 22:18:05 example.com haproxy[16262]: [NOTICE] 272/221805 (16262) : New 
worker #1 (16263) forked
Sep 30 22:18:05 example.com systemd[1]: Started HAProxy Load Balancer.

Adjust systemd
==============

root@example:~# sed -i '/ExecReload=\/usr\//d' 
/lib/systemd/system/haproxy.service
root@example:~# systemctl daemon-reload
root@example:~# systemctl restart haproxy
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: active (running) since Mon 2019-09-30 22:19:15 UTC; 2s ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16318 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=0/SUCCESS)
 Main PID: 16319 (haproxy)
    Tasks: 2 (limit: 2301)
   Memory: 6.7M
   CGroup: /system.slice/haproxy.service
           ├─16319 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock
           └─16320 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock

Sep 30 22:19:15 example.com systemd[1]: Starting HAProxy Load Balancer...
Sep 30 22:19:15 example.com haproxy[16319]: Proxy http started.
Sep 30 22:19:15 example.com haproxy[16319]: Proxy https started.
Sep 30 22:19:15 example.com haproxy[16319]: [NOTICE] 272/221915 (16319) : New 
worker #1 (16320) forked
Sep 30 22:19:15 example.com systemd[1]: Started HAProxy Load Balancer.

Bad config
==========

root@example:~# echo 'foo' >> /etc/haproxy/haproxy.cfg
root@example:~# systemctl reload haproxy
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: active (running) since Mon 2019-09-30 22:19:15 UTC; 14s ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16318 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=0/SUCCESS)
  Process: 16325 ExecReload=/bin/kill -USR2 $MAINPID (code=exited, 
status=0/SUCCESS)
 Main PID: 16319 (haproxy)
    Tasks: 2 (limit: 2301)
   Memory: 7.9M
   CGroup: /system.slice/haproxy.service
           ├─16319 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock
           └─16320 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock

Sep 30 22:19:15 example.com haproxy[16319]: [NOTICE] 272/221915 (16319) : New 
worker #1 (16320) forked
Sep 30 22:19:15 example.com systemd[1]: Started HAProxy Load Balancer.
Sep 30 22:19:25 example.com systemd[1]: Reloading HAProxy Load Balancer.
Sep 30 22:19:25 example.com haproxy[16319]: [WARNING] 272/221925 (16319) : 
Reexecuting Master process
Sep 30 22:19:25 example.com haproxy[16319]: [ALERT] 272/221925 (16319) : 
parsing [/etc/haproxy/haproxy.cfg:107] : unknown keyword 'foo' in 'backend' 
section
Sep 30 22:19:25 example.com haproxy[16319]: [ALERT] 272/221925 (16319) : 
Error(s) found in configuration file : /etc/haproxy/haproxy.cfg
Sep 30 22:19:25 example.com haproxy[16319]: [ALERT] 272/221925 (16319) : Fatal 
errors found in configuration.
Sep 30 22:19:25 example.com haproxy[16319]: [WARNING] 272/221925 (16319) : 
Reexecuting Master process in waitpid mode
Sep 30 22:19:25 example.com haproxy[16319]: [WARNING] 272/221925 (16319) : 
Reexecuting Master process
Sep 30 22:19:25 example.com systemd[1]: Reloaded HAProxy Load Balancer.

Fix config
==========

root@example:~# sed -i '/foo/d' /etc/haproxy/haproxy.cfg
root@example:~# systemctl reload haproxy
root@example:~# systemctl status haproxy
● haproxy.service - HAProxy Load Balancer
   Loaded: loaded (/lib/systemd/system/haproxy.service; enabled; vendor preset: 
enabled)
   Active: active (running) since Mon 2019-09-30 22:19:15 UTC; 40s ago
     Docs: man:haproxy(1)
           file:/usr/share/doc/haproxy/configuration.txt.gz
  Process: 16318 ExecStartPre=/usr/sbin/haproxy -f $CONFIG -c -q $EXTRAOPTS 
(code=exited, status=0/SUCCESS)
  Process: 16333 ExecReload=/bin/kill -USR2 $MAINPID (code=exited, 
status=0/SUCCESS)
 Main PID: 16319 (haproxy)
    Tasks: 2 (limit: 2301)
   Memory: 7.0M
   CGroup: /system.slice/haproxy.service
           ├─16319 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock -sf 16320
           └─16334 /usr/sbin/haproxy -Ws -f /etc/haproxy/haproxy.cfg -p 
/run/haproxy.pid -S /run/haproxy-master.sock -sf 16320

Sep 30 22:19:54 example.com haproxy[16319]: [WARNING] 272/221954 (16320) : 
Proxy GLOBAL stopped (FE: 0 conns, BE: 0 conns).
Sep 30 22:19:54 example.com haproxy[16319]: [WARNING] 272/221954 (16320) : 
Proxy http stopped (FE: 0 conns, BE: 0 conns).
Sep 30 22:19:54 example.com haproxy[16319]: Proxy http stopped (FE: 0 conns, 
BE: 0 conns).
Sep 30 22:19:54 example.com haproxy[16319]: [WARNING] 272/221954 (16320) : 
Proxy https stopped (FE: 0 conns, BE: 0 conns).
Sep 30 22:19:54 example.com haproxy[16319]: Proxy https stopped (FE: 0 conns, 
BE: 0 conns).
Sep 30 22:19:54 example.com haproxy[16319]: [NOTICE] 272/221954 (16319) : New 
worker #1 (16334) forked
Sep 30 22:19:54 example.com systemd[1]: Reloaded HAProxy Load Balancer.
Sep 30 22:19:54 example.com haproxy[16319]: [WARNING] 272/221954 (16319) : 
Former worker #1 (16320) exited with code 0 (Exit)
---
 contrib/systemd/haproxy.service.in | 1 -
 1 file changed, 1 deletion(-)

diff --git a/contrib/systemd/haproxy.service.in 
b/contrib/systemd/haproxy.service.in
index 9b7c3d1bb..a2bffc9b8 100644
--- a/contrib/systemd/haproxy.service.in
+++ b/contrib/systemd/haproxy.service.in
@@ -8,7 +8,6 @@ EnvironmentFile=-/etc/sysconfig/haproxy
 Environment="CONFIG=/etc/haproxy/haproxy.cfg" "PIDFILE=/run/haproxy.pid" 
"EXTRAOPTS=-S /run/haproxy-master.sock"
 ExecStartPre=@SBINDIR@/haproxy -f $CONFIG -c -q $EXTRAOPTS
 ExecStart=@SBINDIR@/haproxy -Ws -f $CONFIG -p $PIDFILE $EXTRAOPTS
-ExecReload=@SBINDIR@/haproxy -f $CONFIG -c -q $EXTRAOPTS
 ExecReload=/bin/kill -USR2 $MAINPID
 KillMode=mixed
 Restart=always
-- 
2.23.0


Reply via email to