Hi Pierre,
On Mon, Oct 24, 2016 at 12:46:34PM +0000, Pierre Cheynier wrote:
> Unfortunately, I remember we had the same issue (but less frequently) on
> CentOS6 which is init-based.
OK but be careful, we used to have other issues with signals in the
past, it's not necessarily exactly the same thing.
> I tried to reproduce, but didn't succeed... So let's ignore that for now, it
> was maybe related to something else.
Yes I prefer not to mix all issues :-)
> > Ah this is getting very interesting. Maybe we should hack systemd-wrapper
> > to log the signals it receives and the signals and pids it sends to see
> > what is happening here. It may also be that the signal is properly sent
> > but never received (but why ?).
>
> Clearly. Apparently I sometimes have a wrong information in the pidfile...
>
> Have a look at journald logs:
>
> Oct 24 12:26:57 haproxys01e02-par haproxy-systemd-wrapper[44319]:
> haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f
> /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds -sf 44941
> Oct 24 12:26:57 haproxys01e02-par haproxy-systemd-wrapper[44319]: [WARNING]
> 297/122657 (44951) : config : 'option forwardfor' ignored for frontend
> 'https-in' as it requires HTTP mode.
> Oct 24 12:27:00 haproxys01e02-par haproxy-systemd-wrapper[44319]:
> haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f
> /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds -sf 44952
> Oct 24 12:27:00 haproxys01e02-par haproxy-systemd-wrapper[44319]: [WARNING]
> 297/122700 (44978) : config : 'option forwardfor' ignored for frontend
> 'https-in' as it requires HTTP mode.
> Oct 24 12:27:05 haproxys01e02-par haproxy-systemd-wrapper[44319]:
> haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f
> /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds -sf 44983
> Oct 24 12:27:05 haproxys01e02-par haproxy-systemd-wrapper[44319]: [WARNING]
> 297/122705 (45131) : config : 'option forwardfor' ignored for frontend
> 'https-in' as it requires HTTP mode.
> Oct 24 12:27:09 haproxys01e02-par haproxy-systemd-wrapper[44319]:
> haproxy-systemd-wrapper: executing /usr/sbin/haproxy -f
> /etc/haproxy/haproxy.cfg -p /run/haproxy.pid -Ds -sf 45132
> Oct 24 12:27:09 haproxys01e02-par haproxy-systemd-wrapper[44319]: [WARNING]
> 297/122709 (45146) : config : 'option forwardfor' ignored for frontend
> 'https-in' as it requires HTTP mode.
>
> Hopefully I've an error in my config, which let me see the process of the
> first child :).
> Here we can the that:
> * 44978 references (-sf) 44952 (child of 44951)
> * 45131 references 44983=nobody that we've seen in the logs... (so 44978 and
> its child will stay alive forever !)
> * 45146 references 45132 (child of 45131)
That's completely strange... but very interesting. I guess we're getting
closer to the root cause of this problem. The fact that you didn't see
44983 in the log is not an issue by itself because it very likely is a
child of 44978. What surprises me however is that 44978 was not seen.
It would be useful to take a timestamped snapshot of your pid file before
each such reload. I'm interested in knowing whether these entries *really*
exist.
What I'm suspecting now is that for any reason sometimes your config takes
time to load (many certs, huge ACL files, FQDN host names for servers adding
a dependency on external DNS, etc). And sometimes a new process might be
restarted before the first one is completely ready. In this case we could
imagine something like this (approximately, still guessing) :
Process A (old) Process B (new)
open(pidfile, O_TRUNC)
write(parent=44978)
write(child=44979)
write(child=44980)
write(child=44981)
write(child=44982)
open(pidfile, O_TRUNC)
write(child=44983)
write(child=45131)
write(child=45132)
write(child=45133)
...
You see the point. In the end you'd have 44983, 45131, 45132, etc... in
the pid file.
This problem could not happen in the past because the reload was synchronous.
But now that it's asynchronous with systemd, there's no way to ensure the
caller waits for the operation to be completed.
At best what we could do is try to lock the pidfile using mandatory
locks (and ignore the error if locks are not implemented as is common
on many embedded systems). This would at least serialize the access to
the pid file, ensuring that nobody writes past each other and that the
file is only read once complete.
I don't know if this is something you're interested in experimenting
with. This is achieved using fcntl(F_SETLKW). It should be done in the
wrapper as well.
Best regards,
Willy
