search

rootless-containers / rootlesskit

Linux-native "fake root" for implementing rootless containers
Apache License 2.0
988 stars 98 forks source link

lxc-user-nic make docker panic (`panic: could not exchange DHCP with eth0: timed out while listening for replies`) #387

Open changsu-axq opened 1 year ago

changsu-axq commented 1 year ago

problem

Docker suddenly crashed and cannot start , 

journalctl --since "14:04"

found

Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]: panic: could not exchange DHCP with eth0: timed out while listening for replies
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]: goroutine 7 [running]:
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]: github.com/rootless-containers/rootlesskit/pkg/network/lxcusernic.dhcpRenewRoutine(0xc0001db620, 0xc000190358, 0x4, 0x
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]:         /go/src/github.com/rootless-containers/rootlesskit/pkg/network/lxcusernic/lxcusernic.go:160 +0x2e3
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]: created by github.com/rootless-containers/rootlesskit/pkg/network/lxcusernic.(*childDriver).ConfigureNetworkChild
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]:         /go/src/github.com/rootless-containers/rootlesskit/pkg/network/lxcusernic/lxcusernic.go:147 +0x853
Jul 28 14:04:57 ip-1 dockerd-rootless.sh[4576]: [rootlesskit:parent] error: child exited: exit status 2

version

user: 

oq

dnsmasq info

lxc-dns+    1575  0.7  0.0  53352  2388 ?        S    Jul27   9:18 dnsmasq -u lxc-dnsmasq --strict-order --bind-interfaces --pid-file=/run/lxc/dnsmasq.pid --listen-address 10.0.3.1 --dhcp-range 10.0.3.2,10.0.3.254 --dhcp-lease-max=253 --dhcp-no-override --except-interface=lo --interface=lxcbr0 --dhcp-leasefile=/var/lib/misc/dnsmasq.lxcbr0.leases --dhcp-authoritative

rootlesskit version

rootlesskit version 1.1.0

lxc version

lxc --version
3.0.3

cat /etc/lxc/lxc-usernet

# USERNAME TYPE BRIDGE COUNT
oq    veth lxcbr0 10

Ask

AkihiroSuda commented 1 year ago

Why does the DHCP timeout occur?

sudo journalctl --no-pager -u lxc-net may show some hint.

Why does the DHCP timeout directly cause a panic? Is there a way to gracefully degrade instead?

This is a bug and has to be fixed.

changsu-axq commented 1 year ago

The incident occurred around 14:04. It can be seen that dnsmasq received the request and offer an address, but rootlesskit did not receive the DHCPOFFER packet, thus timing out.

ul 28 13:10:27 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 2e:c2:d9:ab:be:61
Jul 28 13:10:27 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.75 2e:c2:d9:ab:be:61
Jul 28 13:10:27 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.75 2e:c2:d9:ab:be:61
Jul 28 13:10:27 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.75 2e:c2:d9:ab:be:61
Jul 28 14:04:27 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 2e:c2:d9:ab:be:61
Jul 28 14:04:27 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.75 2e:c2:d9:ab:be:61
Jul 28 14:05:26 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) b2:50:e9:ae:9c:81
Jul 28 14:05:26 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.228 b2:50:e9:ae:9c:81
Jul 28 14:05:26 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.228 b2:50:e9:ae:9c:81
Jul 28 14:05:26 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.228 b2:50:e9:ae:9c:81
Jul 28 14:05:46 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 3a:79:28:63:34:ab
Jul 28 14:05:46 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.254 3a:79:28:63:34:ab
Jul 28 14:05:46 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.254 3a:79:28:63:34:ab
Jul 28 14:05:46 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.254 3a:79:28:63:34:ab
Jul 28 14:06:07 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) f6:09:b1:c2:9a:b7
Jul 28 14:06:07 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.78 f6:09:b1:c2:9a:b7
Jul 28 14:06:07 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.78 f6:09:b1:c2:9a:b7
Jul 28 14:06:07 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.78 f6:09:b1:c2:9a:b7
Jul 28 14:06:27 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 36:b9:0a:1e:31:8d
Jul 28 14:06:27 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.221 36:b9:0a:1e:31:8d
Jul 28 14:06:27 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.221 36:b9:0a:1e:31:8d
Jul 28 14:06:27 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.221 36:b9:0a:1e:31:8d
Jul 28 14:06:48 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 76:38:e8:e9:f0:ef
Jul 28 14:06:48 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.65 76:38:e8:e9:f0:ef
Jul 28 14:06:48 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.65 76:38:e8:e9:f0:ef
Jul 28 14:06:48 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.65 76:38:e8:e9:f0:ef
Jul 28 14:07:08 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) ba:ff:92:12:1b:1c
Jul 28 14:07:08 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.18 ba:ff:92:12:1b:1c
Jul 28 14:07:08 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.18 ba:ff:92:12:1b:1c
Jul 28 14:07:08 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.18 ba:ff:92:12:1b:1c
Jul 28 14:07:29 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 66:ce:6b:a0:70:d1
Jul 28 14:07:29 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.105 66:ce:6b:a0:70:d1
Jul 28 14:07:29 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.105 66:ce:6b:a0:70:d1
Jul 28 14:07:29 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.105 66:ce:6b:a0:70:d1
Jul 28 14:07:49 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 0a:87:3a:b9:e7:7a
Jul 28 14:07:49 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.8 0a:87:3a:b9:e7:7a
Jul 28 14:07:49 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.8 0a:87:3a:b9:e7:7a
Jul 28 14:07:49 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.8 0a:87:3a:b9:e7:7a
Jul 28 14:08:10 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) da:89:4f:16:1b:07
Jul 28 14:08:10 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.232 da:89:4f:16:1b:07
Jul 28 14:08:10 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.232 da:89:4f:16:1b:07
Jul 28 14:08:10 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.232 da:89:4f:16:1b:07
Jul 28 14:08:30 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 26:52:e4:43:dc:b1
Jul 28 14:08:30 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.109 26:52:e4:43:dc:b1
Jul 28 14:08:30 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.109 26:52:e4:43:dc:b1
Jul 28 14:08:30 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.109 26:52:e4:43:dc:b1
Jul 28 14:08:51 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 76:a9:5e:62:4a:21
Jul 28 14:08:51 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.54 76:a9:5e:62:4a:21
Jul 28 14:08:51 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.54 76:a9:5e:62:4a:21
Jul 28 14:08:51 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.54 76:a9:5e:62:4a:21
Jul 28 14:09:11 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 06:2e:fc:5a:7d:4e
Jul 28 14:09:11 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.173 06:2e:fc:5a:7d:4e
Jul 28 14:09:11 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.173 06:2e:fc:5a:7d:4e
Jul 28 14:09:11 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.173 06:2e:fc:5a:7d:4e
Jul 28 14:09:32 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) aa:f2:00:89:c6:7b
Jul 28 14:09:32 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.122 aa:f2:00:89:c6:7b
Jul 28 14:09:32 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.122 aa:f2:00:89:c6:7b
Jul 28 14:09:32 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.122 aa:f2:00:89:c6:7b
Jul 28 14:09:52 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 8e:30:fe:73:9e:07
Jul 28 14:09:52 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.125 8e:30:fe:73:9e:07
Jul 28 14:09:52 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.125 8e:30:fe:73:9e:07
Jul 28 14:09:52 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.125 8e:30:fe:73:9e:07
Jul 28 14:10:13 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) e6:7d:6e:14:2a:c3
Jul 28 14:10:13 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.192 e6:7d:6e:14:2a:c3
Jul 28 14:10:13 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.192 e6:7d:6e:14:2a:c3
Jul 28 14:10:13 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.192 e6:7d:6e:14:2a:c3
Jul 28 14:10:33 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 36:2b:87:bc:d4:4e
Jul 28 14:10:33 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.214 36:2b:87:bc:d4:4e
Jul 28 14:10:33 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.214 36:2b:87:bc:d4:4e
Jul 28 14:10:33 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.214 36:2b:87:bc:d4:4e
Jul 28 14:10:54 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 42:40:ab:39:7c:2c
Jul 28 14:10:54 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.123 42:40:ab:39:7c:2c
Jul 28 14:10:54 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.123 42:40:ab:39:7c:2c
Jul 28 14:10:54 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.123 42:40:ab:39:7c:2c
Jul 28 14:12:18 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 22:4e:eb:45:68:62
Jul 28 14:12:18 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.196 22:4e:eb:45:68:62
Jul 28 14:12:18 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.196 22:4e:eb:45:68:62
Jul 28 14:12:18 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.196 22:4e:eb:45:68:62
Jul 28 14:12:38 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 3a:56:cb:4c:a3:36
Jul 28 14:12:38 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.104 3a:56:cb:4c:a3:36
Jul 28 14:12:38 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.104 3a:56:cb:4c:a3:36
Jul 28 14:12:38 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.104 3a:56:cb:4c:a3:36
Jul 28 14:12:59 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) ce:c0:35:0d:08:ba
Jul 28 14:12:59 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.229 ce:c0:35:0d:08:ba
Jul 28 14:12:59 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.229 ce:c0:35:0d:08:ba
Jul 28 14:12:59 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.229 ce:c0:35:0d:08:ba
Jul 28 14:13:19 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) ea:da:d3:ba:f4:68
Jul 28 14:13:19 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.15 ea:da:d3:ba:f4:68
Jul 28 14:13:19 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.15 ea:da:d3:ba:f4:68
Jul 28 14:13:19 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.15 ea:da:d3:ba:f4:68
Jul 28 14:13:40 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 42:7d:41:88:4e:62
Jul 28 14:13:40 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.29 42:7d:41:88:4e:62
Jul 28 14:13:40 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.29 42:7d:41:88:4e:62
Jul 28 14:13:40 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.29 42:7d:41:88:4e:62
Jul 28 14:14:00 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) 8a:00:bd:b3:e5:2b
Jul 28 14:14:00 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.180 8a:00:bd:b3:e5:2b
Jul 28 14:14:00 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.180 8a:00:bd:b3:e5:2b
Jul 28 14:14:00 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.180 8a:00:bd:b3:e5:2b
Jul 28 14:27:55 ip-1 dnsmasq-dhcp[1575]: DHCPDISCOVER(lxcbr0) ba:d2:0c:1b:83:2e
Jul 28 14:27:55 ip-1 dnsmasq-dhcp[1575]: DHCPOFFER(lxcbr0) 10.0.3.38 ba:d2:0c:1b:83:2e
Jul 28 14:27:55 ip-1 dnsmasq-dhcp[1575]: DHCPREQUEST(lxcbr0) 10.0.3.38 ba:d2:0c:1b:83:2e
Jul 28 14:27:55 ip-1 dnsmasq-dhcp[1575]: DHCPACK(lxcbr0) 10.0.3.38 ba:d2:0c:1b:83:2e
Jul 28 20:00:01 ip-1 systemd[1]: Stopping LXC network bridge setup...
Jul 28 20:00:02 ip-1 systemd[1]: Stopped LXC network bridge setup.

I dont know why the rootlesskit cant receive a response package....

But I think it may need some retry or background logic to request dnsmasq more times