| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-09-27 | |||
| 14:36:56 | mnaser | filtering happens after placement, correct? | |
| 14:37:03 | mnaser | is there no warning message that says "i couldn't find anything?" | |
| 14:37:26 | mnaser | i guess i can just rely on conductor's "Setting instance to ERROR state." | |
| 14:37:39 | bauzas | mriedem: I'm still working on the vgpu reshape patch, and yes, it's a big hurdle :( | |
| 14:38:22 | bauzas | gibi: FWIW, I need to split https://review.openstack.org/#/c/552924/ in two, one targeted for Stein with no NUMA affinity | |
| 14:38:26 | openstackgerrit | Mark Goddard proposed openstack/nova master: Don't emit warning when ironic properties are zero https://review.openstack.org/605754 | |
| 14:38:48 | bauzas | mnaser: you're right, filters are called after we found an allocation candidate | |
| 14:38:56 | gibi | bauzas: ack | |
| 14:38:57 | openstackgerrit | Merged openstack/nova master: consumer gen: more tests for delete allocation cases https://review.openstack.org/591811 | |
| 14:39:21 | mnaser | thanks bauzas, im relying on this logstash query to monitor those: tags:nova AND message:"Setting instance to ERROR state." AND message:NoValidHost_Remote | |
| 14:39:29 | bauzas | mnaser: but you should at least still have the filtering logs | |
| 14:40:02 | mnaser | yeah the filter logs are there but if 0 computes match at the end, but i'm curious if there's any warning if no allocation candidates that come in the first place | |
| 14:40:05 | bauzas | hah, yeah, but we provide an INFO log saying "heh, 0 hosts found" | |
| 14:40:30 | mnaser | so i guess if its gets 0 allocation candidates, it'll just go through filters and end up with 0 anyways | |
| 14:40:32 | bauzas | I also think we tell in the logs whether we found no candidates after placement | |
| 14:40:39 | mnaser | let me verify | |
| 14:40:43 | bauzas | mnaser: sec, checking the gate | |
| 14:40:46 | bauzas | ok | |
| 14:40:58 | mriedem | i don't think we do, | |
| 14:41:20 | mriedem | we just pass an empty list to ComputeNodeList.get_by_uuids() which returns an empty list and passes that down to the filter scheduler driver which then raises NoValidHost | |
| 14:41:54 | mriedem | oh i guess we log something at debug, | |
| 14:41:58 | mriedem | but that won't be indexed by logstash | |
| 14:42:14 | mnaser | yeah we dont do that, too much data | |
| 14:42:20 | mriedem | https://github.com/openstack/nova/blob/master/nova/scheduler/manager.py#L150 | |
| 14:42:32 | bauzas | mnaser: yup, we do http://logs.openstack.org/72/585672/7/check/tempest-full-py3/f1d0b34/controller/logs/screen-n-sch.txt.gz#_Sep_26_19_02_54_285546 | |
| 14:42:59 | mriedem | mnaser: do you have a failure log to check? | |
| 14:43:03 | mriedem | placement should be logging some stuff now too | |
| 14:43:16 | mnaser | mriedem: i might if it hasnt rotated out | |
| 14:43:24 | bauzas | mriedem: see, we put an info log on how many hosts we got from placement ^ | |
| 14:43:31 | mriedem | as to which "filters" in placement resulted in 0 allocation candidates | |
| 14:43:43 | mriedem | Sep 26 19:02:54.285546 ubuntu-xenial-rax-ord-0002338068 nova-scheduler[18720]: DEBUG nova.filters [None req-8a6074ae-e62f-4ac7-a525-4c411c130c39 tempest-AutoAllocateNetworkTest-2112321998 tempest-AutoAllocateNetworkTest-2112321998] Starting with 1 host(s) {{(pid=20232) get_filtered_objects /opt/stack/nova/nova/filters.py:70}} | |
| 14:43:45 | bauzas | oh shit, that's DEBUG | |
| 14:43:47 | mnaser | mriedem: that is a LOG.debug() so a normal deployment wont see it | |
| 14:43:47 | mnaser | yeah | |
| 14:43:50 | mriedem | right | |
| 14:43:51 | bauzas | my bad | |
| 14:43:54 | mriedem | GAWD! | |
| 14:44:13 | mnaser | i think it's useful to get that warning because a lot of times when placement isnt returning anything | |
| 14:44:15 | bauzas | we info out when we have the filtering results | |
| 14:44:16 | mnaser | i would get really confused | |
| 14:44:19 | mriedem | logging https://github.com/openstack/nova/blob/master/nova/scheduler/manager.py#L150 at INFO might be ok | |
| 14:44:26 | mnaser | yeah but we don't even pass things down to filter | |
| 14:44:29 | bauzas | WTF | |
| 14:44:30 | mnaser | if we get 0 allocation candidates | |
| 14:44:39 | mnaser | if i understand what mriedem linked above | |
| 14:44:42 | bauzas | that's correct | |
| 14:44:50 | bauzas | we just said "meh, that's bad" | |
| 14:45:11 | bauzas | my point was, if we end up with 0 hosts from filtering, some INFO log is done | |
| 14:45:30 | bauzas | so, having the pre-filtering result to be INFO seems consistent and valid to me | |
| 14:45:30 | mnaser | yeah that scenario is taken care of i agree | |
| 14:45:44 | bauzas | lemme dig the code | |
| 14:45:47 | mnaser | i'd even go as far as say that's a warning | |
| 14:45:56 | mnaser | https://github.com/openstack/nova/blob/master/nova/scheduler/manager.py#L150 -- just switch that to warning ? | |
| 14:46:11 | bauzas | but I'm pretty sure we say it's INFO (and no ERROR or warning, because a capacity problem isn't a scheduling problem) | |
| 14:46:29 | mnaser | "change debug level for more info" | |
| 14:46:31 | bauzas | mnaser: I'd advocate for INFO | |
| 14:46:36 | bauzas | no WARN | |
| 14:46:48 | mnaser | it would be consistent with the other stuff | |
| 14:46:52 | bauzas | lemme find the existing log we raise post-filtering | |
| 14:46:53 | mriedem | bauzas: unrelated, but is it just me or do we persist RequestSpec.requested_destination? | |
| 14:46:57 | mriedem | and probably shouldn't... | |
| 14:47:03 | mnaser | bauzas: its info, i have an entry here | |
| 14:47:23 | bauzas | mriedem: wait, wait wait | |
| 14:47:23 | mnaser | bauzas: 2018-09-27 12:37:00.467 394218 INFO nova.filters [<snip>] Filter ComputeFilter returned 0 hosts | |
| 14:47:31 | mriedem | mnaser: i'd say info | |
| 14:47:39 | bauzas | mriedem: probably yet another PEBKAC then | |
| 14:47:41 | mriedem | it's not a warning if someone is trying to resize to a flavor that won't fit anywhere | |
| 14:47:48 | bauzas | (for the persisted field) | |
| 14:47:53 | bauzas | mriedem: zactly | |
| 14:47:59 | bauzas | (16:46:11) bauzas: but I'm pretty sure we say it's INFO (and no ERROR or warning, because a capacity problem isn't a scheduling problem) | |
| 14:48:28 | bauzas | gosh, already 4:46pm here :( | |
| 14:48:48 | mriedem | so if we do persist the request spec requested_destination, i'm just not sure how it doesn't cause problems | |
| 14:49:52 | mriedem | maybe we just get lucky and don't call request_spec.save() on the dirty request spec? | |
| 14:50:16 | mnaser | would we be able to backport that log level change? it's kinda useful. if we can i guess i'll file a bug? | |
| 14:50:30 | mriedem | mnaser: sure | |
| 14:51:01 | bauzas | mriedem: https://github.com/openstack/nova/blob/master/nova/objects/request_spec.py#L29 | |
| 14:51:37 | mriedem | bauzas: that doesn't really tell me anything | |
| 14:51:38 | bauzas | and shit, I threw my day on some internal bug and now I'm done, I have to go into a meeting | |
| 14:52:32 | mriedem | mnaser: this is your justification https://github.com/openstack/nova/blob/c6218428e9b29a2c52808ec7d27b4b21aadc0299/nova/filters.py#L130 | |
| 14:52:46 | mriedem | b/c if we got allocation candidates, but the filters rejected all of them, we log something at INFO | |
| 14:53:25 | mriedem | http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Filtering%20removed%20all%20hosts%20for%20the%20request%20with%5C%22%20AND%20tags%3A%5C%22screen-n-sch.txt%5C%22&from=7d | |
| 14:54:28 | bauzas | mriedem: I guess I have to doublecheck this spaghetti code | |
| 14:55:06 | bauzas | mriedem: but since requested_destination is only set on a live migration or an evacuation, I just wonder whether we .save() this | |
| 14:55:45 | mriedem | it's also set on resize | |
| 14:55:52 | mriedem | b/c you can pass a host on resize since queens | |
| 14:56:04 | mriedem | and on resize we persist the request spec with the new flavor before casting to compute | |
| 14:56:14 | mriedem | i'm pretty sure i raised this with takashi when he was writing that | |
| 14:56:54 | bauzas | ah | |
| 14:56:55 | mriedem | ah this is how he dealt with that https://github.com/openstack/nova/blob/master/nova/compute/api.py#L3505 | |
| 14:56:56 | bauzas | ghood point | |
| 14:57:15 | bauzas | anyway, I need to jump on a call | |
| 14:57:17 | mriedem | but....that's likely not good enough if you resize to a specific host, and then live migrate without specifying a host... | |
| 14:57:51 | bauzas | mriedem: live migrate has the same logic IIRC | |
| 14:58:00 | bauzas | we null out the field | |
| 14:58:26 | mriedem | i don't see that happening | |
| 14:58:28 | mriedem | for live migrate | |
| 14:58:36 | bauzas | oh shit no you're right | |
| 14:58:43 | bauzas | bug bug bug | |
| 14:58:48 | openstackgerrit | Mohammed Naser proposed openstack/nova master: Use INFO for logging no allocation candidates https://review.openstack.org/605765 | |
| 14:58:58 | mnaser | mriedem: bauzas ^ | |