Comment 5 for bug 1789654

Got some debug logs from a failed xen CI run:

http://dd6b71949550285df7dc-dda4e480e005aaa13ec303551d2d8155.r49.cf1.rackcdn.com/13/597613/2/check/dsvm-tempest-neutron-network/cc81140/logs/screen-n-cpu.txt.gz

We see that the inventory is updated properly on startup with the correct allocation ratios:

Aug 29 16:56:06.926641 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.resource_tracker [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] Using cpu_allocation_ratio 16.0 for node: 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07

Aug 29 16:56:07.057208 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: DEBUG nova.compute.provider_tree [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] Updating resource provider 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 generation from 0 to 1 during operation: update_inventory {{(pid=24436) _update_generation /opt/stack/new/nova/nova/compute/provider_tree.py:161}}

Aug 29 16:56:07.057499 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.provider_tree [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] Updating inventory in ProviderTree for provider 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 with inventory: {'VCPU': {'allocation_ratio': 16.0, 'total': 8, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 8}, 'MEMORY_MB': {'allocation_ratio': 1.5, 'total': 12795, 'reserved': 512, 'step_size': 1, 'min_unit': 1, 'max_unit': 12795}, 'DISK_GB': {'allocation_ratio': 1.0, 'total': 47, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 47}}

But then a bit later the cpu_allocation_ratio is set to 0.0 in the _normalize_inventory_from_cn_obj method:

Aug 29 16:58:05.483508 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.resource_tracker [None req-a869fa19-aa9d-4335-9816-42ff29b64d48 None None] Using cpu_allocation_ratio 0.0 for node: 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07

Aug 29 16:58:05.614421 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: DEBUG nova.scheduler.client.report [None req-a869fa19-aa9d-4335-9816-42ff29b64d48 None None] Updated inventory for 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 at generation 2: {'VCPU': {'allocation_ratio': 0.0, 'total': 8, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 8}, 'MEMORY_MB': {'allocation_ratio': 0.0, 'total': 12795, 'reserved': 512, 'step_size': 1, 'min_unit': 1, 'max_unit': 12795}, 'DISK_GB': {'allocation_ratio': 0.0, 'total': 47, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 47}} {{(pid=24436) _update_inventory_attempt /opt/stack/new/nova/nova/scheduler/client/report.py:965}}

So it looks like at some random point the ComputeNode.cpu_allocation_ratio is being set to 0.0 but I don't see any of my debug logging for that in the logs:

https://review.openstack.org/#/c/597560/3/nova/objects/compute_node.py

From the startup logs when it dumps nova-cpu.conf, we see the cpu_allocation_ratio option is not set (default is 0.0):

Aug 29 16:56:03.687759 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: DEBUG oslo_service.service [None req-e4bc9238-0584-459a-aa2c-dc5d425d198a None None] cpu_allocation_ratio = 0.0 {{(pid=24436) log_opt_values /usr/local/lib/python2.7/dist-packages/oslo_config/cfg.py:3019}}