Earlier  
Posted Nick Remark
#openstack-nova - 2018-08-30
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 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:27 mriedem we have this with the wrong value
13:32:33 mriedem and we have a good update here:
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: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: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: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 and then the bad update:
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 # we break compatibility with old Liberty computes
13:54:30 mriedem # TODO(sbauza): Remove that in the next major version bump where
13:54:30 mriedem sean-k-mooney: there are todos
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 openstack Launchpad bug 1789654 in OpenStack Compute (nova) rocky "placement allocation_ratio initialized with 0.0" [High,Confirmed]
14:04:07 mriedem posted debug notes in https://bugs.launchpad.net/nova/+bug/1789654
14:05:33 mriedem if the allocation ratio in the db record is 16.0 but the object value in the RT is 0.0, we know that _copy_resources is what's changing our in-memory value and we're not persisting the change
14:06:14 sean-k-mooney mriedem: well we dont actully want to persist the change to the db in this case
14:06:22 sean-k-mooney the db has the correct default
14:06:54 mriedem the db values are likely actually NULL
14:07:03 mriedem which is what the compute node object keys off of
14:07:09 bauzas mriedem: so we directly change the object value without reading it from the DB thru the facade ?
14:07:14 mriedem https://github.com/openstack/nova/blob/f534495a427d1683bc536cf003ec02edbf6d8a45/nova/objects/compute_node.py#L194
14:07:21 sean-k-mooney the db perhaps but the object that is constrted form the db entry gets defaulted correctly
14:07:48 sean-k-mooney yep that is the line i was thinking of
14:07:53 mriedem sean-k-mooney: yes but my theory is we're not "fixing" the allocation ratios within the object after setting the values to 0.0
14:07:59 mriedem because of https://review.openstack.org/#/c/520024/
14:08:25 mriedem zigo: is it possible that you have ^ in your nova package somehow?
14:08:31 sean-k-mooney right because we removed the update call which update the resouce tracker
14:08:51 mriedem zigo: iow, are your nova rocky packages based on stable/rocky or 18.0.0 tags rather than just pulling from master?
14:09:27 sean-k-mooney mriedem: we proably should have kept the self._update on line 574
14:09:50 mriedem that wouldn't have helped us in this case,
14:09:58 mriedem that's for a nova-compute restart where the cn record already exists,
14:10:04 mriedem what we're hitting is the condition above
14:10:05 bauzas mriedem: just to be clear, https://github.com/openstack/nova/blob/f534495a427d1683bc536cf003ec02edbf6d8a45/nova/objects/compute_node.py#L199-L207 is only intended to be executed if on nova-scheduler
14:10:28 bauzas mriedem: because https://github.com/openstack/nova/blob/f534495a427d1683bc536cf003ec02edbf6d8a45/nova/objects/compute_node.py#L198 will always tell you a value if you're on nova-compute
14:10:46 mriedem umm
14:11:06 mriedem that will also always tell you a value if you're on nova-scheduler
14:11:09 mriedem b/c conf is global
14:11:15 mriedem and the value defaults to 0.0 in config
14:12:19 bauzas if executed in separate workers, CONF.cpu_allocation_ratio wouldn't be defined for nova-scheduler
14:12:36 bauzas oh wait, sec
14:12:51 mriedem it doesn't need to be defined in config, we have a default
14:12:53 mriedem which is global
14:13:17 mriedem anyway, that doesn't really matter for this bug
14:13:28 mriedem the compute reports the inventory to placement and is reporting 0.0 allocation ratios
14:14:20 cdent mriedem: one thing that remains unclear for me (becuase apparently I can't read python code) is why the second inventory PUT (the one with the 0.0) is happening at all (and so soon)

Earlier   Later