The attempt to merge lp:~thumper/juju-core/api-juju-run into lp:juju-core failed. Below is the output from the failed tests. ok launchpad.net/juju-core/agent 0.743s ok launchpad.net/juju-core/agent/tools 0.250s ok launchpad.net/juju-core/bzr 7.341s ok launchpad.net/juju-core/cert 3.651s ok launchpad.net/juju-core/charm 0.568s ? launchpad.net/juju-core/charm/hooks [no test files] ok launchpad.net/juju-core/cloudinit 0.032s ok launchpad.net/juju-core/cloudinit/sshinit 1.003s ok launchpad.net/juju-core/cmd 0.259s ok launchpad.net/juju-core/cmd/charm-admin 0.857s ? 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 181.648s ok launchpad.net/juju-core/cmd/jujud 54.857s ok launchpad.net/juju-core/cmd/plugins/juju-metadata 2.618s ? launchpad.net/juju-core/cmd/plugins/juju-restore [no test files] ok launchpad.net/juju-core/constraints 0.026s ok launchpad.net/juju-core/container 0.036s ok launchpad.net/juju-core/container/factory 0.060s ok launchpad.net/juju-core/container/kvm 0.289s ok launchpad.net/juju-core/container/kvm/mock 0.035s ? launchpad.net/juju-core/container/kvm/testing [no test files] ok launchpad.net/juju-core/container/lxc 0.280s ? launchpad.net/juju-core/container/lxc/mock [no test files] ? launchpad.net/juju-core/container/lxc/testing [no test files] ? launchpad.net/juju-core/container/testing [no test files] ok launchpad.net/juju-core/downloader 5.265s ok launchpad.net/juju-core/environs 3.189s ok launchpad.net/juju-core/environs/bootstrap 4.550s ok launchpad.net/juju-core/environs/cloudinit 0.505s ok launchpad.net/juju-core/environs/config 1.095s ok launchpad.net/juju-core/environs/configstore 0.047s ok launchpad.net/juju-core/environs/filestorage 0.039s ok launchpad.net/juju-core/environs/httpstorage 1.065s ok launchpad.net/juju-core/environs/imagemetadata 0.515s ? launchpad.net/juju-core/environs/imagemetadata/testing [no test files] ok launchpad.net/juju-core/environs/instances 0.072s ok launchpad.net/juju-core/environs/jujutest 0.257s ok launchpad.net/juju-core/environs/manual 10.644s ok launchpad.net/juju-core/environs/simplestreams 0.383s ? launchpad.net/juju-core/environs/simplestreams/testing [no test files] ok launchpad.net/juju-core/environs/sshstorage 1.330s ok launchpad.net/juju-core/environs/storage 1.176s ok launchpad.net/juju-core/environs/sync 31.477s ok launchpad.net/juju-core/environs/testing 0.207s ok launchpad.net/juju-core/environs/tools 6.855s ? launchpad.net/juju-core/environs/tools/testing [no test files] ok launchpad.net/juju-core/errors 0.016s ok launchpad.net/juju-core/instance 0.023s ? launchpad.net/juju-core/instance/testing [no test files] ok launchpad.net/juju-core/juju 16.379s ok launchpad.net/juju-core/juju/osenv 0.018s ? 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.025s ? 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.479s ok launchpad.net/juju-core/provider/common 7.713s ok launchpad.net/juju-core/provider/dummy 22.844s ok launchpad.net/juju-core/provider/ec2 19.955s ok launchpad.net/juju-core/provider/ec2/httpstorage 0.231s ok launchpad.net/juju-core/provider/joyent 5.334s ok launchpad.net/juju-core/provider/local 2.438s ok launchpad.net/juju-core/provider/maas 21.575s ok launchpad.net/juju-core/provider/null 1.240s ok launchpad.net/juju-core/provider/openstack 26.326s ok launchpad.net/juju-core/replicaset 12.189s ok launchpad.net/juju-core/rpc 0.093s ok launchpad.net/juju-core/rpc/jsoncodec 0.029s ? launchpad.net/juju-core/rpc/rpcreflect [no test files] ok launchpad.net/juju-core/schema 0.020s ok launchpad.net/juju-core/state 84.948s ok launchpad.net/juju-core/state/api 1.968s ok launchpad.net/juju-core/state/api/agent 2.049s ? launchpad.net/juju-core/state/api/common [no test files] ok launchpad.net/juju-core/state/api/deployer 5.929s ok launchpad.net/juju-core/state/api/keymanager 3.480s ok launchpad.net/juju-core/state/api/keyupdater 2.600s ok launchpad.net/juju-core/state/api/logger 2.257s ok launchpad.net/juju-core/state/api/machiner 3.222s ok launchpad.net/juju-core/state/api/params 0.047s ok launchpad.net/juju-core/state/api/provisioner 9.850s ok launchpad.net/juju-core/state/api/uniter 27.803s ok launchpad.net/juju-core/state/api/upgrader 3.721s ok launchpad.net/juju-core/state/api/watcher 3.034s ok launchpad.net/juju-core/state/apiserver 6.951s ok launchpad.net/juju-core/state/apiserver/agent 3.216s ok launchpad.net/juju-core/state/apiserver/client 46.595s ok launchpad.net/juju-core/state/apiserver/common 1.566s ok launchpad.net/juju-core/state/apiserver/deployer 4.748s ok launchpad.net/juju-core/state/apiserver/keymanager 4.219s ? launchpad.net/juju-core/state/apiserver/keymanager/testing [no test files] ok launchpad.net/juju-core/state/apiserver/keyupdater 3.239s ok launchpad.net/juju-core/state/apiserver/logger 3.972s ok launchpad.net/juju-core/state/apiserver/machine 4.473s ok launchpad.net/juju-core/state/apiserver/provisioner 12.177s ? launchpad.net/juju-core/state/apiserver/testing [no test files] ok launchpad.net/juju-core/state/apiserver/uniter 19.212s ok launchpad.net/juju-core/state/apiserver/upgrader 5.956s ok launchpad.net/juju-core/state/multiwatcher 0.777s ok launchpad.net/juju-core/state/presence 6.470s ? launchpad.net/juju-core/state/statecmd [no test files] ? launchpad.net/juju-core/state/testing [no test files] ok launchpad.net/juju-core/state/watcher 5.817s ok launchpad.net/juju-core/store 20.095s ok launchpad.net/juju-core/testing 1.404s ok launchpad.net/juju-core/testing/checkers 0.020s ok launchpad.net/juju-core/testing/testbase 0.020s ok launchpad.net/juju-core/thirdparty/pbkdf2 0.138s ok launchpad.net/juju-core/tools 0.019s ok launchpad.net/juju-core/upstart 1.212s ok launchpad.net/juju-core/utils 2.420s ok launchpad.net/juju-core/utils/fslock 1.147s ok launchpad.net/juju-core/utils/parallel 0.929s ok launchpad.net/juju-core/utils/set 0.018s ok launchpad.net/juju-core/utils/ssh 1.911s ? launchpad.net/juju-core/utils/ssh/testing [no test files] ok launchpad.net/juju-core/utils/tailer 1.062s ok launchpad.net/juju-core/version 0.067s ok launchpad.net/juju-core/worker 6.668s ok launchpad.net/juju-core/worker/addressupdater 1.446s ok launchpad.net/juju-core/worker/authenticationworker 3.313s ok launchpad.net/juju-core/worker/cleaner 1.274s ok launchpad.net/juju-core/worker/deployer 8.525s ok launchpad.net/juju-core/worker/firewaller 11.358s ok launchpad.net/juju-core/worker/localstorage 0.049s ok launchpad.net/juju-core/worker/logger 1.631s ok launchpad.net/juju-core/worker/machiner 7.656s ok launchpad.net/juju-core/worker/minunitsworker 1.511s ok launchpad.net/juju-core/worker/provisioner 35.113s ok launchpad.net/juju-core/worker/resumer 1.713s ok launchpad.net/juju-core/worker/terminationworker 0.063s ---------------------------------------------------------------------- FAIL: uniter_test.go:954: UniterSuite.TestUniterRelations [LOG] 63.45138 DEBUG juju.environs.configstore Making /tmp/gocheck-3328451335138149956/117/home/ubuntu/.juju/environments [LOG] 63.55161 DEBUG juju.environs.tools reading v1.* tools [LOG] 63.55165 INFO juju environs/testing: uploading FAKE tools 1.17.1-precise-amd64 [LOG] 63.55254 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 63.55256 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 63.55262 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 63.55265 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 63.55269 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 63.55271 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 63.55294 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 63.55334 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 63.55366 INFO juju.environs.bootstrap bootstrapping environment "dummyenv" [LOG] 63.55376 DEBUG juju.environs.bootstrap looking for bootstrap tools: series="precise", arch=, version=1.17.1 [LOG] 63.55381 INFO juju.environs.tools reading tools with major.minor version 1.17 [LOG] 63.55385 INFO juju.environs.tools filtering tools by version: 1.17.1 [LOG] 63.55387 INFO juju.environs.tools filtering tools by series: precise [LOG] 63.55393 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 63.55405 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 63.55411 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 63.55441 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/mirrors.json": file "tools/streams/v1/mirrors.json" not found not found [LOG] 63.55445 DEBUG juju.environs.simplestreams no mirror index file found [LOG] 63.55452 DEBUG juju.environs.simplestreams no mirror information available for { }: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 63.55456 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:56448/dummyenv/private/tools/streams/v1/index.json" [LOG] 63.55472 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 [{Sun, 12 Jan 2014 21:39:44 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 63.55475 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 63.55534 DEBUG juju.environs.simplestreams metadata: &{map[com.ubuntu.juju:12.04:amd64:{ 1.17.1 amd64 map[20140112:0xc20074a4e0]}] map[] Sun, 12 Jan 2014 21:39:44 +0000 products:1.0 com.ubuntu.juju:released:tools} [LOG] 63.55549 INFO juju.environs.bootstrap picked newest version: 1.17.1 [LOG] 63.55556 INFO juju.provider.dummy would pick tools from 1.17.1-precise-amd64 [LOG] 63.55677 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 63.56627 INFO juju.state connection established [LOG] 63.61748 INFO juju.state initializing environment [LOG] 63.65484 INFO juju.state.apiserver listening on "127.0.0.1:52225" [LOG] 63.67261 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 63.69864 INFO juju.state connection established [LOG] 63.70008 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 63.70017 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 63.70490 INFO juju.state connection established [LOG] 63.75872 INFO juju state/api: dialing "wss://127.0.0.1:52225/" [LOG] 63.76296 INFO juju state/api: connection established [LOG] 63.76315 DEBUG juju.state.apiserver <- [73] {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 63.76352 DEBUG juju.state.apiserver -> [73] user-admin 373.369us {"RequestId":1,"Response":{}} Admin[""].Login test 0: simple joined/changed/departed step 0: uniter_test.quickStartRelation{} 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)(0xc200839030), curl:(*charm.URL)(0xc200d4eaf0)} uniter_test.serveCharm{} uniter_test.createUniter{} uniter_test.ensureStateWorker{} uniter_test.createServiceAndUnit{serviceName:""} [LOG] 63.95819 INFO juju state/api: dialing "wss://127.0.0.1:52225/" [LOG] 63.96217 INFO juju state/api: connection established [LOG] 63.96247 DEBUG juju.state.apiserver <- [74] {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"unit-u-0","Password":"Vyn60X4pabiMCACE5DWJx8Zg","Nonce":""}} [LOG] 63.97856 DEBUG juju.state.apiserver -> [74] unit-u-0 16.06845ms {"RequestId":1,"Response":{}} Admin[""].Login API: login as "unit-u-0" successful uniter_test.startUniter{unitTag:""} uniter_test.waitAddresses{} [LOG] 63.97928 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":3,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.97988 DEBUG juju.state.apiserver -> [74] unit-u-0 605.001us {"RequestId":3,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.98057 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":4,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.98106 DEBUG juju.state.apiserver -> [74] unit-u-0 412.13us {"RequestId":4,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.98153 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":5,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 63.98181 DEBUG juju.state.apiserver -> [74] unit-u-0 277.967us {"RequestId":5,"Response":{"Error":null,"Result":"d095899a-fe28-4a40-8d87-8a911a28c4f8"}} Uniter[""].CurrentEnvironUUID [LOG] 63.98198 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 63.98280 INFO juju.worker.uniter unit "u/0" started [LOG] 63.98283 INFO juju.worker.uniter ModeInit starting [LOG] 63.98284 INFO juju.worker.uniter updating unit addresses [LOG] 63.98291 DEBUG juju.worker.uniter juju-run listener running [LOG] 63.98321 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":6,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 63.98335 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":7,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.98497 DEBUG juju.state.apiserver -> [74] unit-u-0 1.746497ms {"RequestId":6,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 63.98510 DEBUG juju.state.apiserver -> [74] unit-u-0 1.760792ms {"RequestId":7,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.98556 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":8,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 63.98571 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":9,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.98647 DEBUG juju.state.apiserver -> [74] unit-u-0 763.257us {"RequestId":9,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.98763 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":10,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.98835 DEBUG juju.state.apiserver -> [74] unit-u-0 790.49us {"RequestId":10,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 63.98949 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":11,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.98997 DEBUG juju.state.apiserver -> [74] unit-u-0 513.664us {"RequestId":11,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.99046 DEBUG juju.state.apiserver -> [74] unit-u-0 4.908887ms {"RequestId":8,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 63.99059 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":12,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.99090 DEBUG juju.state.apiserver -> [74] unit-u-0 330.607us {"RequestId":12,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 63.99120 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":13,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 63.99127 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":14,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.99207 DEBUG juju.state.apiserver -> [74] unit-u-0 735.36us {"RequestId":14,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 63.99220 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 63.99303 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":15,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.99419 DEBUG juju.state.apiserver -> [74] unit-u-0 1.135214ms {"RequestId":15,"Response":{"Results":[{"NotifyWatcherId":"2","Error":null}]}} Uniter[""].Watch [LOG] 63.99515 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":16,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.99523 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":17,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 63.99609 DEBUG juju.state.apiserver -> [74] unit-u-0 4.880448ms {"RequestId":13,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 63.99619 DEBUG juju.state.apiserver -> [74] unit-u-0 1.059045ms {"RequestId":16,"Response":{"Results":[{"NotifyWatcherId":"3","Error":null}]}} Uniter[""].Watch [LOG] 63.99636 INFO juju.worker.uniter reconciling relation state [LOG] 63.99643 DEBUG juju.worker.uniter ModeInit exiting [LOG] 63.99645 INFO juju.worker.uniter ModeContinue starting [LOG] 63.99645 INFO juju.worker.uniter loading uniter state [LOG] 63.99647 INFO juju.worker.uniter charm is not deployed [LOG] 63.99674 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":18,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.99688 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":19,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 63.99696 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":20,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 63.99752 DEBUG juju.state.apiserver -> [74] unit-u-0 764.614us {"RequestId":18,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 63.99765 DEBUG juju.state.apiserver -> [74] unit-u-0 773.89us {"RequestId":19,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].CharmURL [LOG] 63.99782 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 63.99783 INFO juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 starting [LOG] 63.99785 INFO juju.worker.uniter fetching charm "cs:quantal/wordpress-0" [LOG] 63.99806 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":21,"Type":"Uniter","Request":"CharmArchiveURL","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 63.99812 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":22,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 63.99976 DEBUG juju.state.apiserver -> [74] unit-u-0 1.696206ms {"RequestId":21,"Response":{"Results":[{"Error":null,"Result":"http://localhost:43284/charms/wordpress/0","DisableSSLHostnameVerification":false}]}} Uniter[""].CharmArchiveURL [LOG] 63.99990 DEBUG juju.state.apiserver -> [74] unit-u-0 1.77704ms {"RequestId":22,"Response":{"Results":[{"StringsWatcherId":"4","Changes":[],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 64.00020 INFO juju worker/uniter/charm: downloading cs:quantal/wordpress-0 from http://localhost:43284/charms/wordpress/0 [LOG] 64.00023 DEBUG juju.worker.uniter.filter got unit change [LOG] 64.00097 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":23,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.00104 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":24,"Type":"StringsWatcher","Id":"4","Request":"Next","Params":{}} [LOG] 64.00151 DEBUG juju.state.apiserver -> [74] unit-u-0 564.384us {"RequestId":23,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 64.00187 INFO juju worker/uniter/charm: download complete [LOG] 64.00222 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":25,"Type":"Uniter","Request":"CharmArchiveSha256","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 64.00229 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":26,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.00305 DEBUG juju.state.apiserver -> [74] unit-u-0 821.573us {"RequestId":25,"Response":{"Results":[{"Error":null,"Result":"2665e274b4be042bec1c983e3efeefef273d149a891ecb4387d3fbbd7bd5f75e"}]}} Uniter[""].CharmArchiveSha256 [LOG] 64.00318 DEBUG juju.state.apiserver -> [74] unit-u-0 893.479us {"RequestId":26,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 64.00338 INFO juju worker/uniter/charm: download verified [LOG] 64.01375 DEBUG juju.worker.uniter.filter got relations change [LOG] 64.01384 DEBUG juju.worker.uniter.filter got service change [LOG] 64.08442 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":27,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.10657 DEBUG juju.state.apiserver -> [74] unit-u-0 21.147285ms {"RequestId":27,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 64.10995 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":28,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.11050 DEBUG juju.state.apiserver -> [74] unit-u-0 591.939us {"RequestId":28,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL uniter_test.waitUnit{status:"started", info:"", data:params.StatusData(nil), charm:0, resolved:""} [LOG] 64.11104 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 64.12619 DEBUG juju.state.apiserver -> [74] unit-u-0 130.767392ms {"RequestId":17,"Response":{}} NotifyWatcher["2"].Next [LOG] 64.12824 DEBUG juju.worker.uniter.filter got unit change [LOG] 64.12870 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":29,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 64.12923 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":30,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.13159 DEBUG juju.state.apiserver -> [74] unit-u-0 2.350214ms {"RequestId":30,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 64.13218 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":31,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.13508 DEBUG juju.state.apiserver -> [74] unit-u-0 2.905047ms {"RequestId":31,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 64.14005 DEBUG juju.worker.uniter.filter changing charm to "cs:quantal/wordpress-0" [LOG] 64.14049 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":32,"Type":"Uniter","Request":"SetCharmURL","Params":{"Entities":[{"Tag":"unit-u-0","CharmURL":"cs:quantal/wordpress-0"}]}} [LOG] 64.15206 DEBUG juju.state.apiserver -> [74] unit-u-0 11.550575ms {"RequestId":32,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetCharmURL [LOG] 64.15301 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":33,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.15364 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":34,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.15829 DEBUG juju.state.apiserver -> [74] unit-u-0 4.446179ms {"RequestId":34,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 64.15911 INFO juju.worker.uniter deploying charm "cs:quantal/wordpress-0" [LOG] 64.16056 DEBUG juju.state.apiserver -> [74] unit-u-0 7.658406ms {"RequestId":33,"Response":{"Results":[{"NotifyWatcherId":"5","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 64.16161 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":35,"Type":"StringsWatcher","Id":"4","Request":"Stop","Params":{}} [LOG] 64.16171 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":36,"Type":"NotifyWatcher","Id":"5","Request":"Next","Params":{}} [LOG] 64.16203 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":24,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["4"].Next [LOG] 64.16215 DEBUG juju.state.apiserver -> [74] unit-u-0 529.06us {"RequestId":35,"Response":{}} StringsWatcher["4"].Stop [LOG] 64.16261 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":37,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.16402 INFO juju worker/uniter/charm: preparing new charm deployment [LOG] 64.17419 DEBUG juju.state.apiserver -> [74] unit-u-0 10.715442ms {"RequestId":37,"Response":{"Results":[{"StringsWatcherId":"6","Changes":[],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 64.17666 DEBUG juju.worker.uniter.filter no new charm event [LOG] 64.17700 DEBUG juju.worker.uniter.filter got config change [LOG] 64.17703 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 64.18233 DEBUG juju.worker.uniter.filter got relations change [LOG] 64.24582 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":38,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} want unit status "started", got "pending"; still waiting [LOG] 64.26245 DEBUG juju.state.apiserver -> [74] unit-u-0 133.597028ms {"RequestId":29,"Response":{}} NotifyWatcher["2"].Next [LOG] 64.26419 DEBUG juju.worker.uniter.filter got unit change [LOG] 64.26487 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":39,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 64.26537 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":40,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.26661 DEBUG juju.state.apiserver -> [74] unit-u-0 1.460208ms {"RequestId":40,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 64.26775 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":41,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.26875 DEBUG juju.state.apiserver -> [74] unit-u-0 1.13252ms {"RequestId":41,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 64.40752 INFO juju worker/uniter/charm: deploying charm [LOG] 64.40806 INFO juju worker/uniter/charm: charm deployment succeeded want unit status "started", got "pending"; still waiting [LOG] 64.42620 INFO juju.worker.uniter charm "cs:quantal/wordpress-0" is deployed [LOG] 64.42883 DEBUG juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 exiting [LOG] 64.42890 INFO juju.worker.uniter ModeContinue starting [LOG] 64.42892 INFO juju.worker.uniter found queued "install" hook [LOG] 64.43058 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":42,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 64.43459 DEBUG juju.state.apiserver -> [74] unit-u-0 3.984566ms {"RequestId":42,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 64.43576 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":43,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.43661 DEBUG juju.state.apiserver -> [74] unit-u-0 881.373us {"RequestId":43,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 64.43733 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":44,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.43932 DEBUG juju.state.apiserver -> [74] unit-u-0 2.119799ms {"RequestId":44,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 64.44102 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":45,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.44282 DEBUG juju.state.apiserver -> [74] unit-u-0 2.428751ms {"RequestId":45,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 64.44811 INFO juju.worker.uniter running "install" hook want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 64.59136 INFO juju u/0: d095899a-fe28-4a40-8d87-8a911a28c4f8 install [LOG] 64.60092 INFO juju.worker.uniter ran "install" hook [LOG] 64.60112 INFO juju.worker.uniter committing "install" hook [LOG] 64.63962 INFO juju.worker.uniter committed "install" hook [LOG] 64.64006 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 64.64009 INFO juju.worker.uniter ModeContinue starting [LOG] 64.64011 INFO juju.worker.uniter continuing after "install" hook [LOG] 64.64012 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 64.64013 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 64.64131 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":46,"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] 64.65072 DEBUG juju.state.apiserver -> [74] unit-u-0 9.385392ms {"RequestId":46,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 64.65179 DEBUG juju.worker.uniter.filter discarded config event [LOG] 64.65238 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":47,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 64.65519 DEBUG juju.state.apiserver -> [74] unit-u-0 2.774664ms {"RequestId":47,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 64.65614 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":48,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.65726 DEBUG juju.state.apiserver -> [74] unit-u-0 1.245849ms {"RequestId":48,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 64.65784 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":49,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.65950 DEBUG juju.state.apiserver -> [74] unit-u-0 1.616224ms {"RequestId":49,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 64.66046 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":50,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.66286 DEBUG juju.state.apiserver -> [74] unit-u-0 2.495318ms {"RequestId":50,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 64.66778 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] 64.79548 INFO juju u/0: d095899a-fe28-4a40-8d87-8a911a28c4f8 config-changed [LOG] 64.80565 INFO juju.worker.uniter ran "config-changed" hook [LOG] 64.80588 INFO juju.worker.uniter committing "config-changed" hook [LOG] 64.85249 INFO juju.worker.uniter committed "config-changed" hook [LOG] 64.85385 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 64.85392 INFO juju.worker.uniter ModeContinue starting [LOG] 64.85397 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 64.85399 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 64.85405 INFO juju.worker.uniter ModeStarting starting [LOG] 64.85790 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":51,"Type":"Uniter","Request":"APIAddresses","Params":{}} want unit status "started", got "installed"; still waiting [LOG] 64.86484 DEBUG juju.state.apiserver -> [74] unit-u-0 7.015645ms {"RequestId":51,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 64.86792 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":52,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 64.86910 DEBUG juju.state.apiserver -> [74] unit-u-0 1.50659ms {"RequestId":52,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 64.87010 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":53,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.87185 DEBUG juju.state.apiserver -> [74] unit-u-0 1.773972ms {"RequestId":53,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 64.87306 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":54,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 64.87456 DEBUG juju.state.apiserver -> [74] unit-u-0 1.436543ms {"RequestId":54,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 64.87854 INFO juju.worker.uniter running "start" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 65.02938 INFO juju u/0: d095899a-fe28-4a40-8d87-8a911a28c4f8 start want unit status "started", got "installed"; still waiting [LOG] 65.04189 INFO juju.worker.uniter ran "start" hook [LOG] 65.04213 INFO juju.worker.uniter committing "start" hook [LOG] 65.09612 INFO juju.worker.uniter committed "start" hook [LOG] 65.09745 DEBUG juju.worker.uniter ModeStarting exiting [LOG] 65.09749 INFO juju.worker.uniter ModeContinue starting [LOG] 65.09753 INFO juju.worker.uniter continuing after "start" hook [LOG] 65.09755 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 65.09767 INFO juju.worker.uniter ModeAbide starting [LOG] 65.10090 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":55,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} [LOG] 65.12654 DEBUG juju.state.apiserver -> [74] unit-u-0 25.51735ms {"RequestId":55,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 65.12889 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 65.12903 DEBUG juju.worker.uniter.filter no new charm event uniter_test.waitHooks{"install", "config-changed", "start"} waiting for hooks: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} uniter_test.verifyCharm{revision:0, dirty:false} uniter_test.waitHooks{} waiting for hooks: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} uniter_test.addRelation{JujuConnSuite:testing.JujuConnSuite{LoggingSuite:testbase.LoggingSuite{CleanupSuite:testbase.CleanupSuite{testStack:testbase.cleanupStack(nil), suiteStack:testbase.cleanupStack(nil)}}, MgoSuite:testing.MgoSuite{Session:(*mgo.Session)(nil)}, ToolsFixture:testing.ToolsFixture{origDefaultURL:"", origDefaultSyncLocation:"", DefaultBaseURL:""}, Conn:(*juju.Conn)(nil), State:(*state.State)(nil), APIConn:(*juju.APIConn)(nil), APIState:(*api.State)(nil), ConfigStore:configstore.Storage(nil), BackingState:(*state.State)(nil), RootDir:"", oldHome:"", oldJujuHome:"", environ:environs.Environ(nil)}} [LOG] 65.25650 INFO juju writing charm to storage [438 bytes] [LOG] 65.25674 INFO juju adding charm to state uniter_test.addRelationUnit{} uniter_test.waitHooks{"db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 65.33603 DEBUG juju.state.apiserver -> [74] unit-u-0 1.338987893s {"RequestId":20,"Response":{}} NotifyWatcher["3"].Next [LOG] 65.33780 DEBUG juju.worker.uniter.filter got service change [LOG] 65.33820 DEBUG juju.state.apiserver -> [74] unit-u-0 1.092690954s {"RequestId":38,"Response":{"StringsWatcherId":"","Changes":["u:db mysql:server"],"Error":null}} StringsWatcher["6"].Next [LOG] 65.34072 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":56,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 65.34090 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":57,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.34429 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":58,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 65.34501 DEBUG juju.state.apiserver -> [74] unit-u-0 3.973773ms {"RequestId":57,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.34683 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":59,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.34940 DEBUG juju.state.apiserver -> [74] unit-u-0 2.656662ms {"RequestId":59,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 65.35009 DEBUG juju.worker.uniter.filter no new charm event [LOG] 65.35016 DEBUG juju.worker.uniter.filter got relations change [LOG] 65.35076 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":60,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.35406 DEBUG juju.state.apiserver -> [74] unit-u-0 2.819946ms {"RequestId":60,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 65.35476 DEBUG juju.worker.uniter.filter sent relations event [LOG] 65.35539 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":61,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 65.35635 DEBUG juju.state.apiserver -> [74] unit-u-0 932.266us {"RequestId":61,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].RelationById [LOG] 65.36151 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":62,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.36458 DEBUG juju.state.apiserver -> [74] unit-u-0 2.86789ms {"RequestId":62,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 65.36591 INFO juju.worker.uniter joining relation "u:db mysql:server" [LOG] 65.36712 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":63,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.36868 DEBUG juju.state.apiserver -> [74] unit-u-0 1.886493ms {"RequestId":63,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 65.36916 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":64,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.36987 DEBUG juju.state.apiserver -> [74] unit-u-0 710.604us {"RequestId":64,"Response":{"Results":[{"NotifyWatcherId":"7","Error":null}]}} Uniter[""].Watch [LOG] 65.37034 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":65,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.37044 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":66,"Type":"NotifyWatcher","Id":"7","Request":"Next","Params":{}} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 65.39306 DEBUG juju.state.apiserver -> [74] unit-u-0 22.732983ms {"RequestId":65,"Response":{"Results":[{"Error":null}]}} Uniter[""].EnterScope [LOG] 65.39326 INFO juju.worker.uniter joined relation "u:db mysql:server" [LOG] 65.39344 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":67,"Type":"NotifyWatcher","Id":"7","Request":"Stop","Params":{}} [LOG] 65.39352 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":66,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["7"].Next [LOG] 65.39360 DEBUG juju.state.apiserver -> [74] unit-u-0 167.443us {"RequestId":67,"Response":{}} NotifyWatcher["7"].Stop [LOG] 65.39383 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":68,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.39415 DEBUG juju.state.apiserver -> [74] unit-u-0 321.449us {"RequestId":68,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal [LOG] 65.39452 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":69,"Type":"Uniter","Request":"WatchRelationUnits","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.39567 DEBUG juju.state.apiserver -> [74] unit-u-0 1.117462ms {"RequestId":69,"Response":{"Results":[{"RelationUnitsWatcherId":"8","Changes":{"Changed":{"mysql/0":{"Version":2}},"Departed":null},"Error":null}]}} Uniter[""].WatchRelationUnits [LOG] 65.39640 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":70,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 65.39649 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":71,"Type":"RelationUnitsWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 65.39781 DEBUG juju.state.apiserver -> [74] unit-u-0 1.399932ms {"RequestId":70,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 65.39810 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":72,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.39843 DEBUG juju.state.apiserver -> [74] unit-u-0 310.534us {"RequestId":72,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 65.39867 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":73,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.39915 DEBUG juju.state.apiserver -> [74] unit-u-0 478.886us {"RequestId":73,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 65.39943 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":74,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.39995 DEBUG juju.state.apiserver -> [74] unit-u-0 517.907us {"RequestId":74,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 65.40491 INFO juju.worker.uniter running "db-relation-joined" hook ctx.hooksCompleted: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 65.53047 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-joined mysql/0 [LOG] 65.54096 INFO juju.worker.uniter ran "db-relation-joined" hook [LOG] 65.54111 INFO juju.worker.uniter committing "relation-joined" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 65.62538 INFO juju.worker.uniter committed "relation-joined" hook [LOG] 65.62851 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":75,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 65.63328 DEBUG juju.state.apiserver -> [74] unit-u-0 4.802424ms {"RequestId":75,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 65.63435 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":76,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.63559 DEBUG juju.state.apiserver -> [74] unit-u-0 1.290882ms {"RequestId":76,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 65.63689 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":77,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.63886 DEBUG juju.state.apiserver -> [74] unit-u-0 2.101856ms {"RequestId":77,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 65.63978 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":78,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.64136 DEBUG juju.state.apiserver -> [74] unit-u-0 1.443425ms {"RequestId":78,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 65.64659 INFO juju.worker.uniter running "db-relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 65.79872 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-changed mysql/0 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 65.81079 INFO juju.worker.uniter ran "db-relation-changed" hook [LOG] 65.81091 INFO juju.worker.uniter committing "relation-changed" hook [LOG] 65.85137 INFO juju.worker.uniter committed "relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} [LOG] 65.86721 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":79,"Type":"RelationUnitsWatcher","Id":"8","Request":"Stop","Params":{}} [LOG] 65.86804 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":71,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} RelationUnitsWatcher["8"].Next [LOG] 65.86846 DEBUG juju.state.apiserver -> [74] unit-u-0 1.311097ms {"RequestId":79,"Response":{}} RelationUnitsWatcher["8"].Stop [LOG] 65.86935 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 65.86953 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 65.87097 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":80,"Type":"StringsWatcher","Id":"6","Request":"Stop","Params":{}} [LOG] 65.87129 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":58,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["6"].Next [LOG] 65.87150 DEBUG juju.state.apiserver -> [74] unit-u-0 740.874us {"RequestId":80,"Response":{}} StringsWatcher["6"].Stop [LOG] 65.87340 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":81,"Type":"NotifyWatcher","Id":"5","Request":"Stop","Params":{}} [LOG] 65.87358 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":36,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["5"].Next [LOG] 65.87367 DEBUG juju.state.apiserver -> [74] unit-u-0 289.032us {"RequestId":81,"Response":{}} NotifyWatcher["5"].Stop [LOG] 65.87420 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":82,"Type":"NotifyWatcher","Id":"3","Request":"Stop","Params":{}} [LOG] 65.87442 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":56,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["3"].Next [LOG] 65.87450 DEBUG juju.state.apiserver -> [74] unit-u-0 347.88us {"RequestId":82,"Response":{}} NotifyWatcher["3"].Stop [LOG] 65.87496 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":83,"Type":"NotifyWatcher","Id":"2","Request":"Stop","Params":{}} [LOG] 65.87513 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":39,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["2"].Next [LOG] 65.87525 DEBUG juju.state.apiserver -> [74] unit-u-0 292.188us {"RequestId":83,"Response":{}} NotifyWatcher["2"].Stop [LOG] 65.87552 ERROR juju.worker.uniter.filter tomb: dying [LOG] 65.87579 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 65.87582 DEBUG juju.worker.uniter juju-run listener stopped uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{"config-changed"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 65.87684 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":84,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.87815 DEBUG juju.state.apiserver -> [74] unit-u-0 1.35393ms {"RequestId":84,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.87914 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":85,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.87964 DEBUG juju.state.apiserver -> [74] unit-u-0 526.244us {"RequestId":85,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.88004 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":86,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 65.88041 DEBUG juju.state.apiserver -> [74] unit-u-0 361.906us {"RequestId":86,"Response":{"Error":null,"Result":"d095899a-fe28-4a40-8d87-8a911a28c4f8"}} Uniter[""].CurrentEnvironUUID [LOG] 65.88054 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 65.88088 INFO juju.worker.uniter unit "u/0" started [LOG] 65.88090 INFO juju.worker.uniter ModeInit starting [LOG] 65.88091 INFO juju.worker.uniter updating unit addresses [LOG] 65.88099 DEBUG juju.worker.uniter juju-run listener running [LOG] 65.88126 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":87,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 65.88140 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":88,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.88299 DEBUG juju.state.apiserver -> [74] unit-u-0 1.710355ms {"RequestId":87,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 65.88318 DEBUG juju.state.apiserver -> [74] unit-u-0 1.812988ms {"RequestId":88,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.88356 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":89,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 65.88364 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":90,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.88458 DEBUG juju.state.apiserver -> [74] unit-u-0 950.595us {"RequestId":90,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.88556 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":91,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.88641 DEBUG juju.state.apiserver -> [74] unit-u-0 856.913us {"RequestId":91,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 65.88709 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":92,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.88765 DEBUG juju.state.apiserver -> [74] unit-u-0 566us {"RequestId":92,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.88867 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":93,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.88949 DEBUG juju.state.apiserver -> [74] unit-u-0 778.628us {"RequestId":93,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.88977 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":94,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.89045 DEBUG juju.state.apiserver -> [74] unit-u-0 672.656us {"RequestId":94,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 65.89071 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 65.89083 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":95,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.89169 DEBUG juju.state.apiserver -> [74] unit-u-0 8.112208ms {"RequestId":89,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 65.89184 DEBUG juju.state.apiserver -> [74] unit-u-0 970.213us {"RequestId":95,"Response":{"Results":[{"NotifyWatcherId":"9","Error":null}]}} Uniter[""].Watch [LOG] 65.89238 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":96,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 65.89247 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":97,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.89254 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":98,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 65.89406 DEBUG juju.state.apiserver -> [74] unit-u-0 1.552212ms {"RequestId":97,"Response":{"Results":[{"NotifyWatcherId":"10","Error":null}]}} Uniter[""].Watch [LOG] 65.89500 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":99,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.89510 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":100,"Type":"NotifyWatcher","Id":"10","Request":"Next","Params":{}} [LOG] 65.89572 DEBUG juju.state.apiserver -> [74] unit-u-0 723.404us {"RequestId":99,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} Uniter[""].CharmURL [LOG] 65.89674 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":101,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.89816 DEBUG juju.state.apiserver -> [74] unit-u-0 5.845113ms {"RequestId":96,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 65.89836 DEBUG juju.state.apiserver -> [74] unit-u-0 1.658723ms {"RequestId":101,"Response":{"Results":[{"NotifyWatcherId":"11","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 65.89854 INFO juju.worker.uniter reconciling relation state [LOG] 65.89912 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":102,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 65.89923 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":103,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.89936 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":104,"Type":"NotifyWatcher","Id":"11","Request":"Next","Params":{}} [LOG] 65.90002 DEBUG juju.state.apiserver -> [74] unit-u-0 837.723us {"RequestId":102,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].RelationById [LOG] 65.90067 DEBUG juju.state.apiserver -> [74] unit-u-0 1.437695ms {"RequestId":103,"Response":{"Results":[{"StringsWatcherId":"12","Changes":["u:db mysql:server"],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 65.90096 INFO juju.worker.uniter joining relation "u:db mysql:server" [LOG] 65.90106 DEBUG juju.worker.uniter.filter got unit change [LOG] 65.90132 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":105,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.90151 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":106,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.90157 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":107,"Type":"StringsWatcher","Id":"12","Request":"Next","Params":{}} [LOG] 65.90231 DEBUG juju.state.apiserver -> [74] unit-u-0 866.916us {"RequestId":106,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.90268 DEBUG juju.state.apiserver -> [74] unit-u-0 1.368782ms {"RequestId":105,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 65.90300 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":108,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.90309 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":109,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.90351 DEBUG juju.state.apiserver -> [74] unit-u-0 505.227us {"RequestId":108,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 65.90391 DEBUG juju.state.apiserver -> [74] unit-u-0 811.397us {"RequestId":109,"Response":{"Results":[{"NotifyWatcherId":"13","Error":null}]}} Uniter[""].Watch [LOG] 65.90410 DEBUG juju.worker.uniter.filter got relations change [LOG] 65.90448 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":110,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.90457 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":111,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 65.90467 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":112,"Type":"NotifyWatcher","Id":"13","Request":"Next","Params":{}} [LOG] 65.90566 DEBUG juju.state.apiserver -> [74] unit-u-0 1.127293ms {"RequestId":110,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 65.90836 DEBUG juju.worker.uniter.filter got config change [LOG] 65.90843 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 65.90847 DEBUG juju.worker.uniter.filter got service change [LOG] 65.90895 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":113,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.90988 DEBUG juju.state.apiserver -> [74] unit-u-0 5.261038ms {"RequestId":111,"Response":{"Results":[{"Error":null}]}} Uniter[""].EnterScope [LOG] 65.91031 DEBUG juju.state.apiserver -> [74] unit-u-0 1.388546ms {"RequestId":113,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.91084 INFO juju.worker.uniter joined relation "u:db mysql:server" [LOG] 65.91142 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":114,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.91159 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":115,"Type":"NotifyWatcher","Id":"13","Request":"Stop","Params":{}} [LOG] 65.91237 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":112,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["13"].Next [LOG] 65.91255 DEBUG juju.state.apiserver -> [74] unit-u-0 976.661us {"RequestId":115,"Response":{}} NotifyWatcher["13"].Stop [LOG] 65.91315 DEBUG juju.worker.uniter ModeInit exiting [LOG] 65.91326 INFO juju.worker.uniter ModeContinue starting [LOG] 65.91328 INFO juju.worker.uniter loading uniter state [LOG] 65.91405 INFO juju.worker.uniter continuing after "relation-changed" hook [LOG] 65.91408 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 65.91410 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 65.91502 DEBUG juju.state.apiserver -> [74] unit-u-0 3.450506ms {"RequestId":114,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 65.91547 DEBUG juju.worker.uniter.filter no new charm event [LOG] 65.91553 DEBUG juju.worker.uniter.filter discarded config event [LOG] 65.91672 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":116,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 65.92052 DEBUG juju.state.apiserver -> [74] unit-u-0 3.660771ms {"RequestId":116,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 65.92154 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":117,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 65.92250 DEBUG juju.state.apiserver -> [74] unit-u-0 992.924us {"RequestId":117,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 65.92323 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":118,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.92493 DEBUG juju.state.apiserver -> [74] unit-u-0 1.624973ms {"RequestId":118,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 65.92582 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":119,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.92754 DEBUG juju.state.apiserver -> [74] unit-u-0 1.769017ms {"RequestId":119,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 65.93088 INFO juju.worker.uniter running "config-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 65.99166 DEBUG juju.state.apiserver -> [74] unit-u-0 99.049283ms {"RequestId":98,"Response":{}} NotifyWatcher["9"].Next [LOG] 65.99354 DEBUG juju.worker.uniter.filter got unit change [LOG] 65.99424 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":120,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 65.99456 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":121,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.99631 DEBUG juju.state.apiserver -> [74] unit-u-0 1.771868ms {"RequestId":121,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 65.99777 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":122,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 65.99921 DEBUG juju.state.apiserver -> [74] unit-u-0 1.330362ms {"RequestId":122,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 66.09808 INFO juju u/0: d095899a-fe28-4a40-8d87-8a911a28c4f8 config-changed [LOG] 66.10810 INFO juju.worker.uniter ran "config-changed" hook [LOG] 66.10826 INFO juju.worker.uniter committing "config-changed" hook [LOG] 66.16232 INFO juju.worker.uniter committed "config-changed" hook [LOG] 66.16340 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 66.16348 INFO juju.worker.uniter ModeContinue starting [LOG] 66.16352 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 66.16355 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 66.16357 INFO juju.worker.uniter ModeAbide starting [LOG] 66.16572 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":123,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} step 1: uniter_test.addRelationUnit{} [LOG] 66.18568 DEBUG juju.state.apiserver -> [74] unit-u-0 20.240352ms {"RequestId":123,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 66.18606 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 66.18608 DEBUG juju.worker.uniter.filter no new charm event [LOG] 66.18667 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":124,"Type":"Uniter","Request":"WatchRelationUnits","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 66.18898 DEBUG juju.state.apiserver -> [74] unit-u-0 2.394727ms {"RequestId":124,"Response":{"Results":[{"RelationUnitsWatcherId":"14","Changes":{"Changed":{"mysql/0":{"Version":2}},"Departed":null},"Error":null}]}} Uniter[""].WatchRelationUnits [LOG] 66.18930 DEBUG juju.worker.uniter.filter sent relations event [LOG] 66.19013 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":125,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 66.19024 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":126,"Type":"RelationUnitsWatcher","Id":"14","Request":"Next","Params":{}} [LOG] 66.19162 DEBUG juju.state.apiserver -> [74] unit-u-0 1.471651ms {"RequestId":125,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 66.19264 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":127,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.19292 DEBUG juju.state.apiserver -> [74] unit-u-0 326.028us {"RequestId":127,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal step 2: uniter_test.waitHooks{"db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} [LOG] 66.21310 DEBUG juju.state.apiserver -> [74] unit-u-0 22.68805ms {"RequestId":126,"Response":{"RelationUnitsWatcherId":"","Changes":{"Changed":{"mysql/1":{"Version":2}},"Departed":null},"Error":null}} RelationUnitsWatcher["14"].Next [LOG] 66.21487 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":128,"Type":"RelationUnitsWatcher","Id":"14","Request":"Next","Params":{}} [LOG] 66.21510 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":129,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 66.22084 DEBUG juju.state.apiserver -> [74] unit-u-0 5.753289ms {"RequestId":129,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 66.22133 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":130,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 66.22181 DEBUG juju.state.apiserver -> [74] unit-u-0 587.253us {"RequestId":130,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 66.22220 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":131,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.22542 DEBUG juju.state.apiserver -> [74] unit-u-0 3.034246ms {"RequestId":131,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 66.22735 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":132,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.23024 DEBUG juju.state.apiserver -> [74] unit-u-0 2.89556ms {"RequestId":132,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 66.23545 INFO juju.worker.uniter running "db-relation-joined" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} [LOG] 66.38900 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-joined mysql/1 [LOG] 66.39942 INFO juju.worker.uniter ran "db-relation-joined" hook [LOG] 66.39967 INFO juju.worker.uniter committing "relation-joined" hook [LOG] 66.45245 INFO juju.worker.uniter committed "relation-joined" hook [LOG] 66.45638 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":133,"Type":"Uniter","Request":"APIAddresses","Params":{}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0"} [LOG] 66.46308 DEBUG juju.state.apiserver -> [74] unit-u-0 6.659077ms {"RequestId":133,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 66.46423 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":134,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 66.46542 DEBUG juju.state.apiserver -> [74] unit-u-0 1.250015ms {"RequestId":134,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 66.46639 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":135,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.46790 DEBUG juju.state.apiserver -> [74] unit-u-0 1.459043ms {"RequestId":135,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 66.46860 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":136,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.47026 DEBUG juju.state.apiserver -> [74] unit-u-0 1.60426ms {"RequestId":136,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 66.47586 INFO juju.worker.uniter running "db-relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0"} [LOG] 66.61697 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-changed mysql/1 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0"} [LOG] 66.62773 INFO juju.worker.uniter ran "db-relation-changed" hook [LOG] 66.62812 INFO juju.worker.uniter committing "relation-changed" hook [LOG] 66.67942 INFO juju.worker.uniter committed "relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} step 3: uniter_test.changeRelationUnit{name:"mysql/0"} step 4: uniter_test.waitHooks{"db-relation-changed mysql/0 db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} [LOG] 66.69849 DEBUG juju.state.apiserver -> [74] unit-u-0 483.513236ms {"RequestId":128,"Response":{"RelationUnitsWatcherId":"","Changes":{"Changed":{"mysql/0":{"Version":3}},"Departed":null},"Error":null}} RelationUnitsWatcher["14"].Next [LOG] 66.70289 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":137,"Type":"RelationUnitsWatcher","Id":"14","Request":"Next","Params":{}} [LOG] 66.70319 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":138,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 66.70716 DEBUG juju.state.apiserver -> [74] unit-u-0 4.015352ms {"RequestId":138,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 66.70832 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":139,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 66.70953 DEBUG juju.state.apiserver -> [74] unit-u-0 1.269608ms {"RequestId":139,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 66.71038 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":140,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.71190 DEBUG juju.state.apiserver -> [74] unit-u-0 1.466507ms {"RequestId":140,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 66.71218 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":141,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.71266 DEBUG juju.state.apiserver -> [74] unit-u-0 485.236us {"RequestId":141,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 66.71561 INFO juju.worker.uniter running "db-relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} [LOG] 66.86221 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-changed mysql/0 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0"} [LOG] 66.87514 INFO juju.worker.uniter ran "db-relation-changed" hook [LOG] 66.87527 INFO juju.worker.uniter committing "relation-changed" hook [LOG] 66.92205 INFO juju.worker.uniter committed "relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} step 5: uniter_test.removeRelationUnit{name:"mysql/1"} step 6: uniter_test.waitHooks{"db-relation-departed mysql/1 db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 66.94180 DEBUG juju.state.apiserver -> [74] unit-u-0 238.972568ms {"RequestId":137,"Response":{"RelationUnitsWatcherId":"","Changes":{"Changed":null,"Departed":["mysql/1"]},"Error":null}} RelationUnitsWatcher["14"].Next [LOG] 66.94643 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":142,"Type":"RelationUnitsWatcher","Id":"14","Request":"Next","Params":{}} [LOG] 66.94671 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":143,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 66.95095 DEBUG juju.state.apiserver -> [74] unit-u-0 4.235646ms {"RequestId":143,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 66.95171 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":144,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 66.95405 DEBUG juju.state.apiserver -> [74] unit-u-0 2.379262ms {"RequestId":144,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 66.95482 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":145,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.95669 DEBUG juju.state.apiserver -> [74] unit-u-0 1.85146ms {"RequestId":145,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 66.95754 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":146,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 66.95906 DEBUG juju.state.apiserver -> [74] unit-u-0 1.526146ms {"RequestId":146,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 66.96284 INFO juju.worker.uniter running "db-relation-departed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 67.11652 INFO juju u/0 db:0: d095899a-fe28-4a40-8d87-8a911a28c4f8 db-relation-departed mysql/1 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 67.12803 INFO juju.worker.uniter ran "db-relation-departed" hook [LOG] 67.12816 INFO juju.worker.uniter committing "relation-departed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} step 7: uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} [LOG] 67.19529 INFO juju.worker.uniter committed "relation-departed" hook [LOG] 67.20202 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":147,"Type":"RelationUnitsWatcher","Id":"14","Request":"Stop","Params":{}} [LOG] 67.20595 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":142,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} RelationUnitsWatcher["14"].Next [LOG] 67.20662 DEBUG juju.state.apiserver -> [74] unit-u-0 4.480565ms {"RequestId":147,"Response":{}} RelationUnitsWatcher["14"].Stop [LOG] 67.20818 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 67.20843 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 67.20925 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":148,"Type":"StringsWatcher","Id":"12","Request":"Stop","Params":{}} [LOG] 67.20967 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":107,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["12"].Next [LOG] 67.20991 DEBUG juju.state.apiserver -> [74] unit-u-0 878.519us {"RequestId":148,"Response":{}} StringsWatcher["12"].Stop [LOG] 67.21103 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":149,"Type":"NotifyWatcher","Id":"11","Request":"Stop","Params":{}} [LOG] 67.21162 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":104,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["11"].Next [LOG] 67.21188 DEBUG juju.state.apiserver -> [74] unit-u-0 800.383us {"RequestId":149,"Response":{}} NotifyWatcher["11"].Stop [LOG] 67.21282 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":150,"Type":"NotifyWatcher","Id":"10","Request":"Stop","Params":{}} [LOG] 67.21343 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":100,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["10"].Next [LOG] 67.21362 DEBUG juju.state.apiserver -> [74] unit-u-0 866.213us {"RequestId":150,"Response":{}} NotifyWatcher["10"].Stop [LOG] 67.21469 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":151,"Type":"NotifyWatcher","Id":"9","Request":"Stop","Params":{}} [LOG] 67.21504 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":120,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["9"].Next [LOG] 67.21521 DEBUG juju.state.apiserver -> [74] unit-u-0 540.547us {"RequestId":151,"Response":{}} NotifyWatcher["9"].Stop [LOG] 67.21578 ERROR juju.worker.uniter.filter tomb: dying [LOG] 67.21617 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 67.21619 DEBUG juju.worker.uniter juju-run listener stopped uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{"config-changed"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} [LOG] 67.21716 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":152,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.21959 DEBUG juju.state.apiserver -> [74] unit-u-0 2.264762ms {"RequestId":152,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.22126 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":153,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.22306 DEBUG juju.state.apiserver -> [74] unit-u-0 1.888249ms {"RequestId":153,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.22369 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":154,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 67.22483 DEBUG juju.state.apiserver -> [74] unit-u-0 1.213651ms {"RequestId":154,"Response":{"Error":null,"Result":"d095899a-fe28-4a40-8d87-8a911a28c4f8"}} Uniter[""].CurrentEnvironUUID [LOG] 67.22532 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 67.22568 INFO juju.worker.uniter unit "u/0" started [LOG] 67.22570 INFO juju.worker.uniter ModeInit starting [LOG] 67.22571 INFO juju.worker.uniter updating unit addresses [LOG] 67.22578 DEBUG juju.worker.uniter juju-run listener running [LOG] 67.22680 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":155,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 67.22717 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":156,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.22929 DEBUG juju.state.apiserver -> [74] unit-u-0 2.639625ms {"RequestId":155,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 67.22955 DEBUG juju.state.apiserver -> [74] unit-u-0 2.474464ms {"RequestId":156,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.23021 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":157,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 67.23034 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":158,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.23151 DEBUG juju.state.apiserver -> [74] unit-u-0 1.116995ms {"RequestId":158,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.23215 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":159,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.23305 DEBUG juju.state.apiserver -> [74] unit-u-0 836.431us {"RequestId":159,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 67.23410 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":160,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.23578 DEBUG juju.state.apiserver -> [74] unit-u-0 1.757483ms {"RequestId":160,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.23700 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":161,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.23954 DEBUG juju.state.apiserver -> [74] unit-u-0 2.517094ms {"RequestId":161,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.24101 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":162,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.24138 DEBUG juju.state.apiserver -> [74] unit-u-0 11.217688ms {"RequestId":157,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 67.24191 DEBUG juju.state.apiserver -> [74] unit-u-0 920.099us {"RequestId":162,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 67.24234 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 67.24259 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":163,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 67.24282 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":164,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.24651 DEBUG juju.state.apiserver -> [74] unit-u-0 3.547404ms {"RequestId":164,"Response":{"Results":[{"NotifyWatcherId":"15","Error":null}]}} Uniter[""].Watch [LOG] 67.25146 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":165,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.25194 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":166,"Type":"NotifyWatcher","Id":"15","Request":"Next","Params":{}} [LOG] 67.25365 DEBUG juju.state.apiserver -> [74] unit-u-0 2.38419ms {"RequestId":165,"Response":{"Results":[{"NotifyWatcherId":"16","Error":null}]}} Uniter[""].Watch [LOG] 67.25427 DEBUG juju.state.apiserver -> [74] unit-u-0 11.816987ms {"RequestId":163,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 67.25444 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":167,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.25449 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":168,"Type":"NotifyWatcher","Id":"16","Request":"Next","Params":{}} [LOG] 67.25484 DEBUG juju.state.apiserver -> [74] unit-u-0 400.653us {"RequestId":167,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} Uniter[""].CharmURL [LOG] 67.25501 INFO juju.worker.uniter reconciling relation state [LOG] 67.25567 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":169,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 67.25573 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":170,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.25660 DEBUG juju.state.apiserver -> [74] unit-u-0 831.742us {"RequestId":169,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].RelationById [LOG] 67.25711 DEBUG juju.state.apiserver -> [74] unit-u-0 1.357091ms {"RequestId":170,"Response":{"Results":[{"NotifyWatcherId":"17","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 67.25758 INFO juju.worker.uniter joining relation "u:db mysql:server" [LOG] 67.25798 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":171,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 67.25808 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":172,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.25818 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":173,"Type":"NotifyWatcher","Id":"17","Request":"Next","Params":{}} [LOG] 67.25977 DEBUG juju.state.apiserver -> [74] unit-u-0 1.835475ms {"RequestId":171,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 67.26001 DEBUG juju.state.apiserver -> [74] unit-u-0 1.925069ms {"RequestId":172,"Response":{"Results":[{"StringsWatcherId":"18","Changes":["u:db mysql:server"],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 67.26050 DEBUG juju.worker.uniter.filter got config change [LOG] 67.26054 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 67.26056 DEBUG juju.worker.uniter.filter got unit change [LOG] 67.26087 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":174,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.26099 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":175,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.26106 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":176,"Type":"StringsWatcher","Id":"18","Request":"Next","Params":{}} [LOG] 67.26186 DEBUG juju.state.apiserver -> [74] unit-u-0 868.296us {"RequestId":175,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.26227 DEBUG juju.state.apiserver -> [74] unit-u-0 1.410171ms {"RequestId":174,"Response":{"Results":[{"NotifyWatcherId":"19","Error":null}]}} Uniter[""].Watch [LOG] 67.26289 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":177,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.26313 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":178,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 67.26325 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":179,"Type":"NotifyWatcher","Id":"19","Request":"Next","Params":{}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} [LOG] 67.31088 DEBUG juju.state.apiserver -> [74] unit-u-0 47.91581ms {"RequestId":177,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 67.31299 DEBUG juju.worker.uniter.filter got relations change [LOG] 67.31319 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":180,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 67.31347 DEBUG juju.state.apiserver -> [74] unit-u-0 50.376067ms {"RequestId":178,"Response":{"Results":[{"Error":null}]}} Uniter[""].EnterScope [LOG] 67.31377 INFO juju.worker.uniter joined relation "u:db mysql:server" [LOG] 67.31394 DEBUG juju.state.apiserver -> [74] unit-u-0 775.747us {"RequestId":180,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 67.31410 DEBUG juju.worker.uniter.filter got service change [LOG] 67.31420 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":181,"Type":"NotifyWatcher","Id":"19","Request":"Stop","Params":{}} [LOG] 67.31434 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":182,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.31462 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":179,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["19"].Next [LOG] 67.31468 DEBUG juju.state.apiserver -> [74] unit-u-0 481.362us {"RequestId":181,"Response":{}} NotifyWatcher["19"].Stop [LOG] 67.31480 DEBUG juju.worker.uniter ModeInit exiting [LOG] 67.31481 INFO juju.worker.uniter ModeContinue starting [LOG] 67.31482 INFO juju.worker.uniter loading uniter state [LOG] 67.31504 INFO juju.worker.uniter continuing after "relation-departed" hook [LOG] 67.31505 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 67.31506 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 67.31517 DEBUG juju.state.apiserver -> [74] unit-u-0 843.971us {"RequestId":182,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.31536 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":183,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.31564 DEBUG juju.state.apiserver -> [74] unit-u-0 286.334us {"RequestId":183,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 67.31576 DEBUG juju.worker.uniter.filter no new charm event [LOG] 67.31578 DEBUG juju.worker.uniter.filter discarded config event [LOG] 67.31614 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":184,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 67.31720 DEBUG juju.state.apiserver -> [74] unit-u-0 1.018011ms {"RequestId":184,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 67.31741 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":185,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 67.31768 DEBUG juju.state.apiserver -> [74] unit-u-0 270.153us {"RequestId":185,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 67.31786 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":186,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.31828 DEBUG juju.state.apiserver -> [74] unit-u-0 417.31us {"RequestId":186,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 67.31849 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":187,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.31903 DEBUG juju.state.apiserver -> [74] unit-u-0 526.803us {"RequestId":187,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 67.32272 INFO juju.worker.uniter running "config-changed" hook [LOG] 67.36229 DEBUG juju.state.apiserver -> [74] unit-u-0 109.67056ms {"RequestId":166,"Response":{}} NotifyWatcher["15"].Next [LOG] 67.36406 DEBUG juju.worker.uniter.filter got unit change [LOG] 67.36504 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":188,"Type":"NotifyWatcher","Id":"15","Request":"Next","Params":{}} [LOG] 67.36531 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":189,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} [LOG] 67.37473 DEBUG juju.state.apiserver -> [74] unit-u-0 9.392585ms {"RequestId":189,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 67.37645 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":190,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.37847 DEBUG juju.state.apiserver -> [74] unit-u-0 2.019851ms {"RequestId":190,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0"} [LOG] 67.46497 INFO juju u/0: d095899a-fe28-4a40-8d87-8a911a28c4f8 config-changed [LOG] 67.47453 INFO juju.worker.uniter ran "config-changed" hook [LOG] 67.47482 INFO juju.worker.uniter committing "config-changed" hook [LOG] 67.52140 INFO juju.worker.uniter committed "config-changed" hook [LOG] 67.52179 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 67.52182 INFO juju.worker.uniter ModeContinue starting [LOG] 67.52185 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 67.52186 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 67.52187 INFO juju.worker.uniter ModeAbide starting ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-joined mysql/1 db:0", "db-relation-changed mysql/1 db:0", "db-relation-changed mysql/0 db:0", "db-relation-departed mysql/1 db:0", "config-changed"} [LOG] 67.52299 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":191,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} [LOG] 67.53510 DEBUG juju.state.apiserver -> [74] unit-u-0 12.116863ms {"RequestId":191,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 67.53618 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 67.53622 DEBUG juju.worker.uniter.filter no new charm event [LOG] 67.53652 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":192,"Type":"Uniter","Request":"WatchRelationUnits","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 67.54020 DEBUG juju.state.apiserver -> [74] unit-u-0 3.691954ms {"RequestId":192,"Response":{"Results":[{"RelationUnitsWatcherId":"20","Changes":{"Changed":{"mysql/0":{"Version":3}},"Departed":null},"Error":null}]}} Uniter[""].WatchRelationUnits [LOG] 67.54052 DEBUG juju.worker.uniter.filter sent relations event [LOG] 67.54073 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":193,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 67.54081 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":194,"Type":"RelationUnitsWatcher","Id":"20","Request":"Next","Params":{}} [LOG] 67.54165 DEBUG juju.state.apiserver -> [74] unit-u-0 891.855us {"RequestId":193,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 67.54198 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":195,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 67.54230 DEBUG juju.state.apiserver -> [74] unit-u-0 333.756us {"RequestId":195,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal [LOG] 67.54261 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":196,"Type":"RelationUnitsWatcher","Id":"20","Request":"Stop","Params":{}} [LOG] 67.54270 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":194,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} RelationUnitsWatcher["20"].Next [LOG] 67.54281 DEBUG juju.state.apiserver -> [74] unit-u-0 176.745us {"RequestId":196,"Response":{}} RelationUnitsWatcher["20"].Stop [LOG] 67.54301 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 67.54303 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 67.54317 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":197,"Type":"StringsWatcher","Id":"18","Request":"Stop","Params":{}} [LOG] 67.54329 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":176,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["18"].Next [LOG] 67.54336 DEBUG juju.state.apiserver -> [74] unit-u-0 185.172us {"RequestId":197,"Response":{}} StringsWatcher["18"].Stop [LOG] 67.54371 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":198,"Type":"NotifyWatcher","Id":"17","Request":"Stop","Params":{}} [LOG] 67.54386 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":173,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["17"].Next [LOG] 67.54394 DEBUG juju.state.apiserver -> [74] unit-u-0 249.866us {"RequestId":198,"Response":{}} NotifyWatcher["17"].Stop [LOG] 67.54427 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":199,"Type":"NotifyWatcher","Id":"16","Request":"Stop","Params":{}} [LOG] 67.54438 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":168,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["16"].Next [LOG] 67.54444 DEBUG juju.state.apiserver -> [74] unit-u-0 179.58us {"RequestId":199,"Response":{}} NotifyWatcher["16"].Stop [LOG] 67.54473 DEBUG juju.state.apiserver <- [74] unit-u-0 {"RequestId":200,"Type":"NotifyWatcher","Id":"15","Request":"Stop","Params":{}} [LOG] 67.54484 DEBUG juju.state.apiserver -> [74] unit-u-0 0 {"RequestId":188,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["15"].Next [LOG] 67.54491 DEBUG juju.state.apiserver -> [74] unit-u-0 185.741us {"RequestId":200,"Response":{}} NotifyWatcher["15"].Stop [LOG] 67.54527 ERROR juju.worker.uniter.filter tomb: dying [LOG] 67.54545 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 67.54546 DEBUG juju.worker.uniter juju-run listener stopped [LOG] 67.54690 INFO juju.provider.dummy reset environment [LOG] 67.56915 INFO juju Reset successfully reset admin password [LOG] 67.58157 INFO juju Reset successfully reset admin password [LOG] 67.61784 DEBUG juju.environs.configstore Making /tmp/gocheck-3328451335138149956/120/home/ubuntu/.juju/environments [LOG] 67.71484 DEBUG juju.environs.tools reading v1.* tools [LOG] 67.71492 INFO juju environs/testing: uploading FAKE tools 1.17.1-precise-amd64 [LOG] 67.74110 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 67.74112 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 67.74120 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 67.74132 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 67.74136 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 67.74138 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 67.74170 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 67.74172 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 67.74188 INFO juju.environs.bootstrap bootstrapping environment "dummyenv" [LOG] 67.74191 DEBUG juju.environs.bootstrap looking for bootstrap tools: series="precise", arch=, version=1.17.1 [LOG] 67.74192 INFO juju.environs.tools reading tools with major.minor version 1.17 [LOG] 67.74193 INFO juju.environs.tools filtering tools by version: 1.17.1 [LOG] 67.74194 INFO juju.environs.tools filtering tools by series: precise [LOG] 67.74196 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 67.74201 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 67.74203 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 67.74212 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/mirrors.json": file "tools/streams/v1/mirrors.json" not found not found [LOG] 67.74214 DEBUG juju.environs.simplestreams no mirror index file found [LOG] 67.74217 DEBUG juju.environs.simplestreams no mirror information available for { }: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 67.74218 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:37094/dummyenv/private/tools/streams/v1/index.json" [LOG] 67.74228 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 [{Sun, 12 Jan 2014 21:39:48 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 67.74230 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 67.74254 DEBUG juju.environs.simplestreams metadata: &{map[com.ubuntu.juju:12.04:amd64:{ 1.17.1 amd64 map[20140112:0xc201aa0480]}] map[] Sun, 12 Jan 2014 21:39:48 +0000 products:1.0 com.ubuntu.juju:released:tools} [LOG] 67.74260 INFO juju.environs.bootstrap picked newest version: 1.17.1 [LOG] 67.74263 INFO juju.provider.dummy would pick tools from 1.17.1-precise-amd64 [LOG] 67.74319 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 67.75131 INFO juju.state connection established [LOG] 67.79313 INFO juju.state initializing environment [LOG] 67.81492 INFO juju.state.apiserver listening on "127.0.0.1:33042" [LOG] 67.83385 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 67.85855 INFO juju.state connection established [LOG] 67.86049 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 67.86064 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 67.86927 INFO juju.state connection established [LOG] 67.93954 INFO juju state/api: dialing "wss://127.0.0.1:33042/" [LOG] 67.94901 INFO juju state/api: connection established [LOG] 67.94950 DEBUG juju.state.apiserver <- [75] {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 67.95062 DEBUG juju.state.apiserver -> [75] user-admin 1.130938ms {"RequestId":1,"Response":{}} Admin[""].Login test 1: relation becomes dying; unit is not last remaining member step 0: uniter_test.quickStartRelation{} 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)(0xc200bf6150), curl:(*charm.URL)(0xc200ad1aa0)} uniter_test.serveCharm{} uniter_test.createUniter{} uniter_test.ensureStateWorker{} uniter_test.createServiceAndUnit{serviceName:""} [LOG] 68.14056 INFO juju state/api: dialing "wss://127.0.0.1:33042/" [LOG] 68.14516 INFO juju state/api: connection established [LOG] 68.14587 DEBUG juju.state.apiserver <- [76] {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"unit-u-0","Password":"1ijssxQszszuVHQfai4Ug5xm","Nonce":""}} [LOG] 68.16665 DEBUG juju.state.apiserver -> [76] unit-u-0 20.775525ms {"RequestId":1,"Response":{}} Admin[""].Login API: login as "unit-u-0" successful uniter_test.startUniter{unitTag:""} uniter_test.waitAddresses{} [LOG] 68.16870 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":3,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.17069 DEBUG juju.state.apiserver -> [76] unit-u-0 2.024683ms {"RequestId":3,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.17249 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":4,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.17354 DEBUG juju.state.apiserver -> [76] unit-u-0 1.187191ms {"RequestId":4,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.17421 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":5,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 68.17498 DEBUG juju.state.apiserver -> [76] unit-u-0 747.871us {"RequestId":5,"Response":{"Error":null,"Result":"9cca642c-8a3d-4647-83fd-c97f75fb3b9d"}} Uniter[""].CurrentEnvironUUID [LOG] 68.17525 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 68.17652 INFO juju.worker.uniter unit "u/0" started [LOG] 68.17705 INFO juju.worker.uniter ModeInit starting [LOG] 68.17714 INFO juju.worker.uniter updating unit addresses [LOG] 68.17724 DEBUG juju.worker.uniter juju-run listener running [LOG] 68.17753 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":6,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 68.17781 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":7,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.17921 DEBUG juju.state.apiserver -> [76] unit-u-0 1.680578ms {"RequestId":6,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 68.17933 DEBUG juju.state.apiserver -> [76] unit-u-0 1.52852ms {"RequestId":7,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.17977 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":8,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 68.17989 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":9,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.18070 DEBUG juju.state.apiserver -> [76] unit-u-0 840.312us {"RequestId":9,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.18183 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":10,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.18375 DEBUG juju.state.apiserver -> [76] unit-u-0 1.968975ms {"RequestId":10,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 68.18491 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":11,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.18675 DEBUG juju.state.apiserver -> [76] unit-u-0 1.858297ms {"RequestId":11,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.18871 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":12,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.19046 DEBUG juju.state.apiserver -> [76] unit-u-0 1.667033ms {"RequestId":12,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.19120 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":13,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.19276 DEBUG juju.state.apiserver -> [76] unit-u-0 1.565788ms {"RequestId":13,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 68.19330 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 68.19405 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":14,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.19546 DEBUG juju.state.apiserver -> [76] unit-u-0 15.793079ms {"RequestId":8,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 68.19695 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":15,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 68.19875 DEBUG juju.state.apiserver -> [76] unit-u-0 4.765297ms {"RequestId":14,"Response":{"Results":[{"NotifyWatcherId":"2","Error":null}]}} Uniter[""].Watch [LOG] 68.20031 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":16,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.20058 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":17,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 68.20324 DEBUG juju.state.apiserver -> [76] unit-u-0 2.83876ms {"RequestId":16,"Response":{"Results":[{"NotifyWatcherId":"3","Error":null}]}} Uniter[""].Watch [LOG] 68.20562 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":18,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.20636 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":19,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 68.20893 DEBUG juju.state.apiserver -> [76] unit-u-0 3.279395ms {"RequestId":18,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].CharmURL [LOG] 68.21019 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":20,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.21146 DEBUG juju.state.apiserver -> [76] unit-u-0 14.686515ms {"RequestId":15,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 68.21180 INFO juju.worker.uniter reconciling relation state [LOG] 68.21207 DEBUG juju.worker.uniter ModeInit exiting [LOG] 68.21208 INFO juju.worker.uniter ModeContinue starting [LOG] 68.21209 INFO juju.worker.uniter loading uniter state [LOG] 68.21211 INFO juju.worker.uniter charm is not deployed [LOG] 68.21225 DEBUG juju.state.apiserver -> [76] unit-u-0 2.145251ms {"RequestId":20,"Response":{"Results":[{"StringsWatcherId":"4","Changes":[],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 68.21239 DEBUG juju.worker.uniter.filter got service change [LOG] 68.21259 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":21,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.21268 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":22,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.21277 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":23,"Type":"StringsWatcher","Id":"4","Request":"Next","Params":{}} [LOG] 68.21353 DEBUG juju.state.apiserver -> [76] unit-u-0 937.43us {"RequestId":21,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 68.21368 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 68.21369 INFO juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 starting [LOG] 68.21370 INFO juju.worker.uniter fetching charm "cs:quantal/wordpress-0" [LOG] 68.21395 DEBUG juju.state.apiserver -> [76] unit-u-0 1.274472ms {"RequestId":22,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.21418 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":24,"Type":"Uniter","Request":"CharmArchiveURL","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 68.21423 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":25,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.21547 DEBUG juju.state.apiserver -> [76] unit-u-0 1.223088ms {"RequestId":25,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 68.21560 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 68.21562 DEBUG juju.worker.uniter.filter got unit change [LOG] 68.21573 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":26,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.21618 DEBUG juju.state.apiserver -> [76] unit-u-0 2.004739ms {"RequestId":24,"Response":{"Results":[{"Error":null,"Result":"http://localhost:43284/charms/wordpress/0","DisableSSLHostnameVerification":false}]}} Uniter[""].CharmArchiveURL [LOG] 68.21643 INFO juju worker/uniter/charm: downloading cs:quantal/wordpress-0 from http://localhost:43284/charms/wordpress/0 [LOG] 68.21695 DEBUG juju.state.apiserver -> [76] unit-u-0 1.213827ms {"RequestId":26,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.21754 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":27,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.21787 INFO juju worker/uniter/charm: download complete [LOG] 68.21813 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":28,"Type":"Uniter","Request":"CharmArchiveSha256","Params":{"URLs":[{"URL":"cs:quantal/wordpress-0"}]}} [LOG] 68.21846 DEBUG juju.state.apiserver -> [76] unit-u-0 922.793us {"RequestId":27,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 68.21861 DEBUG juju.worker.uniter.filter got relations change [LOG] 68.21894 DEBUG juju.state.apiserver -> [76] unit-u-0 823.073us {"RequestId":28,"Response":{"Results":[{"Error":null,"Result":"2665e274b4be042bec1c983e3efeefef273d149a891ecb4387d3fbbd7bd5f75e"}]}} Uniter[""].CharmArchiveSha256 [LOG] 68.21905 INFO juju worker/uniter/charm: download verified [LOG] 68.30880 DEBUG juju.worker.uniter.filter changing charm to "cs:quantal/wordpress-0" [LOG] 68.31119 DEBUG juju.state.apiserver <- [76] unit-u-0 {"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] 68.33420 DEBUG juju.state.apiserver -> [76] unit-u-0 23.317046ms {"RequestId":29,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetCharmURL [LOG] 68.33578 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":30,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.33599 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":31,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.33719 DEBUG juju.state.apiserver -> [76] unit-u-0 136.65017ms {"RequestId":17,"Response":{}} NotifyWatcher["2"].Next [LOG] 68.33755 DEBUG juju.state.apiserver -> [76] unit-u-0 1.548591ms {"RequestId":31,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.33791 INFO juju.worker.uniter deploying charm "cs:quantal/wordpress-0" [LOG] 68.33868 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":32,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 68.33888 DEBUG juju.state.apiserver -> [76] unit-u-0 3.173383ms {"RequestId":30,"Response":{"Results":[{"NotifyWatcherId":"5","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 68.33962 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":33,"Type":"StringsWatcher","Id":"4","Request":"Stop","Params":{}} [LOG] 68.33978 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":34,"Type":"NotifyWatcher","Id":"5","Request":"Next","Params":{}} [LOG] 68.34030 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":23,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["4"].Next [LOG] 68.34048 DEBUG juju.state.apiserver -> [76] unit-u-0 846.855us {"RequestId":33,"Response":{}} StringsWatcher["4"].Stop [LOG] 68.34139 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":35,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.34230 INFO juju worker/uniter/charm: preparing new charm deployment [LOG] 68.35150 DEBUG juju.state.apiserver -> [76] unit-u-0 9.069794ms {"RequestId":35,"Response":{"Results":[{"StringsWatcherId":"6","Changes":[],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 68.35473 DEBUG juju.worker.uniter.filter no new charm event [LOG] 68.35502 DEBUG juju.worker.uniter.filter got config change [LOG] 68.35519 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 68.35539 DEBUG juju.worker.uniter.filter got unit change [LOG] 68.35767 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":36,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.35812 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":37,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 68.35914 DEBUG juju.state.apiserver -> [76] unit-u-0 1.736252ms {"RequestId":36,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.35951 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":38,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.35979 DEBUG juju.state.apiserver -> [76] unit-u-0 281.213us {"RequestId":38,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 68.35995 DEBUG juju.worker.uniter.filter got relations change want unit status "started", got "pending"; still waiting [LOG] 68.40231 DEBUG juju.state.apiserver -> [76] unit-u-0 63.49669ms {"RequestId":32,"Response":{}} NotifyWatcher["2"].Next [LOG] 68.40312 DEBUG juju.worker.uniter.filter got unit change [LOG] 68.40340 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":39,"Type":"NotifyWatcher","Id":"2","Request":"Next","Params":{}} [LOG] 68.40351 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":40,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.40661 DEBUG juju.state.apiserver -> [76] unit-u-0 2.972874ms {"RequestId":40,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 68.40774 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":41,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.40936 DEBUG juju.state.apiserver -> [76] unit-u-0 1.543077ms {"RequestId":41,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 68.56281 INFO juju worker/uniter/charm: deploying charm [LOG] 68.56329 INFO juju worker/uniter/charm: charm deployment succeeded [LOG] 68.56753 INFO juju.worker.uniter charm "cs:quantal/wordpress-0" is deployed [LOG] 68.57045 DEBUG juju.worker.uniter ModeInstalling cs:quantal/wordpress-0 exiting [LOG] 68.57050 INFO juju.worker.uniter ModeContinue starting [LOG] 68.57052 INFO juju.worker.uniter found queued "install" hook [LOG] 68.57156 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":42,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 68.57800 DEBUG juju.state.apiserver -> [76] unit-u-0 6.283523ms {"RequestId":42,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 68.58041 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":43,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.58253 DEBUG juju.state.apiserver -> [76] unit-u-0 2.143874ms {"RequestId":43,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 68.58430 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":44,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.58668 DEBUG juju.state.apiserver -> [76] unit-u-0 2.527587ms {"RequestId":44,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 68.58736 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":45,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.59021 DEBUG juju.state.apiserver -> [76] unit-u-0 2.51825ms {"RequestId":45,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 68.59591 INFO juju.worker.uniter running "install" hook want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting want unit status "started", got "pending"; still waiting [LOG] 68.75050 INFO juju u/0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d install [LOG] 68.76073 INFO juju.worker.uniter ran "install" hook [LOG] 68.76085 INFO juju.worker.uniter committing "install" hook [LOG] 68.80588 INFO juju.worker.uniter committed "install" hook [LOG] 68.80634 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 68.80636 INFO juju.worker.uniter ModeContinue starting [LOG] 68.80638 INFO juju.worker.uniter continuing after "install" hook [LOG] 68.80639 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 68.80639 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 68.80750 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":46,"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] 68.82028 DEBUG juju.state.apiserver -> [76] unit-u-0 12.803441ms {"RequestId":46,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 68.82185 DEBUG juju.worker.uniter.filter discarded config event [LOG] 68.82198 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":47,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 68.82635 DEBUG juju.state.apiserver -> [76] unit-u-0 4.305561ms {"RequestId":47,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 68.82729 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":48,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 68.82869 DEBUG juju.state.apiserver -> [76] unit-u-0 1.440548ms {"RequestId":48,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 68.83022 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":49,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.83327 DEBUG juju.state.apiserver -> [76] unit-u-0 2.823751ms {"RequestId":49,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 68.83459 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":50,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 68.83616 DEBUG juju.state.apiserver -> [76] unit-u-0 1.742137ms {"RequestId":50,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 68.84038 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] 68.97705 INFO juju u/0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d config-changed [LOG] 68.98571 INFO juju.worker.uniter ran "config-changed" hook [LOG] 68.98591 INFO juju.worker.uniter committing "config-changed" hook want unit status "started", got "installed"; still waiting [LOG] 69.03548 INFO juju.worker.uniter committed "config-changed" hook [LOG] 69.03635 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 69.03643 INFO juju.worker.uniter ModeContinue starting [LOG] 69.03645 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 69.03646 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 69.03647 INFO juju.worker.uniter ModeStarting starting [LOG] 69.03789 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":51,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 69.04208 DEBUG juju.state.apiserver -> [76] unit-u-0 4.18942ms {"RequestId":51,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 69.04441 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":52,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 69.04513 DEBUG juju.state.apiserver -> [76] unit-u-0 1.122764ms {"RequestId":52,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 69.04583 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":53,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.04669 DEBUG juju.state.apiserver -> [76] unit-u-0 867.841us {"RequestId":53,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 69.04709 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":54,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.04866 DEBUG juju.state.apiserver -> [76] unit-u-0 924.204us {"RequestId":54,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress want unit status "started", got "installed"; still waiting [LOG] 69.07428 INFO juju.worker.uniter running "start" hook want unit status "started", got "installed"; still waiting want unit status "started", got "installed"; still waiting [LOG] 69.23147 INFO juju u/0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d start want unit status "started", got "installed"; still waiting [LOG] 69.25375 INFO juju.worker.uniter ran "start" hook [LOG] 69.25409 INFO juju.worker.uniter committing "start" hook [LOG] 69.29788 INFO juju.worker.uniter committed "start" hook [LOG] 69.29915 DEBUG juju.worker.uniter ModeStarting exiting [LOG] 69.29922 INFO juju.worker.uniter ModeContinue starting [LOG] 69.29926 INFO juju.worker.uniter continuing after "start" hook [LOG] 69.29928 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 69.29931 INFO juju.worker.uniter ModeAbide starting [LOG] 69.30198 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":55,"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] 69.32265 DEBUG juju.state.apiserver -> [76] unit-u-0 20.827036ms {"RequestId":55,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 69.32346 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 69.32351 DEBUG juju.worker.uniter.filter no new charm event uniter_test.waitHooks{"install", "config-changed", "start"} waiting for hooks: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} uniter_test.verifyCharm{revision:0, dirty:false} uniter_test.waitHooks{} waiting for hooks: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} uniter_test.addRelation{JujuConnSuite:testing.JujuConnSuite{LoggingSuite:testbase.LoggingSuite{CleanupSuite:testbase.CleanupSuite{testStack:testbase.cleanupStack(nil), suiteStack:testbase.cleanupStack(nil)}}, MgoSuite:testing.MgoSuite{Session:(*mgo.Session)(nil)}, ToolsFixture:testing.ToolsFixture{origDefaultURL:"", origDefaultSyncLocation:"", DefaultBaseURL:""}, Conn:(*juju.Conn)(nil), State:(*state.State)(nil), APIConn:(*juju.APIConn)(nil), APIState:(*api.State)(nil), ConfigStore:configstore.Storage(nil), BackingState:(*state.State)(nil), RootDir:"", oldHome:"", oldJujuHome:"", environ:environs.Environ(nil)}} [LOG] 69.50247 INFO juju writing charm to storage [438 bytes] [LOG] 69.50272 INFO juju adding charm to state uniter_test.addRelationUnit{} uniter_test.waitHooks{"db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 69.57225 DEBUG juju.state.apiserver -> [76] unit-u-0 1.365882421s {"RequestId":19,"Response":{}} NotifyWatcher["3"].Next [LOG] 69.57362 DEBUG juju.worker.uniter.filter got service change [LOG] 69.57425 DEBUG juju.state.apiserver -> [76] unit-u-0 1.216123884s {"RequestId":37,"Response":{"StringsWatcherId":"","Changes":["u:db mysql:server"],"Error":null}} StringsWatcher["6"].Next [LOG] 69.57446 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":56,"Type":"NotifyWatcher","Id":"3","Request":"Next","Params":{}} [LOG] 69.57454 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":57,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 69.57488 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":58,"Type":"StringsWatcher","Id":"6","Request":"Next","Params":{}} [LOG] 69.57515 DEBUG juju.state.apiserver -> [76] unit-u-0 616.888us {"RequestId":57,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 69.57538 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":59,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 69.57566 DEBUG juju.state.apiserver -> [76] unit-u-0 275.273us {"RequestId":59,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 69.57578 DEBUG juju.worker.uniter.filter no new charm event [LOG] 69.57580 DEBUG juju.worker.uniter.filter got relations change [LOG] 69.57618 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":60,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 69.57715 DEBUG juju.state.apiserver -> [76] unit-u-0 944.927us {"RequestId":60,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 69.57759 DEBUG juju.worker.uniter.filter sent relations event [LOG] 69.57792 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":61,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 69.57861 DEBUG juju.state.apiserver -> [76] unit-u-0 661.199us {"RequestId":61,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].RelationById [LOG] 69.58043 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":62,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 69.58215 DEBUG juju.state.apiserver -> [76] unit-u-0 1.484977ms {"RequestId":62,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 69.58281 INFO juju.worker.uniter joining relation "u:db mysql:server" [LOG] 69.58318 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":63,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 69.58528 DEBUG juju.state.apiserver -> [76] unit-u-0 2.001558ms {"RequestId":63,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 69.58623 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":64,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.58780 DEBUG juju.state.apiserver -> [76] unit-u-0 1.570439ms {"RequestId":64,"Response":{"Results":[{"NotifyWatcherId":"7","Error":null}]}} Uniter[""].Watch [LOG] 69.58927 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":65,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 69.58955 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":66,"Type":"NotifyWatcher","Id":"7","Request":"Next","Params":{}} [LOG] 69.60724 DEBUG juju.state.apiserver -> [76] unit-u-0 18.096344ms {"RequestId":65,"Response":{"Results":[{"Error":null}]}} Uniter[""].EnterScope [LOG] 69.60742 INFO juju.worker.uniter joined relation "u:db mysql:server" [LOG] 69.60754 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":67,"Type":"NotifyWatcher","Id":"7","Request":"Stop","Params":{}} [LOG] 69.60762 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":66,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["7"].Next [LOG] 69.60767 DEBUG juju.state.apiserver -> [76] unit-u-0 141.545us {"RequestId":67,"Response":{}} NotifyWatcher["7"].Stop [LOG] 69.60803 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":68,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.60835 DEBUG juju.state.apiserver -> [76] unit-u-0 324.307us {"RequestId":68,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal [LOG] 69.60856 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":69,"Type":"Uniter","Request":"WatchRelationUnits","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 69.60970 DEBUG juju.state.apiserver -> [76] unit-u-0 1.121384ms {"RequestId":69,"Response":{"Results":[{"RelationUnitsWatcherId":"8","Changes":{"Changed":{"mysql/0":{"Version":2}},"Departed":null},"Error":null}]}} Uniter[""].WatchRelationUnits [LOG] 69.61040 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":70,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 69.61053 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":71,"Type":"RelationUnitsWatcher","Id":"8","Request":"Next","Params":{}} [LOG] 69.61166 DEBUG juju.state.apiserver -> [76] unit-u-0 1.253427ms {"RequestId":70,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 69.61189 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":72,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 69.61217 DEBUG juju.state.apiserver -> [76] unit-u-0 282.713us {"RequestId":72,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 69.61239 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":73,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.61283 DEBUG juju.state.apiserver -> [76] unit-u-0 433.091us {"RequestId":73,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 69.61306 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":74,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 69.61375 DEBUG juju.state.apiserver -> [76] unit-u-0 681.613us {"RequestId":74,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 69.61666 INFO juju.worker.uniter running "db-relation-joined" hook ctx.hooksCompleted: []string{"install", "config-changed", "start"} ctx.hooksCompleted: []string{"install", "config-changed", "start"} [LOG] 69.75596 INFO juju u/0 db:0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d db-relation-joined mysql/0 [LOG] 69.76574 INFO juju.worker.uniter ran "db-relation-joined" hook [LOG] 69.76603 INFO juju.worker.uniter committing "relation-joined" hook [LOG] 69.82262 INFO juju.worker.uniter committed "relation-joined" hook [LOG] 69.82667 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":75,"Type":"Uniter","Request":"APIAddresses","Params":{}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 69.83263 DEBUG juju.state.apiserver -> [76] unit-u-0 6.08238ms {"RequestId":75,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 69.83521 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":76,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 69.83646 DEBUG juju.state.apiserver -> [76] unit-u-0 1.270445ms {"RequestId":76,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 69.83777 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":77,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.83946 DEBUG juju.state.apiserver -> [76] unit-u-0 1.634676ms {"RequestId":77,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 69.84033 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":78,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 69.84201 DEBUG juju.state.apiserver -> [76] unit-u-0 1.630116ms {"RequestId":78,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 69.84715 INFO juju.worker.uniter running "db-relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 69.98566 INFO juju u/0 db:0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d db-relation-changed mysql/0 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0"} [LOG] 70.00913 INFO juju.worker.uniter ran "db-relation-changed" hook [LOG] 70.00941 INFO juju.worker.uniter committing "relation-changed" hook [LOG] 70.05246 INFO juju.worker.uniter committed "relation-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} [LOG] 70.05586 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":79,"Type":"RelationUnitsWatcher","Id":"8","Request":"Stop","Params":{}} [LOG] 70.05668 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":71,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} RelationUnitsWatcher["8"].Next [LOG] 70.05704 DEBUG juju.state.apiserver -> [76] unit-u-0 1.331252ms {"RequestId":79,"Response":{}} RelationUnitsWatcher["8"].Stop [LOG] 70.05824 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 70.05880 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 70.05945 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":80,"Type":"StringsWatcher","Id":"6","Request":"Stop","Params":{}} [LOG] 70.06008 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":58,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["6"].Next [LOG] 70.06021 DEBUG juju.state.apiserver -> [76] unit-u-0 768.998us {"RequestId":80,"Response":{}} StringsWatcher["6"].Stop [LOG] 70.06058 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":81,"Type":"NotifyWatcher","Id":"5","Request":"Stop","Params":{}} [LOG] 70.06072 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":34,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["5"].Next [LOG] 70.06078 DEBUG juju.state.apiserver -> [76] unit-u-0 209.065us {"RequestId":81,"Response":{}} NotifyWatcher["5"].Stop [LOG] 70.06121 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":82,"Type":"NotifyWatcher","Id":"3","Request":"Stop","Params":{}} [LOG] 70.06133 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":56,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["3"].Next [LOG] 70.06139 DEBUG juju.state.apiserver -> [76] unit-u-0 213.618us {"RequestId":82,"Response":{}} NotifyWatcher["3"].Stop [LOG] 70.06180 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":83,"Type":"NotifyWatcher","Id":"2","Request":"Stop","Params":{}} [LOG] 70.06216 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":39,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["2"].Next [LOG] 70.06222 DEBUG juju.state.apiserver -> [76] unit-u-0 443.447us {"RequestId":83,"Response":{}} NotifyWatcher["2"].Stop [LOG] 70.06352 ERROR juju.worker.uniter.filter tomb: dying [LOG] 70.06390 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 70.06394 DEBUG juju.worker.uniter juju-run listener stopped uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{"config-changed"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 70.06670 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":84,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.06786 DEBUG juju.state.apiserver -> [76] unit-u-0 1.227651ms {"RequestId":84,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.06840 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":85,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.06873 DEBUG juju.state.apiserver -> [76] unit-u-0 333.312us {"RequestId":85,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.06902 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":86,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 70.06944 DEBUG juju.state.apiserver -> [76] unit-u-0 412.8us {"RequestId":86,"Response":{"Error":null,"Result":"9cca642c-8a3d-4647-83fd-c97f75fb3b9d"}} Uniter[""].CurrentEnvironUUID [LOG] 70.06954 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 70.06977 INFO juju.worker.uniter unit "u/0" started [LOG] 70.06982 INFO juju.worker.uniter ModeInit starting [LOG] 70.06983 INFO juju.worker.uniter updating unit addresses [LOG] 70.06989 DEBUG juju.worker.uniter juju-run listener running [LOG] 70.07005 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":87,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 70.07011 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":88,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.07145 DEBUG juju.state.apiserver -> [76] unit-u-0 1.413446ms {"RequestId":87,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 70.07162 DEBUG juju.state.apiserver -> [76] unit-u-0 1.488558ms {"RequestId":88,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.07201 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":89,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 70.07211 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":90,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.07321 DEBUG juju.state.apiserver -> [76] unit-u-0 1.048503ms {"RequestId":90,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.07453 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":91,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.07508 DEBUG juju.state.apiserver -> [76] unit-u-0 571.033us {"RequestId":91,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 70.07589 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":92,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.07679 DEBUG juju.state.apiserver -> [76] unit-u-0 894.256us {"RequestId":92,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.08076 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":93,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.08313 DEBUG juju.state.apiserver -> [76] unit-u-0 2.395693ms {"RequestId":93,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.08454 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":94,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.08492 DEBUG juju.state.apiserver -> [76] unit-u-0 12.911619ms {"RequestId":89,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 70.08508 DEBUG juju.state.apiserver -> [76] unit-u-0 572.795us {"RequestId":94,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 70.08540 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 70.08551 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":95,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 70.08561 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":96,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.08689 DEBUG juju.state.apiserver -> [76] unit-u-0 1.280821ms {"RequestId":96,"Response":{"Results":[{"NotifyWatcherId":"9","Error":null}]}} Uniter[""].Watch [LOG] 70.08807 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":97,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.08816 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":98,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 70.08945 DEBUG juju.state.apiserver -> [76] unit-u-0 1.46653ms {"RequestId":97,"Response":{"Results":[{"NotifyWatcherId":"10","Error":null}]}} Uniter[""].Watch [LOG] 70.09036 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":99,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.09041 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":100,"Type":"NotifyWatcher","Id":"10","Request":"Next","Params":{}} [LOG] 70.09074 DEBUG juju.state.apiserver -> [76] unit-u-0 5.194626ms {"RequestId":95,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 70.09090 DEBUG juju.state.apiserver -> [76] unit-u-0 558.916us {"RequestId":99,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} Uniter[""].CharmURL [LOG] 70.09107 INFO juju.worker.uniter reconciling relation state [LOG] 70.09173 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":101,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 70.09188 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":102,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.09313 DEBUG juju.state.apiserver -> [76] unit-u-0 1.285644ms {"RequestId":101,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].RelationById [LOG] 70.09460 DEBUG juju.state.apiserver -> [76] unit-u-0 2.734735ms {"RequestId":102,"Response":{"Results":[{"NotifyWatcherId":"11","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 70.09527 INFO juju.worker.uniter joining relation "u:db mysql:server" [LOG] 70.09630 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":103,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.09668 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":104,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.09688 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":105,"Type":"NotifyWatcher","Id":"11","Request":"Next","Params":{}} [LOG] 70.09993 DEBUG juju.state.apiserver -> [76] unit-u-0 3.691369ms {"RequestId":103,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.10033 DEBUG juju.state.apiserver -> [76] unit-u-0 3.661603ms {"RequestId":104,"Response":{"Results":[{"StringsWatcherId":"12","Changes":["u:db mysql:server"],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 70.10199 DEBUG juju.worker.uniter.filter got service change [LOG] 70.10256 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":106,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.10286 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":107,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.10309 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":108,"Type":"StringsWatcher","Id":"12","Request":"Next","Params":{}} [LOG] 70.10486 DEBUG juju.state.apiserver -> [76] unit-u-0 2.033595ms {"RequestId":107,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.10584 DEBUG juju.state.apiserver -> [76] unit-u-0 3.316166ms {"RequestId":106,"Response":{"Results":[{"NotifyWatcherId":"13","Error":null}]}} Uniter[""].Watch [LOG] 70.10702 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":109,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.10735 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":110,"Type":"Uniter","Request":"EnterScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.10759 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":111,"Type":"NotifyWatcher","Id":"13","Request":"Next","Params":{}} [LOG] 70.10844 DEBUG juju.state.apiserver -> [76] unit-u-0 1.522118ms {"RequestId":109,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 70.10903 DEBUG juju.worker.uniter.filter no new charm event [LOG] 70.10905 DEBUG juju.worker.uniter.filter got relations change [LOG] 70.10926 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":112,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.10999 DEBUG juju.state.apiserver -> [76] unit-u-0 2.763748ms {"RequestId":110,"Response":{"Results":[{"Error":null}]}} Uniter[""].EnterScope [LOG] 70.11013 DEBUG juju.state.apiserver -> [76] unit-u-0 874.723us {"RequestId":112,"Response":{"Results":[{"Error":null,"Life":"alive","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.11041 INFO juju.worker.uniter joined relation "u:db mysql:server" [LOG] 70.11044 DEBUG juju.worker.uniter.filter got config change [LOG] 70.11045 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 70.11046 DEBUG juju.worker.uniter.filter got unit change [LOG] 70.11064 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":113,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.11071 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":114,"Type":"NotifyWatcher","Id":"13","Request":"Stop","Params":{}} [LOG] 70.11105 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":111,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["13"].Next [LOG] 70.11113 DEBUG juju.state.apiserver -> [76] unit-u-0 421.202us {"RequestId":114,"Response":{}} NotifyWatcher["13"].Stop [LOG] 70.11128 DEBUG juju.worker.uniter ModeInit exiting [LOG] 70.11130 INFO juju.worker.uniter ModeContinue starting [LOG] 70.11132 INFO juju.worker.uniter loading uniter state [LOG] 70.11162 INFO juju.worker.uniter continuing after "relation-changed" hook [LOG] 70.11163 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 70.11164 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 70.11180 DEBUG juju.state.apiserver -> [76] unit-u-0 1.162555ms {"RequestId":113,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.11210 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":115,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.11239 DEBUG juju.state.apiserver -> [76] unit-u-0 310.707us {"RequestId":115,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 70.11251 DEBUG juju.worker.uniter.filter discarded config event [LOG] 70.11293 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":116,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 70.11413 DEBUG juju.state.apiserver -> [76] unit-u-0 1.204311ms {"RequestId":116,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 70.11441 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":117,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.11472 DEBUG juju.state.apiserver -> [76] unit-u-0 338.386us {"RequestId":117,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 70.11493 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":118,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.11542 DEBUG juju.state.apiserver -> [76] unit-u-0 498.15us {"RequestId":118,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 70.11579 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":119,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.11626 DEBUG juju.state.apiserver -> [76] unit-u-0 556.741us {"RequestId":119,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 70.12050 INFO juju.worker.uniter running "config-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 70.16627 DEBUG juju.state.apiserver -> [76] unit-u-0 78.059652ms {"RequestId":98,"Response":{}} NotifyWatcher["9"].Next [LOG] 70.16700 DEBUG juju.worker.uniter.filter got unit change [LOG] 70.16722 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":120,"Type":"NotifyWatcher","Id":"9","Request":"Next","Params":{}} [LOG] 70.16734 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":121,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.16795 DEBUG juju.state.apiserver -> [76] unit-u-0 612.436us {"RequestId":121,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.16820 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":122,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.16887 DEBUG juju.state.apiserver -> [76] unit-u-0 587.861us {"RequestId":122,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 70.25269 INFO juju u/0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d config-changed ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0"} [LOG] 70.27687 INFO juju.worker.uniter ran "config-changed" hook [LOG] 70.27691 INFO juju.worker.uniter committing "config-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} step 1: uniter_test.custom{f:(func(*gocheck.C, *uniter_test.context))(0x455070)} [LOG] 70.33109 INFO juju.worker.uniter committed "config-changed" hook [LOG] 70.33155 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 70.33157 INFO juju.worker.uniter ModeContinue starting [LOG] 70.33159 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 70.33160 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 70.33160 INFO juju.worker.uniter ModeAbide starting [LOG] 70.33223 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":123,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} step 2: uniter_test.waitHooks{"db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} [LOG] 70.34641 DEBUG juju.state.apiserver -> [76] unit-u-0 14.145258ms {"RequestId":123,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 70.34822 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 70.34827 DEBUG juju.worker.uniter.filter no new charm event [LOG] 70.34855 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":124,"Type":"Uniter","Request":"WatchRelationUnits","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.35585 DEBUG juju.state.apiserver -> [76] unit-u-0 252.51423ms {"RequestId":108,"Response":{"StringsWatcherId":"","Changes":["u:db mysql:server"],"Error":null}} StringsWatcher["12"].Next [LOG] 70.35649 DEBUG juju.state.apiserver -> [76] unit-u-0 7.937908ms {"RequestId":124,"Response":{"Results":[{"RelationUnitsWatcherId":"14","Changes":{"Changed":{"mysql/0":{"Version":2}},"Departed":null},"Error":null}]}} Uniter[""].WatchRelationUnits [LOG] 70.36080 DEBUG juju.worker.uniter.filter sent relations event [LOG] 70.36081 DEBUG juju.worker.uniter.filter got relations change [LOG] 70.36132 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":125,"Type":"StringsWatcher","Id":"12","Request":"Next","Params":{}} [LOG] 70.36143 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":126,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.36170 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":127,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.36177 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":128,"Type":"RelationUnitsWatcher","Id":"14","Request":"Next","Params":{}} [LOG] 70.36402 DEBUG juju.state.apiserver -> [76] unit-u-0 2.564806ms {"RequestId":126,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.36432 DEBUG juju.state.apiserver -> [76] unit-u-0 2.582301ms {"RequestId":127,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.36483 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":129,"Type":"RelationUnitsWatcher","Id":"14","Request":"Stop","Params":{}} [LOG] 70.36494 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":128,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} RelationUnitsWatcher["14"].Next [LOG] 70.36499 DEBUG juju.state.apiserver -> [76] unit-u-0 221.418us {"RequestId":129,"Response":{}} RelationUnitsWatcher["14"].Stop [LOG] 70.36548 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":130,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.36581 DEBUG juju.state.apiserver -> [76] unit-u-0 550.887us {"RequestId":130,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal [LOG] 70.36601 DEBUG juju.worker.uniter.filter sent relations event [LOG] 70.36615 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":131,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.36689 DEBUG juju.state.apiserver -> [76] unit-u-0 750.139us {"RequestId":131,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.36716 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":132,"Type":"Uniter","Request":"GetPrincipal","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.36746 DEBUG juju.state.apiserver -> [76] unit-u-0 298.935us {"RequestId":132,"Response":{"Results":[{"Error":null,"Result":"","Ok":false}]}} Uniter[""].GetPrincipal [LOG] 70.36816 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":133,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 70.36971 DEBUG juju.state.apiserver -> [76] unit-u-0 1.521337ms {"RequestId":133,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 70.36994 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":134,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.37027 DEBUG juju.state.apiserver -> [76] unit-u-0 339.835us {"RequestId":134,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 70.37051 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":135,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.37099 DEBUG juju.state.apiserver -> [76] unit-u-0 483.759us {"RequestId":135,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 70.37126 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":136,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.37177 DEBUG juju.state.apiserver -> [76] unit-u-0 513.559us {"RequestId":136,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 70.37602 INFO juju.worker.uniter running "db-relation-departed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} [LOG] 70.52342 INFO juju u/0 db:0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d db-relation-departed mysql/0 ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed"} [LOG] 70.53053 INFO juju.worker.uniter ran "db-relation-departed" hook [LOG] 70.53058 INFO juju.worker.uniter committing "relation-departed" hook [LOG] 70.56776 INFO juju.worker.uniter committed "relation-departed" hook [LOG] 70.57130 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":137,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 70.57681 DEBUG juju.state.apiserver -> [76] unit-u-0 5.528021ms {"RequestId":137,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 70.57784 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":138,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.57897 DEBUG juju.state.apiserver -> [76] unit-u-0 1.101141ms {"RequestId":138,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0"} [LOG] 70.58275 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":139,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.58603 DEBUG juju.state.apiserver -> [76] unit-u-0 3.308737ms {"RequestId":139,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 70.58745 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":140,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.58940 DEBUG juju.state.apiserver -> [76] unit-u-0 2.019761ms {"RequestId":140,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 70.59471 INFO juju.worker.uniter running "db-relation-broken" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0"} [LOG] 70.77532 INFO juju u/0 db:0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d db-relation-broken [LOG] 70.78507 INFO juju.worker.uniter ran "db-relation-broken" hook [LOG] 70.78526 INFO juju.worker.uniter committing "relation-broken" hook [LOG] 70.78832 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":141,"Type":"Uniter","Request":"LeaveScope","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} step 3: uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} [LOG] 70.79860 DEBUG juju.state.apiserver -> [76] unit-u-0 11.771697ms {"RequestId":141,"Response":{"Results":[{"Error":null}]}} Uniter[""].LeaveScope [LOG] 70.85829 INFO juju.worker.uniter committed "relation-broken" hook [LOG] 70.86093 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 70.86149 INFO juju.worker.uniter unit "u/0" shutting down: tomb: dying [LOG] 70.86464 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":142,"Type":"StringsWatcher","Id":"12","Request":"Stop","Params":{}} [LOG] 70.86514 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":125,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["12"].Next [LOG] 70.86545 DEBUG juju.state.apiserver -> [76] unit-u-0 811.943us {"RequestId":142,"Response":{}} StringsWatcher["12"].Stop [LOG] 70.86647 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":143,"Type":"NotifyWatcher","Id":"11","Request":"Stop","Params":{}} [LOG] 70.86700 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":105,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["11"].Next [LOG] 70.86707 DEBUG juju.state.apiserver -> [76] unit-u-0 686.593us {"RequestId":143,"Response":{}} NotifyWatcher["11"].Stop [LOG] 70.86772 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":144,"Type":"NotifyWatcher","Id":"10","Request":"Stop","Params":{}} [LOG] 70.86788 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":100,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["10"].Next [LOG] 70.86794 DEBUG juju.state.apiserver -> [76] unit-u-0 274.242us {"RequestId":144,"Response":{}} NotifyWatcher["10"].Stop [LOG] 70.86877 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":145,"Type":"NotifyWatcher","Id":"9","Request":"Stop","Params":{}} [LOG] 70.86901 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":120,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["9"].Next [LOG] 70.86914 DEBUG juju.state.apiserver -> [76] unit-u-0 382.225us {"RequestId":145,"Response":{}} NotifyWatcher["9"].Stop [LOG] 70.86948 ERROR juju.worker.uniter.filter tomb: dying [LOG] 70.86973 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 70.86974 DEBUG juju.worker.uniter juju-run listener stopped uniter_test.startUniter{unitTag:""} uniter_test.waitHooks{"config-changed"} waiting for hooks: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0", "config-changed"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} [LOG] 70.87174 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":146,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.87815 DEBUG juju.state.apiserver -> [76] unit-u-0 6.409912ms {"RequestId":146,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.87955 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":147,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.88006 DEBUG juju.state.apiserver -> [76] unit-u-0 510.635us {"RequestId":147,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.88031 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":148,"Type":"Uniter","Request":"CurrentEnvironUUID","Params":{}} [LOG] 70.88058 DEBUG juju.state.apiserver -> [76] unit-u-0 300.346us {"RequestId":148,"Response":{"Error":null,"Result":"9cca642c-8a3d-4647-83fd-c97f75fb3b9d"}} Uniter[""].CurrentEnvironUUID [LOG] 70.88072 DEBUG juju.worker.uniter starting juju-run listener on unix:/tmp/gocheck-3328451335138149956/0/agents/unit-u-0/run.socket [LOG] 70.88094 INFO juju.worker.uniter unit "u/0" started [LOG] 70.88111 INFO juju.worker.uniter ModeInit starting [LOG] 70.88112 INFO juju.worker.uniter updating unit addresses [LOG] 70.88122 DEBUG juju.worker.uniter juju-run listener running [LOG] 70.88207 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":149,"Type":"Uniter","Request":"ProviderType","Params":{}} [LOG] 70.88238 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":150,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.88631 DEBUG juju.state.apiserver -> [76] unit-u-0 4.256783ms {"RequestId":149,"Response":{"Error":null,"Result":"dummy"}} Uniter[""].ProviderType [LOG] 70.88671 DEBUG juju.state.apiserver -> [76] unit-u-0 4.393837ms {"RequestId":150,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.88768 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":151,"Type":"Uniter","Request":"SetPrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"private.dummy.address.example.com"}]}} [LOG] 70.88909 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":152,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.89255 DEBUG juju.state.apiserver -> [76] unit-u-0 4.348263ms {"RequestId":152,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.89387 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":153,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.89683 DEBUG juju.state.apiserver -> [76] unit-u-0 2.959711ms {"RequestId":153,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 70.89969 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":154,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.90192 DEBUG juju.state.apiserver -> [76] unit-u-0 2.411849ms {"RequestId":154,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.90637 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":155,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.90995 DEBUG juju.state.apiserver -> [76] unit-u-0 3.709819ms {"RequestId":155,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.91216 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":156,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.91414 DEBUG juju.state.apiserver -> [76] unit-u-0 2.349133ms {"RequestId":156,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 70.91454 DEBUG juju.state.apiserver -> [76] unit-u-0 26.934059ms {"RequestId":151,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPrivateAddress [LOG] 70.91543 DEBUG juju.worker.uniter.filter charm check skipped, not yet installed. [LOG] 70.91678 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":157,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.91727 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":158,"Type":"Uniter","Request":"SetPublicAddress","Params":{"Entities":[{"Tag":"unit-u-0","Address":"public.dummy.address.example.com"}]}} [LOG] 70.92266 DEBUG juju.state.apiserver -> [76] unit-u-0 5.777712ms {"RequestId":157,"Response":{"Results":[{"NotifyWatcherId":"15","Error":null}]}} Uniter[""].Watch [LOG] 70.92467 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":159,"Type":"Uniter","Request":"Watch","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.92491 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":160,"Type":"NotifyWatcher","Id":"15","Request":"Next","Params":{}} [LOG] 70.92822 DEBUG juju.state.apiserver -> [76] unit-u-0 3.609815ms {"RequestId":159,"Response":{"Results":[{"NotifyWatcherId":"16","Error":null}]}} Uniter[""].Watch [LOG] 70.92987 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":161,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.93030 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":162,"Type":"NotifyWatcher","Id":"16","Request":"Next","Params":{}} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} [LOG] 70.93201 DEBUG juju.state.apiserver -> [76] unit-u-0 2.193041ms {"RequestId":161,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":true}]}} Uniter[""].CharmURL [LOG] 70.93342 DEBUG juju.state.apiserver -> [76] unit-u-0 16.237892ms {"RequestId":158,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetPublicAddress [LOG] 70.93408 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":163,"Type":"Uniter","Request":"WatchConfigSettings","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.93448 INFO juju.worker.uniter reconciling relation state [LOG] 70.93470 DEBUG juju.worker.uniter ModeInit exiting [LOG] 70.93473 INFO juju.worker.uniter ModeContinue starting [LOG] 70.93476 INFO juju.worker.uniter loading uniter state [LOG] 70.93564 INFO juju.worker.uniter continuing after "relation-broken" hook [LOG] 70.93567 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 70.93588 INFO juju.worker.uniter ModeConfigChanged starting [LOG] 70.93739 DEBUG juju.state.apiserver -> [76] unit-u-0 3.317687ms {"RequestId":163,"Response":{"Results":[{"NotifyWatcherId":"17","Error":null}]}} Uniter[""].WatchConfigSettings [LOG] 70.93845 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":164,"Type":"Uniter","Request":"WatchServiceRelations","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.93887 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":165,"Type":"NotifyWatcher","Id":"17","Request":"Next","Params":{}} [LOG] 70.94182 DEBUG juju.state.apiserver -> [76] unit-u-0 3.357545ms {"RequestId":164,"Response":{"Results":[{"StringsWatcherId":"18","Changes":["u:db mysql:server"],"Error":null}]}} Uniter[""].WatchServiceRelations [LOG] 70.94306 DEBUG juju.worker.uniter.filter got service change [LOG] 70.94405 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":166,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.94421 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":167,"Type":"StringsWatcher","Id":"18","Request":"Next","Params":{}} [LOG] 70.94471 DEBUG juju.state.apiserver -> [76] unit-u-0 19.807431ms {"RequestId":160,"Response":{}} NotifyWatcher["15"].Next [LOG] 70.94509 DEBUG juju.state.apiserver -> [76] unit-u-0 1.135784ms {"RequestId":166,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.94569 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":168,"Type":"Uniter","Request":"CharmURL","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.94630 DEBUG juju.state.apiserver -> [76] unit-u-0 585.079us {"RequestId":168,"Response":{"Results":[{"Error":null,"Result":"cs:quantal/wordpress-0","Ok":false}]}} Uniter[""].CharmURL [LOG] 70.94657 DEBUG juju.worker.uniter.filter no new charm event [LOG] 70.94661 DEBUG juju.worker.uniter.filter got relations change [LOG] 70.94714 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":169,"Type":"Uniter","Request":"Relation","Params":{"RelationUnits":[{"Relation":"relation-u.db#mysql.server","Unit":"unit-u-0"}]}} [LOG] 70.94850 DEBUG juju.state.apiserver -> [76] unit-u-0 1.373617ms {"RequestId":169,"Response":{"Results":[{"Error":null,"Life":"dying","Id":0,"Key":"u:db mysql:server","Endpoint":{"ServiceName":"u","Relation":{"Name":"db","Role":"requirer","Interface":"mysql","Optional":false,"Limit":1,"Scope":"global"}}}]}} Uniter[""].Relation [LOG] 70.94897 DEBUG juju.worker.uniter.filter got config change [LOG] 70.94899 DEBUG juju.worker.uniter.filter preparing new config event [LOG] 70.94901 DEBUG juju.worker.uniter.filter got unit change [LOG] 70.94947 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":170,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.94961 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":171,"Type":"NotifyWatcher","Id":"15","Request":"Next","Params":{}} [LOG] 70.95046 DEBUG juju.state.apiserver -> [76] unit-u-0 900.01us {"RequestId":170,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.95109 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":172,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.95208 DEBUG juju.state.apiserver -> [76] unit-u-0 912.848us {"RequestId":172,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 70.95262 DEBUG juju.worker.uniter.filter discarded config event [LOG] 70.95265 DEBUG juju.worker.uniter.filter got unit change [LOG] 70.95418 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":173,"Type":"Uniter","Request":"Life","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.95437 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":174,"Type":"Uniter","Request":"APIAddresses","Params":{}} [LOG] 70.95567 DEBUG juju.state.apiserver -> [76] unit-u-0 1.527551ms {"RequestId":173,"Response":{"Results":[{"Life":"alive","Error":null}]}} Uniter[""].Life [LOG] 70.95754 DEBUG juju.state.apiserver -> [76] unit-u-0 3.188122ms {"RequestId":174,"Response":{"Error":null,"Result":["0.1.2.3:4321"]}} Uniter[""].APIAddresses [LOG] 70.95818 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":175,"Type":"Uniter","Request":"Resolved","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.95835 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":176,"Type":"Uniter","Request":"GetOwnerTag","Params":{"Entities":[{"Tag":"service-u"}]}} [LOG] 70.95979 DEBUG juju.state.apiserver -> [76] unit-u-0 1.500815ms {"RequestId":175,"Response":{"Results":[{"Error":null,"Mode":""}]}} Uniter[""].Resolved [LOG] 70.96012 DEBUG juju.state.apiserver -> [76] unit-u-0 1.793147ms {"RequestId":176,"Response":{"Error":null,"Result":"user-admin"}} Uniter[""].GetOwnerTag [LOG] 70.96160 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":177,"Type":"Uniter","Request":"PublicAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.96313 DEBUG juju.state.apiserver -> [76] unit-u-0 1.602085ms {"RequestId":177,"Response":{"Results":[{"Error":null,"Result":"public.dummy.address.example.com"}]}} Uniter[""].PublicAddress [LOG] 70.96402 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":178,"Type":"Uniter","Request":"PrivateAddress","Params":{"Entities":[{"Tag":"unit-u-0"}]}} [LOG] 70.96563 DEBUG juju.state.apiserver -> [76] unit-u-0 1.715696ms {"RequestId":178,"Response":{"Results":[{"Error":null,"Result":"private.dummy.address.example.com"}]}} Uniter[""].PrivateAddress [LOG] 70.97281 INFO juju.worker.uniter running "config-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} [LOG] 71.12686 INFO juju u/0: 9cca642c-8a3d-4647-83fd-c97f75fb3b9d config-changed ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0"} [LOG] 71.14133 INFO juju.worker.uniter ran "config-changed" hook [LOG] 71.14165 INFO juju.worker.uniter committing "config-changed" hook ctx.hooksCompleted: []string{"install", "config-changed", "start", "db-relation-joined mysql/0 db:0", "db-relation-changed mysql/0 db:0", "config-changed", "db-relation-departed mysql/0 db:0", "db-relation-broken db:0", "config-changed"} step 4: uniter_test.relationState{removed:false, life:1} step 5: uniter_test.removeRelationUnit{name:"mysql/0"} [LOG] 71.21978 INFO juju.worker.uniter committed "config-changed" hook [LOG] 71.22207 DEBUG juju.worker.uniter ModeConfigChanged exiting [LOG] 71.22224 INFO juju.worker.uniter ModeContinue starting [LOG] 71.22229 INFO juju.worker.uniter continuing after "config-changed" hook [LOG] 71.22231 DEBUG juju.worker.uniter ModeContinue exiting [LOG] 71.22252 INFO juju.worker.uniter ModeAbide starting [LOG] 71.22468 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":179,"Type":"Uniter","Request":"SetStatus","Params":{"Entities":[{"Tag":"unit-u-0","Status":"started","Info":"","Data":null}],"Machines":null}} [LOG] 71.23686 DEBUG juju.state.apiserver -> [76] unit-u-0 12.353288ms {"RequestId":179,"Response":{"Results":[{"Error":null}]}} Uniter[""].SetStatus [LOG] 71.23867 DEBUG juju.worker.uniter.filter want forced upgrade false [LOG] 71.23870 DEBUG juju.worker.uniter.filter no new charm event [LOG] 71.23873 DEBUG juju.worker.uniter.filter sent relations event [LOG] 71.23939 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":180,"Type":"Uniter","Request":"RelationById","Params":{"RelationIds":[0]}} [LOG] 71.24006 DEBUG juju.state.apiserver -> [76] unit-u-0 584.872us {"RequestId":180,"Response":{"Results":[{"Error":{"Message":"permission denied","Code":"unauthorized access"},"Life":"","Id":0,"Key":"","Endpoint":{"ServiceName":"","Relation":{"Name":"","Role":"","Interface":"","Optional":false,"Limit":0,"Scope":""}}}]}} Uniter[""].RelationById [LOG] 71.24035 DEBUG juju.worker.uniter ModeAbide exiting [LOG] 71.24039 INFO juju.worker.uniter unit "u/0" shutting down: ModeAbide: permission denied [LOG] 71.24066 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":181,"Type":"StringsWatcher","Id":"18","Request":"Stop","Params":{}} [LOG] 71.24092 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":167,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} StringsWatcher["18"].Next [LOG] 71.24102 DEBUG juju.state.apiserver -> [76] unit-u-0 372.469us {"RequestId":181,"Response":{}} StringsWatcher["18"].Stop [LOG] 71.24159 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":182,"Type":"NotifyWatcher","Id":"17","Request":"Stop","Params":{}} [LOG] 71.24178 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":165,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["17"].Next [LOG] 71.24190 DEBUG juju.state.apiserver -> [76] unit-u-0 319.306us {"RequestId":182,"Response":{}} NotifyWatcher["17"].Stop [LOG] 71.24240 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":183,"Type":"NotifyWatcher","Id":"16","Request":"Stop","Params":{}} [LOG] 71.24257 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":162,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["16"].Next [LOG] 71.24265 DEBUG juju.state.apiserver -> [76] unit-u-0 260.056us {"RequestId":183,"Response":{}} NotifyWatcher["16"].Stop [LOG] 71.24308 DEBUG juju.state.apiserver <- [76] unit-u-0 {"RequestId":184,"Type":"NotifyWatcher","Id":"15","Request":"Stop","Params":{}} [LOG] 71.24326 DEBUG juju.state.apiserver -> [76] unit-u-0 0 {"RequestId":171,"Error":"watcher has been stopped","ErrorCode":"stopped","Response":{}} NotifyWatcher["15"].Next [LOG] 71.24336 DEBUG juju.state.apiserver -> [76] unit-u-0 275.391us {"RequestId":184,"Response":{}} NotifyWatcher["15"].Stop [LOG] 71.24368 ERROR juju.worker.uniter.filter tomb: dying [LOG] 71.24390 DEBUG juju.worker.uniter juju-run listener stopping [LOG] 71.24393 DEBUG juju.worker.uniter juju-run listener stopped step 6: uniter_test.relationState{removed:true, life:0} step 7: uniter_test.verifyRunning{noHooks:false} uniter_test.stopUniter{err:""} uniter_test.go:955: s.runUniterTests(c, relationsTests) uniter_test.go:1346: c.Assert(err, gc.IsNil) ... value *errors.errorString = &errors.errorString{s:"ModeAbide: permission denied"} ("ModeAbide: permission denied") [LOG] 71.27572 INFO juju.provider.dummy reset environment [LOG] 71.30514 INFO juju Reset successfully reset admin password [LOG] 71.31729 INFO juju Reset successfully reset admin password [LOG] 71.34364 DEBUG juju.environs.configstore Making /tmp/gocheck-3328451335138149956/123/home/ubuntu/.juju/environments [LOG] 71.43781 DEBUG juju.environs.tools reading v1.* tools [LOG] 71.43787 INFO juju environs/testing: uploading FAKE tools 1.17.1-precise-amd64 [LOG] 71.46946 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 71.46948 DEBUG juju.environs.tools no series specified when finding tools, looking for any [LOG] 71.46954 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 71.46956 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 71.46960 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.json": file "tools/streams/v1/index.json" not found not found [LOG] 71.46962 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.json": invalid URL "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.json" not found [LOG] 71.46982 INFO juju.environs.tools Writing tools/streams/v1/index.json [LOG] 71.47017 INFO juju.environs.tools Writing tools/streams/v1/com.ubuntu.juju:released:tools.json [LOG] 71.47055 INFO juju.environs.bootstrap bootstrapping environment "dummyenv" [LOG] 71.47064 DEBUG juju.environs.bootstrap looking for bootstrap tools: series="precise", arch=, version=1.17.1 [LOG] 71.47069 INFO juju.environs.tools reading tools with major.minor version 1.17 [LOG] 71.47073 INFO juju.environs.tools filtering tools by version: 1.17.1 [LOG] 71.47077 INFO juju.environs.tools filtering tools by series: precise [LOG] 71.47084 DEBUG juju.environs.tools no architecture specified when finding tools, looking for any [LOG] 71.47096 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson": file "tools/streams/v1/index.sjson" not found not found [LOG] 71.47102 DEBUG juju.environs.simplestreams cannot load index "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson": invalid URL "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.sjson" not found [LOG] 71.47144 DEBUG juju.environs.simplestreams fetchData failed for "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/mirrors.json": file "tools/streams/v1/mirrors.json" not found not found [LOG] 71.47148 DEBUG juju.environs.simplestreams no mirror index file found [LOG] 71.47158 DEBUG juju.environs.simplestreams no mirror information available for { }: mirror data for "com.ubuntu.juju:released:tools" not found [LOG] 71.47163 DEBUG juju.environs.simplestreams read metadata index at "http://127.0.0.1:49245/dummyenv/private/tools/streams/v1/index.json" [LOG] 71.47187 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 [{Sun, 12 Jan 2014 21:39:52 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64]}] [LOG] 71.47193 DEBUG juju.environs.simplestreams finding products at path "streams/v1/com.ubuntu.juju:released:tools.json" [LOG] 71.47252 DEBUG juju.environs.simplestreams metadata: &{map[com.ubuntu.juju:12.04:amd64:{ 1.17.1 amd64 map[20140112:0xc201aa0cc0]}] map[] Sun, 12 Jan 2014 21:39:52 +0000 products:1.0 com.ubuntu.juju:released:tools} [LOG] 71.47270 INFO juju.environs.bootstrap picked newest version: 1.17.1 [LOG] 71.47277 INFO juju.provider.dummy would pick tools from 1.17.1-precise-amd64 [LOG] 71.47401 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 71.47797 INFO juju.state connection established [LOG] 71.51062 INFO juju.state initializing environment [LOG] 71.53262 INFO juju.state.apiserver listening on "127.0.0.1:34798" [LOG] 71.55508 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 71.56106 INFO juju.state connection established [LOG] 71.58181 INFO juju juju: authorization error while connecting to state server; retrying [LOG] 71.58194 INFO juju.state opening state; mongo addresses: ["localhost:38667"]; entity "" [LOG] 71.58977 INFO juju.state connection established [LOG] 71.65218 INFO juju state/api: dialing "wss://127.0.0.1:34798/" [LOG] 71.66435 INFO juju state/api: connection established [LOG] 71.66486 DEBUG juju.state.apiserver <- [77] {"RequestId":1,"Type":"Admin","Request":"Login","Params":{"AuthTag":"user-admin","Password":"dummy-secret","Nonce":""}} [LOG] 71.66586 DEBUG juju.state.apiserver -> [77] user-admin 1.021661ms {"RequestId":1,"Response":{}} Admin[""].Login [LOG] 71.67523 INFO juju.provider.dummy reset environment [LOG] 71.69963 INFO juju Reset successfully reset admin password [LOG] 71.71389 INFO juju Reset successfully reset admin password [LOG] 71.71851 INFO juju Reset successfully reset admin password OOPS: 44 passed, 1 FAILED --- FAIL: TestPackage (147.52 seconds) FAIL FAIL launchpad.net/juju-core/worker/uniter 147.843s ok launchpad.net/juju-core/worker/uniter/charm 3.637s ok launchpad.net/juju-core/worker/uniter/debug 0.152s ok launchpad.net/juju-core/worker/uniter/hook 0.015s ok launchpad.net/juju-core/worker/uniter/jujuc 0.471s ok launchpad.net/juju-core/worker/uniter/relation 1.352s ok launchpad.net/juju-core/worker/upgrader 3.776s warning: building out-of-date packages: launchpad.net/lpad 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 installing these packages with 'go test -i ./...' will speed future tests.