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
