| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2022-05-05 | |||
| 16:45:46 | sean-k-mooney | i think the mysql/mariadb changes were also in devstack | |
| 16:45:55 | sean-k-mooney | we use mariadb on most distos i think now | |
| 16:48:45 | clarkb | sean-k-mooney: it is a bit of a slwo rollout while we work through various things, but ya the images are up and mostly work. The last thing we ran into was phased package updates not making sense for us | |
| 16:49:31 | sean-k-mooney | phased package updates? | |
| 16:49:39 | sean-k-mooney | as in replication to mirrors or something else | |
| 16:50:36 | clarkb | something else. Its new functionality in apt that hashes something about your host and then modulo's that against the percentage of users they want to install the package | |
| 16:51:00 | clarkb | which means they can say things like 10% of users get this package update. Then next week change it to 50% and so on until it is 100% | |
| 16:51:30 | clarkb | but reprepro doesn't understand it and it is disabled by default in chroots (which dib uses to make the images) which means you get the latest available packges as if phases didn't exist at all | |
| 16:57:36 | Uggla | sean-k-mooney, can you have a look at my comment on https://review.opendev.org/c/openstack/nova-specs/+/831506/2/specs/zed/approved/unshelve-to-host.rst#42 ? Please let me know what you think about it. | |
| 16:59:04 | sean-k-mooney | clarkb: oh ok | |
| 16:59:18 | sean-k-mooney | clarkb: ya i think we would want to turn that off | |
| 16:59:45 | mnaser | ok, this is most def a thread leak | |
| 17:00:15 | sean-k-mooney | Uggla i saw that breifly | |
| 17:00:34 | mnaser | kill -USR2 <nova-pid> | |
| 17:00:35 | sean-k-mooney | Uggla: so for unshelve ot az it ends up updating the request spec to the requested az | |
| 17:00:40 | mnaser | grep -i 'Green Thread' /tmp/gar | wc -l => 6094 | |
| 17:01:04 | sean-k-mooney | mnaser: those are the userland trhead not real os thread | |
| 17:01:21 | mnaser | a lot of them are this: | |
| 17:01:25 | mnaser | https://www.irccloud.com/pastebin/YBiYPlrp/ | |
| 17:01:31 | mnaser | and i think the root cause is from https://www.irccloud.com/pastebin/n7Ezs7aB/ | |
| 17:02:22 | sean-k-mooney | Uggla: so for unshelve ot host i think it shoudl also update it to the AZ of the host if and only if the request spec is not none | |
| 17:02:26 | mnaser | so with every failure of this, we'd get an extra greenthread that sits and does nothing | |
| 17:02:39 | sean-k-mooney | Uggla: i need to think about that and make sure that is right | |
| 17:03:00 | sean-k-mooney | Uggla: bug basically if the vm orgringaly requested an AZ we want to update it to match the az of the host | |
| 17:03:11 | sean-k-mooney | Uggla: if it did not then we do not want to update it | |
| 17:03:16 | sean-k-mooney | Uggla: i think | |
| 17:04:12 | sean-k-mooney | mnaser: well that implies that nothing is catching the vif creation failure? | |
| 17:04:48 | sean-k-mooney | or its never been resumed | |
| 17:05:09 | mnaser | sean-k-mooney: maybe.. i've seen similar behaviour here https://github.com/eventlet/eventlet/issues/432 and https://github.com/eventlet/eventlet/issues/662 | |
| 17:05:11 | sean-k-mooney | im not really sure why you would end up with multiple dangeling thread like that | |
| 17:06:37 | mnaser | its supposed to log a warning if it hits that exception | |
| 17:06:45 | mnaser | let me see https://github.com/openstack/nova/blob/stable/wallaby/nova/virt/libvirt/driver.py#L7236-L7245 is logged | |
| 17:07:18 | sean-k-mooney | yes which would do io and cause the thread to yeild | |
| 17:07:32 | sean-k-mooney | *greenthread | |
| 17:07:50 | sean-k-mooney | or at least potentially while the python logger processes the logging event | |
| 17:09:58 | sean-k-mooney | mnaser: that looks promising and also depressing | |
| 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 | |