| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-06-07 | |||
| 00:04:53 | mnaser | sigh. | |
| 00:04:56 | mnaser | two restarts and it works now. | |
| 00:05:03 | mnaser | or 3 rather | |
| 00:05:10 | mnaser | (that specific compute node works rather) | |
| 00:05:37 | mnaser | the rest still broken | |
| 00:05:46 | melwitt | 3 restarts made it work but not 1? | |
| 00:05:55 | melwitt | ... | |
| 00:06:06 | mnaser | yep, first restart it was hung | |
| 00:06:19 | mnaser | restarted once with debug enabled and accidnetally log levels without an s, restarted again right away with an s and it went up fine. | |
| 00:06:19 | melwitt | O.o | |
| 00:06:26 | mnaser | wait | |
| 00:06:42 | mnaser | it might actually have been okay | |
| 00:06:44 | mnaser | the first time :\ | |
| 00:07:14 | melwitt | ok, that is the only thing that could make sense there otherwise....mind blown | |
| 00:07:16 | mnaser | let me see whta happened with th broken ones | |
| 00:07:37 | sean-k-mooney | hehe if its a case that debug mode fixes it calling dibs on not finding out why :P | |
| 00:08:02 | mnaser | hmm, looks like its been doing the same thing | |
| 00:08:06 | mnaser | looping forever in messagingtimeout | |
| 00:08:08 | mnaser | without recover | |
| 00:08:57 | mnaser | it looks like its flapping | |
| 00:09:21 | mnaser | http://paste.openstack.org/show/752617/ | |
| 00:10:22 | sean-k-mooney | could it be a network/loadblancer issue | |
| 00:11:01 | melwitt | looks like that "Recovering" message is a lie. it always resets itself to that when catching Exception | |
| 00:11:19 | sean-k-mooney | all of the rabbit nodes are now back up and in a quoram right | |
| 00:11:28 | melwitt | https://github.com/openstack/nova/blob/master/nova/servicegroup/drivers/db.py#L98 | |
| 00:11:53 | melwitt | so it doesn't mean anything like it's reconnected, it hasn't | |
| 00:13:55 | mnaser | sean-k-mooney: yes | |
| 00:14:10 | mnaser | oslo.messaging._drivers.impl_rabbit [-] Failed to consume message from queue: Queue.declare: (404) NOT_FOUND - failed to perform operation on queue 'compute' in vhost '/nova' due to timeout: NotFound: Queue.declare: (404) NOT_FOUND - failed to perform operation on queue 'compute' in vhost '/nova' due to timeout | |
| 00:14:32 | mnaser | i wonder if the queue.declare is not recoverable | |
| 00:15:35 | sean-k-mooney | this is looking more an more familar with the other rabbitmq issues we were debuging | |
| 00:16:03 | mnaser | i wonder if this fails, and then when i restart the control plane, they declare the queues | |
| 00:16:07 | mnaser | and then you kinda have two refs of bindings | |
| 00:16:39 | sean-k-mooney | this might be related https://bugs.launchpad.net/nova/+bug/1794706 | |
| 00:16:40 | openstack | Launchpad bug 1794706 in OpenStack Compute (nova) "The instance left stuck when oslo.messaging raised MessageDeliveryFailure exception" [Undecided,In progress] - Assigned to Tao Li (eric-litao) | |
| 00:17:45 | melwitt | if that's happening, mnaser should see a trace for MessageDeliveryFailure in the logs | |
| 00:17:54 | sean-k-mooney | mnaser: when we were debugging the wsgi issue i think there was a question over would the connection recovery in oslo.messaging probaly redeclare the queue | |
| 00:19:20 | mnaser | i have a bunch of those melwitt | |
| 00:20:03 | melwitt | ohhhh damn | |
| 00:20:57 | mnaser | Unable to connect to AMQP server on ctl1-xxxxx.vexxhost.cn:5671 after inf tries: Server unexpectedly closed connection | |
| 00:20:59 | mnaser | looks like it gives up | |
| 00:21:35 | sean-k-mooney | that is from here https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L767 | |
| 00:22:52 | sean-k-mooney | i think https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L793 should redeclare teh queue | |
| 00:23:05 | sean-k-mooney | but im not 100% sure about that | |
| 00:23:52 | sean-k-mooney | we should call that on reconnection https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L732 | |
| 00:24:20 | sean-k-mooney | and before we execute the publish https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L741 | |
| 00:24:35 | mnaser | indeed that adds up | |
| 00:24:41 | sean-k-mooney | but i think that is only creating the consumer queues | |
| 00:24:59 | sean-k-mooney | it may not be creating the targe topic queue | |
| 00:25:04 | melwitt | mnaser: in which service(s) do you see MessageDeliveryFailure? I want to add more info that the LP bug | |
| 00:25:09 | mnaser | nova-compute | |
| 00:26:22 | sean-k-mooney | i wonder if _set_current_channel shoudl be ensuring all the exchanges and topic queus are created? | |
| 00:26:31 | melwitt | hm.. not what I expected. I thought instance stuck in scheduling state does not reach compute | |
| 00:26:54 | melwitt | so we wouldn't be able to handle it and put instance into ERROR state | |
| 00:27:14 | mnaser | i wonder if this is a multithread/proc problem | |
| 00:27:18 | mnaser | i mean i see a few reconnects after the disconnect | |
| 00:28:28 | mnaser | and the reconnect is to different rabbitmq servers | |
| 00:29:45 | sean-k-mooney | mnaser: what is the topic/queue name its trying to publish too? | |
| 00:30:06 | mnaser | thats not logged (not running in debug unfortunately) | |
| 00:30:22 | sean-k-mooney | oh it is | |
| 00:30:42 | sean-k-mooney | it was the compute queue on the /nova vhost | |
| 00:30:57 | sean-k-mooney | the /nova vhost is the exchange name right? | |
| 00:31:05 | mnaser | let me check | |
| 00:31:58 | mnaser | seeing a bunch of nova.*, amq.*, reply_* and compute_* one | |
| 00:32:03 | mnaser | i wonder if the compute_fanout was the missing one | |
| 00:33:26 | sean-k-mooney | in theory if we we declared the fanout consuemr using https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L1086 | |
| 00:33:44 | sean-k-mooney | when we created the connection it should be in our consumeer list and we shoudl hav erecreated it | |
| 00:34:15 | melwitt | I added a comment to the LP bug | |
| 00:34:20 | sean-k-mooney | but if we dont make our selves a consumer of a queue then we wont recarte it | |
| 00:34:31 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (16) https://review.opendev.org/576299 | |
| 00:34:47 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (17) https://review.opendev.org/576344 | |
| 00:35:09 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (18) https://review.opendev.org/576673 | |
| 00:35:22 | openstackgerrit | Takashi NATSUME proposed openstack/nova master: Remove mox in unit/network/test_neutronv2.py (19) https://review.opendev.org/576676 | |
| 00:36:19 | mnaser | sean-k-mooney: but then if restarting recreates things, why dont the existing computes start working | |
| 00:36:37 | mnaser | ooooooh hold on | |
| 00:36:51 | mnaser | compute.<hostname> queue only exists for the one that i restarted. | |
| 00:37:24 | mnaser | so when it recovers, its not declaring that again. nb: i don't know much about rabbitmq | |
| 00:37:56 | sean-k-mooney | mnaser: yes its not the fanout queue its the topic queue for that host | |
| 00:39:10 | sean-k-mooney | e.g. the one that is used for calls | |
| 00:39:58 | sean-k-mooney | mnaser: you could enable Durable queues on the rabbit side | |
| 00:40:02 | mnaser | yeah.. i'm trying to find where that all gets declared | |
| 00:40:03 | sean-k-mooney | we might have a config option for that | |
| 00:41:13 | sean-k-mooney | in oslo its one of these two fucntion https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L1051-L1084 | |
| 00:42:04 | sean-k-mooney | setting https://docs.openstack.org/nova/latest/configuration/config.html#oslo-messaging-rabbit will likely help | |
| 00:42:39 | mnaser | yeah i guess, i just kinda wanna get to the bottom of it too | |
| 00:43:06 | mnaser | openstack/nova doesnt seem to define any declare_topic_consumer | |
| 00:43:10 | sean-k-mooney | well it will help by masking the issue so the queue persist across rabbit reboots but ya we should fix it | |
| 00:46:30 | mnaser | imstruggling to find what creates those queues in nova | |
| 00:47:03 | sean-k-mooney | i might be this https://github.com/openstack/nova/blob/master/nova/rpc.py#L66-L92 | |
| 00:47:05 | mnaser | no hits on declare_topic_consumer | |
| 00:51:13 | sean-k-mooney | actully i think its via this https://github.com/openstack/nova/blob/013aa1915c79cfcb90c4333ce1e16b3c40f16be8/nova/service.py#L184-L192 | |
| 00:51:25 | mnaser | https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py#L650-L665 | |
| 00:52:25 | sean-k-mooney | yes so https://github.com/openstack/nova/blob/013aa1915c79cfcb90c4333ce1e16b3c40f16be8/nova/service.py#L186 | |
| 00:52:52 | sean-k-mooney | is where in the base nova serivce calse we declar the target for an rpc to the service based on the topic and host | |
| 00:54:04 | mnaser | i think that is not being recreated.. | |
| 00:54:59 | openstackgerrit | Daniel Speichert proposed openstack/nova-specs master: Directly download and upload images to RBD https://review.opendev.org/658903 | |
| 00:55:09 | sean-k-mooney | i think so too | |
| 00:55:28 | sean-k-mooney | it intally gets created here https://github.com/openstack/nova/blob/013aa1915c79cfcb90c4333ce1e16b3c40f16be8/nova/cmd/compute.py#L56-L58 | |
| 00:55:52 | sean-k-mooney | when we start the agent | |
| 00:56:00 | mnaser | and i think that ends up all the way down here when it starts listneing https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py#L650-L665 | |
| 00:56:15 | mnaser | but declare_topic_consumer doesnt store state or anything, it just does it one time | |