The attempt to merge lp:~thumper/juju-core/upstart-system into lp:juju-core failed. Below is the output from the failed tests. ok launchpad.net/juju-core/agent 0.316s ok launchpad.net/juju-core/agent/tools 0.247s ok launchpad.net/juju-core/bzr 6.939s ok launchpad.net/juju-core/cert 3.805s ok launchpad.net/juju-core/charm 0.539s ? launchpad.net/juju-core/charm/hooks [no test files] ok launchpad.net/juju-core/cloudinit 0.027s ok launchpad.net/juju-core/cmd 0.199s ? launchpad.net/juju-core/cmd/charmd [no test files] ? launchpad.net/juju-core/cmd/charmload [no test files] ok launchpad.net/juju-core/cmd/juju 163.854s ok launchpad.net/juju-core/cmd/jujud 40.986s ok launchpad.net/juju-core/cmd/plugins/juju-metadata 1.759s ok launchpad.net/juju-core/constraints 0.033s ok launchpad.net/juju-core/container/lxc 0.314s ? launchpad.net/juju-core/container/lxc/mock [no test files] ok launchpad.net/juju-core/downloader 5.258s ok launchpad.net/juju-core/environs 2.526s ok launchpad.net/juju-core/environs/bootstrap 5.672s ok launchpad.net/juju-core/environs/cloudinit 0.477s ok launchpad.net/juju-core/environs/config 0.726s ok launchpad.net/juju-core/environs/configstore 0.031s ok launchpad.net/juju-core/environs/filestorage 0.029s ok launchpad.net/juju-core/environs/httpstorage 0.726s ok launchpad.net/juju-core/environs/imagemetadata 0.481s ok launchpad.net/juju-core/environs/instances 0.051s ok launchpad.net/juju-core/environs/jujutest 0.282s ok launchpad.net/juju-core/environs/manual 4.895s ok launchpad.net/juju-core/environs/simplestreams 0.331s ? launchpad.net/juju-core/environs/simplestreams/testing [no test files] ok launchpad.net/juju-core/environs/sshstorage 0.650s ok launchpad.net/juju-core/environs/storage 1.025s ok launchpad.net/juju-core/environs/sync 27.790s ok launchpad.net/juju-core/environs/testing 0.213s ok launchpad.net/juju-core/environs/tools 5.866s ? launchpad.net/juju-core/environs/tools/testing [no test files] ok launchpad.net/juju-core/errors 0.015s ok launchpad.net/juju-core/instance 0.021s ? launchpad.net/juju-core/instance/testing [no test files] ok launchpad.net/juju-core/juju 22.457s ok launchpad.net/juju-core/juju/osenv 0.017s ? launchpad.net/juju-core/juju/testing [no test files] ok launchpad.net/juju-core/log 0.015s ok launchpad.net/juju-core/log/syslog 0.023s ok launchpad.net/juju-core/names 0.031s ? launchpad.net/juju-core/provider [no test files] ? launchpad.net/juju-core/provider/all [no test files] ok launchpad.net/juju-core/provider/azure 6.716s ok launchpad.net/juju-core/provider/common 0.273s ok launchpad.net/juju-core/provider/dummy 21.001s ok launchpad.net/juju-core/provider/ec2 4.894s ok launchpad.net/juju-core/provider/ec2/httpstorage 0.198s ok launchpad.net/juju-core/provider/local 1.651s ok launchpad.net/juju-core/provider/maas 3.883s ok launchpad.net/juju-core/provider/null 1.094s ok launchpad.net/juju-core/provider/openstack 12.162s ok launchpad.net/juju-core/rpc 0.075s ok launchpad.net/juju-core/rpc/jsoncodec 0.027s ? launchpad.net/juju-core/rpc/rpcreflect [no test files] ok launchpad.net/juju-core/schema 0.018s ok launchpad.net/juju-core/state 66.983s ok launchpad.net/juju-core/state/api 1.511s ok launchpad.net/juju-core/state/api/agent 2.034s ? launchpad.net/juju-core/state/api/common [no test files] ok launchpad.net/juju-core/state/api/deployer 6.086s ok launchpad.net/juju-core/state/api/logger 2.191s ok launchpad.net/juju-core/state/api/machiner 3.016s ok launchpad.net/juju-core/state/api/params 0.031s ok launchpad.net/juju-core/state/api/provisioner 7.249s ok launchpad.net/juju-core/state/api/uniter 25.390s ok launchpad.net/juju-core/state/api/upgrader 3.680s ok launchpad.net/juju-core/state/api/watcher 3.251s ok launchpad.net/juju-core/state/apiserver 3.838s ok launchpad.net/juju-core/state/apiserver/agent 2.600s ok launchpad.net/juju-core/state/apiserver/client 20.710s ok launchpad.net/juju-core/state/apiserver/common 1.860s ok launchpad.net/juju-core/state/apiserver/deployer 4.509s ok launchpad.net/juju-core/state/apiserver/logger 3.614s ok launchpad.net/juju-core/state/apiserver/machine 3.842s ok launchpad.net/juju-core/state/apiserver/provisioner 8.561s ? launchpad.net/juju-core/state/apiserver/testing [no test files] ok launchpad.net/juju-core/state/apiserver/uniter 18.715s ok launchpad.net/juju-core/state/apiserver/upgrader 5.963s ok launchpad.net/juju-core/state/multiwatcher 0.837s ok launchpad.net/juju-core/state/presence 6.536s ok launchpad.net/juju-core/state/statecmd 6.812s ? launchpad.net/juju-core/state/testing [no test files] ok launchpad.net/juju-core/state/watcher 5.496s ok launchpad.net/juju-core/store 18.293s ok launchpad.net/juju-core/testing 1.376s ok launchpad.net/juju-core/testing/checkers 0.018s ok launchpad.net/juju-core/testing/testbase 0.018s ok launchpad.net/juju-core/thirdparty/pbkdf2 0.137s ok launchpad.net/juju-core/tools 0.019s ok launchpad.net/juju-core/upstart 1.169s ok launchpad.net/juju-core/utils 1.079s ok launchpad.net/juju-core/utils/fslock 0.955s ok launchpad.net/juju-core/utils/parallel 0.425s ok launchpad.net/juju-core/utils/set 0.016s ok launchpad.net/juju-core/version 0.073s ok launchpad.net/juju-core/worker 1.856s ok launchpad.net/juju-core/worker/cleaner 1.394s ok launchpad.net/juju-core/worker/deployer 3.702s ok launchpad.net/juju-core/worker/firewaller 11.061s ? launchpad.net/juju-core/worker/localstorage [no test files] ok launchpad.net/juju-core/worker/logger 1.611s ok launchpad.net/juju-core/worker/machiner 2.727s ok launchpad.net/juju-core/worker/minunitsworker 1.344s ok launchpad.net/juju-core/worker/provisioner 18.648s ok launchpad.net/juju-core/worker/resumer 1.634s ---------------------------------------------------------------------- FAIL: uniter_test.go:1017: UniterSuite.TestUniterSubordinates [LOG] 22.72002 INFO juju environs/testing: uploading FAKE tools 1.15.1-precise-amd64 [LOG] 22.72124 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 22.72126 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 22.72131 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 22.72133 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 22.72136 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 22.72138 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 22.72158 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 22.72163 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 22.72167 INFO juju.environs.boostrap bootstrapping environment "dummyenv" [LOG] 22.72170 INFO juju.environs.tools reading tools with major.minor version 1.15 [LOG] 22.72171 INFO juju.environs.tools filtering tools by version: 1.15.1 [LOG] 22.72173 INFO juju.environs.tools filtering tools by series: precise [LOG] 22.72177 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 22.72180 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 22.72184 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 22.72197 DEBUG juju.environs.simplestreams no mirror information available for {DataType:content-download MirrorContentId:com.ubuntu.juju:released:tools FilterFunc:0x68eb40 ValueTemplate:{Release: Version: Arch: Size:0 Path: FullPath: FileType: SHA256:}}: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 22.72198 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:47418/dummyenv/private/tools/streams/v1/index.json" [LOG] 22.72203 DEBUG juju.environs.simplestreams candidate matches for products ["com.ubuntu.juju:12.04:amd64" "com.ubuntu.juju:12.04:i386" "com.ubuntu.juju:12.04:arm"] are [{Wed, 02 Oct 2013 01:02:23 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 22.72205 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 22.72227 INFO juju environs/dummy: would pick tools from 1.15.1-precise-amd64 [LOG] 22.75692 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 22.76359 INFO juju.state connection established [LOG] 22.79765 INFO juju.state initializing environment [LOG] 22.81967 INFO juju state/api: listening on "127.0.0.1:43428" [LOG] 22.84708 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 22.86734 INFO juju.state connection established [LOG] 22.86933 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 22.86946 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 22.87701 INFO juju.state connection established [LOG] 22.92383 INFO juju state/api: dialing "wss://127.0.0.1:43428/" [LOG] 22.92705 INFO juju state/api: connection established [LOG] 22.92716 DEBUG juju.rpc.jsoncodec <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 22.92751 DEBUG juju.rpc.jsoncodec -> {"RequestId":1,"Response":{}} test 0: unit becomes dying while subordinates exist step 0: uniter_test.quickStart{} uniter_test.createCharm{revision:0, badHooks:[]string(nil), customize:(func(*gocheck.C, *uniter_test.context, string))(nil)} uniter_test.addCharm{dir:(*charm.Dir)(0xc20045ba20), curl:(*charm.URL)(0xc2018eeb90)} [LOG] 22.97176 DEBUG juju.rpc.jsoncodec <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}} [LOG] 23.00449 DEBUG juju.rpc.jsoncodec -> {"RequestId":2,"Response":{}} uniter_test.serveCharm{} uniter_test.createUniter{} uniter_test.createServiceAndUnit{serviceName:""} [LOG] 23.10732 INFO juju state/api: dialing "wss://127.0.0.1:43428/" [LOG] 23.11153 INFO juju state/api: connection established [LOG] 23.11170 DEBUG juju.rpc.jsoncodec <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"unit-u-0","Password":"password","Nonce":""}} [LOG] 23.12746 DEBUG juju.rpc.jsoncodec -> {"RequestId":1,"Response":{}} API: login as "unit-u-0" successful uniter_test.startUniter{unitTag:""} uniter_test.waitAddresses{} [LOG] 23.12838 DEBUG juju.rpc.jsoncodec <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}} [LOG] 23.12863 DEBUG juju.rpc.jsoncodec <- {"RequestId":3,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.12885 DEBUG juju.rpc.jsoncodec -> {"RequestId":2,"Response":{}} [LOG] 23.13004 DEBUG juju.rpc.jsoncodec -> {"RequestId":3,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.13147 DEBUG juju.rpc.jsoncodec <- {"RequestId":4,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.13184 DEBUG juju.rpc.jsoncodec -> {"RequestId":4,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.13225 DEBUG juju.rpc.jsoncodec <- {"RequestId":5,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 23.13284 DEBUG juju.rpc.jsoncodec -> {"RequestId":5,"Response":{"Error":null,"Result":"43e79ff6-b04b-4c34-851d-057e268b113a"}} [LOG] 23.13311 INFO juju.worker.uniter unit "u/0" started [LOG] 23.13318 INFO juju.worker.uniter ModeInit starting [LOG] 23.13319 INFO juju.worker.uniter updating unit addresses [LOG] 23.13352 DEBUG juju.rpc.jsoncodec <- {"RequestId":6,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 23.13367 DEBUG juju.rpc.jsoncodec <- {"RequestId":7,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.13619 DEBUG juju.rpc.jsoncodec -> {"RequestId":6,"Response":{"Error":null,"Result":"dummy"}} [LOG] 23.13734 DEBUG juju.rpc.jsoncodec -> {"RequestId":7,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.13760 DEBUG juju.rpc.jsoncodec <- {"RequestId":8,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 23.13932 DEBUG juju.rpc.jsoncodec <- {"RequestId":9,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.14113 DEBUG juju.rpc.jsoncodec -> {"RequestId":9,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.14268 DEBUG juju.rpc.jsoncodec <- {"RequestId":10,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.14482 DEBUG juju.rpc.jsoncodec -> {"RequestId":10,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 23.14568 DEBUG juju.rpc.jsoncodec <- {"RequestId":11,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.14803 DEBUG juju.rpc.jsoncodec -> {"RequestId":11,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.14868 DEBUG juju.rpc.jsoncodec <- {"RequestId":12,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.15070 DEBUG juju.rpc.jsoncodec -> {"RequestId":12,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.15184 DEBUG juju.rpc.jsoncodec <- {"RequestId":13,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.15333 DEBUG juju.rpc.jsoncodec -> {"RequestId":13,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 23.15373 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 23.15395 DEBUG juju.rpc.jsoncodec <- {"RequestId":14,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.15593 DEBUG juju.rpc.jsoncodec -> {"RequestId":14,"Response":{"Results":[{"NotifyWatcherId":"2","Error":null}]}} [LOG] 23.15703 DEBUG juju.rpc.jsoncodec <- {"RequestId":15,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.15722 DEBUG juju.rpc.jsoncodec <- {"RequestId":16,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 23.15736 DEBUG juju.rpc.jsoncodec -> {"RequestId":8,"Response":{"Results":[{"Error":null}]}} [LOG] 23.15769 DEBUG juju.rpc.jsoncodec <- {"RequestId":17,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 23.15925 DEBUG juju.rpc.jsoncodec -> {"RequestId":15,"Response":{"Results":[{"NotifyWatcherId":"3","Error":null}]}} [LOG] 23.16006 DEBUG juju.rpc.jsoncodec <- {"RequestId":18,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.16018 DEBUG juju.rpc.jsoncodec <- {"RequestId":19,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 23.16139 DEBUG juju.rpc.jsoncodec -> {"RequestId":18,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} [LOG] 23.16175 DEBUG juju.rpc.jsoncodec <- {"RequestId":20,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.16492 DEBUG juju.rpc.jsoncodec -> {"RequestId":20,"Response":{"Results":[{"StringsWatcherId":"4","Changes":[],"Error":null}]}} [LOG] 23.16527 DEBUG juju.worker.uniter.filter got service change [LOG] 23.16569 DEBUG juju.rpc.jsoncodec <- {"RequestId":21,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.16595 DEBUG juju.rpc.jsoncodec <- {"RequestId":22,"Type":"StringsWatcher","Id":"4","Request":"Next","Params":{}} [LOG] 23.16729 DEBUG juju.rpc.jsoncodec -> {"RequestId":21,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.16759 DEBUG juju.rpc.jsoncodec <- {"RequestId":23,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.16898 DEBUG juju.rpc.jsoncodec -> {"RequestId":17,"Response":{"Results":[{"Error":null}]}} [LOG] 23.16931 DEBUG juju.rpc.jsoncodec -> {"RequestId":23,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 23.16958 INFO juju.worker.uniter reconciling relation state [LOG] 23.16979 DEBUG juju.worker.uniter ModeInit exiting [LOG] 23.16982 INFO juju.worker.uniter ModeContinue starting [LOG] 23.16983 INFO juju.worker.uniter loading uniter state [LOG] 23.16987 INFO juju.worker.uniter charm is not deployed [LOG] 23.17007 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 23.17012 DEBUG juju.worker.uniter.filter got unit change [LOG] 23.17040 DEBUG juju.rpc.jsoncodec <- {"RequestId":24,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.17048 DEBUG juju.rpc.jsoncodec <- {"RequestId":25,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.17089 DEBUG juju.rpc.jsoncodec -> {"RequestId":24,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 23.17108 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 23.17109 INFO juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 starting [LOG] 23.17111 INFO juju.worker.uniter fetching charm "cs:quantal/wordpress-0" [LOG] 23.17122 DEBUG juju.rpc.jsoncodec <- {"RequestId":26,"Type":"Uniter","Request":"CharmArchiveURL","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 23.17159 DEBUG juju.rpc.jsoncodec -> {"RequestId":25,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.17181 DEBUG juju.rpc.jsoncodec <- {"RequestId":27,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.17225 DEBUG juju.rpc.jsoncodec -> {"RequestId":26,"Response":{"Results":[{"Error":null,"Result":"http://localhost:49024/charms/wordpress/0"}]}} [LOG] 23.17249 INFO juju worker/uniter/charm: downloading cs:quantal/wordpress-0 from http://localhost:49024/charms/wordpress/0 [LOG] 23.17318 INFO juju worker/uniter/charm: download complete [LOG] 23.17350 DEBUG juju.rpc.jsoncodec <- {"RequestId":28,"Type":"Uniter","Request":"CharmArchiveSha256","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 23.17409 DEBUG juju.rpc.jsoncodec -> {"RequestId":27,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 23.17423 DEBUG juju.worker.uniter.filter got relations change [LOG] 23.17464 DEBUG juju.rpc.jsoncodec -> {"RequestId":28,"Response":{"Results":[{"Error":null,"Result":"cf84bf96df3eb166609a04c98d9a569820a6b8121d1ef0cdbe09a15892852324"}]}} [LOG] 23.17484 INFO juju worker/uniter/charm: download verified uniter_test.waitUnit{status:"started", info:"", data:params.StatusData(nil), charm:0, resolved:""} [LOG] 23.21421 DEBUG juju.rpc.jsoncodec -> {"RequestId":16,"Response":{}} [LOG] 23.21644 DEBUG juju.worker.uniter.filter got unit change [LOG] 23.21720 DEBUG juju.rpc.jsoncodec <- {"RequestId":29,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 23.21742 DEBUG juju.rpc.jsoncodec <- {"RequestId":30,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.21950 DEBUG juju.rpc.jsoncodec -> {"RequestId":30,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.21985 DEBUG juju.rpc.jsoncodec <- {"RequestId":31,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.22093 DEBUG juju.rpc.jsoncodec -> {"RequestId":31,"Response":{"Results":[{"Error":null,"Mode":""}]}} want unit charm "cs:quantal/wordpress-0", got ""; still waiting [LOG] 23.27049 DEBUG juju.worker.uniter.filter changing charm to "cs:quantal/wordpress-0" [LOG] 23.27113 DEBUG juju.rpc.jsoncodec <- {"RequestId":32,"Type":"Uniter","Request":"SetCharmURL","Params":{"Entities":[{"Tag":"unit-u-0","CharmURL":"cs:quantal/wordpress-0"}]}} [LOG] 23.28851 DEBUG juju.rpc.jsoncodec -> {"RequestId":32,"Response":{"Results":[{"Error":null}]}} [LOG] 23.28952 DEBUG juju.rpc.jsoncodec <- {"RequestId":33,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.28994 DEBUG juju.rpc.jsoncodec <- {"RequestId":34,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.29217 DEBUG juju.rpc.jsoncodec -> {"RequestId":34,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.29262 INFO juju.worker.uniter deploying charm "cs:quantal/wordpress-0" [LOG] 23.29430 DEBUG juju.rpc.jsoncodec -> {"RequestId":33,"Response":{"Results":[{"NotifyWatcherId":"5","Error":null}]}} [LOG] 23.29540 DEBUG juju.rpc.jsoncodec <- {"RequestId":35,"Type":"StringsWatcher","Id":"4","Request":"Stop","Params":{}} [LOG] 23.29563 DEBUG juju.rpc.jsoncodec <- {"RequestId":36,"Type":"NotifyWatcher","Id":"5","Request":"Next","Params":{}} [LOG] 23.29614 DEBUG juju.rpc.jsoncodec -> {"RequestId":22,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 23.29629 DEBUG juju.rpc.jsoncodec -> {"RequestId":35,"Response":{}} [LOG] 23.29676 INFO juju worker/uniter/charm: preparing new charm deployment [LOG] 23.30535 DEBUG juju.rpc.jsoncodec <- {"RequestId":37,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 23.30846 DEBUG juju.rpc.jsoncodec -> {"RequestId":37,"Response":{"Results":[{"StringsWatcherId":"6","Changes":[],"Error":null}]}} [LOG] 23.30899 DEBUG juju.worker.uniter.filter no new charm event [LOG] 23.30915 DEBUG juju.worker.uniter.filter got config change [LOG] 23.30918 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 23.30933 DEBUG juju.worker.uniter.filter got relations change [LOG] 23.31001 DEBUG juju.rpc.jsoncodec <- {"RequestId":38,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} want unit status "started", got "pending"; still waiting [LOG] 23.33243 DEBUG juju.rpc.jsoncodec -> {"RequestId":29,"Response":{}} [LOG] 23.33590 DEBUG juju.worker.uniter.filter got unit change [LOG] 23.33703 DEBUG juju.rpc.jsoncodec <- {"RequestId":39,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 23.33719 DEBUG juju.rpc.jsoncodec <- {"RequestId":40,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.33837 DEBUG juju.rpc.jsoncodec -> {"RequestId":40,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 23.33894 DEBUG juju.rpc.jsoncodec <- {"RequestId":41,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.34332 DEBUG juju.rpc.jsoncodec -> {"RequestId":41,"Response":{"Results":[{"Error":null,"Mode":""}]}} want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 23.49124 INFO juju worker/uniter/charm: deploying charm [LOG] 23.49188 INFO juju worker/uniter/charm: charm deployment succeeded [LOG] 23.49522 INFO juju.worker.uniter charm "cs:quantal/wordpress-0" is deployed [LOG] 23.49728 DEBUG juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 exiting [LOG] 23.49732 INFO juju.worker.uniter ModeContinue starting [LOG] 23.49733 INFO juju.worker.uniter found queued "install" hook [LOG] 23.49815 DEBUG juju.rpc.jsoncodec <- {"RequestId":42,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 23.50041 DEBUG juju.rpc.jsoncodec -> {"RequestId":42,"Response":{"Error":null,"Result":["127.0.0.1:43428"]}} want unit status "started", got "pending"; still waiting [LOG] 23.50240 DEBUG juju.rpc.jsoncodec <- {"RequestId":43,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.50508 DEBUG juju.rpc.jsoncodec -> {"RequestId":43,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 23.50600 DEBUG juju.rpc.jsoncodec <- {"RequestId":44,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.50784 DEBUG juju.rpc.jsoncodec -> {"RequestId":44,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 23.51194 INFO juju.worker.uniter running "install" hook want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 23.63362 INFO juju u/0: 43e79ff6-b04b-4c34-851d-057e268b113a install [LOG] 23.64305 INFO juju.worker.uniter ran "install" hook [LOG] 23.64322 INFO juju.worker.uniter committing "install" hook [LOG] 23.67089 INFO juju.worker.uniter committed "install" hook [LOG] 23.67149 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 23.67153 INFO juju.worker.uniter ModeContinue starting [LOG] 23.67155 INFO juju.worker.uniter continuing after "install" hook [LOG] 23.67156 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 23.67159 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 23.67293 DEBUG juju.rpc.jsoncodec <- {"RequestId":45,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"installed","Info":"","Data":null}],"Machines":null}} want unit status "started", got "pending"; still waiting [LOG] 23.69991 DEBUG juju.rpc.jsoncodec -> {"RequestId":45,"Response":{"Results":[{"Error":null}]}} [LOG] 23.70101 DEBUG juju.worker.uniter.filter discarded config event [LOG] 23.70128 DEBUG juju.rpc.jsoncodec <- {"RequestId":46,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 23.70597 DEBUG juju.rpc.jsoncodec -> {"RequestId":46,"Response":{"Error":null,"Result":["127.0.0.1:43428"]}} [LOG] 23.70669 DEBUG juju.rpc.jsoncodec <- {"RequestId":47,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.70875 DEBUG juju.rpc.jsoncodec -> {"RequestId":47,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 23.70896 DEBUG juju.rpc.jsoncodec <- {"RequestId":48,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.70969 DEBUG juju.rpc.jsoncodec -> {"RequestId":48,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 23.71323 INFO juju.worker.uniter running "config-changed" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 23.82492 INFO juju u/0: 43e79ff6-b04b-4c34-851d-057e268b113a config-changed [LOG] 23.83391 INFO juju.worker.uniter ran "config-changed" hook [LOG] 23.83397 INFO juju.worker.uniter committing "config-changed" hook [LOG] 23.87984 INFO juju.worker.uniter committed "config-changed" hook [LOG] 23.88021 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 23.88024 INFO juju.worker.uniter ModeContinue starting [LOG] 23.88025 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 23.88026 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 23.88029 INFO juju.worker.uniter ModeStarting starting [LOG] 23.88218 DEBUG juju.rpc.jsoncodec <- {"RequestId":49,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 23.88893 DEBUG juju.rpc.jsoncodec -> {"RequestId":49,"Response":{"Error":null,"Result":["127.0.0.1:43428"]}} [LOG] 23.89289 DEBUG juju.rpc.jsoncodec <- {"RequestId":50,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} want unit status "started", got "installed"; still waiting [LOG] 23.89634 DEBUG juju.rpc.jsoncodec -> {"RequestId":50,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 23.89683 DEBUG juju.rpc.jsoncodec <- {"RequestId":51,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 23.89903 DEBUG juju.rpc.jsoncodec -> {"RequestId":51,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 23.90253 INFO juju.worker.uniter running "start" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 24.02763 INFO juju u/0: 43e79ff6-b04b-4c34-851d-057e268b113a start [LOG] 24.04327 INFO juju.worker.uniter ran "start" hook [LOG] 24.04333 INFO juju.worker.uniter committing "start" hook [LOG] 24.08392 INFO juju.worker.uniter committed "start" hook [LOG] 24.08441 DEBUG juju.worker.uniter ModeStarting exiting [LOG] 24.08444 INFO juju.worker.uniter ModeContinue starting [LOG] 24.08445 INFO juju.worker.uniter continuing after "start" hook [LOG] 24.08446 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 24.08447 INFO juju.worker.uniter ModeAbide starting [LOG] 24.08550 DEBUG juju.rpc.jsoncodec <- {"RequestId":52,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} want unit status "started", got "installed"; still waiting [LOG] 24.10558 DEBUG juju.rpc.jsoncodec -> {"RequestId":52,"Response":{"Results":[{"Error":null}]}} [LOG] 24.10648 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 24.10651 DEBUG juju.worker.uniter.filter no new charm event uniter_test.waitHooks{"install", "config-changed", "start"} waiting for hooks: []string{"install", "config-changed", "start"} actual: []string{"install", "config-changed", "start"} uniter_test.verifyCharm{revision:0, dirty:false} uniter_test.waitHooks{} waiting for hooks: []string{"install", "config-changed", "start"} actual: []string{"install", "config-changed", "start"} step 1: uniter_test.addSubordinateRelation{ifce:"juju-info"} [LOG] 24.29720 INFO juju writing charm to storage [637 bytes] [LOG] 24.29728 INFO juju adding charm to state step 2: uniter_test.waitSubordinateExists{name:"logging/0"} [LOG] 24.36733 DEBUG juju.rpc.jsoncodec -> {"RequestId":19,"Response":{}} [LOG] 24.36760 DEBUG juju.rpc.jsoncodec -> {"RequestId":38,"Response":{"StringsWatcherId":"","Changes":["logging:info u:juju-info"],"Error":null}} [LOG] 24.36812 DEBUG juju.worker.uniter.filter got service change [LOG] 24.36830 DEBUG juju.rpc.jsoncodec <- {"RequestId":53,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 24.36839 DEBUG juju.rpc.jsoncodec <- {"RequestId":54,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 24.36845 DEBUG juju.rpc.jsoncodec <- {"RequestId":55,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.36952 DEBUG juju.rpc.jsoncodec -> {"RequestId":55,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 24.37014 DEBUG juju.rpc.jsoncodec <- {"RequestId":56,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.37119 DEBUG juju.rpc.jsoncodec -> {"RequestId":56,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 24.37169 DEBUG juju.worker.uniter.filter no new charm event [LOG] 24.37174 DEBUG juju.worker.uniter.filter got relations change [LOG] 24.37223 DEBUG juju.rpc.jsoncodec <- {"RequestId":57,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.37421 DEBUG juju.rpc.jsoncodec -> {"RequestId":57,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 24.37519 DEBUG juju.worker.uniter.filter sent relations event [LOG] 24.37559 DEBUG juju.rpc.jsoncodec <- {"RequestId":58,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 24.37765 DEBUG juju.rpc.jsoncodec -> {"RequestId":58,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 24.38166 DEBUG juju.rpc.jsoncodec <- {"RequestId":59,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.38236 DEBUG juju.rpc.jsoncodec -> {"RequestId":59,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 24.38266 INFO juju.worker.uniter joining relation "logging:info u:juju-info" [LOG] 24.38278 DEBUG juju.rpc.jsoncodec <- {"RequestId":60,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.38340 DEBUG juju.rpc.jsoncodec -> {"RequestId":60,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 24.38370 DEBUG juju.rpc.jsoncodec <- {"RequestId":61,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.38424 DEBUG juju.rpc.jsoncodec -> {"RequestId":61,"Response":{"Results":[{"NotifyWatcherId":"7","Error":null}]}} [LOG] 24.38458 DEBUG juju.rpc.jsoncodec <- {"RequestId":62,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.38467 DEBUG juju.rpc.jsoncodec <- {"RequestId":63,"Type":"NotifyWatcher","Id":"7","Request":"Next","Params":{}} [LOG] 24.40353 DEBUG juju.rpc.jsoncodec -> {"RequestId":62,"Response":{"Results":[{"Error":null}]}} [LOG] 24.40370 INFO juju.worker.uniter joined relation "logging:info u:juju-info" [LOG] 24.40384 DEBUG juju.rpc.jsoncodec <- {"RequestId":64,"Type":"NotifyWatcher","Id":"7","Request":"Stop","Params":{}} [LOG] 24.40401 DEBUG juju.rpc.jsoncodec -> {"RequestId":63,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.40406 DEBUG juju.rpc.jsoncodec -> {"RequestId":64,"Response":{}} [LOG] 24.40431 DEBUG juju.rpc.jsoncodec <- {"RequestId":65,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.40468 DEBUG juju.rpc.jsoncodec -> {"RequestId":65,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} step 3: uniter_test.custom{f:(func(*gocheck.C, *uniter_test.context))(0x450970)} step 4: uniter_test.waitSubordinateDying{} [LOG] 24.43152 DEBUG juju.rpc.jsoncodec -> {"RequestId":39,"Response":{}} [LOG] 24.43225 DEBUG juju.worker.uniter.filter got unit change [LOG] 24.43253 DEBUG juju.rpc.jsoncodec <- {"RequestId":66,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 24.43284 DEBUG juju.rpc.jsoncodec <- {"RequestId":67,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.43428 DEBUG juju.rpc.jsoncodec -> {"RequestId":67,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.43496 INFO juju.worker.uniter.filter unit is dying [LOG] 24.43592 DEBUG juju.rpc.jsoncodec <- {"RequestId":68,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.43627 DEBUG juju.rpc.jsoncodec <- {"RequestId":69,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.43882 DEBUG juju.rpc.jsoncodec -> {"RequestId":68,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 24.43965 DEBUG juju.rpc.jsoncodec -> {"RequestId":69,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.44081 DEBUG juju.rpc.jsoncodec <- {"RequestId":70,"Type":"Uniter","Request":"DestroyAllSubordinates","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.45028 DEBUG juju.rpc.jsoncodec -> {"RequestId":70,"Response":{"Results":[{"Error":null}]}} [LOG] 24.45050 DEBUG juju.rpc.jsoncodec <- {"RequestId":71,"Type":"Uniter","Request":"LeaveScope","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.45936 DEBUG juju.rpc.jsoncodec -> {"RequestId":71,"Response":{"Results":[{"Error":null}]}} [LOG] 24.45965 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 24.45966 INFO juju.worker.uniter ModeStopping starting [LOG] 24.46034 DEBUG juju.rpc.jsoncodec <- {"RequestId":72,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 24.46232 DEBUG juju.rpc.jsoncodec -> {"RequestId":72,"Response":{"Error":null,"Result":["127.0.0.1:43428"]}} [LOG] 24.46274 DEBUG juju.rpc.jsoncodec <- {"RequestId":73,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.46352 DEBUG juju.rpc.jsoncodec -> {"RequestId":73,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 24.46386 DEBUG juju.rpc.jsoncodec <- {"RequestId":74,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.46454 DEBUG juju.rpc.jsoncodec -> {"RequestId":74,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 24.46713 INFO juju.worker.uniter running "stop" hook step 5: uniter_test.waitHooks{"stop"} waiting for hooks: []string{"install", "config-changed", "start", "stop"} actual: []string{"install", "config-changed", "start"} actual: []string{"install", "config-changed", "start"} [LOG] 24.57916 INFO juju u/0: 43e79ff6-b04b-4c34-851d-057e268b113a stop [LOG] 24.58443 INFO juju.worker.uniter ran "stop" hook [LOG] 24.58445 INFO juju.worker.uniter committing "stop" hook [LOG] 24.62370 INFO juju.worker.uniter committed "stop" hook [LOG] 24.62578 DEBUG juju.worker.uniter ModeStopping exiting [LOG] 24.62596 INFO juju.worker.uniter ModeContinue starting [LOG] 24.62600 INFO juju.worker.uniter continuing after "stop" hook [LOG] 24.62603 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 24.62605 INFO juju.worker.uniter ModeTerminating starting [LOG] 24.62877 DEBUG juju.rpc.jsoncodec <- {"RequestId":75,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"stopped","Info":"","Data":null}],"Machines":null}} actual: []string{"install", "config-changed", "start", "stop"} step 6: uniter_test.verifyRunning{noHooks:true} uniter_test.stopUniter{err:""} [LOG] 24.65813 DEBUG juju.rpc.jsoncodec -> {"RequestId":75,"Response":{"Results":[{"Error":null}]}} [LOG] 24.65850 DEBUG juju.rpc.jsoncodec <- {"RequestId":76,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.65928 DEBUG juju.rpc.jsoncodec -> {"RequestId":76,"Response":{"Results":[{"NotifyWatcherId":"8","Error":null}]}} [LOG] 24.65945 DEBUG juju.worker.uniter ModeTerminating exiting [LOG] 24.65948 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 24.66009 DEBUG juju.rpc.jsoncodec <- {"RequestId":77,"Type":"NotifyWatcher","Id":"8","Request":"Stop","Params":{}} [LOG] 24.66020 DEBUG juju.rpc.jsoncodec <- {"RequestId":78,"Type":"NotifyWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 24.66026 DEBUG juju.rpc.jsoncodec <- {"RequestId":79,"Type":"StringsWatcher","Id":"6","Request":"Stop","Params":{}} [LOG] 24.66049 DEBUG juju.rpc.jsoncodec -> {"RequestId":78,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.66066 DEBUG juju.rpc.jsoncodec -> {"RequestId":77,"Response":{}} [LOG] 24.66081 DEBUG juju.rpc.jsoncodec -> {"RequestId":54,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.66090 DEBUG juju.rpc.jsoncodec -> {"RequestId":79,"Response":{}} [LOG] 24.66162 DEBUG juju.rpc.jsoncodec <- {"RequestId":80,"Type":"NotifyWatcher","Id":"5","Request":"Stop","Params":{}} [LOG] 24.66188 DEBUG juju.rpc.jsoncodec -> {"RequestId":36,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.66198 DEBUG juju.rpc.jsoncodec -> {"RequestId":80,"Response":{}} [LOG] 24.66299 DEBUG juju.rpc.jsoncodec <- {"RequestId":81,"Type":"NotifyWatcher","Id":"3","Request":"Stop","Params":{}} [LOG] 24.66323 DEBUG juju.rpc.jsoncodec -> {"RequestId":53,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.66333 DEBUG juju.rpc.jsoncodec -> {"RequestId":81,"Response":{}} [LOG] 24.66391 DEBUG juju.rpc.jsoncodec <- {"RequestId":82,"Type":"NotifyWatcher","Id":"2","Request":"Stop","Params":{}} [LOG] 24.66413 DEBUG juju.rpc.jsoncodec -> {"RequestId":66,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.66423 DEBUG juju.rpc.jsoncodec -> {"RequestId":82,"Response":{}} [LOG] 24.66463 ERROR juju.worker.uniter.filter tomb: dying uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{} [LOG] 24.66586 DEBUG juju.rpc.jsoncodec <- {"RequestId":83,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.66784 DEBUG juju.rpc.jsoncodec -> {"RequestId":83,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.66831 DEBUG juju.rpc.jsoncodec <- {"RequestId":84,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.66879 DEBUG juju.rpc.jsoncodec -> {"RequestId":84,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 24.66908 DEBUG juju.rpc.jsoncodec <- {"RequestId":85,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 24.66960 DEBUG juju.rpc.jsoncodec -> {"RequestId":85,"Response":{"Error":null,"Result":"43e79ff6-b04b-4c34-851d-057e268b113a"}} [LOG] 24.66983 INFO juju.worker.uniter unit "u/0" started [LOG] 24.66991 INFO juju.worker.uniter ModeInit starting [LOG] 24.66995 INFO juju.worker.uniter updating unit addresses [LOG] 24.67013 DEBUG juju.rpc.jsoncodec <- {"RequestId":86,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 24.67025 DEBUG juju.rpc.jsoncodec <- {"RequestId":87,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.67181 DEBUG juju.rpc.jsoncodec -> {"RequestId":86,"Response":{"Error":null,"Result":"dummy"}} [LOG] 24.67203 DEBUG juju.rpc.jsoncodec -> {"RequestId":87,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.67247 DEBUG juju.rpc.jsoncodec <- {"RequestId":88,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 24.67262 DEBUG juju.rpc.jsoncodec <- {"RequestId":89,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.67381 DEBUG juju.rpc.jsoncodec -> {"RequestId":89,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.67400 INFO juju.worker.uniter.filter unit is dying [LOG] 24.67548 DEBUG juju.rpc.jsoncodec <- {"RequestId":90,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.67624 DEBUG juju.rpc.jsoncodec -> {"RequestId":90,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 24.67753 DEBUG juju.rpc.jsoncodec <- {"RequestId":91,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.67841 DEBUG juju.rpc.jsoncodec -> {"RequestId":91,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 24.67977 DEBUG juju.rpc.jsoncodec <- {"RequestId":92,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.68251 DEBUG juju.rpc.jsoncodec -> {"RequestId":92,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 24.68349 DEBUG juju.rpc.jsoncodec -> {"RequestId":88,"Response":{"Results":[{"Error":null}]}} [LOG] 24.68375 DEBUG juju.rpc.jsoncodec <- {"RequestId":93,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.68386 DEBUG juju.rpc.jsoncodec <- {"RequestId":94,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 24.68462 DEBUG juju.rpc.jsoncodec -> {"RequestId":93,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 24.68578 DEBUG juju.worker.uniter.filter charm check skipped, unit is dying [LOG] 24.68597 DEBUG juju.rpc.jsoncodec <- {"RequestId":95,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.68765 DEBUG juju.rpc.jsoncodec -> {"RequestId":95,"Response":{"Results":[{"NotifyWatcherId":"9","Error":null}]}} [LOG] 24.68924 DEBUG juju.rpc.jsoncodec <- {"RequestId":96,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.68933 DEBUG juju.rpc.jsoncodec <- {"RequestId":97,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 24.69082 DEBUG juju.rpc.jsoncodec -> {"RequestId":96,"Response":{"Results":[{"NotifyWatcherId":"10","Error":null}]}} [LOG] 24.69131 DEBUG juju.rpc.jsoncodec -> {"RequestId":94,"Response":{"Results":[{"Error":null}]}} [LOG] 24.69146 INFO juju.worker.uniter reconciling relation state [LOG] 24.69160 DEBUG juju.worker.uniter ModeInit exiting [LOG] 24.69162 INFO juju.worker.uniter ModeContinue starting [LOG] 24.69163 INFO juju.worker.uniter loading uniter state [LOG] 24.69187 INFO juju.worker.uniter continuing after "stop" hook [LOG] 24.69188 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 24.69189 INFO juju.worker.uniter ModeTerminating starting [LOG] 24.69206 DEBUG juju.rpc.jsoncodec <- {"RequestId":98,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.69226 DEBUG juju.rpc.jsoncodec <- {"RequestId":99,"Type":"NotifyWatcher","Id":"10","Request":"Next","Params":{}} [LOG] 24.69240 DEBUG juju.rpc.jsoncodec <- {"RequestId":100,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"stopped","Info":"","Data":null}],"Machines":null}} [LOG] 24.69303 DEBUG juju.rpc.jsoncodec -> {"RequestId":98,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} [LOG] 24.69383 DEBUG juju.rpc.jsoncodec <- {"RequestId":101,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.69514 DEBUG juju.rpc.jsoncodec -> {"RequestId":101,"Response":{"Results":[{"NotifyWatcherId":"11","Error":null}]}} [LOG] 24.69608 DEBUG juju.rpc.jsoncodec <- {"RequestId":102,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.69619 DEBUG juju.rpc.jsoncodec <- {"RequestId":103,"Type":"NotifyWatcher","Id":"11","Request":"Next","Params":{}} [LOG] 24.69751 DEBUG juju.rpc.jsoncodec -> {"RequestId":102,"Response":{"Results":[{"StringsWatcherId":"12","Changes":["logging:info u:juju-info"],"Error":null}]}} [LOG] 24.69765 DEBUG juju.worker.uniter.filter got service change [LOG] 24.69836 DEBUG juju.rpc.jsoncodec <- {"RequestId":104,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.69844 DEBUG juju.rpc.jsoncodec <- {"RequestId":105,"Type":"StringsWatcher","Id":"12","Request":"Next","Params":{}} [LOG] 24.69870 DEBUG juju.rpc.jsoncodec -> {"RequestId":100,"Response":{"Results":[{"Error":null}]}} [LOG] 24.69880 DEBUG juju.rpc.jsoncodec -> {"RequestId":104,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 24.69919 DEBUG juju.rpc.jsoncodec <- {"RequestId":106,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.69926 DEBUG juju.rpc.jsoncodec <- {"RequestId":107,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 24.69986 DEBUG juju.rpc.jsoncodec -> {"RequestId":107,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 24.70014 DEBUG juju.rpc.jsoncodec -> {"RequestId":106,"Response":{"Results":[{"NotifyWatcherId":"13","Error":null}]}} [LOG] 24.70034 DEBUG juju.worker.uniter.filter charm check skipped, unit is dying [LOG] 24.70037 DEBUG juju.worker.uniter.filter got config change [LOG] 24.70038 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 24.70039 DEBUG juju.worker.uniter.filter got relations change [LOG] 24.70068 DEBUG juju.rpc.jsoncodec <- {"RequestId":108,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 24.70076 DEBUG juju.rpc.jsoncodec <- {"RequestId":109,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.70084 DEBUG juju.rpc.jsoncodec <- {"RequestId":110,"Type":"NotifyWatcher","Id":"13","Request":"Next","Params":{}} [LOG] 24.70154 DEBUG juju.rpc.jsoncodec -> {"RequestId":109,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.70181 DEBUG juju.rpc.jsoncodec -> {"RequestId":108,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 24.70204 DEBUG juju.worker.uniter.filter got unit change [LOG] 24.70213 DEBUG juju.rpc.jsoncodec <- {"RequestId":111,"Type":"Uniter","Request":"HasSubordinates","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.70219 DEBUG juju.rpc.jsoncodec <- {"RequestId":112,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.70268 DEBUG juju.rpc.jsoncodec -> {"RequestId":111,"Response":{"Results":[{"Error":null,"Result":true}]}} [LOG] 24.70281 DEBUG juju.rpc.jsoncodec -> {"RequestId":112,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.70308 DEBUG juju.rpc.jsoncodec <- {"RequestId":113,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.70342 DEBUG juju.rpc.jsoncodec -> {"RequestId":113,"Response":{"Results":[{"Error":null,"Mode":""}]}} waiting for hooks: []string{"install", "config-changed", "start", "stop"} actual: []string{"install", "config-changed", "start", "stop"} step 7: uniter_test.removeSubordinate{} step 8: uniter_test.waitUniterDead{err:""} [LOG] 24.78583 DEBUG juju.rpc.jsoncodec -> {"RequestId":110,"Response":{}} [LOG] 24.78597 DEBUG juju.rpc.jsoncodec -> {"RequestId":97,"Response":{}} [LOG] 24.78638 DEBUG juju.worker.uniter.filter got unit change [LOG] 24.78654 DEBUG juju.rpc.jsoncodec <- {"RequestId":114,"Type":"NotifyWatcher","Id":"13","Request":"Next","Params":{}} [LOG] 24.78670 DEBUG juju.rpc.jsoncodec <- {"RequestId":115,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 24.78692 DEBUG juju.rpc.jsoncodec <- {"RequestId":116,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.78698 DEBUG juju.rpc.jsoncodec <- {"RequestId":117,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.78806 DEBUG juju.rpc.jsoncodec -> {"RequestId":116,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.78817 DEBUG juju.rpc.jsoncodec -> {"RequestId":117,"Response":{"Results":[{"Life":"dying","Error":null}]}} [LOG] 24.78869 DEBUG juju.rpc.jsoncodec <- {"RequestId":118,"Type":"Uniter","Request":"HasSubordinates","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.78905 DEBUG juju.rpc.jsoncodec <- {"RequestId":119,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.78964 DEBUG juju.rpc.jsoncodec -> {"RequestId":118,"Response":{"Results":[{"Error":null,"Result":false}]}} [LOG] 24.79002 DEBUG juju.rpc.jsoncodec -> {"RequestId":119,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 24.79034 DEBUG juju.rpc.jsoncodec <- {"RequestId":120,"Type":"Uniter","Request":"EnsureDead","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 24.79956 DEBUG juju.rpc.jsoncodec -> {"RequestId":120,"Response":{"Results":[{"Error":null}]}} [LOG] 24.80043 DEBUG juju.rpc.jsoncodec <- {"RequestId":121,"Type":"NotifyWatcher","Id":"13","Request":"Stop","Params":{}} [LOG] 24.80117 DEBUG juju.rpc.jsoncodec -> {"RequestId":114,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.80135 DEBUG juju.rpc.jsoncodec -> {"RequestId":121,"Response":{}} [LOG] 24.80210 DEBUG juju.worker.uniter ModeTerminating exiting [LOG] 24.80217 INFO juju.worker.uniter unit "u/0" shutting down: agent should be terminated [LOG] 24.80255 DEBUG juju.rpc.jsoncodec <- {"RequestId":122,"Type":"StringsWatcher","Id":"12","Request":"Stop","Params":{}} [LOG] 24.80278 DEBUG juju.rpc.jsoncodec -> {"RequestId":105,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.80298 DEBUG juju.rpc.jsoncodec -> {"RequestId":122,"Response":{}} [LOG] 24.80374 DEBUG juju.rpc.jsoncodec <- {"RequestId":123,"Type":"NotifyWatcher","Id":"11","Request":"Stop","Params":{}} [LOG] 24.80405 DEBUG juju.rpc.jsoncodec -> {"RequestId":103,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.80432 DEBUG juju.rpc.jsoncodec -> {"RequestId":123,"Response":{}} [LOG] 24.80508 DEBUG juju.rpc.jsoncodec <- {"RequestId":124,"Type":"NotifyWatcher","Id":"10","Request":"Stop","Params":{}} [LOG] 24.80538 DEBUG juju.rpc.jsoncodec -> {"RequestId":99,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.80551 DEBUG juju.rpc.jsoncodec -> {"RequestId":124,"Response":{}} [LOG] 24.80625 DEBUG juju.rpc.jsoncodec <- {"RequestId":125,"Type":"NotifyWatcher","Id":"9","Request":"Stop","Params":{}} [LOG] 24.80642 DEBUG juju.rpc.jsoncodec -> {"RequestId":115,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 24.80653 DEBUG juju.rpc.jsoncodec -> {"RequestId":125,"Response":{}} [LOG] 24.80713 ERROR juju.worker.uniter.filter tomb: dying [LOG] 24.81049 INFO juju environs/dummy: reset environment [LOG] 24.81163 DEBUG juju.rpc.jsoncodec <- error: read tcp 127.0.0.1:39495: use of closed network connection (closing true) [LOG] 24.81353 DEBUG juju.rpc.jsoncodec <- error: read tcp 127.0.0.1:39496: use of closed network connection (closing true) [LOG] 24.95644 INFO juju environs/testing: uploading FAKE tools 1.15.1-precise-amd64 [LOG] 24.95851 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 24.95853 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 24.95859 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 24.95861 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 24.95864 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 24.95866 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 24.95883 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 24.95892 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 24.95896 INFO juju.environs.boostrap bootstrapping environment "dummyenv" [LOG] 24.95899 INFO juju.environs.tools reading tools with major.minor version 1.15 [LOG] 24.95900 INFO juju.environs.tools filtering tools by version: 1.15.1 [LOG] 24.95901 INFO juju.environs.tools filtering tools by series: precise [LOG] 24.95903 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 24.95907 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 24.95909 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 24.95923 DEBUG juju.environs.simplestreams no mirror information available for {DataType:content-download MirrorContentId:com.ubuntu.juju:released:tools FilterFunc:0x68eb40 ValueTemplate:{Release: Version: Arch: Size:0 Path: FullPath: FileType: SHA256:}}: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 24.95924 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:51490/dummyenv/private/tools/streams/v1/index.json" [LOG] 24.95929 DEBUG juju.environs.simplestreams candidate matches for products ["com.ubuntu.juju:12.04:amd64" "com.ubuntu.juju:12.04:i386" "com.ubuntu.juju:12.04:arm"] are [{Wed, 02 Oct 2013 01:02:26 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 24.95930 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 24.95954 INFO juju environs/dummy: would pick tools from 1.15.1-precise-amd64 [LOG] 24.99503 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 25.00149 INFO juju.state connection established [LOG] 25.04400 INFO juju.state initializing environment [LOG] 25.08633 INFO juju state/api: listening on "127.0.0.1:37249" [LOG] 25.10715 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 25.11133 INFO juju.state connection established [LOG] 25.11255 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 25.11267 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 25.11531 INFO juju.state connection established [LOG] 25.15718 INFO juju state/api: dialing "wss://127.0.0.1:37249/" [LOG] 25.16013 INFO juju state/api: connection established [LOG] 25.16024 DEBUG juju.rpc.jsoncodec <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 25.16056 DEBUG juju.rpc.jsoncodec -> {"RequestId":1,"Response":{}} test 1: new subordinate becomes necessary while old one is dying [LOG] 25.16760 DEBUG juju.rpc.jsoncodec <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}} [LOG] 25.16767 DEBUG juju.rpc.jsoncodec -> {"RequestId":2,"Response":{}} step 0: uniter_test.quickStart{} uniter_test.createCharm{revision:0, badHooks:[]string(nil), customize:(func(*gocheck.C, *uniter_test.context, string))(nil)} uniter_test.addCharm{dir:(*charm.Dir)(0xc200b5e240), curl:(*charm.URL)(0xc20102ab40)} uniter_test.serveCharm{} uniter_test.createUniter{} uniter_test.createServiceAndUnit{serviceName:""} [LOG] 25.29523 INFO juju state/api: dialing "wss://127.0.0.1:37249/" [LOG] 25.29879 INFO juju state/api: connection established [LOG] 25.29906 DEBUG juju.rpc.jsoncodec <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"unit-u-0","Password":"password","Nonce":""}} [LOG] 25.31565 DEBUG juju.rpc.jsoncodec -> {"RequestId":1,"Response":{}} API: login as "unit-u-0" successful uniter_test.startUniter{unitTag:""} uniter_test.waitAddresses{} [LOG] 25.31627 DEBUG juju.rpc.jsoncodec <- {"RequestId":2,"Type":"Pinger","Request":"Ping","Params":{}} [LOG] 25.31643 DEBUG juju.rpc.jsoncodec <- {"RequestId":3,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.31663 DEBUG juju.rpc.jsoncodec -> {"RequestId":2,"Response":{}} [LOG] 25.31763 DEBUG juju.rpc.jsoncodec -> {"RequestId":3,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.31881 DEBUG juju.rpc.jsoncodec <- {"RequestId":4,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.31987 DEBUG juju.rpc.jsoncodec -> {"RequestId":4,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.32030 DEBUG juju.rpc.jsoncodec <- {"RequestId":5,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 25.32127 DEBUG juju.rpc.jsoncodec -> {"RequestId":5,"Response":{"Error":null,"Result":"5e78f254-45f6-43c7-8275-0db387c187ff"}} [LOG] 25.32167 INFO juju.worker.uniter unit "u/0" started [LOG] 25.32172 INFO juju.worker.uniter ModeInit starting [LOG] 25.32174 INFO juju.worker.uniter updating unit addresses [LOG] 25.32208 DEBUG juju.rpc.jsoncodec <- {"RequestId":6,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 25.32228 DEBUG juju.rpc.jsoncodec <- {"RequestId":7,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.32535 DEBUG juju.rpc.jsoncodec -> {"RequestId":6,"Response":{"Error":null,"Result":"dummy"}} [LOG] 25.32567 DEBUG juju.rpc.jsoncodec -> {"RequestId":7,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.32656 DEBUG juju.rpc.jsoncodec <- {"RequestId":8,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 25.32682 DEBUG juju.rpc.jsoncodec <- {"RequestId":9,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.32837 DEBUG juju.rpc.jsoncodec -> {"RequestId":9,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.32882 DEBUG juju.rpc.jsoncodec <- {"RequestId":10,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.32945 DEBUG juju.rpc.jsoncodec -> {"RequestId":10,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 25.32986 DEBUG juju.rpc.jsoncodec <- {"RequestId":11,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.33081 DEBUG juju.rpc.jsoncodec -> {"RequestId":11,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.33117 DEBUG juju.rpc.jsoncodec <- {"RequestId":12,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.33224 DEBUG juju.rpc.jsoncodec -> {"RequestId":12,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.33278 DEBUG juju.rpc.jsoncodec <- {"RequestId":13,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.33477 DEBUG juju.rpc.jsoncodec -> {"RequestId":13,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 25.33531 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 25.33559 DEBUG juju.rpc.jsoncodec <- {"RequestId":14,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.33993 DEBUG juju.rpc.jsoncodec -> {"RequestId":14,"Response":{"Results":[{"NotifyWatcherId":"2","Error":null}]}} [LOG] 25.34069 DEBUG juju.rpc.jsoncodec <- {"RequestId":15,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.34078 DEBUG juju.rpc.jsoncodec <- {"RequestId":16,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 25.34194 DEBUG juju.rpc.jsoncodec -> {"RequestId":8,"Response":{"Results":[{"Error":null}]}} [LOG] 25.34209 DEBUG juju.rpc.jsoncodec -> {"RequestId":15,"Response":{"Results":[{"NotifyWatcherId":"3","Error":null}]}} [LOG] 25.34259 DEBUG juju.rpc.jsoncodec <- {"RequestId":17,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 25.34270 DEBUG juju.rpc.jsoncodec <- {"RequestId":18,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.34283 DEBUG juju.rpc.jsoncodec <- {"RequestId":19,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 25.34364 DEBUG juju.rpc.jsoncodec -> {"RequestId":18,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} [LOG] 25.34390 DEBUG juju.rpc.jsoncodec <- {"RequestId":20,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.34600 DEBUG juju.rpc.jsoncodec -> {"RequestId":20,"Response":{"Results":[{"StringsWatcherId":"4","Changes":[],"Error":null}]}} [LOG] 25.34629 DEBUG juju.worker.uniter.filter got unit change [LOG] 25.34683 DEBUG juju.rpc.jsoncodec <- {"RequestId":21,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.34698 DEBUG juju.rpc.jsoncodec <- {"RequestId":22,"Type":"StringsWatcher","Id":"4","Request":"Next","Params":{}} [LOG] 25.34844 DEBUG juju.rpc.jsoncodec -> {"RequestId":21,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.34920 DEBUG juju.rpc.jsoncodec <- {"RequestId":23,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.34985 DEBUG juju.rpc.jsoncodec -> {"RequestId":17,"Response":{"Results":[{"Error":null}]}} [LOG] 25.35004 DEBUG juju.rpc.jsoncodec -> {"RequestId":23,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 25.35025 INFO juju.worker.uniter reconciling relation state [LOG] 25.35037 DEBUG juju.worker.uniter ModeInit exiting [LOG] 25.35038 INFO juju.worker.uniter ModeContinue starting [LOG] 25.35039 INFO juju.worker.uniter loading uniter state [LOG] 25.35041 INFO juju.worker.uniter charm is not deployed [LOG] 25.35051 DEBUG juju.worker.uniter.filter got service change [LOG] 25.35059 DEBUG juju.rpc.jsoncodec <- {"RequestId":24,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.35066 DEBUG juju.rpc.jsoncodec <- {"RequestId":25,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.35123 DEBUG juju.rpc.jsoncodec -> {"RequestId":24,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 25.35135 DEBUG juju.rpc.jsoncodec -> {"RequestId":25,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.35152 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 25.35153 INFO juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 starting [LOG] 25.35155 INFO juju.worker.uniter fetching charm "cs:quantal/wordpress-0" [LOG] 25.35170 DEBUG juju.rpc.jsoncodec <- {"RequestId":26,"Type":"Uniter","Request":"CharmArchiveURL","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 25.35177 DEBUG juju.rpc.jsoncodec <- {"RequestId":27,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.35237 DEBUG juju.rpc.jsoncodec -> {"RequestId":26,"Response":{"Results":[{"Error":null,"Result":"http://localhost:49024/charms/wordpress/0"}]}} [LOG] 25.35249 DEBUG juju.rpc.jsoncodec -> {"RequestId":27,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 25.35282 INFO juju worker/uniter/charm: downloading cs:quantal/wordpress-0 from http://localhost:49024/charms/wordpress/0 [LOG] 25.35286 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 25.35288 DEBUG juju.worker.uniter.filter got relations change [LOG] 25.35341 INFO juju worker/uniter/charm: download complete [LOG] 25.35361 DEBUG juju.rpc.jsoncodec <- {"RequestId":28,"Type":"Uniter","Request":"CharmArchiveSha256","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 25.35405 DEBUG juju.rpc.jsoncodec -> {"RequestId":28,"Response":{"Results":[{"Error":null,"Result":"cf84bf96df3eb166609a04c98d9a569820a6b8121d1ef0cdbe09a15892852324"}]}} [LOG] 25.35415 INFO juju worker/uniter/charm: download verified [LOG] 25.41602 DEBUG juju.worker.uniter.filter changing charm to "cs:quantal/wordpress-0" [LOG] 25.41702 DEBUG juju.rpc.jsoncodec <- {"RequestId":29,"Type":"Uniter","Request":"SetCharmURL","Params":{"Entities":[{"Tag":"unit-u-0","CharmURL":"cs:quantal/wordpress-0"}]}} uniter_test.waitUnit{status:"started", info:"", data:params.StatusData(nil), charm:0, resolved:""} [LOG] 25.43074 DEBUG juju.rpc.jsoncodec -> {"RequestId":29,"Response":{"Results":[{"Error":null}]}} [LOG] 25.43132 DEBUG juju.rpc.jsoncodec <- {"RequestId":30,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.43139 DEBUG juju.rpc.jsoncodec <- {"RequestId":31,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.43216 DEBUG juju.rpc.jsoncodec -> {"RequestId":31,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.43254 INFO juju.worker.uniter deploying charm "cs:quantal/wordpress-0" [LOG] 25.43306 DEBUG juju.rpc.jsoncodec -> {"RequestId":16,"Response":{}} [LOG] 25.43361 DEBUG juju.rpc.jsoncodec -> {"RequestId":30,"Response":{"Results":[{"NotifyWatcherId":"5","Error":null}]}} [LOG] 25.43377 DEBUG juju.rpc.jsoncodec <- {"RequestId":32,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 25.43417 DEBUG juju.rpc.jsoncodec <- {"RequestId":33,"Type":"StringsWatcher","Id":"4","Request":"Stop","Params":{}} [LOG] 25.43430 DEBUG juju.rpc.jsoncodec <- {"RequestId":34,"Type":"NotifyWatcher","Id":"5","Request":"Next","Params":{}} [LOG] 25.43455 DEBUG juju.rpc.jsoncodec -> {"RequestId":22,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 25.43470 DEBUG juju.rpc.jsoncodec -> {"RequestId":33,"Response":{}} [LOG] 25.43592 DEBUG juju.rpc.jsoncodec <- {"RequestId":35,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 25.43747 INFO juju worker/uniter/charm: preparing new charm deployment [LOG] 25.44282 DEBUG juju.rpc.jsoncodec -> {"RequestId":35,"Response":{"Results":[{"StringsWatcherId":"6","Changes":[],"Error":null}]}} [LOG] 25.44572 DEBUG juju.worker.uniter.filter no new charm event [LOG] 25.44588 DEBUG juju.worker.uniter.filter got config change [LOG] 25.44591 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 25.44598 DEBUG juju.worker.uniter.filter got unit change [LOG] 25.45565 DEBUG juju.rpc.jsoncodec <- {"RequestId":36,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.45624 DEBUG juju.rpc.jsoncodec <- {"RequestId":37,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 25.46046 DEBUG juju.rpc.jsoncodec -> {"RequestId":36,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.46308 DEBUG juju.rpc.jsoncodec <- {"RequestId":38,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.46611 DEBUG juju.rpc.jsoncodec -> {"RequestId":38,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 25.47289 DEBUG juju.worker.uniter.filter got relations change want unit status "started", got "pending"; still waiting [LOG] 25.50393 DEBUG juju.rpc.jsoncodec -> {"RequestId":32,"Response":{}} [LOG] 25.50547 DEBUG juju.worker.uniter.filter got unit change [LOG] 25.50600 DEBUG juju.rpc.jsoncodec <- {"RequestId":39,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 25.50624 DEBUG juju.rpc.jsoncodec <- {"RequestId":40,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.50890 DEBUG juju.rpc.jsoncodec -> {"RequestId":40,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 25.50930 DEBUG juju.rpc.jsoncodec <- {"RequestId":41,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.50979 DEBUG juju.rpc.jsoncodec -> {"RequestId":41,"Response":{"Results":[{"Error":null,"Mode":""}]}} want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 25.62726 INFO juju worker/uniter/charm: deploying charm [LOG] 25.62792 INFO juju worker/uniter/charm: charm deployment succeeded [LOG] 25.63239 INFO juju.worker.uniter charm "cs:quantal/wordpress-0" is deployed [LOG] 25.63538 DEBUG juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 exiting [LOG] 25.63548 INFO juju.worker.uniter ModeContinue starting [LOG] 25.63556 INFO juju.worker.uniter found queued "install" hook [LOG] 25.63816 DEBUG juju.rpc.jsoncodec <- {"RequestId":42,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 25.64453 DEBUG juju.rpc.jsoncodec -> {"RequestId":42,"Response":{"Error":null,"Result":["127.0.0.1:37249"]}} [LOG] 25.64840 DEBUG juju.rpc.jsoncodec <- {"RequestId":43,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} want unit status "started", got "pending"; still waiting [LOG] 25.65333 DEBUG juju.rpc.jsoncodec -> {"RequestId":43,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 25.65403 DEBUG juju.rpc.jsoncodec <- {"RequestId":44,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.65571 DEBUG juju.rpc.jsoncodec -> {"RequestId":44,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 25.65975 INFO juju.worker.uniter running "install" hook want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 25.78060 INFO juju u/0: 5e78f254-45f6-43c7-8275-0db387c187ff install [LOG] 25.78935 INFO juju.worker.uniter ran "install" hook [LOG] 25.78941 INFO juju.worker.uniter committing "install" hook want unit status "started", got "pending"; still waiting [LOG] 25.85170 INFO juju.worker.uniter committed "install" hook [LOG] 25.85208 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 25.85211 INFO juju.worker.uniter ModeContinue starting [LOG] 25.85215 INFO juju.worker.uniter continuing after "install" hook [LOG] 25.85218 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 25.85220 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 25.85263 DEBUG juju.rpc.jsoncodec <- {"RequestId":45,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"installed","Info":"","Data":null}],"Machines":null}} [LOG] 25.85908 DEBUG juju.rpc.jsoncodec -> {"RequestId":45,"Response":{"Results":[{"Error":null}]}} [LOG] 25.85992 DEBUG juju.worker.uniter.filter discarded config event [LOG] 25.86004 DEBUG juju.rpc.jsoncodec <- {"RequestId":46,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 25.86210 DEBUG juju.rpc.jsoncodec -> {"RequestId":46,"Response":{"Error":null,"Result":["127.0.0.1:37249"]}} [LOG] 25.86243 DEBUG juju.rpc.jsoncodec <- {"RequestId":47,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.86319 DEBUG juju.rpc.jsoncodec -> {"RequestId":47,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 25.86356 DEBUG juju.rpc.jsoncodec <- {"RequestId":48,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 25.86431 DEBUG juju.rpc.jsoncodec -> {"RequestId":48,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 25.86699 INFO juju.worker.uniter running "config-changed" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 25.96933 INFO juju u/0: 5e78f254-45f6-43c7-8275-0db387c187ff config-changed [LOG] 25.97666 INFO juju.worker.uniter ran "config-changed" hook [LOG] 25.97673 INFO juju.worker.uniter committing "config-changed" hook [LOG] 26.01618 INFO juju.worker.uniter committed "config-changed" hook [LOG] 26.01654 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 26.01658 INFO juju.worker.uniter ModeContinue starting [LOG] 26.01659 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 26.01660 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 26.01661 INFO juju.worker.uniter ModeStarting starting [LOG] 26.01762 DEBUG juju.rpc.jsoncodec <- {"RequestId":49,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 26.01974 DEBUG juju.rpc.jsoncodec -> {"RequestId":49,"Response":{"Error":null,"Result":["127.0.0.1:37249"]}} want unit status "started", got "installed"; still waiting [LOG] 26.02084 DEBUG juju.rpc.jsoncodec <- {"RequestId":50,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.02190 DEBUG juju.rpc.jsoncodec -> {"RequestId":50,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 26.02220 DEBUG juju.rpc.jsoncodec <- {"RequestId":51,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.02282 DEBUG juju.rpc.jsoncodec -> {"RequestId":51,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 26.02531 INFO juju.worker.uniter running "start" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 26.13622 INFO juju u/0: 5e78f254-45f6-43c7-8275-0db387c187ff start [LOG] 26.14515 INFO juju.worker.uniter ran "start" hook [LOG] 26.14522 INFO juju.worker.uniter committing "start" hook [LOG] 26.18257 INFO juju.worker.uniter committed "start" hook [LOG] 26.18341 DEBUG juju.worker.uniter ModeStarting exiting [LOG] 26.18346 INFO juju.worker.uniter ModeContinue starting [LOG] 26.18349 INFO juju.worker.uniter continuing after "start" hook [LOG] 26.18350 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 26.18352 INFO juju.worker.uniter ModeAbide starting [LOG] 26.18494 DEBUG juju.rpc.jsoncodec <- {"RequestId":52,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} want unit status "started", got "installed"; still waiting [LOG] 26.22633 DEBUG juju.rpc.jsoncodec -> {"RequestId":52,"Response":{"Results":[{"Error":null}]}} [LOG] 26.22785 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 26.22789 DEBUG juju.worker.uniter.filter no new charm event uniter_test.waitHooks{"install", "config-changed", "start"} waiting for hooks: []string{"install", "config-changed", "start"} actual: []string{"install", "config-changed", "start"} uniter_test.verifyCharm{revision:0, dirty:false} uniter_test.waitHooks{} waiting for hooks: []string{"install", "config-changed", "start"} actual: []string{"install", "config-changed", "start"} step 1: uniter_test.addSubordinateRelation{ifce:"juju-info"} [LOG] 26.39821 INFO juju writing charm to storage [637 bytes] [LOG] 26.39841 INFO juju adding charm to state step 2: uniter_test.waitSubordinateExists{name:"logging/0"} [LOG] 26.45737 DEBUG juju.rpc.jsoncodec -> {"RequestId":19,"Response":{}} [LOG] 26.45778 DEBUG juju.worker.uniter.filter got service change [LOG] 26.45812 DEBUG juju.rpc.jsoncodec <- {"RequestId":53,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 26.45827 DEBUG juju.rpc.jsoncodec <- {"RequestId":54,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.45863 DEBUG juju.rpc.jsoncodec -> {"RequestId":37,"Response":{"StringsWatcherId":"","Changes":["logging:info u:juju-info"],"Error":null}} [LOG] 26.45903 DEBUG juju.rpc.jsoncodec <- {"RequestId":55,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 26.45940 DEBUG juju.rpc.jsoncodec -> {"RequestId":54,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.45988 DEBUG juju.rpc.jsoncodec <- {"RequestId":56,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.46068 DEBUG juju.rpc.jsoncodec -> {"RequestId":56,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 26.46114 DEBUG juju.worker.uniter.filter no new charm event [LOG] 26.46118 DEBUG juju.worker.uniter.filter got relations change [LOG] 26.46157 DEBUG juju.rpc.jsoncodec <- {"RequestId":57,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 26.46335 DEBUG juju.rpc.jsoncodec -> {"RequestId":57,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.46388 DEBUG juju.worker.uniter.filter sent relations event [LOG] 26.46431 DEBUG juju.rpc.jsoncodec <- {"RequestId":58,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 26.46540 DEBUG juju.rpc.jsoncodec -> {"RequestId":58,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.46881 DEBUG juju.rpc.jsoncodec <- {"RequestId":59,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 26.47140 DEBUG juju.rpc.jsoncodec -> {"RequestId":59,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.47216 INFO juju.worker.uniter joining relation "logging:info u:juju-info" [LOG] 26.47243 DEBUG juju.rpc.jsoncodec <- {"RequestId":60,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 26.47431 DEBUG juju.rpc.jsoncodec -> {"RequestId":60,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.47515 DEBUG juju.rpc.jsoncodec <- {"RequestId":61,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.47704 DEBUG juju.rpc.jsoncodec -> {"RequestId":61,"Response":{"Results":[{"NotifyWatcherId":"7","Error":null}]}} [LOG] 26.47797 DEBUG juju.rpc.jsoncodec <- {"RequestId":62,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 26.47819 DEBUG juju.rpc.jsoncodec <- {"RequestId":63,"Type":"NotifyWatcher","Id":"7","Request":"Next","Params":{}} [LOG] 26.51093 DEBUG juju.rpc.jsoncodec -> {"RequestId":62,"Response":{"Results":[{"Error":null}]}} [LOG] 26.51115 INFO juju.worker.uniter joined relation "logging:info u:juju-info" [LOG] 26.51128 DEBUG juju.rpc.jsoncodec <- {"RequestId":64,"Type":"NotifyWatcher","Id":"7","Request":"Stop","Params":{}} [LOG] 26.51139 DEBUG juju.rpc.jsoncodec -> {"RequestId":63,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 26.51146 DEBUG juju.rpc.jsoncodec -> {"RequestId":64,"Response":{}} [LOG] 26.51176 DEBUG juju.rpc.jsoncodec <- {"RequestId":65,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.51222 DEBUG juju.rpc.jsoncodec -> {"RequestId":65,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} step 3: uniter_test.removeSubordinateRelation{ifce:"juju-info"} step 4: uniter_test.custom{f:(func(*gocheck.C, *uniter_test.context))(0x4517e0)} step 5: uniter_test.addSubordinateRelation{ifce:"logging-dir"} step 6: uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} [LOG] 26.59305 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 26.59309 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 26.59329 DEBUG juju.rpc.jsoncodec <- {"RequestId":66,"Type":"StringsWatcher","Id":"6","Request":"Stop","Params":{}} [LOG] 26.59339 DEBUG juju.rpc.jsoncodec -> {"RequestId":55,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 26.59349 DEBUG juju.rpc.jsoncodec -> {"RequestId":66,"Response":{}} [LOG] 26.59420 DEBUG juju.rpc.jsoncodec <- {"RequestId":67,"Type":"NotifyWatcher","Id":"5","Request":"Stop","Params":{}} [LOG] 26.59464 DEBUG juju.rpc.jsoncodec -> {"RequestId":34,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 26.59506 DEBUG juju.rpc.jsoncodec -> {"RequestId":67,"Response":{}} [LOG] 26.59577 DEBUG juju.rpc.jsoncodec <- {"RequestId":68,"Type":"NotifyWatcher","Id":"3","Request":"Stop","Params":{}} [LOG] 26.59600 DEBUG juju.rpc.jsoncodec -> {"RequestId":53,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 26.59619 DEBUG juju.rpc.jsoncodec -> {"RequestId":68,"Response":{}} [LOG] 26.59696 DEBUG juju.rpc.jsoncodec <- {"RequestId":69,"Type":"NotifyWatcher","Id":"2","Request":"Stop","Params":{}} [LOG] 26.59724 DEBUG juju.rpc.jsoncodec -> {"RequestId":39,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 26.59774 DEBUG juju.rpc.jsoncodec -> {"RequestId":69,"Response":{}} [LOG] 26.59883 ERROR juju.worker.uniter.filter tomb: dying uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{"config-changed"} waiting for hooks: []string{"install", "config-changed", "start", "config-changed"} actual: []string{"install", "config-changed", "start"} [LOG] 26.64385 DEBUG juju.rpc.jsoncodec <- {"RequestId":70,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.64613 DEBUG juju.rpc.jsoncodec -> {"RequestId":70,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.64732 DEBUG juju.rpc.jsoncodec <- {"RequestId":71,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.64851 DEBUG juju.rpc.jsoncodec -> {"RequestId":71,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.64911 DEBUG juju.rpc.jsoncodec <- {"RequestId":72,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 26.64995 DEBUG juju.rpc.jsoncodec -> {"RequestId":72,"Response":{"Error":null,"Result":"5e78f254-45f6-43c7-8275-0db387c187ff"}} [LOG] 26.65044 INFO juju.worker.uniter unit "u/0" started [LOG] 26.65053 INFO juju.worker.uniter ModeInit starting [LOG] 26.65056 INFO juju.worker.uniter updating unit addresses [LOG] 26.65105 DEBUG juju.rpc.jsoncodec <- {"RequestId":73,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 26.65126 DEBUG juju.rpc.jsoncodec <- {"RequestId":74,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.65390 DEBUG juju.rpc.jsoncodec -> {"RequestId":73,"Response":{"Error":null,"Result":"dummy"}} [LOG] 26.65443 DEBUG juju.rpc.jsoncodec -> {"RequestId":74,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.65553 DEBUG juju.rpc.jsoncodec <- {"RequestId":75,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 26.65576 DEBUG juju.rpc.jsoncodec <- {"RequestId":76,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.65802 DEBUG juju.rpc.jsoncodec -> {"RequestId":76,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.66105 DEBUG juju.rpc.jsoncodec <- {"RequestId":77,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.66180 DEBUG juju.rpc.jsoncodec -> {"RequestId":77,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 26.66284 DEBUG juju.rpc.jsoncodec <- {"RequestId":78,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.66340 DEBUG juju.rpc.jsoncodec -> {"RequestId":78,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.66387 DEBUG juju.rpc.jsoncodec -> {"RequestId":75,"Response":{"Results":[{"Error":null}]}} [LOG] 26.66396 DEBUG juju.rpc.jsoncodec <- {"RequestId":79,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.66428 DEBUG juju.rpc.jsoncodec -> {"RequestId":79,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.66452 DEBUG juju.rpc.jsoncodec <- {"RequestId":80,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 26.66462 DEBUG juju.rpc.jsoncodec <- {"RequestId":81,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.66536 DEBUG juju.rpc.jsoncodec -> {"RequestId":81,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 26.66557 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 26.66640 DEBUG juju.rpc.jsoncodec <- {"RequestId":82,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.66771 DEBUG juju.rpc.jsoncodec -> {"RequestId":82,"Response":{"Results":[{"NotifyWatcherId":"8","Error":null}]}} [LOG] 26.66869 DEBUG juju.rpc.jsoncodec <- {"RequestId":83,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.66875 DEBUG juju.rpc.jsoncodec <- {"RequestId":84,"Type":"NotifyWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 26.66954 DEBUG juju.rpc.jsoncodec -> {"RequestId":80,"Response":{"Results":[{"Error":null}]}} [LOG] 26.66963 DEBUG juju.rpc.jsoncodec -> {"RequestId":83,"Response":{"Results":[{"NotifyWatcherId":"9","Error":null}]}} [LOG] 26.66978 INFO juju.worker.uniter reconciling relation state [LOG] 26.66987 DEBUG juju.worker.uniter ModeInit exiting [LOG] 26.66988 INFO juju.worker.uniter ModeContinue starting [LOG] 26.66989 INFO juju.worker.uniter loading uniter state [LOG] 26.67008 INFO juju.worker.uniter continuing after "start" hook [LOG] 26.67009 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 26.67010 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 26.67030 DEBUG juju.rpc.jsoncodec <- {"RequestId":85,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67036 DEBUG juju.rpc.jsoncodec <- {"RequestId":86,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 26.67069 DEBUG juju.rpc.jsoncodec -> {"RequestId":85,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} [LOG] 26.67085 DEBUG juju.rpc.jsoncodec <- {"RequestId":87,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67143 DEBUG juju.rpc.jsoncodec -> {"RequestId":87,"Response":{"Results":[{"NotifyWatcherId":"10","Error":null}]}} [LOG] 26.67176 DEBUG juju.rpc.jsoncodec <- {"RequestId":88,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.67182 DEBUG juju.rpc.jsoncodec <- {"RequestId":89,"Type":"NotifyWatcher","Id":"10","Request":"Next","Params":{}} [LOG] 26.67242 DEBUG juju.rpc.jsoncodec -> {"RequestId":88,"Response":{"Results":[{"StringsWatcherId":"11","Changes":["logging:info u:juju-info","logging:logging-directory u:logging-dir"],"Error":null}]}} [LOG] 26.67255 DEBUG juju.worker.uniter.filter got unit change [LOG] 26.67271 DEBUG juju.rpc.jsoncodec <- {"RequestId":90,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67277 DEBUG juju.rpc.jsoncodec <- {"RequestId":91,"Type":"StringsWatcher","Id":"11","Request":"Next","Params":{}} [LOG] 26.67313 DEBUG juju.rpc.jsoncodec -> {"RequestId":90,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.67331 DEBUG juju.rpc.jsoncodec <- {"RequestId":92,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67362 DEBUG juju.rpc.jsoncodec -> {"RequestId":92,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 26.67375 DEBUG juju.worker.uniter.filter got config change [LOG] 26.67376 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 26.67377 DEBUG juju.worker.uniter.filter discarded config event [LOG] 26.67378 DEBUG juju.worker.uniter.filter got relations change [LOG] 26.67421 DEBUG juju.rpc.jsoncodec <- {"RequestId":93,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.info#u.juju-info","Unit":"unit-u-0"}]}} [LOG] 26.67427 DEBUG juju.rpc.jsoncodec <- {"RequestId":94,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 26.67588 DEBUG juju.rpc.jsoncodec -> {"RequestId":94,"Response":{"Error":null,"Result":["127.0.0.1:37249"]}} [LOG] 26.67629 DEBUG juju.rpc.jsoncodec -> {"RequestId":93,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.67655 DEBUG juju.rpc.jsoncodec <- {"RequestId":95,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67670 DEBUG juju.rpc.jsoncodec <- {"RequestId":96,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.logging-directory#u.logging-dir","Unit":"unit-u-0"}]}} [LOG] 26.67757 DEBUG juju.rpc.jsoncodec -> {"RequestId":95,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} [LOG] 26.67771 DEBUG juju.rpc.jsoncodec -> {"RequestId":96,"Response":{"Results":[{"Error":null,"Life":"alive","Id":1,"Key":"logging:logging-directory u:logging-dir","Endpoint":{"ServiceName":"u","Relation":{"Name":"logging-dir","Role":"provider","Interface":"logging","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.67798 DEBUG juju.worker.uniter.filter got service change [LOG] 26.67805 DEBUG juju.rpc.jsoncodec <- {"RequestId":97,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.67810 DEBUG juju.rpc.jsoncodec <- {"RequestId":98,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 26.67879 DEBUG juju.rpc.jsoncodec -> {"RequestId":98,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.67914 DEBUG juju.rpc.jsoncodec -> {"RequestId":97,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} [LOG] 26.68263 INFO juju.worker.uniter running "config-changed" hook [LOG] 26.71952 DEBUG juju.rpc.jsoncodec <- {"RequestId":99,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} actual: []string{"install", "config-changed", "start"} [LOG] 26.77748 DEBUG juju.rpc.jsoncodec -> {"RequestId":99,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} [LOG] 26.77820 DEBUG juju.worker.uniter.filter no new charm event [LOG] 26.78717 INFO juju u/0: 5e78f254-45f6-43c7-8275-0db387c187ff config-changed [LOG] 26.78800 DEBUG juju.rpc.jsoncodec -> {"RequestId":84,"Response":{}} [LOG] 26.78840 DEBUG juju.worker.uniter.filter got unit change [LOG] 26.78854 DEBUG juju.rpc.jsoncodec <- {"RequestId":100,"Type":"NotifyWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 26.78871 DEBUG juju.rpc.jsoncodec <- {"RequestId":101,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.78923 DEBUG juju.rpc.jsoncodec -> {"RequestId":101,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.78956 DEBUG juju.rpc.jsoncodec <- {"RequestId":102,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.79001 DEBUG juju.rpc.jsoncodec -> {"RequestId":102,"Response":{"Results":[{"Error":null,"Mode":""}]}} [LOG] 26.79365 INFO juju.worker.uniter ran "config-changed" hook [LOG] 26.79367 INFO juju.worker.uniter committing "config-changed" hook actual: []string{"install", "config-changed", "start", "config-changed"} step 7: uniter_test.removeSubordinate{} [LOG] 26.88560 INFO juju.worker.uniter committed "config-changed" hook [LOG] 26.88661 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 26.88668 INFO juju.worker.uniter ModeContinue starting [LOG] 26.88672 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 26.88675 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 26.88677 INFO juju.worker.uniter ModeAbide starting [LOG] 26.89076 DEBUG juju.rpc.jsoncodec <- {"RequestId":103,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} [LOG] 26.92224 DEBUG juju.rpc.jsoncodec -> {"RequestId":103,"Response":{"Results":[{"Error":null}]}} [LOG] 26.92401 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 26.92405 DEBUG juju.worker.uniter.filter no new charm event [LOG] 26.92409 DEBUG juju.worker.uniter.filter sent relations event [LOG] 26.92513 DEBUG juju.rpc.jsoncodec <- {"RequestId":104,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 26.92784 DEBUG juju.rpc.jsoncodec -> {"RequestId":104,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"logging:info u:juju-info","Endpoint":{"ServiceName":"u","Relation":{"Name":"juju-info","Role":"provider","Interface":"juju-info","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.92881 DEBUG juju.rpc.jsoncodec <- {"RequestId":105,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[1]}} [LOG] 26.93121 DEBUG juju.rpc.jsoncodec -> {"RequestId":105,"Response":{"Results":[{"Error":null,"Life":"alive","Id":1,"Key":"logging:logging-directory u:logging-dir","Endpoint":{"ServiceName":"u","Relation":{"Name":"logging-dir","Role":"provider","Interface":"logging","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.93782 DEBUG juju.rpc.jsoncodec <- {"RequestId":106,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.logging-directory#u.logging-dir","Unit":"unit-u-0"}]}} [LOG] 26.94355 DEBUG juju.rpc.jsoncodec -> {"RequestId":106,"Response":{"Results":[{"Error":null,"Life":"alive","Id":1,"Key":"logging:logging-directory u:logging-dir","Endpoint":{"ServiceName":"u","Relation":{"Name":"logging-dir","Role":"provider","Interface":"logging","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.94451 INFO juju.worker.uniter joining relation "logging:logging-directory u:logging-dir" [LOG] 26.94521 DEBUG juju.rpc.jsoncodec <- {"RequestId":107,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-logging.logging-directory#u.logging-dir","Unit":"unit-u-0"}]}} [LOG] 26.95436 DEBUG juju.rpc.jsoncodec -> {"RequestId":107,"Response":{"Results":[{"Error":null,"Life":"alive","Id":1,"Key":"logging:logging-directory u:logging-dir","Endpoint":{"ServiceName":"u","Relation":{"Name":"logging-dir","Role":"provider","Interface":"logging","Optional":false,"Limit":0,"Scope":"container"}}}]}} [LOG] 26.95563 DEBUG juju.rpc.jsoncodec <- {"RequestId":108,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.95714 DEBUG juju.rpc.jsoncodec -> {"RequestId":108,"Response":{"Results":[{"NotifyWatcherId":"12","Error":null}]}} [LOG] 26.95781 DEBUG juju.rpc.jsoncodec <- {"RequestId":109,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-logging.logging-directory#u.logging-dir","Unit":"unit-u-0"}]}} [LOG] 26.95809 DEBUG juju.rpc.jsoncodec <- {"RequestId":110,"Type":"NotifyWatcher","Id":"12","Request":"Next","Params":{}} [LOG] 26.96224 DEBUG juju.rpc.jsoncodec -> {"RequestId":109,"Response":{"Results":[{"Error":{"Message":"cannot enter scope yet: non-alive subordinate unit has not been removed","Code":"cannot enter scope yet"}}]}} [LOG] 26.96259 INFO juju.worker.uniter cannot enter scope for relation "logging:logging-directory u:logging-dir"; waiting for subordinate to be removed step 8: uniter_test.waitSubordinateExists{name:"logging/1"} [LOG] 26.98014 DEBUG juju.rpc.jsoncodec -> {"RequestId":100,"Response":{}} [LOG] 26.98067 DEBUG juju.worker.uniter.filter got unit change [LOG] 26.98091 DEBUG juju.rpc.jsoncodec <- {"RequestId":111,"Type":"NotifyWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 26.98117 DEBUG juju.rpc.jsoncodec <- {"RequestId":112,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.98358 DEBUG juju.rpc.jsoncodec -> {"RequestId":112,"Response":{"Results":[{"Life":"alive","Error":null}]}} [LOG] 26.98524 DEBUG juju.rpc.jsoncodec <- {"RequestId":113,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 26.98699 DEBUG juju.rpc.jsoncodec -> {"RequestId":113,"Response":{"Results":[{"Error":null,"Mode":""}]}} uniter_test.go:1018: s.runUniterTests(c, subordinatesTests) uniter_test.go:1709: c.Fatalf("subordinate was not created") ... Error: subordinate was not created [LOG] 37.02491 DEBUG juju.rpc.jsoncodec <- {"RequestId":114,"Type":"NotifyWatcher","Id":"12","Request":"Stop","Params":{}} [LOG] 37.02504 DEBUG juju.rpc.jsoncodec -> {"RequestId":110,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 37.02511 DEBUG juju.rpc.jsoncodec -> {"RequestId":114,"Response":{}} [LOG] 37.02525 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 37.02532 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 37.02547 DEBUG juju.rpc.jsoncodec <- {"RequestId":115,"Type":"StringsWatcher","Id":"11","Request":"Stop","Params":{}} [LOG] 37.02559 DEBUG juju.rpc.jsoncodec -> {"RequestId":91,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 37.02564 DEBUG juju.rpc.jsoncodec -> {"RequestId":115,"Response":{}} [LOG] 37.02589 DEBUG juju.rpc.jsoncodec <- {"RequestId":116,"Type":"NotifyWatcher","Id":"10","Request":"Stop","Params":{}} [LOG] 37.02604 DEBUG juju.rpc.jsoncodec -> {"RequestId":89,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 37.02610 DEBUG juju.rpc.jsoncodec -> {"RequestId":116,"Response":{}} [LOG] 37.02634 DEBUG juju.rpc.jsoncodec <- {"RequestId":117,"Type":"NotifyWatcher","Id":"9","Request":"Stop","Params":{}} [LOG] 37.02649 DEBUG juju.rpc.jsoncodec -> {"RequestId":86,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 37.02654 DEBUG juju.rpc.jsoncodec -> {"RequestId":117,"Response":{}} [LOG] 37.02676 DEBUG juju.rpc.jsoncodec <- {"RequestId":118,"Type":"NotifyWatcher","Id":"8","Request":"Stop","Params":{}} [LOG] 37.02682 DEBUG juju.rpc.jsoncodec -> {"RequestId":111,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} [LOG] 37.02689 DEBUG juju.rpc.jsoncodec -> {"RequestId":118,"Response":{}} [LOG] 37.02703 ERROR juju.worker.uniter.filter tomb: dying [LOG] 37.02864 INFO juju environs/dummy: reset environment [LOG] 37.02964 DEBUG juju.rpc.jsoncodec <- error: read tcp 127.0.0.1:57578: use of closed network connection (closing true) [LOG] 37.03068 DEBUG juju.rpc.jsoncodec <- error: read tcp 127.0.0.1:57579: use of closed network connection (closing true) [LOG] 37.13675 INFO juju environs/testing: uploading FAKE tools 1.15.1-precise-amd64 [LOG] 37.13879 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 37.13880 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 37.13885 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 37.13891 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 37.13895 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 37.13897 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 37.13917 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 37.13927 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 37.13932 INFO juju.environs.boostrap bootstrapping environment "dummyenv" [LOG] 37.13935 INFO juju.environs.tools reading tools with major.minor version 1.15 [LOG] 37.13936 INFO juju.environs.tools filtering tools by version: 1.15.1 [LOG] 37.13937 INFO juju.environs.tools filtering tools by series: precise [LOG] 37.13939 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 37.13944 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 37.13946 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 37.13965 DEBUG juju.environs.simplestreams no mirror information available for {DataType:content-download MirrorContentId:com.ubuntu.juju:released:tools FilterFunc:0x68eb40 ValueTemplate:{Release: Version: Arch: Size:0 Path: FullPath: FileType: SHA256:}}: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 37.13967 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:42287/dummyenv/private/tools/streams/v1/index.json" [LOG] 37.13972 DEBUG juju.environs.simplestreams candidate matches for products ["com.ubuntu.juju:12.04:amd64" "com.ubuntu.juju:12.04:i386" "com.ubuntu.juju:12.04:arm"] are [{Wed, 02 Oct 2013 01:02:38 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 37.13974 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 37.13996 INFO juju environs/dummy: would pick tools from 1.15.1-precise-amd64 [LOG] 37.19176 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 37.19588 INFO juju.state connection established [LOG] 37.21711 INFO juju.state initializing environment [LOG] 37.24018 INFO juju state/api: listening on "127.0.0.1:47459" [LOG] 37.26180 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 37.26772 INFO juju.state connection established [LOG] 37.27059 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 37.27147 INFO juju.state opening state; mongo addresses: ["localhost:55295"]; entity "" [LOG] 37.28000 INFO juju.state connection established [LOG] 37.36443 INFO juju state/api: dialing "wss://127.0.0.1:47459/" [LOG] 37.36828 INFO juju state/api: connection established [LOG] 37.36839 DEBUG juju.rpc.jsoncodec <- {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 37.36879 DEBUG juju.rpc.jsoncodec -> {"RequestId":1,"Response":{}} [LOG] 37.37623 INFO juju environs/dummy: reset environment [LOG] 37.37635 DEBUG juju.rpc.jsoncodec <- error: read tcp 127.0.0.1:46102: use of closed network connection (closing true) OOPS: 39 passed, 1 FAILED --- FAIL: TestPackage (160.49 seconds) FAIL FAIL launchpad.net/juju-core/worker/uniter 160.740s ok launchpad.net/juju-core/worker/uniter/charm 2.592s ok launchpad.net/juju-core/worker/uniter/debug 1.098s ok launchpad.net/juju-core/worker/uniter/hook 0.014s ok launchpad.net/juju-core/worker/uniter/jujuc 0.470s ok launchpad.net/juju-core/worker/uniter/relation 1.420s ok launchpad.net/juju-core/worker/upgrader 3.091s warning: building out-of-date packages: launchpad.net/goamz/ec2/ec2test launchpad.net/goamz/s3/s3test launchpad.net/goose/testservices/hook launchpad.net/goose/testservices/identityservice launchpad.net/goose/testservices launchpad.net/goose/testservices/novaservice launchpad.net/goose/testservices/swiftservice launchpad.net/goose/testservices/openstackservice launchpad.net/lpad installing these packages with 'go test -i ./...' will speed future tests.