Just filter on error, can see that sometimes it takes a very long time to run:
2014-09-23 16:51:51.494 32200 ERROR nova.compute.manager [-] update_available_resource took 0.296182155609 secs
2014-09-23 16:52:40.761 32200 ERROR nova.compute.manager [-] update_available_resource took 0.17028093338 secs
2014-09-23 16:53:40.887 32200 ERROR nova.compute.manager [-] update_available_resource took 0.109967947006 secs
2014-09-23 16:54:41.639 32200 ERROR nova.compute.manager [-] update_available_resource took 0.105166912079 secs
2014-09-23 16:55:43.663 32200 ERROR nova.compute.manager [-] update_available_resource took 0.128235816956 secs
2014-09-23 16:56:45.131 32200 ERROR nova.compute.manager [-] update_available_resource took 1.59690380096 secs
2014-09-23 16:57:46.012 32200 ERROR nova.compute.manager [-] update_available_resource took 1.47475099564 secs
2014-09-23 16:58:46.088 32200 ERROR nova.compute.manager [-] update_available_resource took 1.55297207832 secs
2014-09-23 16:59:47.132 32200 ERROR nova.compute.manager [-] update_available_resource took 2.59809398651 secs
2014-09-23 17:00:46.144 32200 ERROR nova.compute.manager [-] update_available_resource took 0.605221986771 secs
2014-09-23 17:00:52.047 32200 ERROR nova.compute.manager [-] [instance: 56a02698-d951-436c-82f4-c0ec4dafa199] An error occurred while refreshing the network cache.
2014-09-23 17:01:47.637 32200 ERROR nova.compute.manager [-] update_available_resource took 1.10360908508 secs
2014-09-23 17:02:50.673 32200 ERROR nova.compute.manager [-] update_available_resource took 2.13903999329 secs
2014-09-23 17:03:50.816 32200 ERROR nova.compute.manager [-] update_available_resource took 1.28159403801 secs
2014-09-23 17:04:51.604 32200 ERROR nova.compute.manager [-] update_available_resource took 1.06992197037 secs
2014-09-23 17:05:51.215 32200 ERROR nova.compute.manager [-] update_available_resource took 0.680285930634 secs
2014-09-23 17:08:04.722 32200 ERROR nova.compute.manager [-] update_available_resource took 73.1881198883 secs
2014-09-23 17:08:08.014 32200 ERROR nova.compute.manager [-] update_available_resource took 0.926635026932 secs
2014-09-23 17:08:54.234 32200 ERROR nova.compute.manager [-] update_available_resource took 0.698902130127 secs
2014-09-23 17:09:54.044 32200 ERROR nova.compute.manager [-] update_available_resource took 0.510345935822 secs
2014-09-23 17:10:56.615 32200 ERROR nova.compute.manager [-] update_available_resource took 1.00940585136 secs
2014-09-23 17:11:56.171 32200 ERROR nova.compute.manager [-] update_available_resource took 0.573462963104 secs
2014-09-23 17:12:59.232 32200 ERROR nova.compute.manager [-] update_available_resource took 1.69808387756 secs
2014-09-23 17:13:59.958 32200 ERROR nova.compute.manager [-] update_available_resource took 0.424647808075 secs
2014-09-23 17:15:01.642 32200 ERROR nova.compute.manager [-] update_available_resource took 1.10785794258 secs
2014-09-23 17:16:03.711 32200 ERROR nova.compute.manager [-] update_available_resource took 0.878036975861 secs
2014-09-23 17:17:05.015 32200 ERROR nova.compute.manager [-] update_available_resource took 1.43100094795 secs
2014-09-23 17:18:06.709 32200 ERROR nova.compute.manager [-] update_available_resource took 1.17440009117 secs
2014-09-23 17:19:08.492 32200 ERROR nova.compute.manager [-] update_available_resource took 0.958671092987 secs
2014-09-23 17:20:08.931 32200 ERROR nova.compute.manager [-] update_available_resource took 1.20312309265 secs
2014-09-23 17:23:05.525 32200 ERROR nova.compute.manager [-] update_available_resource took 116.665913105 secs
2014-09-23 17:24:05.693 32200 ERROR nova.compute.manager [-] update_available_resource took 0.773860931396 secs
2014-09-23 17:25:06.691 32200 ERROR nova.compute.manager [-] update_available_resource took 0.866034984589 secs
When its slow it seems to be associated with this warning:
2014-09-23 17:23:04.983 32200 WARNING nova.virt.libvirt.driver [-] Periodic task is updating the host stats, it is trying to get disk info for instance-0000009d, but the backing volume block device was removed by concurrent operations such as resize. Error: No volume Block Device Mapping at path: /dev/disk/by-path/ip-127.0.0.1:3260-iscsi-iqn.2010-10.org.openstack:volume-e6d9fe98-151d-47ba-ae07-ffe6742671c6-lun-1
the periodic task is not slow without this warning being present.
I added some time testing for the update_ available_ resources periodic task:
http:// logs.openstack. org/38/ 123438/ 1/check/ check-tempest- dsvm-neutron- full/95c1ef2/ logs/screen- n-cpu.txt. gz?
Just filter on error, can see that sometimes it takes a very long time to run:
2014-09-23 16:51:51.494 32200 ERROR nova.compute. manager [-] update_ available_ resource took 0.296182155609 secs manager [-] update_ available_ resource took 0.17028093338 secs manager [-] update_ available_ resource took 0.109967947006 secs manager [-] update_ available_ resource took 0.105166912079 secs manager [-] update_ available_ resource took 0.128235816956 secs manager [-] update_ available_ resource took 1.59690380096 secs manager [-] update_ available_ resource took 1.47475099564 secs manager [-] update_ available_ resource took 1.55297207832 secs manager [-] update_ available_ resource took 2.59809398651 secs manager [-] update_ available_ resource took 0.605221986771 secs manager [-] [instance: 56a02698- d951-436c- 82f4-c0ec4dafa1 99] An error occurred while refreshing the network cache. manager [-] update_ available_ resource took 1.10360908508 secs manager [-] update_ available_ resource took 2.13903999329 secs manager [-] update_ available_ resource took 1.28159403801 secs manager [-] update_ available_ resource took 1.06992197037 secs manager [-] update_ available_ resource took 0.680285930634 secs manager [-] update_ available_ resource took 73.1881198883 secs manager [-] update_ available_ resource took 0.926635026932 secs manager [-] update_ available_ resource took 0.698902130127 secs manager [-] update_ available_ resource took 0.510345935822 secs manager [-] update_ available_ resource took 1.00940585136 secs manager [-] update_ available_ resource took 0.573462963104 secs manager [-] update_ available_ resource took 1.69808387756 secs manager [-] update_ available_ resource took 0.424647808075 secs manager [-] update_ available_ resource took 1.10785794258 secs manager [-] update_ available_ resource took 0.878036975861 secs manager [-] update_ available_ resource took 1.43100094795 secs manager [-] update_ available_ resource took 1.17440009117 secs manager [-] update_ available_ resource took 0.958671092987 secs manager [-] update_ available_ resource took 1.20312309265 secs manager [-] update_ available_ resource took 116.665913105 secs manager [-] update_ available_ resource took 0.773860931396 secs manager [-] update_ available_ resource took 0.866034984589 secs
2014-09-23 16:52:40.761 32200 ERROR nova.compute.
2014-09-23 16:53:40.887 32200 ERROR nova.compute.
2014-09-23 16:54:41.639 32200 ERROR nova.compute.
2014-09-23 16:55:43.663 32200 ERROR nova.compute.
2014-09-23 16:56:45.131 32200 ERROR nova.compute.
2014-09-23 16:57:46.012 32200 ERROR nova.compute.
2014-09-23 16:58:46.088 32200 ERROR nova.compute.
2014-09-23 16:59:47.132 32200 ERROR nova.compute.
2014-09-23 17:00:46.144 32200 ERROR nova.compute.
2014-09-23 17:00:52.047 32200 ERROR nova.compute.
2014-09-23 17:01:47.637 32200 ERROR nova.compute.
2014-09-23 17:02:50.673 32200 ERROR nova.compute.
2014-09-23 17:03:50.816 32200 ERROR nova.compute.
2014-09-23 17:04:51.604 32200 ERROR nova.compute.
2014-09-23 17:05:51.215 32200 ERROR nova.compute.
2014-09-23 17:08:04.722 32200 ERROR nova.compute.
2014-09-23 17:08:08.014 32200 ERROR nova.compute.
2014-09-23 17:08:54.234 32200 ERROR nova.compute.
2014-09-23 17:09:54.044 32200 ERROR nova.compute.
2014-09-23 17:10:56.615 32200 ERROR nova.compute.
2014-09-23 17:11:56.171 32200 ERROR nova.compute.
2014-09-23 17:12:59.232 32200 ERROR nova.compute.
2014-09-23 17:13:59.958 32200 ERROR nova.compute.
2014-09-23 17:15:01.642 32200 ERROR nova.compute.
2014-09-23 17:16:03.711 32200 ERROR nova.compute.
2014-09-23 17:17:05.015 32200 ERROR nova.compute.
2014-09-23 17:18:06.709 32200 ERROR nova.compute.
2014-09-23 17:19:08.492 32200 ERROR nova.compute.
2014-09-23 17:20:08.931 32200 ERROR nova.compute.
2014-09-23 17:23:05.525 32200 ERROR nova.compute.
2014-09-23 17:24:05.693 32200 ERROR nova.compute.
2014-09-23 17:25:06.691 32200 ERROR nova.compute.
When its slow it seems to be associated with this warning:
2014-09-23 17:23:04.983 32200 WARNING nova.virt. libvirt. driver [-] Periodic task is updating the host stats, it is trying to get disk info for instance-0000009d, but the backing volume block device was removed by concurrent operations such as resize. Error: No volume Block Device Mapping at path: /dev/disk/ by-path/ ip-127. 0.0.1:3260- iscsi-iqn. 2010-10. org.openstack: volume- e6d9fe98- 151d-47ba- ae07-ffe6742671 c6-lun- 1
the periodic task is not slow without this warning being present.