0

I have a need to start a script on an http get request from an external machine and I'm using Node.js for this. I want the server to start with the system. Everything is working except that it appears the the server is being started too early in the boot process:

-- Logs begin at Mon 2017-01-23 09:55:21 UTC, end at Mon 2017-01-23 10:36:20 UTC. --
Jan 23 09:55:24 powercontrol systemd[1]: Starting Energenie Listener...
Jan 23 09:55:24 powercontrol systemd[1]: Started Energenie Listener.
Jan 23 09:55:28 powercontrol node[474]: events.js:160
Jan 23 09:55:28 powercontrol node[474]: throw er; // Unhandled 'error' event
Jan 23 09:55:28 powercontrol node[474]: ^
Jan 23 09:55:28 powercontrol node[474]: Error: listen EADDRNOTAVAIL 192.168.40.62:8001
Jan 23 09:55:28 powercontrol node[474]: at Object.exports._errnoException (util.js:1022:11)
Jan 23 09:55:28 powercontrol node[474]: at exports._exceptionWithHostPort (util.js:1045:20)
Jan 23 09:55:28 powercontrol node[474]: at Server._listen2 (net.js:1249:19)
Jan 23 09:55:28 powercontrol node[474]: at listen (net.js:1298:10)
Jan 23 09:55:28 powercontrol node[474]: at doListening (net.js:1397:7)
Jan 23 09:55:28 powercontrol node[474]: at _combinedTickCallback (internal/process/next_tick.js:77:11)
Jan 23 09:55:28 powercontrol node[474]: at process._tickCallback (internal/process/next_tick.js:98:9)
Jan 23 09:55:28 powercontrol node[474]: at Module.runMain (module.js:607:11)
Jan 23 09:55:28 powercontrol node[474]: at run (bootstrap_node.js:420:7)
Jan 23 09:55:28 powercontrol node[474]: at startup (bootstrap_node.js:139:9)
Jan 23 09:55:28 powercontrol systemd[1]: energenie_listener.service: main process exited, code=exited, s
Jan 23 09:55:28 powercontrol systemd[1]: Unit energenie_listener.service entered failed state.
Jan 23 09:55:30 powercontrol systemd[1]: energenie_listener.service holdoff time over, scheduling restar
Jan 23 09:55:30 powercontrol systemd[1]: Stopping Energenie Listener...
Jan 23 09:55:30 powercontrol systemd[1]: Starting Energenie Listener...
Jan 23 09:55:30 powercontrol systemd[1]: Started Energenie Listener.
Jan 23 09:55:31 powercontrol node[565]: events.js:160
Jan 23 09:55:31 powercontrol node[565]: throw er; // Unhandled 'error' event
Jan 23 09:55:31 powercontrol node[565]: ^
Jan 23 09:55:31 powercontrol node[565]: Error: listen EADDRNOTAVAIL 192.168.40.62:8001
Jan 23 09:55:31 powercontrol node[565]: at Object.exports._errnoException (util.js:1022:11)
Jan 23 09:55:31 powercontrol node[565]: at exports._exceptionWithHostPort (util.js:1045:20)
Jan 23 09:55:31 powercontrol node[565]: at Server._listen2 (net.js:1249:19)
Jan 23 09:55:31 powercontrol node[565]: at listen (net.js:1298:10)
Jan 23 09:55:31 powercontrol node[565]: at doListening (net.js:1397:7)
Jan 23 09:55:31 powercontrol node[565]: at _combinedTickCallback (internal/process/next_tick.js:77:11)
Jan 23 09:55:31 powercontrol node[565]: at process._tickCallback (internal/process/next_tick.js:98:9)
Jan 23 09:55:31 powercontrol node[565]: at Module.runMain (module.js:607:11)
Jan 23 09:55:31 powercontrol node[565]: at run (bootstrap_node.js:420:7)
Jan 23 09:55:31 powercontrol node[565]: at startup (bootstrap_node.js:139:9)
Jan 23 09:55:31 powercontrol systemd[1]: energenie_listener.service: main process exited, code=exited, s
Jan 23 09:55:31 powercontrol systemd[1]: Unit energenie_listener.service entered failed state.
Jan 23 09:55:33 powercontrol systemd[1]: energenie_listener.service holdoff time over, scheduling restar
Jan 23 09:55:33 powercontrol systemd[1]: Stopping Energenie Listener...
Jan 23 09:55:33 powercontrol systemd[1]: Starting Energenie Listener...
Jan 23 09:55:33 powercontrol systemd[1]: Started Energenie Listener.
Jan 23 09:55:34 powercontrol node[572]: Server running at http://192.168.40.62:8001/

As you can see, after a couple of failures, the server eventually starts and it works fine after that. The .service file is as follows:

[Unit]
Description=Energenie Listener
After=network.target systemd-journald.service

[Service]
ExecStart=/usr/bin/node /var/opt/energenie/energenie_listener.js
Restart=always
RestartSec=2
User=root
Group=root
Environment=PATH=/usr/bin:/usr/local/bin
Environment=NODE_ENV=production
WorkingDirectory=/var/opt/energenie

[Install]
WantedBy=multi-user.target

As well as After=network.target ..., I tried network-online.target, but it makes no difference.

Should I be waiting for a different service? Which one?

I do have one thought: this machine has a static IP but it's assigned via DHCP. If the problem is that network.target (and network-online.target) is up but the IP I'm trying to claim in the Node script is not yet assigned, presumably I need a service to wait on which will guarantee that the IP address is fully configured. Could this be the problem, and if so, is there a suitable service to depend on?

Bob Sammers
  • 309
  • 2
  • 5
  • 10

2 Answers2

1

This could be an interesting use for socket-based action. Instead of having your service start at boot time, it would start up the first time a network request came in to activate it. By then the DHCP network assignment should be complete!

In your service unit file, you add entry to the [Service] section to declare where STDIN comes from:

StandardInput=socket

Then make a .socket file with the same name as your .service file that looks something like this:

[Unit]
Description=Energenie Listener Socket

[Socket]
# Depending your app, you might also use ListenStream= 
# or ListenSequentialPacket= See man systemd.socket for details
ListenDatagram=192.168.40.62:8001
# Allow binding to addresses that may not be configured yet.
FreeBind=true

[Install]
WantedBy=sockets.target

Make sure to run systemd enable on the socket before rebooting.

For more context, see man systemd.socket or search for posts about [systemd socket activation].

Mark Stosberg
  • 3,771
  • 23
  • 27
  • That is an interesting idea. As most of the point of the server (it's just a RasPi) is to service these requests, I'd rather have the overhead of the service start (small though it is) at boot rather than first request, so I'll stick with the generic address solution I've come to. However, this has opened my eyes to some of the more interesting functions of systemd (which I've never really used before). – Bob Sammers Jan 24 '17 at 10:13
  • Yes, socket activation could allow you to "overbook" the memory use of a lightly server, by loading services on demand and then killing them when they are idle. In this way, the server could run more services then it appears to have memory for (without using swap, which is another option). – Mark Stosberg Jan 24 '17 at 12:14
0

I changed the IP address the server was listening on from the specific one in the question's logs to the wildcard, 0.0.0.0. This appears to have solved the problem (which suggests my suspicions about the DHCP address not having been assigned may have been correct).

This isn't a perfect solution (because I still don't know how to wait for the DHCP-assigned address to be available), but as it doesn't make any practical difference for this particular case, it solves the immediate problem of logged errors.

Bob Sammers
  • 309
  • 2
  • 5
  • 10