Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-05-16
21:07:41 imacdonn pfft, it's not like rabbitmq-server is ever going to run out of connection...............
21:07:45 dansmith problem is, stateful firewalls in between client and server may do that without you noticing which will require some delay before you realize the socket is dead
21:08:17 sean-k-mooney right which is proably why the heartbeat is there in the first place
21:08:25 melwitt yeah
21:08:25 imacdonn back in the icehouse days, I had lots of problems trying to do AMQP through a firewall, due to lack of heartbeat support
21:08:46 dansmith right and why I think it's fine to let it be there, and if we wake up within a minute, we're good and if not, then we've got an immediate RST waiting for us so we know to reconnect
21:09:31 openstackgerrit Matt Riedemann proposed openstack/nova master: Restore connection_info after live migration rollback https://review.opendev.org/551349
21:12:07 sean-k-mooney melwitt: this is where the reconnect happens i think
21:12:09 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/9.5.0/oslo_messaging/_drivers/impl_rabbit.py#L897-L928
21:12:49 sean-k-mooney we call self.ensure_connection() if there was an exception wehn we calle self,_heartbeat_check()
21:13:53 sean-k-mooney which is a thread we inital in the dirver wihc is a global so there is again only 1 per process
21:14:41 sean-k-mooney so with threads=8 there is a 1 in 9 chacne that it will get scheduled to run
21:17:24 melwitt so since it does the reconnecting, if it doesn't run first, other thread will hit a closed connection and get MessagingTimeout
21:18:09 sean-k-mooney well the message timeout comes form the fact that we did a request and then stop listening because the connection closed
21:18:19 sean-k-mooney and we did not reconnect before teh timeout expired
21:18:27 sean-k-mooney so the set succfully
21:18:40 sean-k-mooney then it closed and they never go tthe resopnece
21:18:52 melwitt ok
21:19:13 sean-k-mooney which likely means when we recoonet it will be sitting on the queue
21:21:13 sean-k-mooney things like the inststance list would likely be fine in that case
21:21:31 sean-k-mooney since the api is hitting all the cell dbs but not doing an rpc right
21:21:43 sean-k-mooney but things like get_vnc_console woudl fail
21:21:50 efried cmart: what does your [DEFAULT]virt_mkfs option look like?
21:23:05 sean-k-mooney thing like boot would likely be fine too since thats fire and forget
21:23:28 imacdonn so now I'm wondering if the connection reestablishment is working "by accident" with threads=1, or if I can depend on it........
21:23:44 cmart efried I haven't defined it (on Queens, Ubuntu 16.04) so probably the default
21:24:07 sean-k-mooney well with threads=1 thre is a 50% change the connetion tread will run
21:24:20 sean-k-mooney sicne there is the main thread + the heatbeat thread
21:26:38 melwitt :\
21:27:16 sean-k-mooney i did not say it woudl definetly work :P
21:27:23 dansmith sean-k-mooney: there's only one thread,
21:27:25 sean-k-mooney but its better then 1 in 9
21:27:45 imacdonn so if I set threads=0, will it be 100% ? :)
21:27:50 melwitt lol
21:28:02 sean-k-mooney dansmith: the rabbitmq direver spawn a thread to run the heatbeat check
21:28:14 dansmith and I think that if we're monkeypatched, any io we do will always guarantee that we run the waiting greenthreads, so we'd consume the dead connection with the heartbeat right?
21:28:14 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/9.5.0/oslo_messaging/_drivers/impl_rabbit.py#L884
21:28:22 dansmith sean-k-mooney: green thread
21:28:50 sean-k-mooney ah your right if its monkey patched then its a greenthread
21:29:17 dansmith right,
21:29:22 dansmith so we'll always run that stuff on first io
21:29:43 sean-k-mooney i guess it depends on how many io operation were pending or had yeilded
21:29:46 dansmith I think if it was 50% we'd have heard about it
21:29:57 dansmith howso?
21:30:43 efried cmart: It looks like that name is being assigned in this neighborhood: https://opendev.org/openstack/nova/src/branch/stable/queens/nova/virt/libvirt/driver.py#L3510
21:30:46 sean-k-mooney well in the scater gater case at least we are querying a bunch of gread threads to execute then waiting
21:30:59 dansmith the heartbeat gthread is always schedulable work on any io switch if we've not run it in t/2 or whatever it's period is
21:31:33 dansmith sean-k-mooney: right but on the first io that we do, to even start that, we'll run all the greenthreads pending, which is at least the heartbeat gthread, before we do much of anything else
21:31:38 efried cmart: that line or L3533
21:32:01 sean-k-mooney ya we should
21:33:05 cmart efried thank you for the orientation
21:33:30 efried cmart: Good luck :)
21:38:36 openstackgerrit Merged openstack/nova master: Remove fake_libvirt_utils from connection tests. https://review.opendev.org/642557
21:39:09 imacdonn I wonder if part of the issue is that the AMQP message is not being resent in the case where the connection reset is detected during publish, vs. during heartbeat
21:40:20 melwitt I wonder that too
21:40:43 dansmith imacdonn: meaning if we hit it on publish, we reconnect, but didn't actually send, think we did, and wait for it until timeout?
21:40:50 dansmith if so that would be a giant o.msg bug
21:41:12 imacdonn yeah, smth like that
21:41:26 melwitt but I think we know it won't reconnect on publish right
21:41:45 melwitt otherwise the 500 wouldn't happen
21:41:49 dansmith no,
21:41:55 dansmith the 500 is from timeout right?
21:42:02 dansmith which means it's waiting for a reply
21:42:02 melwitt yeah
21:42:11 imacdonn 504 from timeout, yeah
21:42:28 imacdonn look at http://paste.openstack.org/show/751486/ - the reset follows the publish failure, not a heartbeat failure
21:42:28 dansmith which can happen if we effectively connect to rabbit, subscribe to a reply queue, but never sent the thing and thus time out waiting for a reply to nothing
21:42:39 imacdonn the reconnect, I mean
21:43:00 sean-k-mooney this is ment to handel the resent i think https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/impl_rabbit.py#L1088-L1101
21:43:59 sean-k-mooney for a direct send we do not pass retry
21:44:11 imacdonn I don't see any "Failed to publish message to topic" logged
21:44:20 melwitt yeah that's what confuses me, if publish does a reconnect, why are we left hanging for a timeout? unless we never send a thing like you both mentioned
21:44:28 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/impl_rabbit.py#L1204-L1213
21:45:03 dansmith melwitt: it would be if the act of sending triggered the "huh, this is dead, lemme reconnect" but was not followed by a "okay, now that I have reconnected, let me send that thing I had"
21:45:13 melwitt aye
21:45:20 dansmith because socket.write() is where you find out it's dead
21:45:30 dansmith which is how heartbeat is finding out
21:45:42 dansmith it gets scheduled, and does a "shit I'm late.. socket.write(heartbeat mofo!)"
21:46:17 melwitt right
21:51:17 melwitt sean-k-mooney: yeah, I don't know the difference between direct_send and topic_send. though topic_send sounds more like what's probably being used
21:52:25 melwitt (based on the fact that our message queues all have topics, I would think that means those are topic_send, but I don't actually know)
21:53:59 sean-k-mooney so we are invoking the get_vnc_console as a "call"
21:54:01 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/rpc/client.py#L157-L182
21:54:34 sean-k-mooney which im still tracing to see if it sa topic send or a direct send
21:55:27 sean-k-mooney that is where we do the actul call in the nova side https://github.com/openstack/nova/blob/eae1f2257a9ee6e851182bf949568b1cfe2af763/nova/compute/rpcapi.py#L635-L640
21:56:51 sean-k-mooney im getting flashbacks to the openstack bootstrap podcast looking at this code
22:01:14 sean-k-mooney ok instesting so
22:01:29 sean-k-mooney _send_reply uses a direct send
22:02:10 sean-k-mooney and that is used for this heartbeat https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py#L174
22:03:07 sean-k-mooney but this is the send function that matters https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py#L581
22:07:08 sean-k-mooney ok so ya its a topic_send https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py#L628
22:08:18 sean-k-mooney which means the retry behavior is contoled by the context object
22:26:41 openstackgerrit Eric Fried proposed openstack/nova master: DNM: Revert "Use external placement in functional tests" https://review.opendev.org/659680
22:29:46 sean-k-mooney ok dumb question but where does the context objec we use to sent the rpc call come form
22:31:18 sean-k-mooney context = req.environ['nova.context']
22:31:38 sean-k-mooney so what sets that...
22:32:51 sean-k-mooney this https://github.com/openstack/nova/blob/c6218428e9b29a2c52808ec7d27b4b21aadc0299/nova/api/auth.py#L95-L105 ?
22:36:31 sean-k-mooney no that has to be the wrong context that the keystone atuth context
22:39:47 sean-k-mooney ok i give up i cant tell if we actully set retry to ture
22:40:08 imacdonn I suppose I could add debug logging to find out

Earlier   Later