AWS/Joyent/HP/manual/maas: juju deploy error "connection is shut down"

[Abel Deuring]

CI's cloud health test for AWS fails from time to time with this error:

juju --show-log deploy -e test-cloud-aws local:trusty/dummy-source
2014-11-17 20:50:13 INFO juju.conn api.go:270 connecting to API addresses: [ec2-54-165-56-125.compute-1.amazonaws.com:17070 ip-172-31-9-235.ec2.internal:17070 54.165.56.125:17070 172.31.9.235:17070]
2014-11-17 20:50:13 INFO juju.state.api apiclient.go:242 dialing "wss://ec2-54-165-56-125.compute-1.amazonaws.com:17070/environment/77568b34-18a5-4670-8acd-6bd45398d868/api"
2014-11-17 20:50:13 INFO juju.state.api apiclient.go:242 dialing "wss://ip-172-31-9-235.ec2.internal:17070/environment/77568b34-18a5-4670-8acd-6bd45398d868/api"
2014-11-17 20:50:13 INFO juju.state.api apiclient.go:176 connection established to "wss://ec2-54-165-56-125.compute-1.amazonaws.com:17070/environment/77568b34-18a5-4670-8acd-6bd45398d868/api"
2014-11-17 20:50:13 INFO juju.utils http.go:66 hostname SSL verification disabled
Added charm "local:trusty/dummy-source-0" to the environment.
2014-11-17 20:50:15 ERROR juju.cmd supercommand.go:323 connection is shut down

Full logs:

http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7309/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7342/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7364/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7433/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7449/console

A very similar error occurs too:

juju --show-log deploy -e test-cloud-aws local:trusty/dummy-source
2014-11-20 02:52:17 INFO juju.cmd supercommand.go:37 running juju [1.20.10-precise-amd64 gc]
2014-11-20 02:52:17 INFO juju.conn api.go:270 connecting to API addresses: [ec2-54-165-6-96.compute-1.amazonaws.com:17070 ip-172-31-7-87.ec2.internal:17070 54.165.6.96:17070 172.31.7.87:17070]
2014-11-20 02:52:17 INFO juju.state.api apiclient.go:242 dialing "wss://ec2-54-165-6-96.compute-1.amazonaws.com:17070/environment/14c196de-42d7-4d30-8167-eb630de31e7b/api"
2014-11-20 02:52:17 INFO juju.state.api apiclient.go:242 dialing "wss://ip-172-31-7-87.ec2.internal:17070/environment/14c196de-42d7-4d30-8167-eb630de31e7b/api"
2014-11-20 02:52:17 INFO juju.state.api apiclient.go:176 connection established to "wss://ec2-54-165-6-96.compute-1.amazonaws.com:17070/environment/14c196de-42d7-4d30-8167-eb630de31e7b/api"
2014-11-20 02:52:19 INFO juju.utils http.go:66 hostname SSL verification disabled
2014-11-20 02:52:19 ERROR juju.cmd supercommand.go:323 cannot upload charm: Post https://ec2-54-165-6-96.compute-1.amazonaws.com:17070/charms?series=trusty: EOF

http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7363/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7380/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7395/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7481/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-aws/7488/console

[Abel Deuring (adeuring)]

I see similar or the same errors for CI's Joyent tests:

juju --show-log deploy -e test-cloud-joyent local:trusty/dummy-source
2014-11-25 10:48:33 INFO juju.cmd supercommand.go:37 running juju [1.20.10-precise-amd64 gc]
2014-11-25 10:48:33 INFO juju.conn api.go:270 connecting to API addresses: [72.2.112.147:17070 10.112.7.79:17070]
2014-11-25 10:48:33 INFO juju.state.api apiclient.go:242 dialing "wss://72.2.112.147:17070/environment/7642a7c1-d029-4e11-8084-a5dd0e460e87/api"
2014-11-25 10:48:33 INFO juju.state.api apiclient.go:176 connection established to "wss://72.2.112.147:17070/environment/7642a7c1-d029-4e11-8084-a5dd0e460e87/api"
2014-11-25 10:48:33 INFO juju.utils http.go:66 hostname SSL verification disabled
Added charm "local:trusty/dummy-source-0" to the environment.
2014-11-25 10:48:36 ERROR juju.cmd supercommand.go:323 connection is shut down

full llog for the rror above:
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5188/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5147/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5029/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5028/console

or:

juju --show-log deploy -e test-cloud-joyent local:trusty/dummy-source
2014-11-25 06:58:05 INFO juju.cmd supercommand.go:37 running juju [1.20.10-precise-amd64 gc]
2014-11-25 06:58:05 INFO juju.conn api.go:270 connecting to API addresses: [165.225.130.222:17070 10.112.75.119:17070]
2014-11-25 06:58:05 INFO juju.state.api apiclient.go:242 dialing "wss://165.225.130.222:17070/environment/687b798a-0fdd-4035-87d6-6794308b3719/api"
2014-11-25 06:58:05 INFO juju.state.api apiclient.go:176 connection established to "wss://165.225.130.222:17070/environment/687b798a-0fdd-4035-87d6-6794308b3719/api"
2014-11-25 06:58:06 INFO juju.utils http.go:66 hostname SSL verification disabled
2014-11-25 06:58:08 ERROR juju.cmd supercommand.go:323 cannot upload charm: Post https://165.225.130.222:17070/charms?series=trusty: EOF

full logs:
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5184/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5174/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5146/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5077/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5067/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5066/console
http://juju-ci.vapour.ws:8080/view/Cloud%20Health/job/test-cloud-joyent/5030/console

or

juju --show-log deploy -e test-cloud-joyent local:trusty/dummy-source
2014-11-23 13:49:15 INFO juju.cmd supercommand.go:37 running juju [1.20.10-precise-amd64 gc]
2014-11-23 13:49:15 INFO juju.conn api.go:270 connecting to API addresses: [165.225.131.14:17070 10.112.73.200:17070]
2014-11-23 13:49:15 INFO juju.state.api apiclient.go:242 dialing "wss://165.225.131.14:17070/environment/2db0f749-da09-4c44-89ec-c8ba0fd52753/api"
2014-11-23 13:49:15 INFO juju.state.api apiclient.go:242 dialing "wss://10.112.73.200:17070/environment...

[Aaron Bentley (abentley)]

Manual provider is also affected: http://juju-ci.vapour.ws:8080/job/manual-deploy-precise-amd64/1531/console

[Curtis Hovey (sinzui)]

A more recent example http://juju-ci.vapour.ws:8080/job/joyent-deploy-trusty-amd64/3/console

[John George (jog)]

Recently this issue is hit by most test attempts of the master branch on MaaS.

The same tests go through for the 1.21 branch, so it seems something has exasperated the situation for master and although intermittent, potentially a regression.

It seems that then Juju returns from Bootstrap, the server is not actually ready to accept connections, yet a scripted Juju solution will immediately attempt the next juju command. Is it possible to guarantee that Juju is ready for connections when bootstrap returns?

QA could add a wait to our test case but that would only mask an issue that customers who also want to script Juju will encounter.

[John George (jog)]

Raising to critical, since this is causing test failures on multiple substrates at more frequent rates.

[Dimiter Naydenov (dimitern)]

It does seem the underlying issue is actually bug #1403721 so this one might be a duplicate.

[Nate Finch (natefinch)]

I'm looking at fixing the above bug to resolve this one.

[Menno Finlay-Smits (menno.smits)]

AWS health test runs are now clean so marking this as Fix Committed to unblock CI

[Menno Finlay-Smits (menno.smits)]

Fix Released even...

[Eric Snow (ericsnowcurrently)]

FTR: https://github.com/juju/juju/pull/1346