Fleet loses socket after SIGHUP

[akaspin]

I'm trying to change fleet metadata without restarting fleet daemon under CoreOS. OK (fleet v0.10.0):

core-01 core # systemctl kill -s SIGHUP fleet
core-01 core # journalctl -fu fleet
-- Logs begin at Thu 2015-04-16 02:29:34 UTC. --
Apr 16 02:35:37 core-01 fleetd[1192]: INFO fleet.go:87: Reloading configuration from
Apr 16 02:35:37 core-01 fleetd[1192]: INFO fleet.go:157: Using default config file /etc/fleet/fleet.conf
Apr 16 02:35:37 core-01 fleetd[1192]: INFO fleet.go:94: Restarting server components
Apr 16 02:35:37 core-01 fleetd[1192]: INFO client.go:292: Failed getting response from http://127.0.0.1:4001/: cancelled
Apr 16 02:35:37 core-01 fleetd[1192]: ERROR event.go:105: etcd watcher {Watch /_coreos.com/fleet/job} returned error: cancelled
Apr 16 02:35:37 core-01 fleetd[1192]: INFO client.go:292: Failed getting response from http://127.0.0.1:4001/: cancelled
Apr 16 02:35:37 core-01 fleetd[1192]: ERROR event.go:105: etcd watcher {Watch /_coreos.com/fleet/job} returned error: cancelled
Apr 16 02:35:37 core-01 fleetd[1192]: INFO server.go:152: Establishing etcd connectivity
Apr 16 02:35:37 core-01 fleetd[1192]: ERROR server.go:51: Failed serving HTTP on listener: @
...
core-01 core # /opt/bin/fleetctl list-units
Error retrieving list of units from repository: googleapi: Error 503: fleet server currently unavailable

Any ideas?

[adomenech73]

Are you sure you don't have to renew your discovery token for the cluster? I've seen this message in that situation

[akaspin]

@adomenech73 No. I just want to reload fleetd instead restart.
For now we using own solution for sync fleetd metadata with EC2 metadata (instance tags, EIPs e.t.c.). But I need to restart fleetd on change. It's pain.

[bcwaldon]

@akaspin

1. your specific use-case of needing to reload to change metadata will be addressed by Dynamic Metadata #1077
2. Losing the socket is definitely a bug we need to triage further

[dalbani]

Hey @akaspin, did you find a solution / workaround to this issue?
How do you dynamically update the metadata in fleet after all?

[kayrus]

@dalbani nohow. only restarting fleet. but if you would like to keep all running services and don't restart them use this workaround:

kill -9 $(pidof fleetd); systemctl restart fleet

[dalbani]

@kayrus: that's an interesting workaround, seems to work just fine! 👍

By the way, I've added a little more error logging to api/server.go to see what's going with HUP reloading:

fleetd[1784]: INFO server.go:157: Establishing etcd connectivity 
fleetd[1784]: ERROR server.go:51: Failed serving HTTP on listener: 127.0.0.1:42748 
fleetd[1784]: ERROR server.go:52: accept tcp 127.0.0.1:42748: accept: invalid argument

Any idea where this accept issue come from?

[kayrus]

@dalbani don't know yet. it requires more investigation.

[dongsupark]

I'm looking into this issue, i.e. losing the listener socket after receiving SIGHUP.

I can reproduce it quite easily. After adding some debugging messages, I can see the "invalid argument"too, as @dalbani mentioned.
The listener's address and port number don't change across restarting server components, as expected. But accept() fails with an error like "invalid argument", which means usually "nothing is listening on the socket".

My debug log:

INFO fleetd.go:115: Restarting server components
INFO server.go:216: Stop: listener: 127.0.0.1:46540
DEBUG coreos.go:92: Halting CoreOSMachine.PeriodicRefresh
DEBUG agent.go:78: HeartbeatJobs exiting due to stop signal
DEBUG monitor.go:40: Monitor exiting due to stop signal
DEBUG reconcile.go:80: Reconciler exiting due to stop signal
DEBUG reconcile.go:80: Reconciler exiting due to stop signal
DEBUG coreos.go:37: Created CoreOSMachine with static state {  map[] v0.10.1-184-g94489f7462c1-dirty}
DEBUG coreos.go:171: Attempting to retrieve IP route info from netlink
DEBUG coreos.go:189: Found default route with interface eth0
INFO server.go:119: New: listener: 127.0.0.1:46540
ERROR server.go:48: Serve: before goroutine: 127.0.0.1:46540
INFO server.go:166: Establishing etcd connectivity
ERROR server.go:52: Failed serving HTTP on listener: 127.0.0.1:46540 accept tcp 127.0.0.1:46540: accept: invalid argument

[antrik]

I wonder whether it might be related to #1452 ? Could you check whether it behaves differently on that branch?

[dongsupark]

@antrik Nice catch, thanks for the comment. So I just tested it again, but the issue still remains also with the current master, where #1452 is merged.
I suppose this issue has something to do with the lower layer, socket activation mechanism of go-systemd. When observing the return value of activation.Listeners(), you would probably find out something is not quite right. I'd like to look into it further, probably next week.