machine fails to start with "connection permanently impossible" error

[Martin Hilton]

In a prodstack model I had a machine that gave up whilst being provisioned with the following error:

2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:582 "api-caller" manifold worker stopped: [466165] "machine-13" cannot open api: connection permanently impossible

This seems to indicate that the agent couldn't log in to the controller, as I understand it this should not happen.

For completeness the entire machine log is:

2018-12-11 11:54:19 INFO juju.cmd supercommand.go:56 running jujud [2.4.7 gc go1.11.2]
2018-12-11 11:54:19 DEBUG juju.cmd supercommand.go:57 args: []string{"/var/lib/juju/tools/machine-13/jujud", "machine", "--data-dir", "/var/lib/juju", "--machine-id", "13", "--debug"}
2018-12-11 11:54:19 DEBUG juju.utils gomaxprocs.go:24 setting GOMAXPROCS to 1
2018-12-11 11:54:19 DEBUG juju.agent agent.go:545 read agent config, format "2.0"
2018-12-11 11:54:19 INFO juju.worker.upgradesteps worker.go:74 upgrade steps for 2.4.7 have already been run.
2018-12-11 11:54:19 DEBUG juju.worker.introspection socket.go:97 introspection worker listening on "@jujud-machine-13"
2018-12-11 11:54:19 DEBUG juju.worker.introspection socket.go:127 stats worker now serving
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "clock" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "upgrade-check-gate" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "termination-signal-handler" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "agent" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "upgrade-steps-gate" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "upgrade-check-flag" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "api-config-watcher" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "state-config-watcher" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.dependency engine.go:545 "upgrade-steps-flag" manifold worker started
2018-12-11 11:54:19 DEBUG juju.worker.apicaller connect.go:128 connecting with old password
2018-12-11 11:54:19 DEBUG juju.api apiclient.go:883 successfully dialed "wss://10.25.2.109:17070/model/466165d9-6c80-4833-835f-8fee6e1f32d2/api"
2018-12-11 11:54:19 INFO juju.api apiclient.go:603 connection established to "wss://10.25.2.109:17070/model/466165d9-6c80-4833-835f-8fee6e1f32d2/api"
2018-12-11 11:54:20 DEBUG juju.worker.apicaller connect.go:155 [466165] failed to connect
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:582 "api-caller" manifold worker stopped: [466165] "machine-13" cannot open api: connection permanently impossible
2018-12-11 11:54:20 INFO juju.agent uninstall.go:36 marking agent ready for uninstall
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "upgrade-steps-flag" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "upgrade-check-flag" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "upgrade-steps-gate" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "upgrade-check-gate" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "clock" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "termination-signal-handler" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "agent" manifold worker completed successfully
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "api-config-watcher" manifold worker completed successfully
2018-12-11 11:54:20 INFO juju.worker.stateconfigwatcher manifold.go:119 tomb dying
2018-12-11 11:54:20 DEBUG juju.worker.dependency engine.go:572 "state-config-watcher" manifold worker completed successfully
2018-12-11 11:54:20 INFO juju.agent uninstall.go:47 agent already marked ready for uninstall
2018-12-11 11:54:20 INFO juju.cmd.jujud machine.go:1238 uninstalling agent
2018-12-11 11:54:20 DEBUG juju.service discovery.go:115 discovered init system "systemd" from local host
2018-12-11 11:54:20 DEBUG juju.cmd.jujud introspection.go:72 engine stopped, stopping introspection
2018-12-11 11:54:20 DEBUG juju.worker.introspection socket.go:136 stats worker closing listener
2018-12-11 11:54:20 DEBUG juju.worker.introspection socket.go:131 stats worker serving finished
2018-12-11 11:54:20 DEBUG juju.worker.introspection socket.go:140 stats worker finished
2018-12-11 11:54:20 DEBUG juju.cmd.jujud introspection.go:75 introspection stopped
2018-12-11 11:54:20 DEBUG juju.service.systemd service.go:397 service "jujud-machine-13" successfully removed
2018-12-11 11:54:20 DEBUG juju.service discovery.go:115 discovered init system "systemd" from local host
2018-12-11 11:54:20 DEBUG juju.service.systemd service.go:349 service "juju-db" not running
2018-12-11 11:54:20 DEBUG juju.service.systemd service.go:391 service "juju-db" not installed
2018-12-11 11:54:20 INFO cmd supercommand.go:465 command finished
2018-12-11 11:54:20 DEBUG juju.cmd.jujud main.go:201 jujud complete, code 0, err <nil>

[Casey Marshall (cmars)]

I've seen the same issue: https://paste.ubuntu.com/p/T5zdbRSXmY/