Comment 2 for bug 1341420

Revision history for this message
Robert Collins (lifeless) wrote :

Here is a snippet showing the scheduler thinking that cc0a5455-0978-4687-988e-8f3161cbc521 has no instances on it [host: (undercloud, cc0a5455-0978-4687-988e-8f3161cbc521) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], returning it in a list, and then an instance rescheduling because it actually has no resources:

scheduler.log:
2014-07-14 07:59:34.478 3915 DEBUG nova.scheduler.filter_scheduler [req-d701a25b-7bbc-44ed-9b31-57245e291ae1 None] Weighed [WeighedHost [host: (undercloud, aa4c5e32-46a5-46f2-b312-262a2df23980) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, c63bc9b2-5340-4d46-837a-a4f9a77a00d3) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 1b44fa97-a41f-4aa1-a578-08e82b6ed624) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, a5104c42-37e1-48ef-a5b6-0ba2d8808d8e) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 75e03645-caa6-4d16-9f9d-eb66bf0df769) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, cc0a5455-0978-4687-988e-8f3161cbc521) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 47bbaf38-9e0d-43a0-932b-eb0c9ec7af26) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 9686995e-3ff0-4a10-8c3c-bf3e09ffa770) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 578cf11e-3d79-45ae-883e-583a83f46e23) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, a3f05b92-e693-4338-843b-62c8ccaad397) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 69dc8c40-dd79-4ed6-83a9-374dcb18c39b) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, a76e82f6-b454-4b24-accb-b260fa361f27) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 0270cb74-4784-46ef-8521-38697daafb1d) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, d69b7468-9b3a-44b1-b7b0-4fcf7e3452d5) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, dc86f4ac-b416-410b-ab03-7912f1b9a1b8) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, a9d71ef3-3a7f-4932-a952-534c1128a1e6) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, b07295ee-1c09-484c-9447-10b9efee340c) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, c37db96f-e689-4789-929c-4d45067ba654) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 101a1fba-acd7-4c9e-9e3c-8436c35e4cef) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 7097eae3-c049-4e5a-ad90-dcb54d82d575) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 17fdb7b4-a7cf-4f67-a736-cb84ec3d49e9) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, aede7973-6209-4144-a243-308a03d07e0b) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 3a2ab650-6daf-4a79-9eb4-2ea3f8af8faf) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, dd6eaa66-5289-4689-9034-0d7f706add47) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 381fd1a4-fb1b-411c-a0c8-538781afb48e) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, c4b0f4cc-ca2c-4225-9e84-87c1f4b08ebd) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 38595174-e830-46ce-855e-f54d080b5971) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 7a3ccba1-6db6-4b57-a11f-524ac23bf672) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 34ece3c2-7a0d-42fe-acc3-9e429f587c60) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 9c4dfded-92ef-45e7-9db4-e81ae0d9a249) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 16c374af-2919-4d7d-a281-a69d461adc59) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 69f95874-ddf9-4ede-a6ff-6178d4dcd67c) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 7196471a-12af-4430-89cb-01321f95c942) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 719312a2-f7f7-470b-8cc4-da399af66237) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, ed8bd319-d238-4679-b2c3-0f93d7604bbd) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 8ba5f5ff-3c15-4cb5-b0af-e3ac0f593b95) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 30837020-4728-459e-a5bd-dd19827ac1b5) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 53a0adf4-802c-4e52-8af4-2205e5d8343e) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0], WeighedHost [host: (undercloud, 75fad715-3029-43b8-a47c-891b680fe94e) ram:98304 disk:1638400 io_ops:0 instances:0, weight: 1.0]] _schedule /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/scheduler/filter_scheduler.py:274
2014-07-14 07:59:37.940 3915 DEBUG nova.filters [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] Starting with 46 host(s) get_filtered_objects /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/filters.py:70
2014-07-14 07:59:37.941 3915 DEBUG nova.scheduler.filters.retry_filter [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] Host [u'undercloud', u'cc0a5455-0978-4687-988e-8f3161cbc521'] fails. Previously tried hosts: [[u'undercloud', u'cc0a5455-0978-4687-988e-8f3161cbc521']] host_passes /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/scheduler/filters/retry_filter.py:42

nova-compute.log:
2014-07-14 07:59:37.845 20886 DEBUG nova.openstack.common.lockutils [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] Got semaphore / lock "instance_claim" inner /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/openstack/common/lockutils.py:324
2014-07-14 07:59:37.845 20886 DEBUG nova.compute.resource_tracker [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] Memory overhead for 98304 MB instance; 0 MB instance_claim /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/resource_tracker.py:117
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Attempting claim: memory 98304 MB, disk 1600 GB, VCPUs 24
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Total memory: 98304 MB, used: 98304.00 MB
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] memory limit: 98304.00 MB, free: 0.00 MB
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Total disk: 1600 GB, used: 1600.00 GB
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] disk limit not specified, defaulting to unlimited
2014-07-14 07:59:37.847 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Total CPUs: 24 VCPUs, used: 24.00 VCPUs
2014-07-14 07:59:37.848 20886 AUDIT nova.compute.claims [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] CPUs limit not specified, defaulting to unlimited
2014-07-14 07:59:37.848 20886 DEBUG nova.openstack.common.lockutils [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] Semaphore / lock released "instance_claim" inner /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/openstack/common/lockutils.py:328
2014-07-14 07:59:37.848 20886 DEBUG nova.compute.manager [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Insufficient compute resources: Free memory 0.00 MB < requested 98304 MB. _build_and_run_instance /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/manager.py:1981
2014-07-14 07:59:37.849 20886 DEBUG nova.compute.utils [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Insufficient compute resources: Free memory 0.00 MB < requested 98304 MB. notify_about_instance_usage /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/utils.py:291
2014-07-14 07:59:37.850 20886 DEBUG nova.compute.manager [req-0015ebce-2a43-45d6-9dda-e7c0d1b61df9 None] [instance: 564bbc63-8bf2-4fa0-8353-ba246bd2ba15] Build of instance 564bbc63-8bf2-4fa0-8353-ba246bd2ba15 was re-scheduled: Insufficient compute resources: Free memory 0.00 MB < requested 98304 MB. do_build_and_run_instance /opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/manager.py:1896