Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-05-16
22:50:57 sean-k-mooney ya
22:51:02 sean-k-mooney i shoudl have read the commet
22:53:39 sean-k-mooney ok so this https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L666 is where the retry is implemented
23:00:22 sean-k-mooney ok do i have traced that fully through nova into oslo.messaging and unless there is a bug in the auto retry suppupot in the kombu lib which i doubt the issue is not tha twe think we sent the message on publish
23:00:33 imacdonn seems that that retries ensuring that a connection exists, but doesn't retry sending a message ?
23:00:51 sean-k-mooney it does it delegate it to kombu
23:01:15 melwitt yeah, I saw that too, just passes everything (including the message) to kombu's autoretry method
23:01:24 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L745-L752
23:01:32 melwitt so you would think after reconnecting, it would send the message
23:03:27 melwitt I guess I'm wondering now if what's in these callbacks are what controls how it behaves, whether it would send the message after reconnecting?
23:04:08 sean-k-mooney i assume that is what on_revive=on_reconnection is doing?
23:04:30 imacdonn I'm missing something .. where is the message passed to the autoretry method ?
23:05:06 sean-k-mooney exec methond is a functoll.partial thing
23:05:30 melwitt imacdonn: here https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L1098-L1101
23:05:50 sean-k-mooney https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L1098
23:06:47 sean-k-mooney so the execute_method has the mesg and all the args curried in the partial callable
23:07:29 melwitt yeah, so the on_reconnection method just reconfigures some things
23:07:58 sean-k-mooney yes but that is called when the conenct is revived but the auto retry i think would retry?
23:07:59 melwitt unfortunately it looks like we're going to have to look at what autoretry source does
23:08:15 openstackgerrit Merged openstack/nova master: Test macvtap port with resource request https://review.opendev.org/641309
23:08:26 sean-k-mooney unless you think we are ending up here https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L760-L771
23:08:30 melwitt you would think so but symptom suggests it's not
23:08:59 sean-k-mooney well we set the retry limit to float("inf")
23:09:11 sean-k-mooney so it could take a while to hit that :)
23:09:12 melwitt no, I don't think we're ending up there (we haven't seen that log)
23:10:33 melwitt we see a reconnect message, and then we see a timeout fire some milliseconds later http://paste.openstack.org/show/751486/
23:11:07 imacdonn the timeout is one minute later
23:11:27 melwitt oh guh, sorry
23:11:32 imacdonn ;)
23:11:33 melwitt I see now
23:17:00 sean-k-mooney thats being raised form https://github.com/openstack/oslo.messaging/blob/master/oslo_messaging/_drivers/impl_rabbit.py#L1125 form inside the partial functionin the auto retry thing
23:18:26 sean-k-mooney actully its from the publish line but im looking at master on github
23:19:36 sean-k-mooney so ya after the first trace which is the publish failing we see the reconnect
23:20:24 sean-k-mooney and then i think the timeout for sending that message has expired after we reconnect
23:20:51 sean-k-mooney we started to send it at 2019-05-16 18:24:09.089
23:22:04 sean-k-mooney but that doesnt make sense
23:22:27 sean-k-mooney the conenct is reestablished at 2019-05-16 18:24:10.109
23:22:43 sean-k-mooney and then there are no log messages untill the time out 1 minut later
23:22:58 melwitt right
23:23:06 sean-k-mooney but the rpc timeout should be longer then 60 seconds right?
23:23:28 melwitt I think it probably defaults to 60s
23:23:40 melwitt I can't remember where it is, lemme see
23:23:55 imacdonn 2019-05-16 18:16:05.973 23144 DEBUG nova.api.openstack.wsgi_app [-] long_rpc_timeout = 1800 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2571
23:24:11 imacdonn wait that's not it
23:24:16 melwitt default to 60 https://github.com/openstack/oslo.messaging/blob/7102eddb1fd799d949ff5dca8aa2637794bb8a43/oslo_messaging/rpc/client.py#L41
23:24:21 sean-k-mooney the long_rpc_timeout is not used for every rpc
23:24:44 melwitt rpc_response_timeout is the one
23:26:25 sean-k-mooney so this is what kombu is doing https://github.com/celery/kombu/blob/master/kombu/connection.py#L500-L547
23:33:56 openstackgerrit Merged openstack/nova master: Fix some issues with the newton release notes https://review.opendev.org/659623
23:34:08 imacdonn attempting repro with kombu debug logging
23:38:45 melwitt good call, because looking at the code it looks like it should be doing the right thing. no clue what's happening
23:42:21 imacdonn weird .. not getting the connection resets now
23:42:41 sean-k-mooney does it not take time for it to happen
23:42:45 sean-k-mooney e.g a few minutes
23:42:54 melwitt did you remember to set threads=8?
23:43:05 imacdonn yeah, I waited 5 mins the first try, then a little over 3 mins second try
23:43:19 imacdonn yes, threads=8, but I should see the connection reset either way
23:43:40 melwitt true
23:45:02 sean-k-mooney ok its technically friday here so im going to have pizza and then sleep. if ye find anything let me know but for no i guess we shoudl update the bug and tell people to run with thread=1
23:45:15 sean-k-mooney our maybe with debug loging...
23:45:31 melwitt pizza, sounds like a solid plan
23:46:24 imacdonn Thanks, sean-k-mooney - pizza/sleep well!
23:46:29 sean-k-mooney i actully had a c++ bug where debug builds did not have the bug because it was an unitialised variable and in debug mode the compiler was "kind" enouch to initalise it to 0
23:48:47 imacdonn ahh, got the reset now ... paste in a few mins
23:51:16 imacdonn http://paste.openstack.org/show/AZQET5IOgntK785RHtxh/
23:57:51 melwitt weird, it says basic_publish_confirm but then one minute later timeout happens
23:58:24 melwitt so confused.
#openstack-nova - 2019-05-17
00:02:03 imacdonn not sure what what basic_publish_confirm message really means
00:02:40 melwitt I don't either but just the indication that it made an attempt to send the message
00:03:00 melwitt I guess that implies it for some reason couldn't get through and results in the timeout?
00:05:33 imacdonn basic_publish_confirm is the method (that's supposed to get autoretry'ed), I guess
00:06:14 imacdonn I think it comes from python-amqp (?)
00:07:31 imacdonn File "/usr/lib/python2.7/site-packages/amqp/channel.py", line 1787, in basic_publish_confirm
00:10:59 imacdonn it does seem like it calls it the second time (at 23:48:19.113), but apparently still doesn't get an answer
00:12:07 melwitt yeah, that's the one I was looking at, the second that times out even after re-establishing the connection
00:13:23 openstackgerrit Dustin Cowles proposed openstack/nova master: Use SDK instead of ironicclient for setting instance id https://review.opendev.org/659690
00:15:04 openstackgerrit Dustin Cowles proposed openstack/nova master: WIP: Use SDK instead of ironicclient for add/remove instance info from node https://review.opendev.org/659691
00:34:56 openstackgerrit Merged openstack/nova master: Stop logging traceback when skipping quiesce https://review.opendev.org/659374
01:08:39 imacdonn another data-point: the retried request DOES actually get sent, because I see the compute node act upon it ... I guess somehow the client (nova-api) has some issue with the response
03:02:16 openstackgerrit chenker proposed openstack/python-novaclient master: Optimize limit option docs string description for novaclient https://review.opendev.org/643035
03:03:42 openstackgerrit Guo Jingyu proposed openstack/nova master: Skip existing VMs when hosts apply forceconfig_drive https://review.opendev.org/659703
03:17:07 openstackgerrit Guo Jingyu proposed openstack/nova master: Skip existing VMs when hosts apply force_config_drive https://review.opendev.org/659703
04:46:38 ykarel TheJulia, dtantsur|afk can you check comment in https://review.opendev.org/#/c/653279/1
04:48:21 ykarel hmm looks like some issue is already there, as i can see https://review.opendev.org/#/c/659612/1, can you check if this ^^ is same issue or something else
05:25:41 openstackgerrit Guo Jingyu proposed openstack/nova master: Add rfb.VNC support for novncproxy https://review.opendev.org/622336
05:26:26 openstackgerrit Guo Jingyu proposed openstack/nova-specs master: Proposal for a safer noVNC console with password authentication https://review.opendev.org/623120
06:21:19 openstackgerrit Guo Jingyu proposed openstack/nova master: Skip existing VMs when hosts apply force_config_drive https://review.opendev.org/659703
08:01:14 kashyap aspiers: That's in queue, I'm still backlogged :-( I know it is ready to merge. If I look at, I would like to spend a 2-hour block on it. So trying to find that :P
08:01:18 kashyap aspiers: From your comment:
08:01:19 kashyap "I don't quite understand how the fix in https://www.redhat.com/archives/libvir-list/2019-April/msg01418.html would make the Python arguments optional however, since they're still missing defaults."
08:01:34 kashyap aspiers: Just write to the upstream list (no subscription required; you can ask to be Cced)
08:02:23 kashyap aspiers: But as you noted yourself it's not required, given that you've obtained correct value for @emulatorbin via "Parse <emulator> elements from virConnectGetCapabilities()"
08:03:20 kashyap aspiers: Actually, let me give my review. You've addressed all my concerns
08:24:04 aspiers kashyap: I'm backlogged too ;-)
08:24:55 aspiers kashyap: So I probably owe you some reviews too. Let me know if I can make the review process easier in any way.
08:26:02 kashyap aspiers: Thanks for the offer! I need to do some work similar to yours -- introducing new CPU-related APIs
08:26:55 kashyap aspiers: For this spec: https://opendev.org/openstack/nova-specs/src/branch/master/specs/train/approved/cpu-selection-with-hypervisor-consideration.rst
08:27:01 kashyap See the action items at the end.
08:28:54 aspiers ok
08:45:07 kashyap aspiers: ACKed your change, FWIW

Earlier   Later