Arch Linux

TheCoon

Member

Registered: 2016-05-10

Posts: 42

[SOLVED] System freeze, maybe caused by Docker

I have a headless system which is mostly used for running several Docker containers, using both "docker" and "docker-compose".
I began experiencing different issues with the system a couple weeks ago, something having to do with "i915" which I assumed was related to Intel graphics modules (although this system isn't connected to a monitor/screen). After installing the "mesa" package (as suggested by posts with similar issues) it seems these errors have gone away.

The most recent is a networking issue, and the reason for this thread.
About one week ago I removed the "dhcpcd" package and enabled "systemd-networkd" instead. This didn't play well with Docker networking, and so I disabled "systemd-networkd", and instead set a static IP address using a simple "netctl" configuration file, as described here.
Since then I have two issues, one small*, which I hope to solve soon, another more critical, which is giving me a very hard time:
At some point in the day, usually once, networking simply stops working -- meaning my main and only physical interface "enp1s0" loses connectivity. Therefore I also lose SSH access and can't debug the system, and I have to hard reset the system. I'm working on getting an external monitor to further debug the issue, but at the moment what I do have is the "journalctl" logs from right before connectivity is lost.
Here are the last ~30 lines from the last two days, right before the network went down (chronologically, first lines are older):

May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=7
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=8
May 31 18:49:58 myhostname kernel: audit: type=1325 audit(1590940198.709:72822): table=nat family=2 entries=5
May 31 18:49:58 myhostname kernel: audit: type=1325 audit(1590940198.709:72823): table=nat family=2 entries=7
May 31 18:49:58 myhostname kernel: audit: type=1325 audit(1590940198.709:72824): table=nat family=2 entries=8
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=10
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=11
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=12
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=13
May 31 18:49:58 myhostname kernel: audit: type=1325 audit(1590940198.719:72825): table=nat family=2 entries=10
May 31 18:49:58 myhostname audit: NETFILTER_CFG table=nat family=2 entries=14
May 31 18:49:58 myhostname kernel: eth0: renamed from vetha38bdf8
May 31 18:49:58 myhostname kernel: IPv6: ADDRCONF(NETDEV_CHANGE): vethcd63f02: link becomes ready
May 31 18:49:58 myhostname kernel: br-63548908ed36: port 1(vethcd63f02) entered blocking state
May 31 18:49:58 myhostname kernel: br-63548908ed36: port 1(vethcd63f02) entered forwarding state
May 31 18:49:59 myhostname dockerd[1265]: time="2020-05-31T18:49:59.448984556+03:00" level=info msg="shim reaped" id=9b51d1689d9350eb1f97e1f7d92044df72dceaf905dcb3d90f6aa829e2486cea
May 31 18:49:59 myhostname dockerd[1213]: time="2020-05-31T18:49:59.459205309+03:00" level=info msg="ignoring event" module=libcontainerd namespace=moby topic=/tasks/delete type="*e>
May 31 18:49:59 myhostname audit: NETFILTER_CFG table=nat family=2 entries=51
May 31 18:49:59 myhostname audit: NETFILTER_CFG table=filter family=2 entries=93
May 31 18:49:59 myhostname audit: NETFILTER_CFG table=nat family=2 entries=50
May 31 18:49:59 myhostname kernel: br-63548908ed36: port 1(vethcd63f02) entered disabled state
May 31 18:49:59 myhostname kernel: vetha38bdf8: renamed from eth0
May 31 18:49:59 myhostname systemd-udevd[753720]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
May 31 18:49:59 myhostname kernel: br-63548908ed36: port 1(vethcd63f02) entered disabled state
May 31 18:49:59 myhostname audit: ANOM_PROMISCUOUS dev=vethcd63f02 prom=0 old_prom=256 auid=4294967295 uid=0 gid=0 ses=4294967295
May 31 18:49:59 myhostname kernel: device vethcd63f02 left promiscuous mode
May 31 18:49:59 myhostname kernel: br-63548908ed36: port 1(vethcd63f02) entered disabled state
May 31 18:49:59 myhostname systemd[1279]: run-docker-netns-c45f8c147a8c.mount: Succeeded.
May 31 18:49:59 myhostname systemd[1]: run-docker-netns-c45f8c147a8c.mount: Succeeded.
May 31 18:49:59 myhostname systemd[1]: var-lib-docker-containers-9b51d1689d9350eb1f97e1f7d92044df72dceaf905dcb3d90f6aa829e2486cea-mounts-shm.mount: Succeeded.
May 31 18:49:59 myhostname systemd[1279]: var-lib-docker-containers-9b51d1689d9350eb1f97e1f7d92044df72dceaf905dcb3d90f6aa829e2486cea-mounts-shm.mount: Succeeded.
May 31 18:49:59 myhostname systemd[1279]: var-lib-docker-overlay2-c4e7ea524e1ca52cdf4e7798c06352550361e8ca86c928fd0bde68c4a3e6d668-merged.mount: Succeeded.
May 31 18:49:59 myhostname systemd[1]: var-lib-docker-overlay2-c4e7ea524e1ca52cdf4e7798c06352550361e8ca86c928fd0bde68c4a3e6d668-merged.mount: Succeeded.
May 31 18:50:08 myhostname smartd[856]: Device: /dev/sdb [SAT], SMART Usage Attribute: 194 Temperature_Celsius changed from 75 to 74

Today:

Jun 01 17:47:19 myhostname systemd-udevd[239801]: Using default interface naming scheme 'v245'.
Jun 01 17:47:19 myhostname systemd-udevd[239802]: Using default interface naming scheme 'v245'.
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=49
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=filter family=2 entries=92
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.029:23412): table=nat family=2 entries=49
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.029:23413): table=filter family=2 entries=92
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=50
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.039:23414): table=nat family=2 entries=50
Jun 01 17:47:19 myhostname dockerd[1281]: time="2020-06-01T17:47:19.099542204+03:00" level=info msg="shim containerd-shim started" address=/containerd-shim/0589eada1b4f508f7a58c75c803a84bc07925dd973e5748a8c6f37da8f514784.sock debug=false pid=239820
Jun 01 17:47:19 myhostname systemd[4131]: run-docker-runtime\x2drunc-moby-9b51d1689d9350eb1f97e1f7d92044df72dceaf905dcb3d90f6aa829e2486cea-runc.aDWCMo.mount: Succeeded.
Jun 01 17:47:19 myhostname systemd[1]: run-docker-runtime\x2drunc-moby-9b51d1689d9350eb1f97e1f7d92044df72dceaf905dcb3d90f6aa829e2486cea-runc.aDWCMo.mount: Succeeded.
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=0
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.499:23415): table=nat family=2 entries=0
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=filter family=2 entries=0
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=5
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=7
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.509:23416): table=filter family=2 entries=0
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.509:23417): table=nat family=2 entries=5
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.509:23418): table=nat family=2 entries=7
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=8
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=10
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.519:23419): table=nat family=2 entries=8
Jun 01 17:47:19 myhostname kernel: audit: type=1325 audit(1591022839.519:23420): table=nat family=2 entries=10
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=11
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=12
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=13
Jun 01 17:47:19 myhostname audit: NETFILTER_CFG table=nat family=2 entries=14
Jun 01 17:47:19 myhostname kernel: eth0: renamed from veth0657214
Jun 01 17:47:19 myhostname kernel: IPv6: ADDRCONF(NETDEV_CHANGE): veth8c5e2eb: link becomes ready
Jun 01 17:47:19 myhostname kernel: br-63548908ed36: port 1(veth8c5e2eb) entered blocking state
Jun 01 17:47:19 myhostname kernel: br-63548908ed36: port 1(veth8c5e2eb) entered forwarding state

I think this is related to Docker somehow, since those network interface names ("veth*") are created by Docker.
There is one issue mentioned in the troubleshooting section on the Docker wiki: https://wiki.archlinux.org/index.php/do … networking
But I don't think this is related, I'll try the solution anyway, just to see if it helps.

Any ideas on how I can further debug this? I realize I need to get my hands on a monitor, but until then...

The smaller issue seems unrelated to me, but I will mention it just in case:
One of my containers runs PiHole for adblock, and this is also the DNS server for the rest of the system.  Ever since I disabled "dhcpcd", my Docker containers' DNS didn't work, even though they could reach the static IP address where PiHole serves DNS (i.e. not 127.0.0.1, but rather 192.168.0.2), and "dig" queries to 192.168.0.2 work fine. Setting the same DNS address in "/etc/docker/daemon.json" also didn't help, but for some reason setting 8.8.8.8 in "/etc/docker/daemon.json" suddenly worked. Seems like something with Docker's networking got messed up after I disabled "dhcpcd", but when I tried to enable "dhcpcd" again, the issue persisted.
Not sure if this could be related to my main issue.

Thanks for any help with this.

EDIT: Renamed thread, it's a general freeze, not only network

Last edited by TheCoon (2020-06-23 11:20:33)

TheCoon

Member

Registered: 2016-05-10

Posts: 42

Re: [SOLVED] System freeze, maybe caused by Docker

The issue I'm facing is still occurring on a daily basis, the entire system freezes (not only networking).
I've connected a monitor and I don't see any errors when the system freezes.
I've run Memtest86 and no errors were found.
How else can I debug this issue? I would expect at least some output to tty1. Anything I need to enable in terms of logging and debug output?
What I've enabled thus far:
- https://wiki.archlinux.org/index.php/Ge … ay_on_tty1
- "debug" kernel parameter

Last edited by TheCoon (2020-06-08 15:19:56)

TheCoon

Member

Registered: 2016-05-10

Posts: 42

Re: [SOLVED] System freeze, maybe caused by Docker

Another update after connecting a VGA monitor and enabling debug logging, the system freezes with the following log on screen (OCR'd text since I had no way of copying the actual text):

[117518.804768] audit: type=1325 audit(1591746974.6@9:35339): table=nat family=2 entries=50
[117519.213998] audit: type=1325 audit(1591746975.0819:35348): table=nat family=2 entries=0
[117519.225859] audit: type=1325 audit(1591746975.829:35341): table=filter family=2 entries=0
[117519.2370891] audit: type=1325 audit(1591746975.849:35342): table=nat family=2 entries=5
[117519.246326] audit: type=1325 audit(1591746975.849:35343): table=nat family=2 entries=7
[117519.254016] audit: tupe=1325 audit(1591746975.0859:35344): table=nat family=2 entries=8
[117519.261783] audit: type=1325 audit(1591746975.0859:35345): table=nat family=2 entries=10
[117519.337979] eth0: renamed from vethffceb8e
[117519.387411] IPv6: ADDRCONF(NETDEV_CHANGE): veth334d41f: link becomes ready
[117519.391557] br-63548988ed36: port 1(veth334d41f) entered blocking state
[117519.395554] br-63548988ed36: port 1(veth334d41f) entered forwarding state
[117528.865791] br-63548988ed36: port 1(veth334d41f) entered disabled state
[117528.869887] vethffceb8e: renamed from eth0
[117528.183852] br-63548988ed36: port 1(veth334d41f) entered disabled state
[117528.193944] device veth334d41f left promiscuous mode
[117528.197926] br-63548988ed36: port 1(veth334d41f) entered disabled state
[117578.654157] systemd-journald[497]: Sent WATCHDOG=1 notification.
[117588.846388] br-63548908ed36: port 1(vethc08d873) entered blocking state
[117588.858452] br-63548908ed36: port 1(vethc08d873) entered disabled state
[117588,854587] device vethc88d873 entered promiscuous mode
[117588,858456] kauditd_printk_skb: 8 callbacks suppressed
[1175808,858458] audit: type=1700 audit(1591747835,849:35354): dev=vethc08d873 prom=256 old_prom=8 auid=4294967295 uid=0 gid=0 ses=4294967295

What else can I do to debug this issue?

EDIT 2020-06-23:
In case anyone stumbles upon this, what appears to have been the solution to this was removing a rather recent change I made to the file /etc/docker/daemon.json. The file contents were:

{"dns": ["1.1.1.1", "10.0.0.2", "10.0.0.1"] }

Which are: Cloudflare, PiHole, home router. I originally made this change because DNS wasn't working properly in some Docker containers.
My solution to the system freeze issue was to completely remove the dameon.json file (which included only these DNS settings). The containers which previously didn't get proper DNS, are suddenly working fine again. I'm still unsure what went on there, but I'm glad everything is back to normal.
As to why the DNS setting was causing a system freeze, I would guess that something about this altered DNS operation on Docker's end caused it to recreate network interfaces at a higher than normal rate, and something about that was causing the freezes.

Last edited by TheCoon (2020-06-23 11:19:49)