Bug 951309

beaker-provision sometimes runs commands more than once.

In order to trigger this, beaker-provision must receive several new commands at once that take longer than the polling interval (20 seconds) to complete. I can reproduce it in my devel environment just by queueing a job with two recipes. (Adding more recipes should make it more likely to be triggered, in labs where the mirror is faster or for power types which are faster than virsh.)

The problem was introduced in commit 1a180c0f in Beaker 0.10.1 but became more noticeable in 0.12.0 because of the new code for enforcing task status consistency:

2013-04-12 12:51:55,991 bkr.server.model ERROR command callback failed: Status for T:1084 updated in another transaction

This is the also the root cause of the duplicate system_status_duration rows in bug 903902.

The problem is with these lines in the poll() method in LabController/src/bkr/labcontroller/provision.py:

 73)             greenlet.link(lambda greenlet: self._handler_complete(
 74)                     greenlet, command['id']))

Because of Python's late binding, the 'command' variable in the lambda references the final command in the loop, not the one being handled at the time the lambda was created. So commands might be removed from the self.commands dict before they are actually completed, causing them to be run again on the next iteration of the polling loop.