sslh depends on nscd

[symphorien]

Describe the bug
Since 20.09, sslh runs as a DynamicUser but its iptables require the username to resolve. If nscd and sslh are restarted as the same time (happens on system update) nscd is not ready and the username does not resolve, and sslh fails.

Nov 29 05:39:19 blitiri sslh-pre-start[22263]: iptables v1.8.5 (legacy): owner: Bad value for "--uid-owner" option: "sslh"
Nov 29 05:39:19 blitiri sslh-pre-start[22263]: Try `iptables -h' or 'iptables --help' for more information.
Nov 29 05:39:19 blitiri systemd[1]: sslh.service: Control process exited, code=exited, status=2/INVALIDARGUMENT
Nov 29 05:39:20 blitiri sslh-post-stop[22290]: iptables v1.8.5 (legacy): owner: Bad value for "--uid-owner" option: "sslh"
Nov 29 05:39:20 blitiri sslh-post-stop[22290]: Try `iptables -h' or 'iptables --help' for more information.
Nov 29 05:39:20 blitiri systemd[1]: sslh.service: Control process exited, code=exited, status=2/INVALIDARGUMENT
Nov 29 05:39:20 blitiri systemd[1]: sslh.service: Failed with result 'exit-code'.
Nov 29 05:39:21 blitiri systemd[1]: sslh.service: Scheduled restart job, restart counter is at 1.
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring file `/etc/passwd` (1)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring file `/etc/group` (3)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:31 blitiri sslh-pre-start[22545]: RTNETLINK answers: File exists
Nov 29 05:39:31 blitiri systemd[1]: sslh.service: Control process exited, code=exited, status=2/INVALIDARGUMENT
Nov 29 05:39:31 blitiri systemd[1]: sslh.service: Failed with result 'exit-code'.
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring file `/etc/passwd` (1)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring file `/etc/group` (3)
Nov 29 05:39:31 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:31 blitiri nixos-upgrade-start[21772]: Job for sslh.service failed because the control process exited with error code.
Nov 29 05:39:31 blitiri nixos-upgrade-start[21772]: See "systemctl status sslh.service" and "journalctl -xe" for details.
Nov 29 05:39:32 blitiri systemd[1]: sslh.service: Scheduled restart job, restart counter is at 2.
Nov 29 05:39:32 blitiri nscd[22139]: 22139 monitoring file `/etc/passwd` (1)
Nov 29 05:39:32 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:32 blitiri nscd[22139]: 22139 monitoring file `/etc/group` (3)
Nov 29 05:39:32 blitiri nscd[22139]: 22139 monitoring directory `/etc` (2)
Nov 29 05:39:34 blitiri sslh[22586]: sslh-fork v1.21c started
Nov 29 05:39:34 blitiri sslh[22586]: sslh-fork v1.21c started

To Reproduce
(Untested):
enable sslh with services.sslh.transparent = true
restart sslh and nscd at the same time

Expected behavior
sslh starts successfully on the first try

I'll open a PR shortly

Notify maintainers

@fpletz @koral

Metadata

• system: "x86_64-linux"
• host os: Linux 5.8.18, NixOS, 20.09.2090.e111e9d4c05 (Nightingale)
• multi-user?: yes
• sandbox: yes
• version: nix-env (Nix) 2.3.9
• channels(root): "nixos-20.09.2090.e111e9d4c05, nixos-unstable-21.03pre246543.24c9b05ac53"
• channels(symphorien): "home-manager-20.09"
• nixpkgs: /nix/var/nix/profiles/per-user/root/channels/nixos

Maintainer information:

# a list of nixpkgs attributes affected by the problem
attribute:
# a list of nixos modules affected by the problem
module: sslh

[stale]

I marked this as stale due to inactivity. → More info

[symphorien]

It still happened to me today, on 21.05.

The PR fixing this is still open #106336

[dasJ]

Can you check if the problem happens less often when you do systemd.services.nscd.stopIfChanged = false?

[symphorien]

I saw your message but I don't have time to dedicate this right now (and I think I don't keep logs long enough to get stats from my existing system to compare with). I intend to answer later.

[symphorien]

So I took the time to make some rough statistics: it happened about twice a month in 2021 and once a month in 2022 (it's not 100% reliable because I don't keep logs so long). I'm adding systemd.services.nscd.stopIfChanged = false and I can get back to you next year :)

[dasJ]

We have that in our downstream repo and we haven't had any issues like this for months (years?) so I hope this fixes it for you

[dasJ]

I finally wrote nscd-wait, this should make it possible to wait for nscd to start, eliminating most races.
Intended use is:

{
  systemd.services.nscd.ExecStartPost = "${pkgs.wait-nscd}/bin/wait-nscd";
}

[symphorien]

So I took the time to make some rough statistics: it happened about twice a month in 2021 and once a month in 2022 (it's not 100% reliable because I don't keep logs so long). I'm adding systemd.services.nscd.stopIfChanged = false and I can get back to you next year :)

the issue does not happen anymore. Honestly I lost track of all the attempted fixes, and anyway nscd is not used for non overlaid packages anymore, so feel free to close or not.