| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2023-02-07 | |||
| 13:37:54 | sean-k-mooney | so the same would happen for debiany 11->12 or centos 9->10 in the future | |
| 13:38:42 | sean-k-mooney | its to ensure you can upgrade openstack without nessiarly needing to upgrade the OS it also mimic how our greneade jobs work | |
| 13:39:36 | sean-k-mooney | its related to https://github.com/openstack/governance/blob/master/resolutions/20220210-release-cadence-adjustment.rst the skip level upgrade release and the new lifecycle for integrated release projects | |
| 13:40:01 | sean-k-mooney | dvo-plv: o/ | |
| 13:40:05 | kashyap | sean-k-mooney: Yeah, the upgradeability makes sense | |
| 13:40:31 | sean-k-mooney | kashyap: bauzas any objection to doing the bump in a few weeks after RC 1 is out | |
| 13:40:41 | sean-k-mooney | better to try and do that early rather then late | |
| 13:40:55 | sean-k-mooney | or at least identify what our next versions should be declared as | |
| 13:41:02 | bauzas | when RC1 is out, then the master branch will be the Bobcat release, so ok | |
| 13:41:14 | kashyap | sean-k-mooney: Definitely agree on doing it earlier | |
| 13:42:20 | opendevreview | Merged openstack/nova master: Move comment about _destroy_evacuated_instances() https://review.opendev.org/c/openstack/nova/+/872348 | |
| 13:42:28 | opendevreview | Merged openstack/nova stable/wallaby: [stable-only][cve] Check VMDK create-type against an allowed list https://review.opendev.org/c/openstack/nova/+/871557 | |
| 13:42:35 | bauzas | \o/ | |
| 13:45:10 | bauzas | gibi: interestingly, if I restrict the logsearch call to ImportError: This test imports the 'libvirt' module, which it should not in the test environment. Please add appropriate mocking to this test." which is the latest exception I only get 19/143 failures that match (from the last 20 days) | |
| 13:45:26 | opendevreview | Maxim Monin proposed openstack/nova master: Server Rescue leads to Server ERROR state if base image is deleted https://review.opendev.org/c/openstack/nova/+/872385 | |
| 13:45:41 | bauzas | by comparing https://7ffaea22ff93fca2f0ea-bf433abff5f8b85f7f80257b72ac6f67.ssl.cf5.rackcdn.com/869900/7/gate/nova-tox-functional-py38/3b10d8a/testr_results.html to https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_d00/868237/9/check/nova-tox-functional-py38/d00d1ff/testr_results.html that's why I think we have this | |
| 13:46:44 | gibi | I dont see the difference both has the import error line | |
| 13:57:31 | bauzas | gibi: I mean, this is just a canary line for not getting the false positives | |
| 13:58:03 | gibi | do you have a false positive where this line is missing? | |
| 14:00:35 | opendevreview | David Hill proposed openstack/nova master: Increase user_data from 64k to 128k https://review.opendev.org/c/openstack/nova/+/872931 | |
| 14:04:31 | bauzas | gibi: one of the false positives is https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_aea/850501/15/check/nova-tox-functional-py38/aea02af/testr_results.html | |
| 14:05:22 | bauzas | gibi: you can find the DB issue in job_output.txt but the tests aren't failing | |
| 14:05:25 | bauzas | https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_aea/850501/15/check/nova-tox-functional-py38/aea02af/job-output.txt | |
| 14:06:05 | bauzas | and you won't see the canary line | |
| 14:06:08 | gibi | I see. So the difference between the false positive and a real positive is that the real one hits the libvirt import check and fails the actual check while the false one did not | |
| 14:06:17 | bauzas | yup | |
| 14:06:21 | gibi | s/actual check/actual test/ | |
| 14:06:23 | bauzas | so now I'm trying to find the pattern | |
| 14:06:32 | gibi | I see | |
| 14:06:34 | bauzas | I stestr loaded all the subunites | |
| 14:06:35 | gibi | good progress | |
| 14:06:48 | bauzas | now, I'm grepping this large txtfile I generated | |
| 14:13:57 | bauzas | gibi: see, the fact that we get the same exceptions with or without failing makes me think that the canary isn't maybe just a canary but rather the root cause of the failure | |
| 14:14:26 | bauzas | or rather some condition to a failure | |
| 14:15:00 | bauzas | if we can understand why in some cases we say meh and why not, then we could fix the problem | |
| 14:21:34 | bauzas | gibi: https://4dca9d38a541907e85e1-0253beca39d73a6e7192d5b32ed5edc2.ssl.cf2.rackcdn.com/860282/2/check/nova-tox-functional-py310/466e0d7/testr_results.html is a good candidate to use as it got | |
| 14:21:48 | bauzas | *both* false positive and true positives | |
| 14:22:00 | bauzas | test_resize_revert_across_azs is a true positive | |
| 14:22:13 | bauzas | while other api failures are false ones | |
| 14:27:29 | gibi | are the hits in the same worker? that would be the best to find a worker with multipl hits as that would mean that worker had more than one leak | |
| 14:28:45 | bauzas | 2023-01-24 18:37:50.710671 | ubuntu-jammy | File "/home/zuul/src/opendev.org/openstack/nova/nova/virt/libvirt/driver.py", line 10619, in _live_migration 2023-01-24 18:37:50.710677 | ubuntu-jammy | self.live_migration_abort(instance) | |
| 14:28:56 | bauzas | looks to me all our pain comes from this ^ | |
| 14:31:18 | bauzas | and then I'm confused | |
| 14:31:48 | bauzas | why so the f... are we calling live_migration_abort() is some functional test that just creates an instance ? | |
| 14:31:52 | bauzas | https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_d00/868237/9/check/nova-tox-functional-py38/d00d1ff/testr_results.html | |
| 14:32:02 | gibi | bauzas: the leaked thread calls it :) | |
| 14:32:18 | bauzas | hah | |
| 14:32:33 | gibi | bauzas: I think the global state the leak acts on to infulence the later tests is sys.meta_path from ImportModulePoisonFixture | |
| 14:33:23 | gibi | so my current theory: we leak a thread/eventlet that eventually calls live_migration_abort while a later test runs. As the later test sets the global posion on libvirt import the later test gets the failure | |
| 14:33:56 | gibi | if there is no ImportModulePoisonFixture set in the later test then we only see the stack trace | |
| 14:33:56 | bauzas | yeah, the global libvirt object is set to None by something else | |
| 14:34:14 | bauzas | so the threads get this NoneError and fails whivh tramples the whole terst | |
| 14:34:39 | bauzas | something we merged tampered the libvirt import | |
| 14:34:49 | bauzas | and we need to find it | |
| 14:35:19 | gibi | I think we intentionally posion libvirt import | |
| 14:35:47 | bauzas | by posion, you mean poison, right? | |
| 14:36:19 | bauzas | but yeah got it | |
| 14:36:26 | gibi | yeah, sorry | |
| 14:36:34 | bauzas | afaicr, our libvirt functional tests do poison indeed the import | |
| 14:37:46 | bauzas | the problem is that it seems that some test that calls live_mig_abort() doesn't use the libvirt poisoned instance, hence the issue | |
| 14:38:01 | bauzas | but which one and how to find it ? | |
| 14:39:15 | bauzas | v.org/openstack/nova/nova/scheduler/rpcapi.py", line 174, in update_instance_info\n cctxt.cast(ctxt, \'update_instance_info\', host_name=host_name,\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/fixtures/_fixtures/monkeypatch.py", line 86, in avoid_get\n return captured_method(*args, **kwargs)\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38 | |
| 14:39:15 | bauzas | fo(ctxt, instance)\n', ' File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py", line 2219, in _update_scheduler_instance_info\n self.query_client.update_instance_info(context, self.host,\n', ' File "/home/zuul/src/opendev.org/openstack/nova/nova/scheduler/client/query.py", line 69, in update_instance_info\n self.scheduler_rpcapi.update_instance_info(context, host_name,\n', ' File "/home/zuul/src/opende | |
| 14:39:15 | bauzas | \nDuring handling of the above exception, another exception occurred:\n\n', 'Traceback (most recent call last):\n', ' File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py", line 203, in decorated_function\n return function(self, context, *args, **kwargs)\n', ' File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py", line 9300, in _post_live_migration\n self._update_scheduler_instance_in | |
| 14:39:15 | bauzas | /queue.py", line 322, in get\n return waiter.wait()\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/eventlet/queue.py", line 141, in wait\n return get_hub().switch()\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/eventlet/hubs/hub.py", line 313, in switch\n return self.greenlet.switch()\n', '_queue.Empty\n', ' | |
| 14:39:15 | bauzas | 2023-02-06 16:15:47,325 ERROR [root] Original exception being dropped: ['Traceback (most recent call last):\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/oslo_messaging/_drivers/impl_fake.py", line 207, in _send\n reply, failure = reply_q.get(timeout=timeout)\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/eventlet | |
| 14:39:17 | bauzas | /lib/python3.8/site-packages/oslo_messaging/rpc/client.py", line 190, in call\n result = self.transport._send(\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/oslo_messaging/transport.py", line 123, in _send\n return self._driver.send(target, ctxt, message,\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/oslo_mess | |
| 14:39:19 | bauzas | aging/_drivers/impl_fake.py", line 222, in send\n return self._send(target, ctxt, message, wait_for_reply, timeout,\n', ' File "/home/zuul/src/opendev.org/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/oslo_messaging/_drivers/impl_fake.py", line 213, in _send\n raise oslo_messaging.MessagingTimeout(\n', 'oslo_messaging.exceptions.MessagingTimeout: No reply on topic scheduler\n'] 2023-02-06 16:15:47,361 WAR | |
| 14:39:21 | bauzas | NING [nova.virt.libvirt.driver] Error monitoring migration: (sqlite3.OperationalError) no such table: compute_nodes | |
| 14:39:53 | gibi | maybe the test has the poison but it is removed after the test finished, but the thread that will do the abort call is leaked to another test that might or might not have (or need) the poision | |
| 14:49:33 | opendevreview | Elod Illes proposed openstack/nova stable/ussuri: DNM: CI test https://review.opendev.org/c/openstack/nova/+/872184 | |
| 15:02:39 | elodilles | bauzas: i'll update the meeting wiki (stable section) if you are OK with it | |
| 15:02:51 | bauzas | elodilles: do it | |
| 15:02:56 | elodilles | ack | |
| 15:04:10 | bauzas | gibi: any way we could have to introspect in some log what was creating the thread ? | |
| 15:05:01 | bauzas | ChatGPT, maybe you know ? | |
| 15:07:48 | elodilles | :) | |
| 15:08:04 | elodilles | (meanwhile, I'm done with the wiki editing) | |
| 15:10:57 | gibi | bauzas: we can try printing https://github.com/openstack/nova/blob/9bc198e05733c03ba1a40f89cd6a77ab54b7e480/nova/tests/fixtures/notifications.py#L154-L160 to get the name of the testcase that started the eventlet | |
| 15:13:01 | bauzas | gibi: I can write a patch | |
| 15:13:17 | bauzas | given the occurrences, we may have evidences coming up | |
| 15:13:22 | bauzas | sooner than later | |
| 15:14:00 | gibi | yeah lets try that | |
| 15:15:28 | bauzas | gibi: that being said, the thread is maybe not a FakeVersionedNotifier | |
| 15:16:28 | gibi | bauzas: FakeVersionedNotifier was on the receiving end in the past not on the sending side. in the current case the poison is on the receiving side, and the live_mig_abort is on the sending side afaik | |
| 15:16:32 | bauzas | gibi: are you proposing me to add this directly in File "/home/zuul/src/opendev.org/openstack/nova/nova/compute/manager.py", line 8854, in _do_live_migration self.driver.live_migration(context, instance, dest, ? | |
| 15:17:50 | gibi | if we want to print only in true positive cases then add it in /home/zuul/src/opendev.org/openstack/nova/nova/tests/fixtures/nova.py line 1849, | |
| 15:17:59 | gibi | if we want to print in false positive cases too then in /home/zuul/src/opendev.org/openstack/nova/nova/virt/libvirt/driver.py", line 10071, in live_migration_abort | |
| 15:18:54 | gibi | don't call _get_sender_test_case_id just copy the implementation of it | |
| 15:19:36 | bauzas | yup, I see | |
| 15:21:12 | bauzas | gibi: but we want to know the parent, right? | |
| 15:21:35 | gibi | bauzas: print the first id it gets that will be the name of the test case leaked the thread either directly or indirectly | |
| 15:21:56 | gibi | hm, direclty, hence the walking on the parents | |
| 15:22:25 | gibi | so print the first id that will be the eventlet nova spawn or spawn_n started and have the test case id emeded | |
| 15:22:59 | gibi | we walk the parents as eventlets later can spawn other eventlets which we don't control and therefore we cannot propagate the testcase id there | |
| 15:32:37 | opendevreview | Sylvain Bauza proposed openstack/nova master: DNM: Add logging for leaking out the non-poisoned libvirt testcase https://review.opendev.org/c/openstack/nova/+/872975 | |
| 15:32:43 | bauzas | gibi: ^ | |
| 15:32:59 | bauzas | I said DNM but we could merge it | |
| 15:33:18 | bauzas | instead of us rechecking | |
| 15:46:35 | opendevreview | Dan Smith proposed openstack/nova master: Add docs for stable-compute-uuid behaviors https://review.opendev.org/c/openstack/nova/+/872977 | |