Packet "phone home" is failing

[johananl]

The packet-phone-home.service systemd unit is currently failing. This causes cluster bootstrap failures in some cases.

● packet-phone-home.service - Report Success to Packet
   Loaded: loaded (/etc/systemd/system/packet-phone-home.service; enabled; vendor preset: enabled)
   Active: inactive (dead) (Result: resources) since Thu 2019-06-20 19:08:51 UTC; 5min ago

Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: packet-phone-home.service: Service RestartSec=2s expired, scheduling restart.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: packet-phone-home.service: Scheduled restart job, restart counter is at 7.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: Stopped Report Success to Packet.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: Dependency failed for Report Success to Packet.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: packet-phone-home.service: Job packet-phone-home.service/start failed with result 'dependency'.

core@johannes-test-controller-0 ~ $ cat /etc/systemd/system/packet-phone-home.service
[Unit]
Description=Report Success to Packet
ConditionFirstBoot=true
Requires=coreos-metadata.service
After=coreos-metadata.service

[Service]
EnvironmentFile=/run/metadata/flatcar
ExecStart=/usr/bin/curl --header "Content-Type: application/json" --request POST "${COREOS_PACKET_PHONE_HOME_URL}"
Restart=on-failure
RestartSec=2

[Install]
WantedBy=multi-user.target

core@johannes-test-controller-0 ~ $ systemctl status coreos-metadata.service | cat
● coreos-metadata.service - CoreOS Metadata Agent
   Loaded: loaded (/etc/systemd/system/coreos-metadata.service; enabled; vendor preset: enabled)
   Active: failed (Result: start-limit-hit) since Thu 2019-06-20 19:08:49 UTC; 10min ago
  Process: 1329 ExecStart=/usr/bin/coreos-metadata ${COREOS_METADATA_OPT_PROVIDER} --attributes=/run/metadata/coreos (code=exited, status=0/SUCCESS)
 Main PID: 1329 (code=exited, status=0/SUCCESS)

Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:49 johannes-test-controller-0 coreos-metadata[1329]: Jun 20 19:08:49.612 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:49 johannes-test-controller-0 coreos-metadata[1329]: Jun 20 19:08:49.617 INFO Fetch successful
Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Start request repeated too quickly.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Failed with result 'start-limit-hit'.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: Failed to start CoreOS Metadata Agent.

core@johannes-test-controller-0 ~ $ journalctl -u coreos-metadata.service | cat
-- Logs begin at Thu 2019-06-20 19:08:01 UTC, end at Thu 2019-06-20 19:21:24 UTC. --
Jun 20 19:08:29 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:30 johannes-test-controller-0 coreos-metadata[921]: Jun 20 19:08:30.037 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:30 johannes-test-controller-0 coreos-metadata[921]: Jun 20 19:08:30.050 INFO Fetch successful
Jun 20 19:08:30 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:30 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:32 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:32 johannes-test-controller-0 coreos-metadata[1067]: Jun 20 19:08:32.266 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:32 johannes-test-controller-0 coreos-metadata[1067]: Jun 20 19:08:32.267 INFO Failed to fetch: http://metadata.packet.net/metadata: failed to lookup address information: Name or service not known
Jun 20 19:08:33 johannes-test-controller-0 coreos-metadata[1067]: Jun 20 19:08:33.268 INFO Fetching http://metadata.packet.net/metadata: Attempt #2
Jun 20 19:08:33 johannes-test-controller-0 coreos-metadata[1067]: Jun 20 19:08:33.277 INFO Fetch successful
Jun 20 19:08:33 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:33 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:35 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:35 johannes-test-controller-0 coreos-metadata[1076]: Jun 20 19:08:35.583 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:40 johannes-test-controller-0 coreos-metadata[1076]: Jun 20 19:08:40.595 INFO Fetch successful
Jun 20 19:08:40 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:40 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:42 johannes-test-controller-0 coreos-metadata[1105]: Jun 20 19:08:42.364 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:42 johannes-test-controller-0 coreos-metadata[1105]: Jun 20 19:08:42.370 INFO Fetch successful
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:42 johannes-test-controller-0 coreos-metadata[1157]: Jun 20 19:08:42.863 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:42 johannes-test-controller-0 coreos-metadata[1157]: Jun 20 19:08:42.869 INFO Fetch successful
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:42 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:45 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:45 johannes-test-controller-0 coreos-metadata[1302]: Jun 20 19:08:45.112 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:45 johannes-test-controller-0 coreos-metadata[1302]: Jun 20 19:08:45.118 INFO Fetch successful
Jun 20 19:08:45 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:45 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:47 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:47 johannes-test-controller-0 coreos-metadata[1315]: Jun 20 19:08:47.362 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:47 johannes-test-controller-0 coreos-metadata[1315]: Jun 20 19:08:47.369 INFO Fetch successful
Jun 20 19:08:47 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:47 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: Starting CoreOS Metadata Agent...
Jun 20 19:08:49 johannes-test-controller-0 coreos-metadata[1329]: Jun 20 19:08:49.612 INFO Fetching http://metadata.packet.net/metadata: Attempt #1
Jun 20 19:08:49 johannes-test-controller-0 coreos-metadata[1329]: Jun 20 19:08:49.617 INFO Fetch successful
Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Succeeded.
Jun 20 19:08:49 johannes-test-controller-0 systemd[1]: Started CoreOS Metadata Agent.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Start request repeated too quickly.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: coreos-metadata.service: Failed with result 'start-limit-hit'.
Jun 20 19:08:51 johannes-test-controller-0 systemd[1]: Failed to start CoreOS Metadata Agent.

[johananl]

This is caused by the fact that packet-phone-home.service expects metadata at /run/metadata/flatcar, not /run/metadata/coreos. Fixed in #28.