Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2018-08-30
13:16:04 mriedem alex_xu: ^ looks like a behavior change
13:17:43 mriedem cdent: oh i remember now, i had to re-run the xen ci patch last night b/c it wasn't picking up my dependency in depends-on: <url> form b/c it's still using zuul v2
13:18:08 cdent mriedem: fun!
13:18:37 mriedem the logs are there in the latest failed run though
13:18:40 mriedem http://dd6b71949550285df7dc-dda4e480e005aaa13ec303551d2d8155.r49.cf1.rackcdn.com/13/597613/2/check/dsvm-tempest-neutron-network/cc81140/logs/screen-n-cpu.txt.gz
13:18:48 mriedem looking at req-99d9d496-6720-4837-a2ee-560605fd1afe
13:18:56 mriedem naichuans: efried: ^
13:19:28 mriedem 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
13:19:41 mriedem Aug 29 16:56:06.926926 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.resource_tracker [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] RT: Sending compute node inventory changes back toplacement for node: 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07
13:19:55 mriedem WAH WAH
13:19:55 mriedem Aug 29 16:56:06.965945 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.provider_tree [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] Inventory has not changed in ProviderTree for provider: 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07
13:20:23 mriedem hmm, but then it says it does update inventory
13:20:24 mriedem 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-citr
13:20:24 mriedem ia-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,
13:20:24 mriedem n_unit': 1, 'max_unit': 12795}, 'DISK_GB': {'allocation_ratio': 1.0, 'total': 47, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 47}}
13:20:48 mriedem there the allocation ratios are all correct
13:21:08 mriedem Aug 29 16:56:07.058213 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: DEBUG nova.scheduler.client.report [None req-99d9d496-6720-4837-a2ee-560605fd1afe None None] Updated inventory for 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 at generation 1: {'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
13:21:08 mriedem 12, '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}} {{(pid=24436) _update_inventory_attempt /opt/stack/new/nova/nova/scheduler/client/report.py:965}}
13:21:42 cdent goes to zero at 16:58:05.613741
13:23:03 cdent right after an "Inventory has not changed in ProviderTree for provider"
13:23:14 openstackgerrit Radoslav Gerganov proposed openstack/nova-specs master: VMware: add support for live migration https://review.openstack.org/598163
13:24:40 mriedem 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
13:24:41 mriedem yeah wtf
13:25:09 mriedem that's in the _normalize_inventory_from_cn_obj method
13:25:21 cdent I'm gonna go with "something is being side-effecty"
13:25:33 mriedem somehow the ComputeNode.cpu_allocation_ratio is getting persisted as 0.0 maybe?
13:25:54 cdent you added a log for that didn't you?
13:26:00 mriedem yes and i don't see either of them
13:26:03 mriedem https://review.openstack.org/#/c/597560/3/nova/objects/compute_node.py.
13:26:50 cdent w & the t & the actual f
13:31:34 cdent write before the correct inventory is sent we have this line "Using cpu_allocation_ratio 0.0 for node [...]". that value, I would guess, is somehow being used for the _next_ inventory
13:32:22 mriedem i noticed that also,
13:32:26 cdent we're getting update inventories within 2 ms of one another. first one right, second one wrong
13:32:27 mriedem we have this with the wrong value
13:32:27 mriedem 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
13:32:33 mriedem and we have a good update here:
13:32:38 mriedem Aug 29 16:58:05.525151 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.provider_tree [None req-a869fa19-aa9d-4335-9816-42ff29b64d48 None None] Updating inventory in ProviderTree for provider 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 with inventory: {u'VCPU': {u'allocation_ratio': 16.0, u'total': 8, u'reserved': 0, u'step_size': 1, u'min_unit': 1, u'max_unit': 8}, u'MEMORY_MB': {u'allocation_ratio':
13:32:38 mriedem , u'total': 12795, u'reserved': 512, u'step_size': 1, u'min_unit': 1, u'max_unit': 12795}, u'DISK_GB': {u'allocation_ratio': 1.0, u'total': 47, u'reserved': 0, u'step_size': 1, u'min_unit': 1, u'max_unit': 47}}
13:32:47 mriedem and then the bad update:
13:32:47 mriedem Aug 29 16:58:05.613741 dsvm-devstack-citrix-mia-nodepool-1379368 nova-compute[24436]: INFO nova.compute.provider_tree [None req-a869fa19-aa9d-4335-9816-42ff29b64d48 None None] Updating inventory in ProviderTree for provider 2f5a2e04-1b61-4437-ab6e-8dbbf797dc07 with inventory: {'VCPU': {'allocation_ratio': 0.0, 'total': 8, 'reserved': 0, 'step_size': 1, 'min_unit': 1, 'max_unit': 8}, 'MEMORY_MB': {'allocation_ratio': 0.0, 'tot
13:32:47 mriedem 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}}
13:42:51 mriedem hmm https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L622
13:43:03 mriedem ^ we set the ComputeNode.cpu_allocation_ratio based on the config, which is 0.0
13:43:45 sean-k-mooney mriedem: so it had the correct allocation ratio then it was chaged to 0.0
13:43:46 mriedem i bet that is the problem
13:45:10 mriedem _copy_resources is called from _init_compute_node,
13:45:29 cdent mriedem: but none of that stuff is new is it?
13:45:37 mriedem and on initial create of the compute node record, the ComputeNode.create() method will call _from_db_object at the end and fix the 0.0 allocation ratio to the hard-coded one,
13:45:57 openstackgerrit Takashi NATSUME proposed openstack/nova master: Transform compute_task notifications https://review.openstack.org/482629
13:46:09 mriedem then in a periodic run, the cn already exists, we'll copy over the busted 0.0 allocations from config, but b/c we removed the _update calls there, we don't fix the allocation ratios
13:46:30 cdent ah, there's the rub
13:46:31 mriedem which is https://review.openstack.org/#/c/520024/
13:46:40 mriedem but that doesn't explain how zigo was hitting this on rocky
13:46:50 mriedem or how we're *not* hitting this in the normal gate
13:47:17 openstackgerrit Merged openstack/nova master: (Re)start caching scheduler after starting computes in tests https://review.openstack.org/597606
13:47:26 cdent does the normal gate set conf?
13:47:31 mriedem no
13:47:34 sean-k-mooney mriedem: is there a reason we do not set the defults here https://github.com/openstack/nova/blob/master/nova/conf/compute.py#L413-L416
13:47:49 mriedem http://logs.openstack.org/24/520024/9/check/tempest-full/cbd025d/controller/logs/etc/nova/nova-cpu_conf.txt.gz
13:48:00 mriedem sean-k-mooney: yes read the help text
13:48:27 alex_xu mriedem: yea, sounds like
13:49:48 sean-k-mooney mriedem: hum right... so we can single to use the schduler nodes value
13:50:21 mriedem this was the change to make the defaults 0.0 https://github.com/openstack/nova/commit/4a9e14a7a73832b6b878160ba4a45f259d078d27
13:51:30 sean-k-mooney mriedem: "That compat mode (having ratios defaulted to 0.0) is only planned to be kept for
13:51:31 sean-k-mooney Liberty and will be removed in the next release (Mitaka)
13:52:03 sean-k-mooney well that never happened
13:52:46 mriedem talk to bauzas
13:54:06 bauzas I'm back
13:54:10 sean-k-mooney mriedem: its just one of those things if there is not an explit TODO in teh code you can grep for at the end of a release its easy to miss removing this stuff
13:54:14 mriedem in a few months i'll be able to remove all the req spec compat code
13:54:30 mriedem sean-k-mooney: there are todos
13:54:30 mriedem # TODO(sbauza): Remove that in the next major version bump where
13:54:30 mriedem # we break compatibility with old Liberty computes
13:54:46 bauzas I think the comments explained the 0.0 values
13:55:00 bauzas it's because of an upgrade concern between Liberty and Mitaka
13:55:02 mriedem https://github.com/openstack/nova/blob/master/nova/objects/compute_node.py#L186
13:55:27 mriedem cdent: so i'm adding more debug logs to verify where i think this is breaking down and will get another xen run
13:55:32 bauzas it was for knowing whether the operator was modifying the options directly, or using the defaults
13:55:37 bauzas sean-k-mooney: ^
13:55:47 bauzas (a signal)
13:55:55 cdent mriedem: sounds like a good plan
13:56:12 sean-k-mooney bauzas: yes the commit and comments make that clear but presumably we should have deleted it before rocky
13:56:34 bauzas indeed
13:57:18 sean-k-mooney bauzas: i assume the reason that there was not a explcit optin bool flag was so that we did not need modify the configs to get the new behavior if the operator had not overriden it before
13:58:39 bauzas sean-k-mooney: it was because we changed so the options were per compute
13:58:46 mriedem in case you haven't noticed, the allocation ratio stuff is still biting us in the ass, so this isn't a very clear "now we can just remove stuff" case
13:58:58 mriedem i think jaypipes has at least 10 specs for dealing with this
13:59:27 bauzas mriedem: because we now use the ratio values directly without using the ComputeNode object
13:59:30 mriedem and this is such a mine field i'm afraid to change anything
13:59:40 jaypipes mriedem: yeah. :(
13:59:44 mriedem bauzas: not really
14:00:17 mriedem bauzas: this is where we get the allocatoin ratio to put into placement inventory https://github.com/openstack/nova/blob/master/nova/compute/resource_tracker.py#L107
14:00:21 mriedem if that's what you're referring to
14:00:25 mriedem which uses the compute node facade
14:00:35 sean-k-mooney the main issue we have at the moment is we have 2 different sets fo defaults that get applied depending on the code path we take for the same value
14:00:44 mriedem and because of https://review.openstack.org/#/c/520024/ it looks like we've side-stepped the facade from breaking us
14:03:16 bauzas mriedem: I'm trying to understand the problems, I should look at jaypipes's specs
14:03:44 openstackgerrit Matt Riedemann proposed openstack/nova master: Add debug logs for when provider inventory changes https://review.openstack.org/597560
14:04:07 mriedem posted debug notes in https://bugs.launchpad.net/nova/+bug/1789654
14:04:07 openstack Launchpad bug 1789654 in OpenStack Compute (nova) rocky "placement allocation_ratio initialized with 0.0" [High,Confirmed]

Earlier   Later