Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2021-10-12
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 self.compute1_service_id, {"status": "disabled"})
15:45:58 gibi sorry
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
15:51:33 sean-k-mooney here https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L2548-L2549
15:51:43 sean-k-mooney so it unshelve to the same hsot
15:51:52 bauzas gibi: sean-k-mooney: discussing about https://bugs.launchpad.net/nova/+bug/1946339 ?
15:52:01 gibi bauzas: yes
15:52:01 sean-k-mooney right i know it would break the test logic
15:52:11 bauzas ack thanks
15:52:13 sean-k-mooney but im wondering if some how we are not landing on host 2
15:52:31 sean-k-mooney e.g. to confirm your assertion that perhaps the disabel is not working
15:52:49 sean-k-mooney we might need a wait before the unshleve
15:54:00 gibi if I just disable host2 then the test times out at https://github.com/openstack/nova/blob/a8d3ab2513c39aeac3393b2154988316dfa2db3a/nova/tests/functional/test_servers_resource_request.py#L2558 as no expcetion happens host1 can unshelve the instance
15:55:53 sean-k-mooney we should be abel to assert the service is disabeld form the responce https://docs.openstack.org/api-ref/compute/?expanded=update-compute-service-detail#update-compute-service
15:58:13 gibi yeah that would only help if I could reproduce the problem
15:58:21 gibi checking the response
15:58:34 gibi I still have to track down why could we re-schedule
16:00:01 bauzas #startmeeting nova
16:00:01 opendevmeet Meeting started Tue Oct 12 16:00:01 2021 UTC and is due to finish in 60 minutes. The chair is bauzas. Information about MeetBot at http://wiki.debian.org/MeetBot.
16:00:01 opendevmeet Useful Commands: #action #agreed #help #info #idea #link #topic #startvote.
16:00:01 opendevmeet The meeting name has been set to 'nova'
16:00:10 bauzas hola folks
16:00:14 bauzas #link https://wiki.openstack.org/wiki/Meetings/Nova#Agenda_for_next_meeting
16:00:16 gibi o/
16:00:58 sean-k-mooney o/
16:01:39 gmann o/
16:01:41 elodilles o/
16:01:50 bauzas ok, let's start
16:02:26 bauzas #topic Bugs (stuck/critical)
16:02:30 bauzas No Critical bug
16:02:36 bauzas #link 18 new untriaged bugs (+5 since the last meeting): #link https://bugs.launchpad.net/nova/+bugs?search=Search&field.status=New
16:02:50 bauzas sorry I didn't had to triage the bugs this week, will do that tomorrow
16:03:14 bauzas any bug to discuss ?
16:04:00 bauzas ok, looks not
16:04:05 bauzas #topic Gate status
16:04:09 bauzas Nova gate bugs #link https://bugs.launchpad.net/nova/+bugs?field.tag=gate-failure

Earlier   Later