Veth device immediately dying (RHEL 7)

I’ve managed to get this RHEL 7 box in a strange state:

  • docker commands like ‘ps’ or ‘images’ work fine
  • I can not actually start containers

docker info:
Kernel Version: 3.10.0-229.4.2.el7.x86_64
Operating System: Red Hat Enterprise Linux Server 7.1 (Maipo)

‘docker run hello-world’ fails with:

ERROR: Could not determine network interfaces, you must use a interfaces config line
FATA[0003] Error response from daemon: Cannot start container a6619c7c091ae6b1e1a87a64a306bcc8f7e8f16116d0c2bdb5b43ec7034ed42d: [8] System error: no such process 

watching the journal, it seems to show the virtual network device disappearing:

Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="POST /v1.18/containers/create"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job create()"
Jun 09 14:52:24 awsdevrh7l03 kernel: EXT4-fs (dm-8): mounted filesystem with ordered data mode. Opts: discard
Jun 09 14:52:24 awsdevrh7l03 kernel: EXT4-fs (dm-8): mounted filesystem with ordered data mode. Opts: discard
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job log(create, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae5...rld:latest)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job log(create, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae5...t) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job create() = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="POST /v1.18/containers/212051c01bf871f0472deb384e166e669444df62faf147962ab53c790...=1&stream=1"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job container_inspect(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job container_inspect(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790...3) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job attach(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="POST /v1.18/containers/212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53/start"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job start(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 kernel: EXT4-fs (dm-8): mounted filesystem with ordered data mode. Opts: discard
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job allocate_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job allocate_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c79...3) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job log(start, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53...rld:latest)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job log(start, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53...t) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=filter family=2 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=raw family=2 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=security family=2 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=mangle family=2 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=nat family=2 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=filter family=10 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=raw family=10 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=security family=10 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=mangle family=10 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=NETFILTER_CFG msg=audit(1433875944.425:679): table=nat family=10 entries=0
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=SYSCALL msg=audit(1433875944.425:679): arch=c000003e syscall=56 success=yes exit=5217 a0=6c020011 a1=0 a2=0 a3=0 items...
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=EOE msg=audit(1433875944.425:679):
Jun 09 14:52:24 awsdevrh7l03 systemd[1]: Starting docker container 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53.
Jun 09 14:52:24 awsdevrh7l03 systemd[1]: Started docker container 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53.
Jun 09 14:52:24 awsdevrh7l03 kernel: device veth39ca400 entered promiscuous mode
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=ANOM_PROMISCUOUS msg=audit(1433875944.453:680): dev=veth39ca400 prom=256 old_prom=0 auid=4294967295 uid=0 ...s=4294967295
Jun 09 14:52:24 awsdevrh7l03 kernel: IPv6: ADDRCONF(NETDEV_UP): veth39ca400: link is not ready
Jun 09 14:52:24 awsdevrh7l03 kernel: docker0: port 1(veth39ca400) entered forwarding state
Jun 09 14:52:24 awsdevrh7l03 kernel: docker0: port 1(veth39ca400) entered forwarding state
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=SYSCALL msg=audit(1433875944.453:680): arch=c000003e syscall=16 success=yes exit=0 a0=12 a1=89a2 a2=c20866338c a3=0 it...
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=EOE msg=audit(1433875944.453:680):
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): carrier is OFF (but ignored)
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): new Veth device (driver: 'unknown' ifindex: 41)
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): exported as /org/freedesktop/NetworkManager/Devices/25
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (docker0): bridge port veth39ca400 was attached
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): enslaved to docker0
Jun 09 14:52:24 awsdevrh7l03 kernel: docker0: port 1(veth39ca400) entered disabled state
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>      read connection 'veth39ca400'
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: unmanaged -> unavailable (reason 'connection-assumed') [10 20 41]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: unavailable -> disconnected (reason 'connection-assumed') [20 30 41]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: starting connection 'veth39ca400'
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 1 of 5 (Device Prepare) scheduled...
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 1 of 5 (Device Prepare) started...
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 2 of 5 (Device Configure) scheduled...
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 1 of 5 (Device Prepare) complete.
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 2 of 5 (Device Configure) starting...
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: prepare -> config (reason 'none') [40 50 0]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 2 of 5 (Device Configure) successful.
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 3 of 5 (IP Configure Start) scheduled.
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 2 of 5 (Device Configure) complete.
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 3 of 5 (IP Configure Start) started...
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: config -> ip-config (reason 'none') [50 70 0]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: Stage 3 of 5 (IP Configure Start) complete.
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: ip-config -> secondaries (reason 'none') [70 90 0]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: secondaries -> activated (reason 'none') [90 100 0]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): Activation: successful, device activated.
Jun 09 14:52:24 awsdevrh7l03 dbus[617]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Jun 09 14:52:24 awsdevrh7l03 dbus-daemon[617]: dbus[617]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Jun 09 14:52:24 awsdevrh7l03 systemd[1]: Starting Network Manager Script Dispatcher Service...
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=warning msg="exit status 1"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job release_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 dbus-daemon[617]: dbus[617]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 09 14:52:24 awsdevrh7l03 dbus[617]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jun 09 14:52:24 awsdevrh7l03 nm-dispatcher[5225]: Dispatching action 'up' for veth39ca400
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=ANOM_PROMISCUOUS msg=audit(1433875944.500:681): dev=veth39ca400 prom=0 old_prom=256 auid=4294967295 uid=0 ...s=4294967295
Jun 09 14:52:24 awsdevrh7l03 kernel: docker0: port 1(veth39ca400) entered disabled state
Jun 09 14:52:24 awsdevrh7l03 systemd[1]: Started Network Manager Script Dispatcher Service.
Jun 09 14:52:24 awsdevrh7l03 kernel: device veth39ca400 left promiscuous mode
Jun 09 14:52:24 awsdevrh7l03 kernel: docker0: port 1(veth39ca400) entered disabled state
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): device state change: activated -> unmanaged (reason 'removed') [100 10 36]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <info>  (veth39ca400): deactivating device (reason 'removed') [36]
Jun 09 14:52:24 awsdevrh7l03 NetworkManager[701]: <warn>  (docker0): failed to detach bridge port veth39ca400
Jun 09 14:52:24 awsdevrh7l03 audispd[599]: node=awsdevrh7l03 type=SERVICE_START msg=audit(1433875944.502:682): pid=1 uid=0 auid=4294967295 ses=4294967295 msg=' comm="Networ...res=success'
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job release_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790...3) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job attach(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job release_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job release_interface(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790...3) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=error msg="Error unmounting device 212051c01bf871f0472deb384e166e669444df62faf147962ab53c7...c790cd5ae53"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="+job log(die, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53, ...rld:latest)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job log(die, 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53, ...t) = OK (0)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: Cannot start container 212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53: [8] System error: read parent: connection reset by peer
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=info msg="-job start(212051c01bf871f0472deb384e166e669444df62faf147962ab53c790cd5ae53) = ERR (1)"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=error msg="Handler for POST /containers/{name:.*}/start returned error: Cannot start conta...set by peer"
Jun 09 14:52:24 awsdevrh7l03 docker[5040]: time="2015-06-09T14:52:24-04:00" level=error msg="HTTP Error: statusCode=500 Cannot start container 212051c01bf871f0472deb384e166...set by peer"
Jun 09 14:52:24 awsdevrh7l03 nm-dispatcher[5225]: Cannot find device "veth39ca400"
Jun 09 14:52:24 awsdevrh7l03 nm-dispatcher[5225]: Dispatching action 'down' for veth39ca400

has anyone seen anything like this before?

2 Likes