RebootSuite.TestRebootNoContainers failed with panic after juju.testing failed to start mongo: mongod failed to listen on port 34249

[Heather Lanigan]

http://ci.jujucharms.com/job/make-check-juju/3739/consoleFull

14:58:20 ----------------------------------------------------------------------
14:58:20 FAIL: reboot_test.go:60: RebootSuite.SetUpTest
14:58:20
14:58:20 [LOG] 0:00.005 DEBUG juju.environs.tools reading v1.* agent binaries
14:58:20 [LOG] 0:00.005 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-precise-amd64
14:58:20 [LOG] 0:00.012 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-trusty-amd64
14:58:20 [LOG] 0:00.013 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-xenial-amd64
14:58:20 [LOG] 0:00.014 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-bionic-amd64
14:58:20 [LOG] 0:00.016 INFO juju.environs.tools Writing tools/streams/v1/index2.json
14:58:20 [LOG] 0:00.016 INFO juju.environs.tools Writing tools/streams/v1/index.json
14:58:20 [LOG] 0:00.016 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju-released-tools.json
14:58:20 [LOG] 0:00.025 DEBUG juju.environs.tools reading v1.* agent binaries
14:58:20 [LOG] 0:00.025 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-precise-amd64
14:58:20 [LOG] 0:00.026 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-trusty-amd64
14:58:20 [LOG] 0:00.027 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-xenial-amd64
14:58:20 [LOG] 0:00.027 INFO juju.environs.testing uploading FAKE tools 2.6-beta1-bionic-amd64
14:58:20 [LOG] 0:00.029 DEBUG juju.environs.simplestreams skipping index "file:///tmp/juju-unittestfs/check-2694337319047928910/5/tools/streams/v1/index2.json" because of missing information: "content-download" data not found
14:58:20 [LOG] 0:00.030 DEBUG juju.environs.simplestreams skipping index "file:///tmp/juju-unittestfs/check-2694337319047928910/5/tools/streams/v1/index2.json" because of missing information: "content-download" data not found
14:58:20 [LOG] 0:00.030 DEBUG juju.environs.simplestreams skipping index "file:///tmp/juju-unittestfs/check-2694337319047928910/5/tools/streams/v1/index2.json" because of missing information: "content-download" data not found
14:58:20 [LOG] 0:00.031 INFO juju.environs.tools Writing tools/streams/v1/index2.json
14:58:20 [LOG] 0:00.031 INFO juju.environs.tools Writing tools/streams/v1/index.json
14:58:20 [LOG] 0:00.031 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju-devel-tools.json
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.bootstrap model "controller" supports application/machine networks: true
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.bootstrap network management by juju enabled: true
14:58:20 [LOG] 0:00.043 INFO cmd Loading image metadata
14:58:20 [LOG] 0:00.043 INFO juju.environs.bootstrap looking for bootstrap agent binaries: version=2.6-beta1
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.tools finding agent binaries in stream: "devel, proposed, released"
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.tools reading agent binaries with major.minor version 2.6
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.tools filtering agent binaries by version: 2.6-beta1
14:58:20 [LOG] 0:00.043 DEBUG juju.environs.tools filtering agent binaries by architecture: amd64
14:58:20 [LOG] 0:00.047 DEBUG juju.environs.simplestreams skipping index "file:///tmp/juju-unittestfs/check-2694337319047928910/5/tools/streams/v1/index2.sjson" because of missing information: "content-download" data not found
14:58:20 [LOG] 0:00.048 INFO juju.environs.bootstrap found 4 packaged agent binaries
14:58:20 [LOG] 0:00.049 INFO cmd Starting new instance for initial controller
14:58:20 [LOG] 0:00.049 INFO juju.provider.dummy would pick agent binaries from 2.6-beta1-bionic-amd64
14:58:20 [LOG] 0:00.049 INFO juju.provider.dummy creating bootstrap instance
14:58:20 [LOG] 0:00.049 INFO juju.environs.bootstrap newest version: 2.6-beta1
14:58:20 [LOG] 0:00.049 INFO juju.environs.bootstrap picked bootstrap agent binary version: 2.6-beta1
14:58:20 [LOG] 0:00.067 DEBUG juju.cloudconfig.instancecfg Setting numa ctl preference to false
14:58:20 [LOG] 0:00.070 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.142 DEBUG juju.state mongodb initialised
14:58:20 [LOG] 0:00.142 INFO juju.state running state anonymously; using unique store id
14:58:20 [LOG] 0:00.142 INFO juju.state starting standard state workers
14:58:20 [LOG] 0:00.142 INFO juju.state creating cloud image metadata storage
14:58:20 [LOG] 0:00.142 INFO juju.state started state for model-deadbeef-0bad-400d-8000-4b1d0d06f00d successfully
14:58:20 [LOG] 0:00.143 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.144 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.144 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.144 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.145 DEBUG juju.state.presence using $bit operations with Mongo 3.6.3
14:58:20 [LOG] 0:00.147 INFO juju.state initializing controller model deadbeef-0bad-400d-8000-4b1d0d06f00d
14:58:20 [LOG] 0:00.353 DEBUG juju.provider.dummy setting password for "admin" to "dummy-secret"
14:58:20 [LOG] 0:00.364 WARNING juju.apiserver.logsink Unable to prime /tmp/juju-unittestfs/check-2694337319047928910/4/logsink.log (proceeding anyway): chown /tmp/juju-unittestfs/check-2694337319047928910/4/logsink.log: operation not permitted
14:58:20 [LOG] 0:00.399 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.419 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.454 INFO juju.state starting standard state workers
14:58:20 [LOG] 0:00.454 INFO juju.state creating cloud image metadata storage
14:58:20 [LOG] 0:00.454 INFO juju.state started state for model-deadbeef-0bad-400d-8000-4b1d0d06f00d successfully
14:58:20 [LOG] 0:00.456 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.456 DEBUG juju.environs ControllerInstances returned: [localhost]
14:58:20 [LOG] 0:00.456 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.456 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:42985"
14:58:20 [LOG] 0:00.456 DEBUG juju.state.presence using $bit operations with Mongo 3.6.3
14:58:20 [LOG] 0:00.457 DEBUG juju.api looked up localhost -> [127.0.0.1]
14:58:20 [LOG] 0:00.470 DEBUG juju.apiserver [1] API connection from 127.0.0.1:51086
14:58:20 [LOG] 0:00.470 DEBUG juju.api successfully dialed "wss://localhost:42767/model/deadbeef-0bad-400d-8000-4b1d0d06f00d/api"
14:58:20 [LOG] 0:00.470 INFO juju.api connection established to "wss://localhost:42767/model/deadbeef-0bad-400d-8000-4b1d0d06f00d/api"
14:58:20 [LOG] 0:00.470 DEBUG juju.apiserver <- [1] {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
14:58:20 [LOG] 0:00.484 DEBUG juju.apiserver model login: user admin has "superuser" for controller; "admin" for model deadbeef-0bad-400d-8000-4b1d0d06f00d
14:58:20 [LOG] 0:00.484 DEBUG juju.apiserver model login: user-admin for deadbeef-0bad-400d-8000-4b1d0d06f00d
14:58:20 [LOG] 0:00.485 DEBUG juju.apiserver -> [1] 14.411518ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
14:58:20 [LOG] 0:00.486 DEBUG juju.state setting apiHostPorts: [[localhost:42767]]
14:58:20 [LOG] 0:00.486 DEBUG juju.state setting apiHostPortsForAgents: [[localhost:42767]]
14:58:20 [LOG] 0:00.506 DEBUG juju.testing starting mongo in /tmp/juju-unittestfs/test-mgo667342863
14:58:20 [LOG] 0:00.507 DEBUG juju.testing using mongod at: "/usr/bin/mongod" (version=3.6.3)
14:58:20 [LOG] 0:00.603 WARNING juju.testing failed to start mongo: mongod failed to listen on port 34249
14:58:20 reboot_test.go:74:
14:58:20 c.Assert(err, jc.ErrorIsNil)
14:58:20 ... value *errors.errorString = &errors.errorString{s:"mongod failed to listen on port 34249"} ("mongod failed to listen on port 34249")
14:58:20
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongodb has exited without being killed
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: note: noprealloc may hurt performance in many applications
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] MongoDB starting : pid=6339 port=34249 dbpath=/tmp/juju-unittestfs/test-mgo667342863 64-bit host=pr-check-9916-make-check-juju-1553020634
14:58:20
14:58:20 ----------------------------------------------------------------------
14:58:20 PANIC: reboot_nix_test.go:46: RebootSuite.TestRebootNoContainers
14:58:20
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] db version v3.6.3
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] git version: 9586e557d54ef70f9ca4b43c26892cd55257e1a5
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.1.0g 2 Nov 2017
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] allocator: tcmalloc
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] modules: none
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] build environment:
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] distarch: x86_64
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] target_arch: x86_64
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 I CONTROL [initandlisten] options: { net: { ipv6: true, port: 34249, ssl: { PEMKeyFile: "/tmp/juju-unittestfs/test-mgo667342863/server.pem", PEMKeyPassword: "<password>", mode: "requireSSL" }, unixDomainSocket: { enabled: false } }, replication: { oplogSizeMB: 10 }, security: { authorization: "enabled", keyFile: "/tmp/juju-unittestfs/test-mgo667342863/keyfile" }, setParameter: { enableTestCommands: "1" }, storage: { dbPath: "/tmp/juju-unittestfs/test-mgo667342863", engine: "mmapv1", mmapv1: { nsSize: 1, preallocDataFiles: false, smallFiles: true } } }
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.790+0000 E STORAGE [initandlisten] Failed to set up listener: SocketException: Address already in use
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.791+0000 I CONTROL [initandlisten] now exiting
14:58:20 [LOG] 0:00.605 ERROR juju.testing mongod: 2019-03-19T18:54:59.791+0000 I CONTROL [initandlisten] shutting down with code:48
14:58:20 [LOG] 0:00.605 DEBUG juju.api RPC connection died
14:58:20 [LOG] 0:00.605 DEBUG juju.rpc error closing codec: write tcp 127.0.0.1:42767->127.0.0.1:51086: write: broken pipe
14:58:20 [LOG] 0:00.605 DEBUG juju.apiserver [1] user-admin API connection terminated after 135.545865ms
14:58:20 [LOG] 0:00.605 DEBUG juju.state closed state without error
14:58:20 [LOG] 0:00.605 INFO juju.provider.dummy reset model
14:58:20 [LOG] 0:00.605 DEBUG juju.provider.dummy closing httpServer
14:58:20 [LOG] 0:00.605 DEBUG juju.provider.dummy stopping apiServer
14:58:20 [LOG] 0:00.613 DEBUG juju.provider.dummy stopping modelCache worker
14:58:20 [LOG] 0:00.613 DEBUG juju.provider.dummy closing apiStatePool
14:58:20 [LOG] 0:00.615 DEBUG juju.state closed state without error
14:58:20 [LOG] 0:00.615 DEBUG juju.provider.dummy resetting MgoServer
14:58:20 [LOG] 0:00.617 INFO juju.testing reset successfully reset admin password
14:58:20 [LOG] 0:00.638 INFO juju.testing reset successfully reset admin password
14:58:20 ... Panic: Fixture has panicked (see related PANIC)
14:58:20
14:58:20 ----------------------------------------------------------------------

[Canonical Juju QA Bot (juju-qa-bot)]

This bug has not been updated in 2 years, so we're marking it Low importance. If you believe this is incorrect, please update the importance.