Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-07-25
22:31:49 eandersson Yea - that is exactly it.
22:32:49 eandersson We are fine with it failing due to the race condition.
22:33:00 sean-k-mooney if we make it to 2020 then this should be fixed in U when all that stuff is in placmenet. but back to your current problem are there any error in the conductor that could indicate why the instance was not put into error state
22:33:20 eandersson Nope just the above errors.
22:34:27 eandersson Starts with the expected
22:34:29 eandersson > Free vcpu 0.00 VCPU < requested 20 VCPU
22:34:51 sean-k-mooney what release are you running?
22:35:26 sean-k-mooney this is where that error is being raised by the way https://github.com/openstack/nova/blob/3370f0f03ce17aaf3a7ebaa95d497f62bef238c0/nova/conductor/manager.py#L630
22:35:31 eandersson Rocky
22:35:58 sean-k-mooney have you disabled the core,ram and disk filters
22:36:04 eandersson We have not
22:36:25 sean-k-mooney http://lists.openstack.org/pipermail/openstack-dev/2018-January/126283.html
22:36:38 sean-k-mooney they have been deprecated and should not be enabled after ocata
22:37:30 sean-k-mooney we stopped reporting the info it used i think in rocky or stien
22:38:02 sean-k-mooney so it might not have been a race we could have elimiated all the host because the filter did not work
22:40:40 eandersson I feel like that would have been a more visible problem thou
22:40:54 eandersson We are seeing this happen in %0.1>
22:41:15 sean-k-mooney ya i think if we got to this part of the code its not the filters
22:41:34 sean-k-mooney you should turn them off however as they will break when you upgade to stien
22:42:23 sean-k-mooney so after we log that message we shoudl raise here https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L601
22:42:50 sean-k-mooney and end up just below it here https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L615
22:43:22 sean-k-mooney at which port we shoudl notify that the vm state should be error
22:47:39 sean-k-mooney https://github.com/openstack/nova/blob/stable/rocky/nova/scheduler/utils.py#L573 is where teh exception is being loged as a waning
22:47:54 sean-k-mooney and we do an instance.save right after it
22:48:19 sean-k-mooney that save should have updated the instance to error
22:48:49 eandersson Does overcommit no longer work in aggregates?
22:49:10 sean-k-mooney we broke that
22:49:29 sean-k-mooney in ocata
22:51:30 sean-k-mooney from ocata on you need to set the overcommit per node
22:51:37 sean-k-mooney in stien we implemneted https://github.com/openstack/nova-specs/blob/master/specs/stein/implemented/initial-allocation-ratios.rst
22:51:56 sean-k-mooney which allow you to manage allocation ratios directly via placement
22:52:09 sean-k-mooney and only specifiy an initall option in teh config
22:53:21 sean-k-mooney eandersson: but yes that is why melwitt sent http://lists.openstack.org/pipermail/openstack-dev/2018-January/126283.html and why we deprecated teh core,ram and disk filters and there aggrate* conterparts
22:56:11 eandersson We might have placement slightly misconfigured
22:57:26 mriedem https://docs.openstack.org/nova/latest/admin/configuration/schedulers.html#allocation-ratios on the scheduler allocation ratio + placement config stuff
22:57:48 mriedem the initial* options are only new in stein
22:57:52 mriedem so that doesn't help you in rocky
22:58:31 sean-k-mooney eandersson: in rocky the nova compute agent will continuoly set the ratios back to whatever is in the compute node config
22:58:32 mriedem you can either override allocation ratios per compute or override the providers in placement...but i think compute will overwrite anything you set out of band
22:58:32 melwitt eandersson: >= ocata there's no notion of a per aggregate allocation ratio. so you have to set them separately per compute host nova.conf
22:58:38 sean-k-mooney or use the defualt in code if not set
22:59:08 eandersson We set the computes wrong for non-overcommited at the moment
22:59:17 eandersson That could be causing the issue
22:59:45 mriedem note that you might not even be getting this far https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L619
22:59:51 sean-k-mooney its tricky becaue it will inially appar to work fine until you start filling your hosts
22:59:56 mriedem ^ is only if you hit a primary host, it fails and you reschedule
23:00:08 mriedem if initial scheduling fails, you should get NoValidHost and the instances should be put into ERROR status
23:00:59 mriedem if initial scheduling fails, you should go here https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L1240
23:01:04 mriedem and the instances go into cell0 with ERROR status
23:01:14 mriedem if your nova_cell0 db fell over then you're missing some updates...
23:01:15 eandersson > | OS-EXT-STS:task_state | scheduling
23:01:16 eandersson > | OS-EXT-STS:vm_state | building
23:01:22 eandersson It was stuck like this until we deleted btw
23:01:28 eandersson 12 hours later
23:01:36 mriedem was the instance ever reported as being on a host?
23:01:38 mriedem or in cell0?
23:01:53 sean-k-mooney mriedem: for some reason that is not happening and the error eandersson is seeing is loged form here https://github.com/openstack/nova/blob/stable/rocky/nova/scheduler/utils.py#L573
23:01:57 eandersson It tried to schedule, but the moment it did it failed with
23:01:58 eandersson > Free vcpu 0.00 VCPU < requested 20 VCPU
23:02:00 mriedem if something fell over in conductor, like the db insert/update, you should have had error logs
23:02:21 mriedem sean-k-mooney: that utils code is called from multple places in conductor
23:02:22 eandersson Only other time I have seen this happen was when we moved nova-conductor to a new host
23:02:34 eandersson and forgot that the db is configured in mysql
23:02:38 sean-k-mooney yes
23:02:42 mriedem sean-k-mooney: https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L1205
23:02:51 sean-k-mooney i tracked it from here https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L601
23:02:57 sean-k-mooney based on teh message that was loged
23:03:33 mriedem ok i think i've reported a bug that we could be failing to set instances to ERROR in build_instances if something fails, i remember talking with gibi about it
23:03:47 melwitt +1 look for db-related errors in the log. that is how I've seen other situations internally where instance got stuck in building/scheduling state
23:04:18 sean-k-mooney eandersson are you seeing the "'Setting instance to %s state.'" message
23:04:53 eandersson Does that have the instance uuid?
23:04:59 sean-k-mooney yes
23:05:13 mriedem rpc could have also fallen over
23:05:15 eandersson Then no
23:05:31 sean-k-mooney mriedem: right that is the only thing between those two lines that could fail
23:05:33 mriedem in that case you'd probably have MessagingTimeouts for the db save rpc calls
23:06:52 eandersson I have 1-2 MySQL server has gone away in the logs, but nothing near the time that happened
23:07:18 eandersson (also those only failed on select 1)
23:07:22 sean-k-mooney well i was wondering if the notifier = rpc.get_notifier(service) line is where it stoped
23:07:34 sean-k-mooney so it might not be related to the db
23:07:36 sean-k-mooney but to rabbit
23:09:11 eandersson hmm does placement do rpc?
23:09:20 eandersson or would this be within nova only?
23:09:25 sean-k-mooney this is in nova
23:09:30 sean-k-mooney in the conductor
23:09:42 sean-k-mooney and no placment does not do any rpc as far as i am aware
23:10:14 sean-k-mooney its just a wsgi app in front of a db
23:10:42 eandersson One thing I don't like with oslo.messaging is that it ack's the message before it gets processed
23:14:24 eandersson oh
23:14:26 eandersson > Exception during message handling
23:14:46 eandersson > Exception during message handling: MaxRetriesExceeded: Exceeded maximum number of retries.
23:15:02 eandersson That is the error I posted above
23:15:08 eandersson And this is from a normal failure
23:15:11 eandersson > Setting instance to ERROR state.: MaxRetriesExceeded: Exceeded maximum number of retries.
23:17:00 mriedem yeah that's this https://opendev.org/openstack/nova/src/branch/master/nova/scheduler/utils.py#L730
23:17:10 mriedem called from https://github.com/openstack/nova/blob/stable/rocky/nova/conductor/manager.py#L619
23:17:22 mriedem the instance change should be saved here https://opendev.org/openstack/nova/src/branch/master/nova/scheduler/utils.py#L736
23:19:32 sean-k-mooney right but in the case where it remains in building we get Exception during message handling:... instead of Setting instance to ERROR state.:...
23:19:50 sean-k-mooney eandersson: is ^ correct
23:19:54 eandersson https://opendev.org/openstack/oslo.messaging/src/branch/master/oslo_messaging/rpc/server.py#L174

Earlier   Later