Comment 1 for bug 1651091

The race here is as follows

   477 def _assert_instance_states(self, instance_id, expected_states,
   478 fast_fail_status=None,
   479 require_all_states=False):
   480 """Keep polling for the expected instance states until the instance
   481 acquires either the last or fast-fail state.
   482
   483 If the instance state does not match the state expected at the time of
   484 polling (and 'require_all_states' is not set) the code assumes the
   485 instance had already acquired before and moves to the next expected
   486 state.
   487 """
   488
   489 self.report.log("Waiting for states (%s) for instance: %s" %
   490 (expected_states, instance_id))
   491
   492 if fast_fail_status is None:
   493 fast_fail_status = ['ERROR', 'FAILED']
   494 found = False
   495 for status in expected_states:
   496 if require_all_states or found or self._has_status(
   497 instance_id, status, fast_fail_status=fast_fail_status):
   498 found = True
   499 start_time = timer.time()
   500 try:
   501 poll_until(lambda: self._has_status(
   502 instance_id, status,
   503 fast_fail_status=fast_fail_status),
   504 sleep_time=self.def_sleep_time,
   505 time_out=self.def_timeout)
   506 self.report.log("Instance '%s' has gone '%s' in %s." %
   507 (instance_id, status,
   508 self._time_since(start_time)))
   509 except exception.PollTimeOut:
   510 self.report.log(
   511 "Status of instance '%s' did not change to '%s' "
   512 "after %s."
   513 % (instance_id, status, self._time_since(start_time)))
   514 return False
   515 else:
   516 self.report.log(
   517 "Instance state was not '%s', moving to the next expected "
   518 "state." % status)
   519
   520 return found

The code at 496 finds the instance to have the right state and goes into the try at 501 but the instance has changed state by that point and the test at 501 now times out.