In the amd64-generic-paladin run at http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8929329919858702736, network.DefaultProfile failed in the TastVMTest stage. From the logs at http://pantheon/storage/browser/chromeos-image-archive/amd64-generic-paladin/R72-11280.0.0-rc1/tast_vm_test_results_1/tast_vm_paladin/ :

2018/11/20 08:05:19 Started test network.DefaultProfile
2018/11/20 08:06:15 [08:05:18.589] Waiting for org.chromium.flimflam D-Bus service
2018/11/20 08:06:15 [08:05:23.626] Error at default_profile.go:67: Failed getting profiles: failed getting properties: context deadline exceeded
...
2018/11/20 08:06:15 Completed test network.DefaultProfile in 23.404s with 2 error(s)

The timestamps are interesting -- ones on the left are from the shard, while ones in brackets are from the DUT at the time when the message was generated.

The DUT restarted shill at 08:05:18.589, but its GetProperties D-Bus call to it timed out five seconds later. Additionally, those messages didn't arrive back at the shard until 08:06:15, almost a minute later. My guess would be that shill was hanging for a period of time at startup, which both made the D-Bus call fail and resulted in the messages being delayed.

Here's net.log:

...
2018-11-20T16:05:18.403016+00:00 INFO shill[922]: [INFO:shill_main.cc(249)] Process exiting.
2018-11-20T16:05:18.646102+00:00 INFO shill[2364]: [INFO:manager.cc(297)] Manager started.
2018-11-20T16:05:18.646421+00:00 WARNING shill[2364]: [WARNING:libpolicy.cc(38)] Could not load the device policy file.
2018-11-20T16:05:18.649154+00:00 INFO shill[2364]: [INFO:chromeos_power_manager_proxy.cc(355)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendImminentsuccess: 1
2018-11-20T16:05:18.650231+00:00 INFO shill[2364]: [INFO:chromeos_power_manager_proxy.cc(355)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendDonesuccess: 1
2018-11-20T16:05:18.651291+00:00 INFO shill[2364]: [INFO:chromeos_power_manager_proxy.cc(355)] OnSignalConnected interface: org.chromium.PowerManager signal: DarkSuspendImminentsuccess: 1
2018-11-20T16:05:18.651902+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:05:18.652083+00:00 INFO shill[2364]: [INFO:key_file_store.cc(75)] Creating a new key file at /var/cache/shill/default.profile
2018-11-20T16:05:18.709363+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:05:18.710213+00:00 INFO shill[2364]: [INFO:manager.cc(549)] PushProfileInternal finished; 1 profile(s) now present.
2018-11-20T16:05:18.710389+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:05:18.710449+00:00 INFO shill[2364]: [INFO:modem_manager.cc(93)] Start watching modem manager service: org.chromium.ModemManager
2018-11-20T16:05:18.713935+00:00 INFO shill[2364]: [INFO:modem_manager_1.cc(35)] Start watching modem manager service: org.freedesktop.ModemManager1
2018-11-20T16:05:18.717290+00:00 INFO shill[2364]: [INFO:service.cc(271)] etherneteap service 0 constructed.
2018-11-20T16:05:18.719156+00:00 INFO shill[2364]: [INFO:device.cc(188)] Device created: eth0 index 2
2018-11-20T16:05:18.723329+00:00 INFO shill[2364]: [INFO:service.cc(271)] ethernet service 1 constructed.
2018-11-20T16:05:18.725938+00:00 INFO shill[2364]: [INFO:manager.cc(1237)] Device eth0 registered.
2018-11-20T16:05:18.726198+00:00 INFO shill[2364]: [INFO:manager.cc(1512)] Device eth0 updated: enabled
2018-11-20T16:05:20.757344+00:00 INFO shill[2364]: [INFO:ethernet.cc(109)] Registering eth0 with manager.
^^^ long delay here
2018-11-20T16:05:47.590979+00:00 WARNING shill[2364]: [WARNING:ethernet.cc(455)] Failed to enable wake-on-lan: Operation not supported.
2018-11-20T16:05:47.644846+00:00 INFO shill[2364]: [INFO:manager.cc(1632)] Default physical service: 1 (not connected)
2018-11-20T16:05:47.645300+00:00 INFO shill[2364]: [INFO:service.cc(284)] Auto-connecting to service 1
2018-11-20T16:05:47.645799+00:00 INFO shill[2364]: [INFO:service.cc(300)] Connect to service 1: AutoConnect
2018-11-20T16:05:47.658087+00:00 INFO shill[2364]: [INFO:dhcp_config.cc(193)] Spawned /sbin/dhcpcd with pid: 2408
2018-11-20T16:05:47.658360+00:00 INFO shill[2364]: [INFO:service.cc(379)] Service 1: state Idle -> Configuring
2018-11-20T16:05:47.658456+00:00 INFO shill[2364]: [INFO:manager.cc(1487)] Service 1 updated; state: Configuring failure Unknown
2018-11-20T16:05:47.674232+00:00 NOTICE dhcpcd[2408]: dhcpcd is running with reduced privileges
2018-11-20T16:05:47.681881+00:00 INFO shill[2364]: [INFO:service.cc(293)] Suppressed autoconnect to service 1 (connecting)
2018-11-20T16:05:47.686157+00:00 INFO dhcpcd[2408]: status changed to Init
2018-11-20T16:05:47.686881+00:00 INFO shill[2364]: [INFO:chromeos_dbus_objectmanager_proxy.cc(80)] OnServiceAvailable: 1
2018-11-20T16:05:47.687297+00:00 INFO shill[2364]: [INFO:power_manager.cc(174)] OnPowerManagerAppeared
2018-11-20T16:05:47.687455+00:00 INFO shill[2364]: [INFO:chromeos_power_manager_proxy.cc(173)] RegisterSuspendDelayInternal(19500, dark=false)
2018-11-20T16:05:47.692467+00:00 INFO shill[2364]: [INFO:chromeos_power_manager_proxy.cc(173)] RegisterSuspendDelayInternal(19500, dark=true)
2018-11-20T16:05:47.702154+00:00 INFO shill[2364]: [INFO:modem_manager.cc(47)] Modem manager org.freedesktop.ModemManager1 appeared.
2018-11-20T16:05:47.704344+00:00 INFO shill[2364]: [INFO:dhcp_config.cc(134)] Init DHCP Proxy: eth0 at :1.36
2018-11-20T16:05:48.338978+00:00 INFO dhcpcd[2408]: status changed to Reboot
2018-11-20T16:05:48.339169+00:00 INFO dhcpcd[2408]: eth0: rebinding lease of 10.0.2.15
2018-11-20T16:05:48.339399+00:00 INFO dhcpcd[2408]: eth0: sending REQUEST (xid 0xe2847183), next in 4.2 seconds
2018-11-20T16:05:48.342174+00:00 INFO dhcpcd[2408]: eth0: received ACK with xid 0xe2847183
2018-11-20T16:05:48.342222+00:00 INFO dhcpcd[2408]: eth0: acknowledged 10.0.2.15 from 10.0.2.2
2018-11-20T16:05:48.342278+00:00 INFO dhcpcd[2408]: eth0: leased 10.0.2.15 for 86400 seconds
2018-11-20T16:05:48.343412+00:00 INFO dhcpcd[2408]: event REBOOT on interface eth0
2018-11-20T16:05:48.344284+00:00 INFO dhcpcd[2408]: status changed to Bound
2018-11-20T16:05:48.345829+00:00 INFO shill[2364]: [INFO:dhcpv4_config.cc(111)] Event reason: REBOOT
2018-11-20T16:05:48.348336+00:00 INFO shill[2364]: [INFO:connection.cc(269)] UpdateFromIPConfig: Installing with parameters: local=10.0.2.15 broadcast=10.0.2.31 peer=<unknown> gateway=10.0.2.2
2018-11-20T16:05:48.350179+00:00 INFO shill[2364]: [INFO:service.cc(379)] Service 1: state Configuring -> Connected
2018-11-20T16:05:48.398461+00:00 INFO shill[2364]: [INFO:manager.cc(1487)] Service 1 updated; state: Connected failure Unknown
2018-11-20T16:05:48.457297+00:00 INFO shill[2364]: [INFO:service.cc(379)] Service 1: state Connected -> Online
2018-11-20T16:05:48.457407+00:00 INFO shill[2364]: [INFO:manager.cc(1487)] Service 1 updated; state: Online failure Unknown
2018-11-20T16:05:48.695113+00:00 INFO shill[2364]: [INFO:manager.cc(1636)] Default physical service: 1 (connected)
2018-11-20T16:06:07.892265+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:06:07.892749+00:00 INFO shill[2364]: [INFO:key_file_store.cc(75)] Creating a new key file at /run/shill/user_profiles/chronos/shill.profile
2018-11-20T16:06:07.931803+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:06:07.964774+00:00 INFO shill[2364]: [INFO:manager.cc(549)] PushProfileInternal finished; 2 profile(s) now present.
2018-11-20T16:06:10.403414+00:00 INFO shill[2364]: [INFO:manager.cc(595)] Skipping unload of service 1: wasn't using this profile.
2018-11-20T16:06:10.404297+00:00 INFO shill[2364]: [INFO:manager.cc(620)] PopProfileInternal finished; 1 profile(s) still present.
2018-11-20T16:06:54.674000+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:06:54.674313+00:00 INFO shill[2364]: [INFO:key_file_store.cc(75)] Creating a new key file at /run/shill/user_profiles/chronos/shill.profile
2018-11-20T16:06:54.745988+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:06:54.747495+00:00 INFO shill[2364]: [INFO:manager.cc(549)] PushProfileInternal finished; 2 profile(s) now present.
2018-11-20T16:07:01.481014+00:00 INFO shill[2364]: [INFO:manager.cc(595)] Skipping unload of service 1: wasn't using this profile.
2018-11-20T16:07:01.481411+00:00 INFO shill[2364]: [INFO:manager.cc(620)] PopProfileInternal finished; 1 profile(s) still present.
2018-11-20T16:07:19.940346+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:07:19.940811+00:00 INFO shill[2364]: [INFO:key_file_store.cc(75)] Creating a new key file at /run/shill/user_profiles/chronos/shill.profile
2018-11-20T16:07:19.990968+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:07:19.991539+00:00 INFO shill[2364]: [INFO:manager.cc(549)] PushProfileInternal finished; 2 profile(s) now present.
2018-11-20T16:07:22.970142+00:00 INFO shill[2364]: [INFO:manager.cc(595)] Skipping unload of service 1: wasn't using this profile.
2018-11-20T16:07:22.970805+00:00 INFO shill[2364]: [INFO:manager.cc(620)] PopProfileInternal finished; 1 profile(s) still present.
2018-11-20T16:08:02.481039+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:08:02.481229+00:00 INFO shill[2364]: [INFO:key_file_store.cc(75)] Creating a new key file at /run/shill/user_profiles/chronos/shill.profile
2018-11-20T16:08:02.533267+00:00 ERR shill[2364]: [ERROR:crypto_des_cbc.cc(95)] Unable to load key matter from /var/lib/whitelist/owner.key
2018-11-20T16:08:02.537238+00:00 INFO shill[2364]: [INFO:manager.cc(549)] PushProfileInternal finished; 2 profile(s) now present.

There are logs from an earlier successful amd64-generic-paladin run at http://pantheon/storage/browser/chromeos-image-archive/amd64-generic-paladin/R72-11279.0.0-rc3/tast_vm_test_results_1/tast_vm_paladin/ .

2018-11-20T11:41:49.637844+00:00 INFO shill[2441]: [INFO:manager.cc(297)] Manager started.
...
2018-11-20T11:41:49.740685+00:00 INFO shill[2441]: [INFO:manager.cc(1237)] Device eth0 registered.
2018-11-20T11:41:49.740824+00:00 INFO shill[2441]: [INFO:manager.cc(1512)] Device eth0 updated: enabled
2018-11-20T11:41:51.821596+00:00 INFO shill[2441]: [INFO:ethernet.cc(109)] Registering eth0 with manager.
^^^ short delay here
2018-11-20T11:41:51.993845+00:00 WARNING shill[2441]: [WARNING:ethernet.cc(455)] Failed to enable wake-on-lan: Operation not supported.
2018-11-20T11:41:52.025989+00:00 INFO shill[2441]: [INFO:manager.cc(1632)] Default physical service: 1 (not connected)
2018-11-20T11:41:52.027738+00:00 INFO shill[2441]: [INFO:service.cc(284)] Auto-connecting to service 1
2018-11-20T11:41:52.027791+00:00 INFO shill[2441]: [INFO:service.cc(300)] Connect to service 1: AutoConnect
2018-11-20T11:41:52.069491+00:00 INFO shill[2441]: [INFO:dhcp_config.cc(193)] Spawned /sbin/dhcpcd with pid: 2446
2018-11-20T11:41:52.069586+00:00 INFO shill[2441]: [INFO:service.cc(379)] Service 1: state Idle -> Configuring
2018-11-20T11:41:52.069640+00:00 INFO shill[2441]: [INFO:manager.cc(1487)] Service 1 updated; state: Configuring failure Unknown
2018-11-20T11:41:52.078165+00:00 NOTICE dhcpcd[2446]: dhcpcd is running with reduced privileges
2018-11-20T11:41:52.084627+00:00 INFO dhcpcd[2446]: status changed to Init
2018-11-20T11:41:52.087682+00:00 INFO shill[2441]: [INFO:service.cc(293)] Suppressed autoconnect to service 1 (connecting)
2018-11-20T11:41:52.087884+00:00 INFO shill[2441]: [INFO:chromeos_dbus_objectmanager_proxy.cc(80)] OnServiceAvailable: 1
2018-11-20T11:41:52.096802+00:00 INFO shill[2441]: [INFO:power_manager.cc(174)] OnPowerManagerAppeared
2018-11-20T11:41:52.096837+00:00 INFO shill[2441]: [INFO:chromeos_power_manager_proxy.cc(173)] RegisterSuspendDelayInternal(19500, dark=false)
2018-11-20T11:41:52.105696+00:00 INFO shill[2441]: [INFO:chromeos_power_manager_proxy.cc(173)] RegisterSuspendDelayInternal(19500, dark=true)
2018-11-20T11:41:52.158592+00:00 INFO shill[2441]: [INFO:modem_manager.cc(47)] Modem manager org.freedesktop.ModemManager1 appeared.
2018-11-20T11:41:52.160502+00:00 INFO shill[2441]: [INFO:dhcp_config.cc(134)] Init DHCP Proxy: eth0 at :1.36
2018-11-20T11:41:52.241845+00:00 INFO dhcpcd[2446]: status changed to Reboot
2018-11-20T11:41:52.242537+00:00 INFO dhcpcd[2446]: eth0: rebinding lease of 10.0.2.15
2018-11-20T11:41:52.242858+00:00 INFO dhcpcd[2446]: eth0: sending REQUEST (xid 0xbc497896), next in 4.1 seconds
2018-11-20T11:41:52.250756+00:00 INFO dhcpcd[2446]: eth0: received ACK with xid 0xbc497896
2018-11-20T11:41:52.250906+00:00 INFO dhcpcd[2446]: eth0: acknowledged 10.0.2.15 from 10.0.2.2
2018-11-20T11:41:52.250951+00:00 INFO dhcpcd[2446]: eth0: leased 10.0.2.15 for 86400 seconds
2018-11-20T11:41:52.251767+00:00 INFO dhcpcd[2446]: event REBOOT on interface eth0
2018-11-20T11:41:52.264683+00:00 INFO dhcpcd[2446]: status changed to Bound

In the failed run, what was shill doing between "Registering eth0 with manager." and "Failed to enable wake-on-lan: Operation not supported."?

It may be possible to increase the timeout on the D-Bus call, but it'd be good to know the reason for the delay.