Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-05-16
20:36:41 imacdonn I don't think reconnection is being prevented .. you can see it happen in the log at http://paste.openstack.org/show/751486/ ... but I tihnk it might matter *when* it happens
20:37:35 imacdonn (line 227 in the log shows reconnected)
20:38:28 melwitt oh yeah, I see. so why MessagingTimeout? sorry, I just don't get this
20:39:00 imacdonn maybe the RPC request got sent to a dead connection, somehow??
20:39:04 sean-k-mooney the "best" respocne in https://www.reddit.com/r/Python/comments/4s40ge/understanding_uwsgi_threads_processes_and_gil/ seam to gel with how i tought this would be working
20:40:06 sean-k-mooney if we are initalising the connection pool as a module vaiable we are sharing it between the threads and all the therads are being run sequtually under the gil
20:40:47 sean-k-mooney so with threads=8 you had 8 instance of the api all sharing the same connection pool
20:43:58 sean-k-mooney there is a follow futher down where there is a code wakthorugh which explaing the init flow
20:50:52 artom efried, you added me to that review but I think you'll get through them before I get a chance to even start
20:51:04 artom We're all putting out CI fires with our upcoming release
20:51:09 artom (Maybe I shouldn't say that in public?)
20:51:35 efried artom: no worries, I noticed you were on the one above it, which is the important one, but that one's getting a -1 from me in a few minutes here, so you got time :)
20:52:12 artom https://photos.app.goo.gl/fRQoJpE5WnqYeP6E8 was my desk not long ago. Yes, I needed both those drinks to get through the bugs
20:53:30 artom ... and I need to go pick kids up
20:53:33 artom o/
20:54:42 sean-k-mooney dansmith: imacdonn so i think this is the issue https://github.com/openstack/nova/blob/760fc2de32057817bafc0a1512a735dab1c7c68a/nova/rpc.py#L69
20:55:10 sean-k-mooney we intial the transport as a module level vaiable so that is shared across all wsgi ap instace in the same process
20:55:43 sean-k-mooney that end up calling https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/transport.py#L192
20:55:52 dansmith sean-k-mooney: well, that's the global thing that does the connectioning to rabbit, yeah
20:56:17 sean-k-mooney which calls the diver manger to construt RabitmqDriver instance which has a connection pool internally
20:56:23 dansmith yup
20:56:30 sean-k-mooney so the connection pool become global too
20:56:35 dansmith right
20:57:09 dansmith sean-k-mooney: this is only part of the equation by the way
20:57:13 sean-k-mooney and sicne we have muleple python threads and the gil limits there exectuion we could starge the heartbeat
20:57:32 dansmith sean-k-mooney: because I think that TRANSPORT is what we use for initializing a connection which we would use if we were going to start a server and listen
20:57:58 dansmith sean-k-mooney: but connections to the *cell* rpc brokers happens in nova.context, because we connect per cell once we read that out
20:58:19 dansmith sean-k-mooney: it's effectively the same situaton though, I imagine they both suffer from the same behavior
20:59:18 sean-k-mooney riping out those gloabls would proably be a pain
20:59:40 dansmith sean-k-mooney: https://github.com/openstack/nova/blob/760fc2de32057817bafc0a1512a735dab1c7c68a/nova/context.py#L376
20:59:56 dansmith sean-k-mooney: having implemented multi-cell tests, I can assure you it is
21:00:24 dansmith but also, it's the thing that avoids us having to build that stuff up a hundred times, even for a single request where we make a couple rpc calls
21:00:41 sean-k-mooney and yep we are storing the connection in a module level CELL_CACHE
21:00:47 dansmith right
21:00:49 sean-k-mooney so yep ist the same issue
21:01:11 melwitt reconnect
21:01:11 melwitt so if the heartbeat thread gets starved, then connections get closed down, and then if reconnect in another thread races with an API request coming in and the API request hits before the reconnect, it will get the MessagingTimeout? I'm looking through the oslo.messaging code and from what I can tell, the reconnect is done on-the-fly when a message is attempted to be sent, so I don't understand how a different thread is doing the
21:02:02 cmart Hello -- can someone help me understand the process by which ephemeral disks get a filesystem label? It's usually `ephemeral0` but I have an instance created today which has `ephemeral0_160_40`
21:02:16 melwitt but if that were true that oslo.messaging automatically tries to reconnect, then the API request shouldn't fail, it would try to reconnect. so, nevermind, I don't know what I'm talking about
21:02:50 sean-k-mooney melwitt: well thats praobly the proble it like is not auto recoonectin on making a request
21:03:06 sean-k-mooney we poroubl have preiodic task or something that is doing th reconnection
21:03:12 sean-k-mooney that is jsut a guess
21:03:25 sean-k-mooney i havent look at this that closely in the past
21:03:42 melwitt yeah. I just can't tell what triggers a reconnect. in https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/amqpdriver.py I see a bunch of stuff where "recoverable error" will try to reconnect
21:04:12 sean-k-mooney are we using the amqp driver or the rabbitmq one
21:04:16 melwitt sorry, wrong link https://github.com/openstack/oslo.messaging/blob/9.5.0/oslo_messaging/_drivers/impl_rabbit.py
21:04:50 melwitt that other link was me trying to find where/how it raises MessagingTimeout
21:05:54 sean-k-mooney hum i wonder if setting https://github.com/openstack/oslo.messaging/blob/9.5.0/oslo_messaging/_drivers/impl_rabbit.py#L145-L149 to 0 would help?
21:06:10 dansmith sean-k-mooney: that was mentioned earlier
21:06:35 sean-k-mooney oh ok i tought you were asking if there was a way to disable it eariler
21:06:36 melwitt that is, you think it might allow threads=8 config to reconnect?
21:06:54 dansmith I said it would be good to test with it, *but* I think the downside of it is that the rabbit server side won't terminate the connection because of lack of heartbeats which means more likelihood of just having stale connections that have been forgotten by the conntracks in between
21:06:56 sean-k-mooney i think it might not close the connect
21:07:00 sean-k-mooney *connection
21:07:02 melwitt oh ok
21:07:14 sean-k-mooney e.g. it would only close if the tcp soecket closed
21:07:17 melwitt yeah, I see
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 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:25 melwitt yeah
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 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/9.5.0/oslo_messaging/_drivers/impl_rabbit.py#L884
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: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

Earlier   Later