Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2021-10-12
14:31:59 kashyap gibi: Hi, I'll look and investigate. The submitter told me they even tested it in a real deployment (I took their word)
14:32:39 gibi kashyap: I can accept that it works but for me it is really hard to follow. maybe other in the core team has more knowledge to figure out what happens.
14:32:40 kashyap gibi: Thanks for the review time! We definitely don't want this rushed in. And needs careful integration testing. As it impacts live migration
14:33:03 kashyap gibi: No, if it's hard to follow for you, that's a reason enough to clean it up. And also it needs code comments too
14:33:04 gibi so I'm more concerned about understandabilty now than correctness
14:33:15 gibi ahh, ok
14:33:30 kashyap Yeah; I agree this needs more explnaations
14:40:27 gibi lyarwood: I looked into https://bugs.launchpad.net/nova/+bug/1946339 in short I don't see what happens and I cannot reproduce it locally while it is happening on the gate frequently. I'm a bit stuck
14:46:07 sean-k-mooney gibi: lyarwood is hopfule preparing for an operation later today and will be recovering for the next ~2 weeks
14:47:05 gibi sean-k-mooney: ack, I know. I just wanted to get back to him. (I update the bug with my finding)
14:47:07 sean-k-mooney ah test_unshelve_offloaded_server_with_qos_port_pci_update_fails
14:50:12 sean-k-mooney gibi: presumable this is some interaction between artoms fix for updating the pci device slot in the port profile on unshleve and minium band with based scheduling
14:50:30 opendevreview Alexey Stupnikov proposed openstack/nova master: Rollback problematic port bindings on source host only https://review.opendev.org/c/openstack/nova/+/813659
14:50:32 sean-k-mooney gibi: have you tried ensuring that the pci device claimied as part of the unshelve is different
14:51:13 sean-k-mooney e.g. boot a vm, shelve it, boot another vm ensuring it claims the same pci device as the first then try unslevleing the first vm
14:52:22 sean-k-mooney oh this is in the func tests
14:52:29 sean-k-mooney not an end user bug
14:53:11 gibi nope
14:53:22 gibi and the first exception is part of the test
14:53:43 sean-k-mooney so it looks like somehow the db get torwn down too early?
14:53:50 gibi something like that
14:53:58 gibi but I don't get how can that be
14:54:18 sean-k-mooney that is presumable created by the fixture in setup
14:54:33 sean-k-mooney so ya that is hard to understand
14:56:07 sean-k-mooney gibi: this is not messing with any global state right https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L2523-L2526
14:56:21 sean-k-mooney gibi: we have our own isntance of placement per test function
14:56:25 sean-k-mooney that has its own db
14:57:02 gibi I assume we have placement per test case per test executor
14:57:12 gibi otherwise everything would be unstable
14:57:23 sean-k-mooney ya that is my assumtion too
14:57:36 gibi btw the sriov placement tree is created in the test case setup so that is per test case for sure
14:57:45 gibi and the uuids shoudl be unique
15:01:09 sean-k-mooney could this be failing due to the update_avaiable_resouce_provier periodic task?
15:01:59 sean-k-mooney if that ran it would raise the same error internally but it might now catch it
15:02:53 gibi there is no proof in the logs that the period runs https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_b15/713498/27/check/nova-tox-functional-py38/b1582a8/job-output.txt
15:03:15 gibi we have test cases where we trigger the periodic manually, so I think we even turn of the periodic for the func test
15:10:19 gibi I cannot reproduce it even if I delay the compute side of the execution locally, the wait for server status timeouts first not the conductor
15:10:36 gibi so I don't get how the conductor can time out in the gate
15:12:37 gibi I will try pulling out the test execution order from a failed gate run and see if that reproduce it locally or not..
15:13:27 sean-k-mooney your referign to "oslo_messaging.exceptions.MessagingTimeout: No reply on topic conductor\n"
15:13:36 gibi yepp
15:14:03 sean-k-mooney this is also using the in memory driver so there is no networking issues that could be at play
15:14:35 sean-k-mooney with that said do you know what we set the time out too
15:14:54 sean-k-mooney we make spawn and other thing synconouse in the functional tests
15:15:17 sean-k-mooney i wonder if we only see this in a slow node
15:15:38 sean-k-mooney like is the time out 1 second of something tiny like that
15:15:43 sean-k-mooney when using the fake driver
15:15:51 gibi I don't know the timeout value in the funct test, but I put a sleep(10) in the compute side just before raising the expected exception, and it makes the test waiting for the server state time out instead of the fake driver
15:20:09 sean-k-mooney so i think this is where that messaging timeout gets raised https://github.com/openstack/oslo.messaging/blob/ca939fc0e4683efce87b567a9a074063a9c75b4f/oslo_messaging/_drivers/impl_fake.py#L207-L214
15:21:02 sean-k-mooney which happend due to a _queue.Empty from return self.greenlet.switch()
15:22:03 sean-k-mooney the resource provider error on the compute was boubled up all the way to the rpc server
15:25:05 sean-k-mooney that first traceback is form here https://github.com/openstack/oslo.messaging/blob/ca939fc0e4683efce87b567a9a074063a9c75b4f/oslo_messaging/rpc/server.py#L178-L180
15:26:04 gibi but that line is visible in case of a successful run too
15:27:07 sean-k-mooney well after that message is printed we sent the failure to the conductor/api here https://github.com/openstack/oslo.messaging/blob/ca939fc0e4683efce87b567a9a074063a9c75b4f/oslo_messaging/rpc/server.py#L186
15:29:16 sean-k-mooney would that be recied by https://github.com/openstack/nova/blob/master/nova/conductor/api.py#L140-L141 ?
15:29:43 gibi this is the log from a successful run https://paste.opendev.org/show/809928/
15:29:58 sean-k-mooney no it would be in the conductor maager https://github.com/openstack/nova/blob/fdfdba265833d237e22676f9a223ab8ca0fe1e03/nova/conductor/manager.py#L941
15:30:48 sean-k-mooney gibi: right so in that case we see more output in the python loggin capture
15:31:13 sean-k-mooney where as ehre it stops and we get stderr
15:31:45 gibi sean-k-mooney: it is strange, the timeout is from self.compute_task_api.build_instances not from unshelve_instance
15:32:16 sean-k-mooney build instance?
15:32:25 sean-k-mooney so here https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L2533-L2534
15:32:31 sean-k-mooney oh
15:32:40 sean-k-mooney we mess withthe name before we boot the vm
15:32:48 sean-k-mooney are we somethimes landing on host2
15:33:05 sean-k-mooney we are not forcing it to boot on host1
15:33:44 gibi we request to land on host1 first https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L554
15:35:43 gibi in the meantime I confirm that it is not about testcase ordering. the same order that failed on the gate passing for me locally
15:37:16 gibi I don't get how can we fail on the build_instance so late
15:37:27 gibi the VM went to active according to the test
15:39:04 gibi shit is it is a reschedule
15:39:14 gibi that calls back to build_instance
15:39:30 gibi File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py", line 2263, in _do_build_and_run_instance
15:41:17 sean-k-mooney ya i was just checkign that we dont use build an drun instance in unshelve which we dont we use driver.spawn
15:41:19 sean-k-mooney https://github.com/openstack/nova/blob/fdfdba265833d237e22676f9a223ab8ca0fe1e03/nova/compute/manager.py#L6675
15:41:56 sean-k-mooney gibi: you think for some reason it did not boot on host1 and reschduled to host2
15:42:12 sean-k-mooney we could tetst this by disabling host1 and see if that cause the error
15:42:38 sean-k-mooney we shoudl see the schduler select the host though right
15:43:48 gibi I can test that
15:45:07 gibi if I disable host1 at the start of the test case then the initial boot will fail and the VM is in ERROR state
15:45:21 gibi * initial boot fails
15:45:31 sean-k-mooney \noslo_messaging.exceptions.MessagingTimeout: No reply on topic conductor\n', 'host2')
15:45:32 gibi so the test forces the VM to host1
15:45:45 sean-k-mooney the message time out was for host 2
15:45:52 gibi could it be that # make host1 unusable so the subsequent unshelve needs to select host2
15:45:55 gibi self.admin_api.put_service(
15:45:58 gibi sorry
15:45:58 gibi self.compute1_service_id, {"status": "disabled"})
15:46:26 gibi coudl it be that https://github.com/openstack/nova/blob/fdfdba265833d237e22676f9a223ab8ca0fe1e03/nova/tests/functional/test_servers_resource_request.py#L2548 does not disable the host quickly enough and ushelve selects host1?
15:47:47 gibi hm, but why host2 is the call, true
15:47:54 bauzas quick reminder
15:48:06 bauzas nova meeting in 12-ish minutes in this channel
15:49:40 sean-k-mooney its posible although that is ment to be a blocking call
15:50:05 sean-k-mooney gibi: have you tied inverting the logic an disbaling host2 instead of host one
15:50:23 sean-k-mooney here https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L2548-L2549
15:50:55 gibi so change the test from boot:host1, shelve offload, unshelve:host2 -> to boot:host2, shelve offload, unshelve:host1 /
15:50:56 sean-k-mooney you could be right that we are racing with that disabel and we neeed to add a get
15:50:58 gibi ?
15:51:27 sean-k-mooney no i ment use replace self.compute1_service_id with self.compute2_service_id
15:51:32 gibi I cannot simply disable host2 as we need to unshelve on a compute where the placement RP tree is wrong

Earlier   Later