Comment 5 for bug 1038296

bingo!

There is a race between adding a service (which causes the PA to add a machine) and the FA trying to open a port.

----------------------------------------------------------------------
FAIL: provisioning_test.go:32: ProvisioningSuite.TestRunStop

[LOG] 45.64421 JUJU state: opening state; zookeeper addresses: ["127.0.0.1:51885"]
[LOG] 45.68421 JUJU state: initializing zookeeper
[LOG] 45.68958 JUJU state: opening state; zookeeper addresses: ["127.0.0.1:51885"]
[LOG] 45.70337 JUJU state: waiting for state to be initialized
[LOG] 45.70566 JUJU:DEBUG Updating 3 secret(s) in environment "foo"
[LOG] 45.70686 JUJU state: opening state; zookeeper addresses: ["127.0.0.1:51885"]
[LOG] 45.71256 JUJU state: waiting for state to be initialized
[LOG] 45.71317 JUJU:DEBUG provisioning: opened state
[LOG] 45.73088 JUJU provisioner loaded new environment configuration
[LOG] 45.73096 JUJU firewaller loaded new environment configuration
[LOG] 45.73100 JUJU:DEBUG firewaller: started watching machine 0
[LOG] 45.73689 JUJU dummy startinstance, machine 0
[LOG] 45.73688 JUJU:DEBUG firewaller: started watching unit test-service/0
[LOG] 45.74026 JUJU provisioner started machine 0 as instance foo-0
provisioning_test.go:63:
    c.Check(opRecvTimeout(c, op, dummy.OpOpenPorts{}), NotNil)
provisioning_test.go:89:
    c.Errorf("time out wating for operation")
... Error: time out wating for operation

[LOG] 48.74239 JUJU restarting provisioner and firewaller after error: cannot change firewall ports: instance id for machine 0 is not set not found
[LOG] 48.74246 JUJU state: opening state; zookeeper addresses: ["127.0.0.1:51885"]
[LOG] 48.75381 JUJU state: waiting for state to be initialized
[LOG] 48.75438 JUJU:DEBUG provisioning: opened state
[LOG] 48.75537 JUJU provisioner loaded new environment configuration
[LOG] 48.75588 JUJU firewaller loaded new environment configuration
[LOG] 48.75592 JUJU:DEBUG firewaller: started watching machine 0
[LOG] 48.76049 JUJU machine 0 already started as instance "foo-0"
[LOG] 48.76098 JUJU:DEBUG firewaller: started watching unit test-service/0
[LOG] 48.76289 JUJU openPorts 0, []state.Port{state.Port{Protocol:"tcp", Number:999}}
[LOG] 48.76293 JUJU firewaller: opened ports [{tcp 999}] on machine 0
[LOG] 48.76342 JUJU dummy: reset environment
[LOG] 48.84154 JUJU testing: reset zk server at 127.0.0.1:51885