intermittent test failure on bot - MachineSuite.TestManageStateServesAPI

[Ian Booth]

A bot test run failed with the below error, which was in code unrelated to my branch. A resubmitted and all was good the second time.

----------------------------------------------------------------------
FAIL: machine_test.go:377: MachineSuite.TestManageStateServesAPI

[LOG] 44.19070 INFO juju environs/testing: uploading FAKE tools 1.13.3-precise-amd64
[LOG] 44.20722 INFO juju.environs.boostrap bootstrapping environment "dummyenv"
[LOG] 44.20725 INFO juju.environs.tools reading tools with major.minor version 1.13
[LOG] 44.20726 INFO juju.environs.tools filtering tools by version: 1.13.3
[LOG] 44.20727 INFO juju.environs.tools filtering tools by series: precise
[LOG] 44.20728 DEBUG juju.environs.tools reading v1.13 tools
[LOG] 44.20730 DEBUG juju.environs.tools reading v1.13 tools
[LOG] 44.20732 DEBUG juju.environs.tools found 1.13.3-precise-amd64
[LOG] 44.20736 INFO juju environs/dummy: would pick tools from 1.13.3-precise-amd64
[LOG] 44.22801 INFO juju.state opening state; mongo addresses: ["localhost:35479"]; entity ""
[LOG] 44.24639 INFO juju.state connection established
[LOG] 44.27283 INFO juju.state initializing environment
[LOG] 44.29394 INFO juju state/api: listening on "127.0.0.1:43394"
[LOG] 44.31724 INFO juju.state opening state; mongo addresses: ["localhost:35479"]; entity ""
[LOG] 44.32022 INFO juju.state connection established
[LOG] 44.32098 INFO juju juju: authorization error while connecting to state server; retrying
[LOG] 44.32104 INFO juju.state opening state; mongo addresses: ["localhost:35479"]; entity ""
[LOG] 44.32848 INFO juju.state connection established
[LOG] 44.35858 INFO juju state/api: dialing "wss://127.0.0.1:43394/"
[LOG] 44.36155 INFO juju state/api: connection established
[LOG] 44.36169 DEBUG juju rpc/jsoncodec: <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}}
[LOG] 44.36205 DEBUG juju rpc/jsoncodec: -> {"RequestId":1,"Response":{}}
[LOG] 44.36230 INFO juju.container.lxc lxcObjectFactory replaced with mock lxc factory
[LOG] 44.36333 DEBUG juju rpc/jsoncodec: <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}}
[LOG] 44.36339 DEBUG juju rpc/jsoncodec: -> {"RequestId":2,"Response":{}}
[LOG] 44.43620 INFO juju machine agent machine-0 start
[LOG] 44.45290 INFO juju Starting StateWorker for machine-0
[LOG] 44.45318 INFO juju worker: start "state"
[LOG] 44.45322 INFO juju.state opening state; mongo addresses: ["localhost:35479"]; entity "machine-0"
[LOG] 44.45349 INFO juju worker: start "api"
[LOG] 44.45369 INFO juju state/api: dialing "wss://localhost:52590/"
[LOG] 44.45418 ERROR juju state/api: websocket.Dial wss://localhost:52590/: dial tcp 127.0.0.1:52590: connection refused
[LOG] 44.45421 ERROR juju worker: exited "api": websocket.Dial wss://localhost:52590/: dial tcp 127.0.0.1:52590: connection refused
[LOG] 44.45423 INFO juju worker: restarting "api" in 50ms
[LOG] 44.47690 INFO juju.state connection established
[LOG] 44.48655 INFO juju state/api: dialing "wss://localhost:52590/"
[LOG] 44.48678 INFO juju worker: start "lxc-provisioner"
[LOG] 44.48681 INFO juju worker: start "apiserver"
[LOG] 44.48688 INFO juju state/api: listening on "[::]:52590"
[LOG] 44.51019 INFO juju worker: start "cleaner"
[LOG] 44.51049 INFO juju worker: start "resumer"
[LOG] 44.51066 INFO juju worker: start "minunitsworker"
[LOG] 44.51085 ERROR juju state/api: websocket.Dial wss://localhost:52590/: dial tcp 127.0.0.1:52590: connection refused
[LOG] 44.51097 INFO juju worker: start "api"
[LOG] 44.51126 INFO juju state/api: dialing "wss://localhost:52590/"
[LOG] 44.51558 INFO juju.provisioner Starting up provisioner task 0
[LOG] 44.51592 INFO juju state/api: connection established
[LOG] 44.51604 DEBUG juju rpc/jsoncodec: <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"machine-0","Password":"machine-password","Nonce":"user-admin:bootstrap"}}
[LOG] 44.51862 DEBUG juju rpc/jsoncodec: -> {"RequestId":1,"Response":{}}
[LOG] 44.53298 DEBUG juju rpc/jsoncodec: <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}}
[LOG] 44.53312 DEBUG juju rpc/jsoncodec: <- {"RequestId":3,"Type":"Agent","Request":"GetEntities","Params":{"Entities":[{"Tag":"machine-0"}]}}
[LOG] 44.53323 DEBUG juju rpc/jsoncodec: -> {"RequestId":2,"Response":{}}
[LOG] 44.53393 DEBUG juju rpc/jsoncodec: -> {"RequestId":3,"Response":{"Entities":[{"Life":"alive","Jobs":["JobManageState"],"Error":null}]}}
[LOG] 44.53424 DEBUG juju rpc/jsoncodec: <- {"RequestId":4,"Type":"Agent","Request":"SetPasswords","Params":{"Changes":[{"Tag":"machine-0","Password":"qLTZojCIihA2ybN6x0Ftb3I6"}]}}
[LOG] 44.53702 INFO juju state/api: dialing "wss://localhost:52590/"
[LOG] 44.54772 INFO juju state/api: connection established
[LOG] 44.54806 DEBUG juju rpc/jsoncodec: <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"machine-0","Password":"machine-password","Nonce":"user-admin:bootstrap"}}
[LOG] 44.55720 DEBUG juju rpc/jsoncodec: -> {"RequestId":1,"Error":"invalid entity name or password","ErrorCode":"unauthorized access","Response":{}}
machine_test.go:385:
    s.assertJobWithState(c, state.JobManageState, func(conf agent.Config, agentState *state.State) {
        st, _, err := conf.OpenAPI(fastDialOpts)
        c.Assert(err, gc.IsNil)
        defer st.Close()
        m, err := st.Machiner().Machine(conf.Tag())
        c.Assert(err, gc.IsNil)
        c.Assert(m.Life(), gc.Equals, params.Alive)
    })
machine_test.go:380:
    c.Assert(err, gc.IsNil)
... value *params.Error = &params.Error{"unauthorized access", "invalid entity name or password"} ("invalid entity name or password")

[LOG] 44.56918 DEBUG juju worker: killing runner 0xc200298ae0
[LOG] 44.56937 INFO juju worker: runner is dying
[LOG] 44.56940 DEBUG juju worker: killing "state"
[LOG] 44.56943 DEBUG juju worker: killing runner 0xc2005f9900
[LOG] 44.56947 INFO juju worker: runner is dying
[LOG] 44.56949 DEBUG juju worker: killing "lxc-provisioner"
[LOG] 44.56952 DEBUG juju worker: killing "apiserver"
[LOG] 44.56955 DEBUG juju worker: killing "cleaner"
[LOG] 44.56958 DEBUG juju worker: killing "resumer"
[LOG] 44.56961 DEBUG juju worker: killing "minunitsworker"
[LOG] 44.56988 INFO juju.provisioner Shutting down provisioner task 0
[LOG] 44.57111 DEBUG juju rpc/jsoncodec: <- error: read tcp 127.0.0.1:50102: use of closed network connection (closing true)
[LOG] 44.57126 DEBUG juju rpc/jsoncodec: -> {"RequestId":4,"Response":{"Results":[{"Error":null}]}}
[LOG] 44.57227 INFO juju worker: ignoring start request for "state" when dying
[LOG] 44.57234 INFO juju worker: start "machiner"
[LOG] 44.57239 DEBUG juju worker: killing "api"
[LOG] 44.57242 DEBUG juju worker: killing runner 0xc20078d120
[LOG] 44.57259 INFO juju worker: start "upgrader"
[LOG] 44.57264 INFO juju worker: runner is dying
[LOG] 44.57270 DEBUG juju worker: killing "machiner"
[LOG] 44.57273 DEBUG juju worker: killing "upgrader"
[LOG] 44.57422 DEBUG juju rpc/jsoncodec: <- error: read tcp 127.0.0.1:50101: use of closed network connection (closing true)
[LOG] 44.57518 ERROR juju worker: fatal "machiner": connection is shut down
[LOG] 44.57523 ERROR juju worker: fatal "upgrader": connection is shut down
[LOG] 44.57532 INFO juju rpc: error closing codec: write tcp 127.0.0.1:52590: connection reset by peer
[LOG] 44.57536 ERROR juju worker: exited "api": connection is shut down
[LOG] 44.57546 INFO juju.container.lxc lxcObjectFactory replaced with &{}
[LOG] 44.57730 INFO juju environs/dummy: reset environment
[LOG] 44.57759 DEBUG juju rpc/jsoncodec: <- error: read tcp 127.0.0.1:51459: use of closed network connection (closing true)
[jujuc whatever]
[remote]
[/path/to/remote]
[remote --help]
[unknown]
[remote --error borken]
[remote --unknown]
[remote unwanted]
OOPS: 31 passed, 3 skipped, 1 FAILED
--- FAIL: TestPackage (37.52 seconds)
FAIL
FAIL launchpad.net/juju-core/cmd/jujud 37.797s

[John A Meinel (jameinel)]

sorry I missed this one, apparently Launchpad dedupe doesn't find the test name if you have the prefix on it. :(

Anyway, marking dupe of my bug since I already have an associated branch.