| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2021-10-12 | |||
| 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 | |
| 16:04:19 | bauzas | I saw gibi and sean-k-mooney discussing about one of them | |
| 16:04:43 | bauzas | folks, do you want to discuss about this now or off the meeting ? | |
| 16:04:55 | bauzas | context : https://bugs.launchpad.net/nova/+bug/1946339 | |
| 16:04:55 | sean-k-mooney | i think off meeting | |
| 16:04:59 | gibi | I have nothing specific to say :) | |
| 16:05:06 | bauzas | cool, moving on then | |
| 16:05:08 | gibi | still trying to reproduce / understand what happens | |
| 16:05:13 | sean-k-mooney | im still reviewing the logs and trying to repoduce | |