Charm stuck in pending state

[Jacek Nykis]

I had a service with 4 subordinate charms. When I run "juju add-unit". New unit ended up with 2 subordintes stuck in pending state (but 2 started fine). This looks similar to #1218119 but logs suggest cause is different.

Log for one of the failing subordinates:
2013-08-29 16:14:57 INFO juju.jujud unit.go:72 unit agent unit-xxxx start
2013-08-29 16:14:57 INFO juju runner.go:253 worker: start "state"
2013-08-29 16:14:57 INFO juju open.go:69 state: opening state; mongo addresses: ["x.x.x.x:37017"]; entity "unit-xxxx"
2013-08-29 16:14:57 INFO juju runner.go:253 worker: start "api"
2013-08-29 16:14:57 INFO juju apiclient.go:106 state/api: dialing "wss://x.x.x.x:17070/"
2013-08-29 16:14:57 INFO juju open.go:107 state: connection established
2013-08-29 16:14:57 INFO juju runner.go:253 worker: start "uniter"
2013-08-29 16:14:57 INFO juju apiclient.go:116 state/api: connection established
2013-08-29 16:14:57 INFO juju.worker.uniter uniter.go:83 unit "wordpress-plugin-openid/1" started
2013-08-29 16:14:57 INFO juju.worker.uniter modes.go:404 ModeInit starting
2013-08-29 16:14:57 INFO juju.worker.uniter modes.go:29 updating unit addresses
2013-08-29 16:14:57 DEBUG juju.worker.uniter.filter filter.go:472 charm check skipped, not yet installed.
2013-08-29 16:14:57 DEBUG juju.worker.uniter.filter filter.go:289 got unit change
2013-08-29 16:14:57 DEBUG juju.worker.uniter.filter filter.go:313 got relations change
2013-08-29 16:14:57 DEBUG juju.worker.uniter.filter filter.go:297 got service change
2013-08-29 16:14:57 DEBUG juju.worker.uniter.filter filter.go:472 charm check skipped, not yet installed.
2013-08-29 16:14:57 INFO juju runner.go:253 worker: start "upgrader"
2013-08-29 16:14:57 INFO juju.worker.upgrader upgrader.go:137 required tools: 1.13.2.1-precise-amd64
2013-08-29 16:15:02 DEBUG juju.worker.uniter.filter filter.go:289 got unit change

[Jacek Nykis (jacekn)]

I chedked thet status and my subordinates eventually got deployed. Logs show that one of them woke up over 30 minutes later and the other one nearly 4 hours.

Log snippet 1:
2013-08-29 16:14:56 DEBUG juju.worker.uniter.filter filter.go:472 charm check skipped, not yet installed.
2013-08-29 16:14:56 DEBUG juju.worker.uniter.filter filter.go:289 got unit change
2013-08-29 16:14:56 DEBUG juju.worker.uniter.filter filter.go:313 got relations change
2013-08-29 16:14:56 DEBUG juju.worker.uniter.filter filter.go:297 got service change
2013-08-29 16:14:56 DEBUG juju.worker.uniter.filter filter.go:472 charm check skipped, not yet installed.
2013-08-29 16:14:56 INFO juju runner.go:253 worker: start "upgrader"
2013-08-29 16:14:57 INFO juju.worker.upgrader upgrader.go:137 required tools: 1.13.2.1-precise-amd64
2013-08-29 16:15:01 DEBUG juju.worker.uniter.filter filter.go:289 got unit change
2013-08-29 16:52:20 INFO juju.worker.uniter modes.go:48 reconciling relation state
2013-08-29 16:52:20 DEBUG juju.worker.uniter modes.go:406 ModeInit exiting
2013-08-29 16:52:20 INFO juju.worker.uniter modes.go:404 ModeContinue starting
2013-08-29 16:52:20 INFO juju.worker.uniter modes.go:61 loading uniter state
2013-08-29 16:52:20 INFO juju.worker.uniter modes.go:64 charm is not deployed
2013-08-29 16:52:20 DEBUG juju.worker.uniter modes.go:406 ModeContinue exiting
2013-08-29 16:52:20 INFO juju.worker.uniter modes.go:404 ModeInstalling local:precise/wordpress-plugin-teams-integration-39 starting
2013-08-29 16:52:20 INFO juju.worker.uniter uniter.go:230 fetching charm "local:precise/wordpress-plugin-teams-integration-39"
2013-08-29 16:52:20 INFO juju charm.go:56 worker/uniter/charm: downloading local:precise/wordpress-plugin-teams-integration-39 from http://x.x.x.x:8080/v1/xxxx/jacek-prodstack/local_3a_precise_2f_wordpress-plugin-teams-integration-39
2013-08-29 16:52:20 INFO juju charm.go:68 worker/uniter/charm: download complete
2013-08-29 16:52:20 INFO juju charm.go:80 worker/uniter/charm: download verified
2013-08-29 16:52:20 DEBUG juju.worker.uniter.filter filter.go:347 changing charm to "local:precise/wordpress-plugin-teams-integration-39"
2013-08-29 16:52:20 DEBUG juju.worker.uniter.filter filter.go:486 no new charm event
2013-08-29 16:52:20 INFO juju.worker.uniter uniter.go:253 deploying charm "local:precise/wordpress-plugin-teams-integration-39"
2013-08-29 16:52:20 DEBUG juju.worker.uniter.filter filter.go:305 got config change
2013-08-29 16:52:20 DEBUG juju.worker.uniter.filter filter.go:309 preparing new config event
2013-08-29 16:52:20 DEBUG juju.worker.uniter.filter filter.go:313 got relations change
2013-08-29 16:52:20 INFO juju deployer.go:118 worker/uniter/charm: preparing new charm deployment
2013-08-29 16:52:20 INFO juju deployer.go:137 worker/uniter/charm: deploying charm
2013-08-29 16:52:20 INFO juju deployer.go:98 worker/uniter/charm: charm deployment succeeded
2013-08-29 16:52:20 INFO juju.worker.uniter uniter.go:264 charm "local:precise/wordpress-plugin-teams-integration-39" is deployed
2013-08-29 16:52:20 DEBUG juju.worker.uniter modes.go:406 ModeInstalling local:precise/wordpress-plugin-teams-integration-39 exiting
2013-08-29 16:52:20 INFO juju...

[Jacek Nykis (jacekn)]

This could be related to #1218651