I have the following units:
test_socket_activation.socket
[Unit]
Description="************** MY TEST SOCKET ***************"
PartOf=test_socket_activation.service
[Socket]
ListenStream=127.0.0.1:9991
[Install]
WantedBy=sockets.target
test_socket_activation.service
[Unit]
Description="********** MY TEST SERVICE *****************"
[Service]
ExecStart=/home/xxx/sysadmin/systemd_units/socket_based_activation/testservice.sh
[Install]
WantedBy=multi-user.target
testservice.sh
#!/bin/bash
echo "Socket Service Triggered" > output.txt
In theory systemd should be listening on 127.0.0.1 port 9991 (via test_scocket_activation.socket). When the socket is accessed, systemd should call the parent unit (test_scocket_activation.service), which in turn should execute the script listed in the ExecStart directive (testservice.sh) which would then create a text file named output.txt to notify that the socket has been accessed.
This works as expected (i.e output.txt is created when the socket is accessed) except that the service unit (test_scocket_activation.service) fails afterwards due to "start request repeated too quickly, refusing to start" even though the socket is only accessed once. The failure of the service then triggers a failure of the associated socket, which stops listening.
I did some testing here are my steps and log outputs:
❯ sudo systemctl start test_socket_activation.socket
❯ sudo systemctl status test_socket_activation.socket
● test_socket_activation.socket - "************** MY TEST SOCKET ***************"
Loaded: loaded (/etc/systemd/system/test_socket_activation.socket; disabled)
Active: active (listening) since Thu 2020-03-19 14:08:40 +01; 17s ago
Listen: 127.0.0.1:9991 (Stream)
Mar 19 14:08:40 toshi systemd[1]: Starting "************** MY TEST SOCKET ***************".
Mar 19 14:08:40 toshi systemd[1]: Listening on "************** MY TEST SOCKET ***************".
❯ echo "hello" | netcat 127.0.0.1 9991
❯ ls
output.txt testservice.sh
❯ sudo systemctl status test_socket_activation.service
● test_socket_activation.service - "********** MY TEST SERVICE *****************"
Loaded: loaded (/etc/systemd/system/test_socket_activation.service; disabled)
Active: failed (Result: start-limit) since Thu 2020-03-19 14:10:42 +01; 9min ago
Process: 2842 ExecStart=/home/mkr/sysadmin/systemd_units/socket_based_activation/testservice.sh (code=exited, status=0/SUCCESS)
Main PID: 2842 (code=exited, status=0/SUCCESS)
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: test_socket_activation.service start request repeated too quickly, refusing to start.
Mar 19 14:10:42 toshi systemd[1]: Failed to start "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Unit test_socket_activation.service entered failed state.
❯ sudo systemctl status test_socket_activation.socket
● test_socket_activation.socket - "************** MY TEST SOCKET ***************"
Loaded: loaded (/etc/systemd/system/test_socket_activation.socket; disabled)
Active: failed (Result: service-failed-permanent) since Thu 2020-03-19 14:10:42 +01; 41s ago
Listen: 127.0.0.1:9991 (Stream)
Mar 19 14:08:40 toshi systemd[1]: Starting "************** MY TEST SOCKET ***************".
Mar 19 14:08:40 toshi systemd[1]: Listening on "************** MY TEST SOCKET ***************".
Mar 19 14:10:42 toshi systemd[1]: Unit test_socket_activation.socket entered failed state.
❯ sudo journalctl -u test_socket_activation.service
-- Logs begin at Thu 2020-03-19 14:05:23 +01, end at Thu 2020-03-19 14:17:29 +01. --
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: Started "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Starting "********** MY TEST SERVICE *****************"...
Mar 19 14:10:42 toshi systemd[1]: test_socket_activation.service start request repeated too quickly, refusing to start.
Mar 19 14:10:42 toshi systemd[1]: Failed to start "********** MY TEST SERVICE *****************".
Mar 19 14:10:42 toshi systemd[1]: Unit test_socket_activation.service entered failed state.
As you can see above, the socket is accessed ONCE only, the service is triggered and it does call upon the script to create the output.txt file. But shortly after the service fails as it tries to start multiple times.
My questions are as follows:
Why is the service starting more than once, when the socket is only accessed once (via echo "hello" | netcat 127.0.0.1 9991)?
How can I avoid having the service start multiple times when the associated socket is only accessed once?
All answers / input / insights would be greatly appreciated, thanks.
