Slow portmaster restart after portmaster-start release

[northys]

Checklist:

• I'm using the official portmaster release (i.e no custom builds)
• I searched for similar/existing issues first.
• My issue is not mentioned in the Known Issues section of my OS

What happened:

Since portmaster-start was introduced together with new systemd unit file the systemctl restart portmaster.service takes really long. Let's say 2 minutes.

What you expected to happen:

Portmaster restarts as usually in few seconds.

How to reproduce it (as minimally and precisely as possible):

1. ubuntu with systemd-resolve, no custom dns stuff + portmaster
2. systemctl restart portmaster
3. wait 2 minutes untill restart

Anything else we need to know?:

When I restart portmaster using the restart button in dashboard it takes ~2 seconds.

Environment:

LOGLEVEL=trace
PORTMASTER_ARGS="--experimental-nfqueue"

Portmaster Version:

Name: Portmaster
Version: 0.5.1
Commit: tags/v0.5.1-0-g6ded9b3f8cf9b0bff1ccb310eca3367bd6292d5b
Build Options: main.go
Build User: user
Build Host: docker
Build Date: 10.08.2020
Build Source: https://github.com/safing/portmaster

Operating System:

• Windows 7
• Windows 8/8.1
• Windows 10
• Linux

NAME="Ubuntu"
VERSION="20.04.1 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.1 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal

If applicable you can provide related sections from the log files and ensure to remove sensitive or otherwise private information.

[dhaavi]

We had a problem with a timeout on shutdown. This should be fixed in v0.5.2, please test again with the newest version.

[northys]

@dhaavi works, thanks

[northys]

@dhaavi it doesn't work. it timeouts when problem described in #132 happens.

<INTERRUPT> again, but already shutting down. 4 more to force. is me trying to killall portmaster-start

srp 12 15:46:30 northys-laptop systemd[1]: Stopping Portmaster by Safing...
srp 12 15:47:16 northys-laptop portmaster-start[206373]: [control] 2020/08/12 13:47:16 got terminated signal (ignoring), waiting for child to exit...
srp 12 15:47:25 northys-laptop portmaster-start[206373]:  <INTERRUPT> again, but already shutting down. 4 more to force.
srp 12 15:47:31 northys-laptop portmaster-start[206373]: [control] 2020/08/12 13:47:31 got terminated signal (ignoring), waiting for child to exit...
srp 12 15:47:33 northys-laptop portmaster-start[206373]:  <INTERRUPT> again, but already shutting down. 3 more to force.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: State 'stop-sigterm' timed out. Killing.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206373 (portmaster-star) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206533 (portmaster-core) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206532 (portmaster-star) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206540 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206541 (portmaster-core) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206560 (portmaster-core) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206561 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206562 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206564 (portmaster-core) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206660 (portmaster-core) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206792 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206793 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Killing process 206874 (n/a) with signal SIGKILL.
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Main process exited, code=killed, status=9/KILL
srp 12 15:48:00 northys-laptop iptables[355165]: iptables: No chain/target/match by that name.
srp 12 15:48:00 northys-laptop iptables[355168]: iptables: No chain/target/match by that name.
srp 12 15:48:00 northys-laptop iptables[355170]: iptables: No chain/target/match by that name.
srp 12 15:48:00 northys-laptop bash[355179]: enabled
srp 12 15:48:00 northys-laptop systemd[1]: portmaster.service: Failed with result 'timeout'.
srp 12 15:48:00 northys-laptop systemd[1]: Stopped Portmaster by Safing.
srp 12 15:48:00 northys-laptop systemd[1]: Started Portmaster by Safing.

[dhaavi]

I think is caused by #132 and further confirms our suspicion that the workers created by the nameserver hang because of #132. The shutdown procedure waits for all these workers, until it eventually times out and exits.

[ppacher]

Closing due to inactivity. This should have been resolved already.