| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-06-06 | |||
| 23:06:54 | mnaser | each controller has 16 nova-scheduler processes, which adds up to 48 | |
| 23:07:08 | mnaser | so the theory is nova-conductor is doing its job but the scheduler just isn't picking up work off the queue.. | |
| 23:07:56 | penick | 3.6.15 | |
| 23:08:09 | melwitt | penick: I wondered whether it might be related to queue mirroring or non, clustered or non, how it behaves when a node leaves and rejoins | |
| 23:08:22 | mnaser | yeah we're at 3.6.16 so we're not far away | |
| 23:08:38 | mnaser | melwitt: yeah so actually i wondered if that was maybe the issue.. | |
| 23:08:46 | imacdonn | FWIW, I don't run clustered rabbitmq - just a single instance | |
| 23:09:01 | melwitt | I had thought there might have been some configuration where that doesn't work well, but I can't remember anything more about it | |
| 23:09:12 | mnaser | imacdonn: you're living life | |
| 23:09:40 | melwitt | :D | |
| 23:09:44 | imacdonn | I think so :) My career experience with clustering amounts to "it usually causes more problems than it solves" | |
| 23:09:48 | mnaser | thanks penick for the insights, i guess we might be hitting the weird ssl things you might have ran into | |
| 23:10:15 | mnaser | i guess i can bring the log levels up on the mq stuff and see how/why its getting bound and why its not picking up any messages | |
| 23:10:44 | imacdonn | yeah, there's stuff you can turn on with default_log_levels | |
| 23:11:12 | mnaser | i mean i think the api is doing its job pushing things out to the scheduler fanout, but then things faceplant there | |
| 23:12:01 | melwitt | log levels in python are totally easy to control (not) | |
| 23:12:29 | mnaser | i'll at least shut down the other 2 schedulers so i can debug on one ost | |
| 23:16:01 | mnaser | oh that's interesitng | |
| 23:16:04 | mnaser | it actually schedules it | |
| 23:16:28 | mnaser | it even puts allocations in placement | |
| 23:16:34 | mnaser | sends notifications.. | |
| 23:18:32 | melwitt | so, it doesn't get past the scheduler? doesn't move on back to conductor and then to compute? | |
| 23:20:04 | mnaser | it gets to the scheduler, then the scheduler sends something, gets a reply, and it seems to stall out there | |
| 23:22:40 | mnaser | i guess i need to find out what happens after an instance is scheduled, it send something back to the conductor (or it casts to that cell?) | |
| 23:22:51 | penick | @mnaser if it helps we don't use durable queues | |
| 23:22:56 | melwitt | mnaser: this is old but sounds kind of the same? https://github.com/rabbitmq/rabbitmq-server/issues/224 | |
| 23:23:19 | mnaser | hmm, wonder what the defaults are | |
| 23:23:42 | mnaser | oslo_messaging_rabbit.amqp_durable_queues = False yeah same here | |
| 23:24:51 | mnaser | oh interesting | |
| 23:25:39 | melwitt | are you using mirrored queues? | |
| 23:26:41 | melwitt | penick doesn't use mirrored and I think that's the thing that had issues that I'm vaguely remembering. and that issue I linked from rabbitmq also seems to have to do with mirrored queues | |
| 23:26:49 | mnaser | i think we mirror a subset of queus in OSA | |
| 23:29:19 | melwitt | that issue was fixed eons ago but was about "some kind of race with mirrored, auto_delete queues" | |
| 23:29:27 | mnaser | https://github.com/openstack/openstack-ansible/blob/dc5729ad6f10b7e6083d60c2270f75090cf3d5f4/inventory/group_vars/all/infra.yml#L27-L31 | |
| 23:29:56 | melwitt | I wonder if a new race could have cropped up recently | |
| 23:31:15 | mnaser | so question, after an instance is scheduled, does it then contact the rabbitmq cluster @ the cell? | |
| 23:33:58 | melwitt | we do a sync call over rpc from conductor to scheduler, get the result in conductor, then conductor async casts to compute over rpc | |
| 23:34:35 | melwitt | it sounds like what you're saying is scheduler does fine, creates allocs in placement etc, but then the reply never goes back to conductor over rpc | |
| 23:35:04 | mnaser | it looks like the reply to the conductor does get sent out.. so i need to maybe go back and check the conductor this time i guess | |
| 23:35:09 | melwitt | if that is the case, then it's never getting the to cell mq part | |
| 23:35:52 | melwitt | if the super conductor receives the reply, the next step is super conductor casts to the cell mq | |
| 23:36:05 | mnaser | ok, ill move away from scheduler and start looking at conductor now | |
| 23:37:12 | mnaser | conductor, the worlds quietest service | |
| 23:37:16 | melwitt | :) | |
| 23:38:12 | melwitt | you know.... we do cache mq connection info. so if you find it's hanging up at the step where super conductor is trying to drop the "build instance" message onto the cell mq and that cached info is no longer valid, that could be the culprit | |
| 23:38:40 | melwitt | but no, you said things return to normal if you kill the rabbit queues and recreate them without restarting any nova services yeah? | |
| 23:38:54 | melwitt | that would mean the nova cache thing doesn't matter | |
| 23:40:23 | mnaser | ok so schedule_and_build_instances gets to the point where its gets an asigned host | |
| 23:42:52 | mnaser | and it creates a block device mapping in the db for the cell | |
| 23:43:56 | melwitt | ok, so it's getting the reply from the scheduler. so it must be that the message going onto the cell mq is going into the ether | |
| 23:43:59 | melwitt | which makes me suspicious about the mq connection caching | |
| 23:44:43 | melwitt | mnaser: when you do the queues recreate thing, are you restarting nova services after? | |
| 23:45:16 | mnaser | yes i have to restart them too after (but i do that just to keep things clean rather than make it work) | |
| 23:45:21 | melwitt | *do you restart nova services after? | |
| 23:45:33 | melwitt | ok, then it might be a problem with that cache (it never refreshes) | |
| 23:46:05 | melwitt | have you ever tried restarting services without recreating the queues? | |
| 23:46:40 | mnaser | yep, no bueno | |
| 23:47:18 | melwitt | restarting would only help new server creates though, not the stuck ones | |
| 23:47:19 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Fix cleaning up console tokens https://review.opendev.org/637716 | |
| 23:47:51 | mnaser | so i know i at least get to here: https://github.com/openstack/nova/blob/3370f0f03ce17aaf3a7ebaa95d497f62bef238c0/nova/conductor/manager.py#L1400-L1401 | |
| 23:48:01 | melwitt | mnaser: does recreating the queues and restarting services make the stuck servers finish building? | |
| 23:48:05 | mnaser | melwitt: yeah but ive restarted them all in this case and no bueno | |
| 23:48:06 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Add a live migration regression test https://review.opendev.org/641200 | |
| 23:48:11 | mnaser | nope, all the stuck ones stay stuck | |
| 23:48:26 | melwitt | ok, so restarting services only will NOT make new server creates work? | |
| 23:48:35 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (13) https://review.opendev.org/576020 | |
| 23:48:58 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (14) https://review.opendev.org/576027 | |
| 23:49:07 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (15) https://review.opendev.org/576031 | |
| 23:49:52 | mnaser | melwitt: correct | |
| 23:49:54 | melwitt | if restarting services only doesn't make new server creates work, then I'd think the issue has to be with rabbit or oslo.messaging | |
| 23:50:08 | mnaser | yeah my feeling is this is oslo.messaging | |
| 23:50:35 | mnaser | https://github.com/openstack/nova/blob/3370f0f03ce17aaf3a7ebaa95d497f62bef238c0/nova/conductor/manager.py#L1462-L1473 -- i get here, i see it connect to rabbit, i see it cast on compute. |
|
| 23:50:37 | mnaser | and then nothing | |
| 23:51:05 | melwitt | could also be a mirrored queues thing in rabbit, there's been that similar bug in the past | |
| 23:51:13 | melwitt | that I linked earlier | |
| 23:51:39 | mnaser | yeah.. it also connects to rabbitmq successfuly... well the weird thing is i think maybe what is broken is casts only? | |
| 23:51:46 | mnaser | because the normal rpc stuff works | |
| 23:51:51 | mnaser | its the compute cast that fails | |
| 23:52:22 | melwitt | you could try something that is a call to compute to see if that works. that would be an interesting test | |
| 23:52:28 | melwitt | like getting vnc console url | |
| 23:52:28 | mnaser | the service does report as up too inside nova | |
| 23:52:33 | mnaser | dont have any vms unfortunately :P | |
| 23:52:44 | melwitt | lemme see if there's something else | |
| 23:52:56 | mnaser | hypervisor-stats maybe | |
| 23:53:11 | melwitt | get_diagnostics | |
| 23:53:17 | mnaser | err -utpime | |
| 23:53:51 | mnaser | isnt diag per vm | |
| 23:54:19 | mnaser | nova hypervisor-uptime <hypervisor-uuid> hangs | |
| 23:54:29 | melwitt | oh yeah, sorry | |
| 23:54:41 | openstackgerrit | Matt Riedemann proposed openstack/nova-specs master: Specifying az when restore shelved server https://review.opendev.org/624689 | |
| 23:54:51 | melwitt | ok, so it doesn't have to do with cast vs call, it's an issue with trying to get to the cell message queue in general | |
| 23:56:26 | mnaser | i mean the configs match.. in terms of cell_mapping | |
| 23:56:31 | mnaser | and it successfully connects.. | |
| 23:56:46 | mnaser | i guess now that i know its just reproducable with something far more basic.. | |
| 23:56:56 | melwitt | yeah... true | |
| 23:58:29 | sean-k-mooney | melwitt: are you suspecting this is is similar to the wsgi issue? | |
| 23:59:02 | mnaser | CALL msg_id: 7dc9fa9615ed4ef8bf083ac84e40beef exchange 'nova' topic 'compute.<hostname>' _send | |
| 23:59:19 | melwitt | sean-k-mooney: no, this is something different. I wondered if it's something like this old bug that was fixed in the past, if another race like this has re-emerged https://github.com/rabbitmq/rabbitmq-server/issues/224 | |
| 23:59:26 | mnaser | that's how far it'll get and then hang, same way it hung for the new compute | |
| 23:59:42 | mnaser | i mean let me restart the nova-compute... but still feels like it should be recovering on its own.. | |