worker/provisioner: FAIL: provisioner_test.go:327: ProvisionerSuite.TestProvisioningRecoversAfterInvalidEnvironmentPublished

FAIL: provisioner_test.go:327: ProvisionerSuite.TestProvisioningRecoversAfterInvalidEnvironmentPublished

[LOG] 52.34105 JUJU putting fake tools
[LOG] 52.34190 JUJU state: opening state; mongo addresses: ["localhost:43130"]
[LOG] 52.35207 JUJU:DEBUG watcher: reading most recent document to ignore past history...
[LOG] 52.37183 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.37283 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.37520 JUJU state: storing no-secrets environment configuration
[LOG] 52.38249 JUJU state: opening state; mongo addresses: ["localhost:43130"]
[LOG] 52.38598 JUJU:DEBUG watcher: reading most recent document to ignore past history...
[LOG] 52.38669 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.41732 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.42983 JUJU:DEBUG watcher: got request: watcher.reqWatch{key:watcher.watchKey{c:"settings", id:"e"}, info:watcher.watchInfo{ch:(chan<- watcher.Change)(0xf8401f2820), revno:3}}
[LOG] 52.43039 JUJU:DEBUG watcher: got request: watcher.reqWatch{key:watcher.watchKey{c:"machines", id:interface {}(nil)}, info:watcher.watchInfo{ch:(chan<- watcher.Change)(0xf8400017d0), revno:0}}
[LOG] 52.43489 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.43494 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.43496 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.43502 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.43540 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00$"}, bson.DocElem{Name:"machines", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{0}}, bson.DocElem{Name:"r", Value:[]interface {}{2}}}}}
[LOG] 52.43547 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00#"}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{3}}}}}
[LOG] 52.43552 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00\""}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{3}}}}}
[LOG] 52.43585 JUJU dummy startinstance, machine 0
[LOG] 52.43603 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.43604 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.43608 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.43614 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.43951 JUJU provisioner started machine 0 as instance dummyenv-0
[LOG] 52.52949 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.52958 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.52977 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.52983 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.53090 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00&"}, bson.DocElem{Name:"machines", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{1}}, bson.DocElem{Name:"r", Value:[]interface {}{2}}}}}
[LOG] 52.53108 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00%"}, bson.DocElem{Name:"machines", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{0}}, bson.DocElem{Name:"r", Value:[]interface {}{3}}}}}
[LOG] 52.53241 JUJU dummy startinstance, machine 1
[LOG] 52.53291 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.53298 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.53308 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.53309 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.54915 JUJU provisioner started machine 1 as instance dummyenv-1
[LOG] 52.65041 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.65046 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.65048 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.65054 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.65092 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00,"}, bson.DocElem{Name:"machines", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{2}}, bson.DocElem{Name:"r", Value:[]interface {}{2}}}}}
[LOG] 52.65100 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00+"}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{5}}}}}
[LOG] 52.65106 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00*"}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{5}}}}}
[LOG] 52.65111 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00)"}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{4}}}}}
[LOG] 52.65116 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00("}, bson.DocElem{Name:"settings", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{"e"}}, bson.DocElem{Name:"r", Value:[]interface {}{4}}}}}
[LOG] 52.65121 JUJU:DEBUG watcher: got changelog document: bson.D{bson.DocElem{Name:"_id", Value:"Ps\u007f)\xd3\xfd\xf5k\xe0\x00\x00'"}, bson.DocElem{Name:"machines", Value:bson.D{bson.DocElem{Name:"d", Value:[]interface {}{1}}, bson.DocElem{Name:"r", Value:[]interface {}{3}}}}}
[LOG] 52.65188 JUJU dummy startinstance, machine 2
[LOG] 52.65204 JUJU:DEBUG presence: got request: presence.reqSync{done:(chan bool)(nil)}
[LOG] 52.65206 JUJU:DEBUG presence: synchronizing watcher knowledge with database...
[LOG] 52.65213 JUJU:DEBUG watcher: got request: watcher.reqSync{done:(chan bool)(nil)}
[LOG] 52.65214 JUJU:DEBUG watcher: loading new events from changelog collection...
[LOG] 52.65637 JUJU provisioner started machine 2 as instance dummyenv-2
provisioner_test.go:363:
    // the PA should create it using the new environment
    s.checkStartInstance(c, m, "beef")
provisioner_test.go:82:
    c.Assert(o.Secret, Equals, secret)
... obtained string = "pork"
... expected string = "beef"

[LOG] 52.74053 JUJU:DEBUG watcher: got request: watcher.reqUnwatch{key:watcher.watchKey{c:"machines", id:interface {}(nil)}, ch:(chan<- watcher.Change)(0xf8400017d0)}
[LOG] 52.74063 JUJU:DEBUG watcher: got request: watcher.reqUnwatch{key:watcher.watchKey{c:"settings", id:"e"}, ch:(chan<- watcher.Change)(0xf8401f2820)}
[LOG] 52.74073 JUJU dummy: reset environment
OOPS: 8 passed, 1 FAILED
--- FAIL: TestPackage-9 (3.24 seconds)
FAIL
FAIL launchpad.net/juju-core/worker/provisioner 3.261s