| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2022-05-05 | |||
| 17:10:13 | sean-k-mooney | i.e. that python logging is broken and has been for ever | |
| 17:10:16 | mnaser | sean-k-mooney: sadly it looks like the logs got rotated out :( | |
| 17:10:29 | mnaser | with the kill -USR2 it wiped a bunch of the old logs | |
| 17:10:58 | sean-k-mooney | are you using oslo.log's logrotation feature | |
| 17:11:09 | sean-k-mooney | or using logrotate externally | |
| 17:11:22 | mnaser | no, this is bc we run stuff inside k8s, so the max-log-size feature or whatever its called i believe hit here | |
| 17:11:27 | sean-k-mooney | kill -USR2 usually requires a process restart to recover form | |
| 17:11:59 | sean-k-mooney | ack so dumping the GMR proably caused the pod to be restarted | |
| 17:11:59 | mnaser | to me it sounds like there should not be a traceback for this thing to start with | |
| 17:13:43 | mnaser | this is wallaby blergh | |
| 17:14:12 | Uggla | sean-k-mooney, ok by the way we (with Artom) added some tests to ensure a cold migration after shelve/unshelve to host is moving back the host to the origin host. | |
| 17:15:24 | Uggla | sean-k-mooney, but we can discuss that tomorrow, it will let you think about it. | |
| 17:15:31 | mnaser | ok it looks like timeout was raised, then since `vif_plugging_is_fatal`, that raises another exception again, which bubbles back up to the `except Exception` | |
| 17:15:43 | mnaser | https://github.com/openstack/nova/blob/stable/wallaby/nova/virt/libvirt/driver.py#L7235-L7266 | |
| 17:16:32 | mnaser | then we LOG.error() the whole stack, which seems to add up | |
| 17:17:24 | sean-k-mooney | causign this expct block to be taken | |
| 17:17:24 | sean-k-mooney | that is timeing out after 300 seconds | |
| 17:17:24 | sean-k-mooney | we start waiting in this context manager https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L7491-L7494= | |
| 17:17:24 | sean-k-mooney | so we plug the start a timer to with for the viff plugged event then we plug the vifs then we creat the guest | |
| 17:17:24 | sean-k-mooney | so its being rasised form here https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L7499= | |
| 17:19:38 | mnaser | https://eventlet.net/doc/modules/timeout.html | |
| 17:19:42 | mnaser | "If the code block catches and doesn’t re-raise BaseException (for example, with except:), then it will catch the Timeout exception, and might not abort as intended." | |
| 17:19:42 | mnaser | "If the code block catches and doesn’t re-raise BaseException (for example, with except:), then it will catch the Timeout exception, and might not abort as intended." | |
| 17:19:46 | sean-k-mooney | if you have logs for this in the future you could proably check fo rthis log https://github.com/openstack/nova/blob/7520711a0e3b20354c0a9d46cb1dd62c8f56db24/nova/compute/manager.py#L559-L569= | |
| 17:20:49 | sean-k-mooney | mnaser: i dont think we are incorectly cathching this | |
| 17:24:08 | sean-k-mooney | hum https://github.com/openstack/nova/blob/7520711a0e3b20354c0a9d46cb1dd62c8f56db24/nova/compute/manager.py#L2202-L2242= | |
| 17:25:44 | sean-k-mooney | we are not using a threadpool here so this should be fine | |
| 17:25:50 | mnaser | i believ this issue surfaces if you have a lot of port plugging timeouts, which is why it might not be noticed | |
| 17:26:09 | mnaser | (i could solve this by figuring out why the ports are all timing out being plugged, since that is the cause, but still seems to be an issue) | |
| 17:26:31 | mnaser | i wonder if it can be reproduced by spinning up a bunch of instances with n-ovs-agent shut down for example | |
| 17:27:01 | sean-k-mooney | but it proably woudl be simpler to reproduce in teh func test | |
| 17:27:19 | sean-k-mooney | just mock out the part of the nueton fixture that sends the event | |
| 17:27:45 | sean-k-mooney | what i dont get is why is the thread not being resumed | |
| 17:28:31 | sean-k-mooney | it raising the excption (either timeour or vif plugged) but nothign is resuming the greenthreadn and its just waiting forever | |
| 17:28:41 | sean-k-mooney | i wonder if this because we use spawn_n | |
| 17:28:49 | sean-k-mooney | instead of spawn | |
| 17:30:02 | sean-k-mooney | mnaser: gibi mentioned something abtou this in a differnt context https://review.opendev.org/c/openstack/nova/+/825015/4/nova/healthcheck/manager.py#214= | |
| 17:32:19 | sean-k-mooney | maybe we shoudl be useing spawn here instead https://github.com/openstack/nova/blob/7520711a0e3b20354c0a9d46cb1dd62c8f56db24/nova/compute/manager.py#L2242-L2247 | |
| 17:35:15 | sean-k-mooney | mnaser: this is hte comment that gibi was intening i read i think | |
| 17:35:17 | sean-k-mooney | https://review.opendev.org/c/openstack/nova/+/813114/1..4//COMMIT_MSG#b19= | |
| 17:35:43 | sean-k-mooney | https://github.com/eventlet/eventlet/issues/731#issuecomment-953761883 | |
| 17:35:59 | kashyap | gibi: I need to head out, but I see that you've got a new rev up w/ a new package removals. And Zuul seems to be happy. Will check tomm :) | |
| 17:38:08 | sean-k-mooney | melwitt: you might also have context on mnaser greenthread leaking issue | |
| 17:38:42 | sean-k-mooney | melwitt: is there a reason that you are aware of to not remvoe all uses of spawn_n and replace them with spawn? | |
| 17:40:33 | sean-k-mooney | we likely woudl have to add https://github.com/eventlet/eventlet/issues/731#issuecomment-953761883 to our monkey patch file | |
| 17:40:42 | sean-k-mooney | to cater for the thread.start case you noted | |
| 17:40:49 | melwitt | sean-k-mooney: no, temoto recommended not to use spawn_n | |
| 17:41:15 | sean-k-mooney | yep reading the bug that is clear | |
| 17:41:33 | sean-k-mooney | so we coudl replace all the calls and also do | |
| 17:41:37 | melwitt | I did do a patch to change them all but we still had some come up bc for example oslo.messaging uses spawn_n when in eventlet mode | |
| 17:41:40 | sean-k-mooney | import eventlet | |
| 17:41:42 | sean-k-mooney | eventlet.spawn_n = eventlet.spawn | |
| 17:41:44 | sean-k-mooney | eventlet.convenient.spawn_n = eventlet.spawn | |
| 17:41:46 | sean-k-mooney | eventlet.monkey_patch() | |
| 17:42:08 | sean-k-mooney | melwitt: right but if we gloablly repoalce spawn_n with spawn | |
| 17:42:12 | sean-k-mooney | when we monkey patch | |
| 17:42:20 | sean-k-mooney | the oslo will also start using spwan | |
| 17:42:28 | sean-k-mooney | although we probly shoudl fix it in oslo too | |
| 17:42:30 | melwitt | ah, true. I was thinking of when I tried literally changing them all + a hacking rule | |
| 17:42:40 | melwitt | +1 | |
| 17:43:03 | sean-k-mooney | did you ever raise that with oslo? | |
| 17:43:13 | sean-k-mooney | removing there use of spawn_n | |
| 17:43:59 | melwitt | no. at the time I was so mired in trying to sort the eventlet issue that I didn't think to initiate that | |
| 17:44:53 | sean-k-mooney | ack | |
| 17:45:08 | sean-k-mooney | it looks like spawn_n is pretty common in openstack | |
| 17:45:10 | sean-k-mooney | https://codesearch.opendev.org/?q=spawn_n&i=nope&literal=nope&files=&excludeFiles=&repos= | |
| 17:45:31 | melwitt | I had also intended to put together a more concise repro of the spawn_n problematic behavior to do another eventlet issue but lost steam | |
| 17:45:46 | melwitt | yeah I was thinking that might be the case. I probably checked back then and then forgot | |
| 17:47:18 | sean-k-mooney | so this could be a redherring as to why nothing seams to be resuming the greenthread after the excption is raised when there i s a netowk vif plugged | |
| 17:47:26 | sean-k-mooney | event that fails | |
| 17:47:33 | mnaser | so probably the spawn_n here is causing this somehow ? | |
| 17:47:50 | sean-k-mooney | mnaser: thats what im specualting but not sure | |
| 17:48:04 | sean-k-mooney | im wondiering if we just spawned a fucntion taht raise woudl that trigger this | |
| 17:50:26 | sean-k-mooney | anyway i need to go fo today but it might be worth tryign to repoduce this outside fo nova with a simpel script that use eventles swan_n and raises | |
| 17:50:53 | sean-k-mooney | https://eventlet.net/doc/basic_usage.html#eventlet.spawn_n | |
| 17:50:56 | mnaser | yeah.. I don’t know if I have spare cycles right now for that but I think I should probably file a bug in launchpad at least | |
| 17:50:58 | sean-k-mooney | The same as spawn(), but it’s not possible to know how the function terminated (i.e. no return value or exceptions). This makes execution faster. See spawn_n for more details. | |
| 17:51:19 | sean-k-mooney | https://eventlet.net/doc/modules/greenthread.html#eventlet.greenthread.spawn_n | |
| 17:51:31 | melwitt | yeah, I'll try to look into this too | |
| 17:51:34 | sean-k-mooney | If an exception is raised in the function, spawn_n prints a stack trace; the print can be disabled by calling eventlet.debug.hub_exceptions() with False. | |
| 17:52:17 | sean-k-mooney | so ya i think this is a high likely hood that this is the probelm | |
| 17:52:52 | opendevreview | Balazs Gibizer proposed openstack/nova master: Adapt tools/test-setup to Fedora 35 https://review.opendev.org/c/openstack/nova/+/840684 | |
| 17:53:13 | sean-k-mooney | if this was c or c++ spwan_n woudl be annotated with [[noreturn]] | |
| 17:53:51 | sean-k-mooney | ok got to go but let me know if this helps | |
| 18:27:21 | mnaser | sean-k-mooney, melwitt: https://bugs.launchpad.net/nova/+bug/1971760 | |
| 18:28:03 | melwitt | great, thanks | |
| 18:34:51 | opendevreview | melanie witt proposed openstack/nova stable/wallaby: Define new functional test tox env for placement gate to run https://review.opendev.org/c/openstack/nova/+/840717 | |
| 18:36:27 | opendevreview | melanie witt proposed openstack/placement stable/wallaby: placement-status: check only consumers in allocation table https://review.opendev.org/c/openstack/placement/+/840701 | |
| 18:38:53 | opendevreview | melanie witt proposed openstack/placement stable/wallaby: placement-status: check only consumers in allocation table https://review.opendev.org/c/openstack/placement/+/840701 | |
| 18:38:54 | opendevreview | melanie witt proposed openstack/placement stable/wallaby: Use 'functional-without-sample-db-tests' tox env for placement nova job https://review.opendev.org/c/openstack/placement/+/840718 | |
| 19:23:28 | mnaser | melwitt, sean-k-mooney: found this https://github.com/openstack/nova/blob/0190d585418f088728533334872820689642a9e3/nova/compute/manager.py#L479 which goes to https://github.com/openstack/nova/blob/0190d585418f088728533334872820689642a9e3/nova/network/model.py#L623 | |
| 19:23:46 | mnaser | which references https://github.com/openstack/nova/blob/0190d585418f088728533334872820689642a9e3/nova/network/model.py#L590 | |
| 19:23:58 | mnaser | so .spawn_n which calls .spawn | |
| 19:28:41 | melwitt | mnaser: I don't see any spawn_n there, or is that what you're pointing out? | |
| 19:30:49 | mnaser | melwitt: oh right, so _locked_do_build_and_run_instance calls spawn().. and down the line that ends up in wait_for_instance_event() which calls .wait() for the event | |
| 19:31:06 | mnaser | i mean, i am trying to create a reproducer but not really able to get something to fail :( | |
| 19:32:00 | mnaser | https://paste.opendev.org/show/b2msfzi2ASYNwN0Fguqp/ | |
| 19:32:15 | mnaser | then kill -USR2 <pid> and no bueno, i dont see those extra threads | |
| 19:35:03 | melwitt | hm ok | |
| 19:35:22 | mnaser | im trying to play with it to reproduce but there's a lot in play i think | |