| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-06-06 | |||
| 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.. | |
| #openstack-nova - 2019-06-07 | |||
| 00:00:06 | mnaser | i mean | |
| 00:00:13 | melwitt | sean-k-mooney: well, at least I didn't think it's related, but wasn't thinking in that direction at all tbh | |
| 00:00:28 | mnaser | oh this is interesting | |
| 00:00:33 | mnaser | the compute service is getting a messagingtimeout | |
| 00:00:36 | mnaser | even though conductor is up | |
| 00:00:43 | melwitt | yeah, it should be recovering on its own | |
| 00:00:58 | sean-k-mooney | melwitt: ok i just wondered since you were suggesting the vnc console call | |
| 00:01:02 | mnaser | just looping on "Timed out waiting for reply.." | |
| 00:01:17 | melwitt | sean-k-mooney: haha no, we were just trying to see if the cast vs call behavior was consistent | |
| 00:01:22 | sean-k-mooney | just got back to the start of the converstation so now have a bit more context | |
| 00:01:37 | mnaser | i'll try restarting it (i have bunch of other computes that are broken so at least it will say if a restart fixes it) | |
| 00:01:47 | mnaser | ill still have a one in broken state | |
| 00:02:25 | melwitt | good thing you have a lot of broken computes huh! | |
| 00:02:29 | mnaser | hah | |
| 00:02:39 | mnaser | looks like it's not going up, the capabilities xml string just got logged and its stuck | |
| 00:02:42 | sean-k-mooney | we had an upstream or posible downstream bug that was similar to this | |
| 00:02:49 | sean-k-mooney | not to long ago | |
| 00:03:02 | mnaser | i assume it'll just blow up now complaining the message timed out | |
| 00:03:13 | melwitt | hm, weird | |
| 00:03:38 | melwitt | sean-k-mooney: lettuce know if you have any links | |
| 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 | melwitt | O.o | |
| 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: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 | |