Comment 2 for bug 1292643

I have seen a failure with the same test, the link in the bug description is dead. Below is an extract of my logs.

It looks to be due to the length of time the test are taking to run. The logs show that the service status is unavailable which indicates that more than 60 seconds passed between when the module was loaded and when the tests were run.

2014-03-24 14:15:27.572 | ======================================================================
2014-03-24 14:15:27.572 | FAIL: cinder.tests.api.contrib.test_hosts.HostTestCase.test_list_hosts_with_zone
2014-03-24 14:15:27.572 | tags: worker-0
2014-03-24 14:15:27.572 | ----------------------------------------------------------------------
2014-03-24 14:15:27.572 | Empty attachments:
2014-03-24 14:15:27.573 | pythonlogging:''
2014-03-24 14:15:27.573 | stderr
2014-03-24 14:15:27.573 | stdout
2014-03-24 14:15:27.573 |
2014-03-24 14:15:27.573 | pythonlogging:''-1: {{{
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('qpid = oslo.messaging._drivers.impl_qpid:QpidDriver')
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('zmq = oslo.messaging._drivers.impl_zmq:ZmqDriver')
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('kombu = oslo.messaging._drivers.impl_rabbit:RabbitDriver')
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('rabbit = oslo.messaging._drivers.impl_rabbit:RabbitDriver')
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('fake = oslo.messaging._drivers.impl_fake:FakeDriver')
2014-03-24 14:15:27.573 | found extension EntryPoint.parse('cinder.openstack.common.notifier.no_op_notifier = oslo.messaging.notify._impl_noop:NoOpDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('cinder.openstack.common.notifier.log_notifier = oslo.messaging.notify._impl_log:LogDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('cinder.openstack.common.notifier.test_notifier = oslo.messaging.notify._impl_test:TestDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('cinder.openstack.common.notifier.rpc_notifier2 = oslo.messaging.notify._impl_messaging:MessagingV2Driver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('cinder.openstack.common.notifier.rpc_notifier = oslo.messaging.notify._impl_messaging:MessagingDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('log = oslo.messaging.notify._impl_log:LogDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('messagingv2 = oslo.messaging.notify._impl_messaging:MessagingV2Driver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('noop = oslo.messaging.notify._impl_noop:NoOpDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('routing = oslo.messaging.notify._impl_routing:RoutingDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('test = oslo.messaging.notify._impl_test:TestDriver')
2014-03-24 14:15:27.574 | found extension EntryPoint.parse('messaging = oslo.messaging.notify._impl_messaging:MessagingDriver')
2014-03-24 14:15:27.574 | }}}
2014-03-24 14:15:27.574 |
2014-03-24 14:15:27.575 | Traceback (most recent call last):
2014-03-24 14:15:27.575 | File "cinder/tests/api/contrib/test_hosts.py", line 103, in test_list_hosts_with_zone
2014-03-24 14:15:27.575 | self.assertEqual(hosts, LIST_RESPONSE)
2014-03-24 14:15:27.575 | File "/home/jenkins/workspace/gate-cinder-python26/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 321, in assertEqual
2014-03-24 14:15:27.575 | self.assertThat(observed, matcher, message)
2014-03-24 14:15:27.575 | File "/home/jenkins/workspace/gate-cinder-python26/.tox/py26/lib/python2.6/site-packages/testtools/testcase.py", line 406, in assertThat
2014-03-24 14:15:27.575 | raise mismatch_error
2014-03-24 14:15:27.575 | MismatchError: !=:
2014-03-24 14:15:27.575 | reference = [{'host_name': 'test.host.1',
2014-03-24 14:15:27.575 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:15:27.575 | 'service': 'cinder-volume',
2014-03-24 14:15:27.576 | 'service-state': 'enabled',
2014-03-24 14:15:27.576 | 'service-status': 'unavailable',
2014-03-24 14:15:27.576 | 'zone': 'cinder'},
2014-03-24 14:15:27.576 | {'host_name': 'test.host.1',
2014-03-24 14:15:27.576 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:15:27.576 | 'service': 'cinder-volume',
2014-03-24 14:15:27.576 | 'service-state': 'enabled',
2014-03-24 14:15:27.576 | 'service-status': 'unavailable',
2014-03-24 14:15:27.576 | 'zone': 'cinder'},
2014-03-24 14:15:27.576 | {'host_name': 'test.host.1',
2014-03-24 14:15:27.576 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:15:27.577 | 'service': 'cinder-volume',
2014-03-24 14:15:27.577 | 'service-state': 'enabled',
2014-03-24 14:15:27.577 | 'service-status': 'unavailable',
2014-03-24 14:15:27.577 | 'zone': 'cinder'},
2014-03-24 14:15:27.577 | {'host_name': 'test.host.1',
2014-03-24 14:15:27.577 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:15:27.577 | 'service': 'cinder-volume',
2014-03-24 14:15:27.577 | 'service-state': 'enabled',
2014-03-24 14:15:27.577 | 'service-status': 'unavailable',
2014-03-24 14:15:27.577 | 'zone': 'cinder'}]
2014-03-24 14:15:27.577 | actual = [{'host_name': 'test.host.1',
2014-03-24 14:15:27.577 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:15:27.578 | 'service': 'cinder-volume',
2014-03-24 14:15:27.578 | 'service-state': 'enabled',
2014-03-24 14:15:27.578 | 'service-status': 'available',
2014-03-24 14:15:27.578 | 'zone': 'cinder'},
2014-03-24 14:15:27.578 | {'host_name': 'test.host.1',
2014-03-24 14:15:27.578 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:21:02.610 | 'service': 'cinder-voNo handlers could be found for logger "cinder.volume.drivers.vmware.api"
2014-03-24 14:21:11.472 | lume',
2014-03-24 14:21:11.472 | 'service-state': 'enabled',
2014-03-24 14:21:11.472 | 'service-status': 'available',
2014-03-24 14:21:11.472 | 'zone': 'cinder'},
2014-03-24 14:21:11.472 | {'host_name': 'test.host.1',
2014-03-24 14:21:11.472 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:21:11.472 | 'service': 'cinder-volume',
2014-03-24 14:21:11.473 | 'service-state': 'enabled',
2014-03-24 14:21:11.473 | 'service-status': 'available',
2014-03-24 14:21:11.473 | 'zone': 'cinder'},
2014-03-24 14:21:11.473 | {'host_name': 'test.host.1',
2014-03-24 14:21:11.473 | 'last-update': datetime.datetime(2014, 3, 24, 14, 14, 25, 96923),
2014-03-24 14:21:11.473 | 'service': 'cinder-volume',
2014-03-24 14:21:11.473 | 'service-state': 'enabled',
2014-03-24 14:21:11.473 | 'service-status': 'available',
2014-03-24 14:21:11.473 | 'zone': 'cinder'}]