| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-03-07 | |||
| 18:52:36 | mnaser | yes we're hoping to kill off their dell ps array | |
| 18:52:44 | mnaser | ceph is wonderful for all of this | |
| 18:52:55 | smcginnis | That might be good anyway. PS is no longer going to be supported. | |
| 18:53:11 | mnaser | good, then we can force them to get off | |
| 18:53:12 | mnaser | :-P | |
| 18:53:23 | smcginnis | ;) | |
| 18:58:40 | openstackgerrit | Merged openstack/nova master: Move legacy-grenade-dsvm-neutron-multinode-live-migration in-tree https://review.openstack.org/640181 | |
| 19:01:05 | openstackgerrit | Jack Ding proposed openstack/nova master: Preserve UEFI NVRAM variable store https://review.openstack.org/621646 | |
| 19:07:26 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Clean up block_device_allocate_retries config option help https://review.openstack.org/641759 | |
| 19:07:27 | mriedem | mnaser: i'm having a problem letting shitty docs slide lately ^ | |
| 19:08:36 | mnaser | mriedem: i like that | |
| 19:08:41 | mnaser | that's a lot more clear | |
| 19:10:57 | openstackgerrit | Merged openstack/nova master: Make nova-grenade-live-migration voting and gating https://review.openstack.org/640182 | |
| 19:17:58 | mnaser | ok i've got this really strange breakage inside OSA that seems to happen within nova | |
| 19:18:04 | mnaser | http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/openstack/aio1-nova/nova-compute.log.txt.gz#_2019-03-06_12_35_49_535 | |
| 19:18:10 | mnaser | "Neutron Reported failure on event network-vif-plugged-4095592d-730d-4a32-82b7-1ec3133f5862 for instance a43072b3-43e5-4fce-ae32-c11510b569fc: NovaException: In shutdown, no new events can be scheduled" | |
| 19:18:29 | mnaser | seems to me that the ` NovaException: In shutdown, no new events can be scheduled` portion is actually coming from `prepare_for_instance_event` | |
| 19:18:42 | mnaser | so the error is a bit misleading too | |
| 19:18:51 | mriedem | http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/manager.py#n317 | |
| 19:19:07 | mnaser | yeah, i dug that out, i need a faster way to link from vscode :< | |
| 19:19:23 | mnaser | i'm not sure what or why self._events is, and why it's set to `None` | |
| 19:19:31 | mnaser | the port seems to be plugging fine from the neutron side of things, according to the logs | |
| 19:19:45 | mriedem | self._events = None generally means nova-compute is stopping | |
| 19:20:05 | mnaser | strange, it doesn't seeeeeeem to be in those logs? you can see it continue to do things | |
| 19:20:09 | mriedem | http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/manager.py#n397 | |
| 19:20:33 | mriedem | the only thing that calls that is cleanup_host http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/manager.py#n1236 | |
| 19:20:45 | dansmith | that message is exactly what is supposed to happen if compute is shutting down | |
| 19:20:55 | mriedem | http://git.openstack.org/cgit/openstack/nova/tree/nova/service.py#n286 | |
| 19:21:16 | mnaser | that's so strange, interestingly enough, the logs don't show anything about cleaning up | |
| 19:21:22 | mnaser | or any of the "popping stuff out of event queue" messages | |
| 19:21:50 | mnaser | we did recently merge a change where we had vif_plugging_is_fatal default to true, so this might have exposed something (and it was always failing?! i hope not..) | |
| 19:22:12 | dansmith | vif plugging fatal should be set to true | |
| 19:22:18 | mnaser | sorry, i mean we set it to false | |
| 19:22:22 | dansmith | ack okay | |
| 19:22:34 | dansmith | wait, you mean you had been setting it to false, and recently fixed that yeah? | |
| 19:22:39 | mnaser | yeah | |
| 19:22:44 | dansmith | either way, that won't affect the incoming events, | |
| 19:22:49 | dansmith | just whether or not we wait for them | |
| 19:22:58 | dansmith | and what you show above is just event delivery | |
| 19:23:00 | mnaser | well, if something was broken before, we probably just exposed it (in osa or whatever) | |
| 19:23:13 | mnaser | we might have been just blindly plugging ports and it just worked™ -- this just exposed it | |
| 19:23:29 | mnaser | the interesting thing is i dont see "Canceling in-flight event" in the logs anywhere | |
| 19:23:42 | mnaser | but i guess the blocking new events might do it there | |
| 19:23:42 | mriedem | https://review.openstack.org/#/c/420026/ | |
| 19:23:47 | mriedem | ^ is it this? | |
| 19:23:58 | mriedem | did something sighup the service? | |
| 19:23:59 | dansmith | mnaser: you wouldn't if nothing is waiting when the shutdown starts | |
| 19:24:08 | dansmith | mriedem: see my comments/ | |
| 19:24:15 | dansmith | mriedem: we don't call cleanup_host on sighup | |
| 19:24:28 | mnaser | let me check systemd logs | |
| 19:24:59 | mriedem | well i'm all out of ideas :P | |
| 19:25:02 | dansmith | if we did we'd be tearing down rpc and dropping things all over the place, which would be a pretty big problem for what sighup is supposed to do | |
| 19:25:38 | mriedem | mnaser: are you hitting this consistently in osa ci? because a simple debug patch should tell us what is triggering the stop | |
| 19:25:40 | mnaser | http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/host/messages.txt.gz#_Mar__6_12_12_43 we reload here, but that's almost 23 minutes before it happened | |
| 19:25:51 | mnaser | yes, we're perma-borked right now | |
| 19:26:14 | dansmith | mnaser: are you maybe starting to shut down nova services before tests have finished or something? | |
| 19:26:17 | mnaser | that's the latest reference to a the nova-compute service | |
| 19:26:30 | dansmith | or maybe tests are done but instances are still coming up or something? | |
| 19:26:48 | mnaser | system logs would have shown us shutting down the service (it's a systemd unit) | |
| 19:27:05 | mnaser | it is possible that a reload might put the nova-compute in a weird state? | |
| 19:27:06 | dansmith | well, if you're using systemd to shut it down, sure | |
| 19:27:24 | dansmith | mnaser: shouldn't and the code does very little on sighup | |
| 19:29:01 | mnaser | oh thats weird | |
| 19:29:06 | mnaser | the change mriedem linked is missing in master | |
| 19:29:12 | mnaser | https://github.com/openstack/nova/blob/master/nova/compute/manager.py#L548 | |
| 19:29:12 | dansmith | it's unmerged | |
| 19:29:15 | dansmith | because it's bad | |
| 19:29:17 | mnaser | ah oops | |
| 19:29:19 | mnaser | my eyes failed me | |
| 19:30:31 | dansmith | that change would also mean a sighup will cause any instances waiting to boot when you sighup fail with a timeout | |
| 19:30:37 | dansmith | which would be pretty bad | |
| 19:30:44 | dansmith | especially if you're sighup | |
| 19:30:45 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Set min=0 for block_device_allocate_retries option https://review.openstack.org/641770 | |
| 19:30:52 | dansmith | ping nova-compute so you can turn on debug or something :) | |
| 19:31:28 | mnaser | http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/openstack/aio1-nova/nova-compute.log.txt.gz#_2019-03-06_12_12_43_207 | |
| 19:31:59 | mriedem | that matches http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/host/messages.txt.gz#_Mar__6_12_12_43 | |
| 19:32:03 | dansmith | mnaser: but it also clearly ran the compute manager reset just a couple lines below "reloading" | |
| 19:32:05 | mriedem | but not http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/openstack/aio1-nova/nova-compute.log.txt.gz#_2019-03-06_12_35_49_535 | |
| 19:32:15 | dansmith | maybe some oslo.service regression? | |
| 19:32:37 | mnaser | yeah that's what im wondering, if oslo service isn't doing the right thing, i'm gonna try to see in oslo service | |
| 19:32:49 | dansmith | https://bugs.launchpad.net/neutron/+bug/1780139 | |
| 19:32:50 | openstack | Launchpad bug 1780139 in neutron "Sending SIGHUP to neutron-server process causes it to hang" [Undecided,Triaged] - Assigned to Bernard Cafarelli (bcafarel) | |
| 19:33:17 | dansmith | https://github.com/openstack/oslo.service/blob/master/oslo_service/service.py#L375 | |
| 19:33:29 | dansmith | should only exit if it's unhandled I think | |
| 19:33:42 | mnaser | yeah it looks like the exiting is a little misleading there | |
| 19:34:11 | dansmith | https://github.com/openstack/oslo.service/blob/master/oslo_service/service.py#L344 | |
| 19:34:28 | dansmith | so unless it redefined the thing we need to override to handle sighup or something | |
| 19:35:14 | dansmith | but clearly not, | |
| 19:35:18 | dansmith | since we did actually do our own reload | |
| 19:35:34 | dansmith | seems fishy | |
| 19:35:34 | mnaser | yeah the logs show that the correct thing happened | |
| 19:35:44 | dansmith | or ... | |
| 19:35:51 | dansmith | maybe there was actually a respawn in between there? | |
| 19:36:00 | dansmith | maybe it did exit? we don't have pid in the logs to tell I think | |
| 19:36:34 | dansmith | mnaser: because after the log dump: http://logs.openstack.org/08/641308/2/check/openstack-ansible-deploy-aio_lxc-centos-7/2485c9a/logs/openstack/aio1-nova/nova-compute.log.txt.gz#_2019-03-06_12_12_55_326 | |
| 19:36:41 | dansmith | er, conf dump | |
| 19:36:50 | dansmith | that seems extremely wrong | |
| 19:37:09 | dansmith | and may explain why people think that "reset events" change is necessary, because we're incorrectly really exiting? | |
| 19:37:46 | mnaser | it looks like a new startup based on the logs | |
| 19:37:56 | dansmith | yeah that's uncool | |