CoreOS goes offline on DHCP failure on Amazon VPC

[pctj101]

Issue Report

Bug

Bug

Container Linux Version

NAME="Container Linux by CoreOS"
ID=coreos
VERSION=1409.2.0
VERSION_ID=1409.2.0
BUILD_ID=2017-06-19-2321
PRETTY_NAME="Container Linux by CoreOS 1409.2.0 (Ladybug)"
ANSI_COLOR="38;5;75"
HOME_URL="https://coreos.com/"
BUG_REPORT_URL="https://issues.coreos.com"
COREOS_BOARD="amd64-usr"

Environment

Amazon EC2 ami-d05bdab3 c4.xlarge

Expected Behavior

Network Retry for DHCP on failure

Actual Behavior

System goes "offline" on network DHCP failure on Amazon VPC

Reproduction Steps

Run a system online and try to leave it online?

Other Information

Jun 23 06:11:53 ip-172-16-193-63 locksmithd[661]: [etcd.service etcd2.service] are inactive
Jun 23 06:11:53 ip-172-16-193-63 locksmithd[661]: Unlocking old locks failed: [etcd.service etcd2.service] are inactive. Retrying in 5m0s.
Jun 23 06:17:46 ip-172-16-193-63 dbus[643]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30779ms)
Jun 23 06:22:20 ip-172-16-193-63 update_engine[641]: I0623 06:21:54.843482 641 prefs.cc:51] certificate-report-to-send-update not present in /var/lib/update_engine/prefs
Jun 23 06:26:45 ip-172-16-193-63 update_engine[641]: I0623 06:23:44.415855 641 prefs.cc:51] certificate-report-to-send-download not present in /var/lib/update_engine/prefs
Jun 23 06:23:47 ip-172-16-193-63 systemd-networkd[637]: eth0: Could not set DHCPv4 address: Connection timed out
Jun 23 06:23:56 ip-172-16-193-63 systemd-networkd[637]: eth0: Failed
Jun 23 06:24:02 ip-172-16-193-63 systemd-timesyncd[610]: Network configuration changed, trying to establish connection.
Jun 23 06:24:49 ip-172-16-193-63 systemd-timesyncd[610]: Synchronized to time server 128.199.134.40:123 (3.coreos.pool.ntp.org).
Jun 23 06:42:57 ip-172-16-193-63 update_engine[641]: I0623 06:36:37.163439 641 omaha_request_params.cc:59] Current group set to stable
Jun 23 06:42:57 ip-172-16-193-63 update_engine[641]: I0623 06:38:59.888404 641 update_attempter.cc:483] Already updated boot flags. Skipping.
Jun 23 06:42:57 ip-172-16-193-63 update_engine[641]: I0623 06:39:44.682675 641 update_attempter.cc:626] Scheduling an action processor start.
Jun 23 06:42:57 ip-172-16-193-63 update_engine[641]: I0623 06:40:33.294565 641 action_processor.cc:36] ActionProcessor::StartProcessing: OmahaRequestAction
Jun 23 06:27:01 ip-172-16-193-63 systemd-networkd[637]: eth0: Could not set DHCPv4 route: Connection timed out
Jun 23 07:08:54 ip-172-16-193-63 update_engine[641]: I0623 06:44:18.532464 641 omaha_request_action.cc:245] Posting an Omaha request to https://public.update.core-os.net/v1/update/
Jun 23 07:08:54 ip-172-16-193-63 update_engine[641]: I0623 06:44:59.759989 641 omaha_request_action.cc:246] Request:
Jun 23 07:08:54 ip-172-16-193-63 update_engine[641]:
Jun 23 07:08:54 ip-172-16-193-63 update_engine[641]:
Jun 23 07:08:54 ip-172-16-193-63 update_engine[641]: <app appid="{e96281a6-d1af-4bde-9a0a-97b76e56dc57}" version="1409.2.0" track="stable" bootid="{7540ea92-f47f-4725-9fa1-38b6abdb8af3}" oem="ami" oemversion="0.0.7-r1" alephversion="1353.8.0" machineid=
-- Reboot ---- Reboot --

[lucab]

Jun 23 06:23:47 ip-172-16-193-63 systemd-networkd[637]: eth0: Could not set DHCPv4 address: Connection timed out

This a pretty bad error, meaning that networkd is unbale to talk to the kernel via netlink socket due to not receiving an answer in a sane amount of time. This is however just the symptom or something else going deeply wrong with your system, as this other dbus timeout shows:

dbus[643]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30779ms)

Is this system under very high memory/cpu usage? Is this by chance related to #2019 (tmpfs filled up)?

[pctj101]

I'm going to close this issue for now. I've noticed another machine with memory pressure that has similar problems. Let's see if a simple tuning of memory usage/capacity solves the issue of tmpfs filling up and preventing DHCP from working properly.

If so perhaps some magical way of logging OOM for the entire server would make the cause more obvious.

[abh]

FWIW I see this too after updating to 1409.2.0 (CoreOS is running under KVM, host is RHEL 6.9)