| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2023-02-07 | |||
| 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 | |
| 16:01:03 | opendevmeet | The meeting name has been set to 'nova' | |
| 16:01:03 | opendevmeet | Useful Commands: #action #agreed #help #info #idea #link #topic #startvote. | |
| 16:01:03 | opendevmeet | Meeting started Tue Feb 7 16:01:03 2023 UTC and is due to finish in 60 minutes. The chair is bauzas. Information about MeetBot at http://wiki.debian.org/MeetBot. | |
| 16:01:03 | bauzas | #startmeeting nova | |
| 16:01:13 | bauzas | sorry folks, forgot to remind you of the meeting | |
| 16:01:43 | bauzas | who's around ? | |
| 16:01:57 | Uggla | o/ | |
| 16:02:04 | elodilles | o/ | |
| 16:02:44 | bauzas | I guess we can make a soft start | |
| 16:02:55 | bauzas | #link https://wiki.openstack.org/wiki/Meetings/Nova#Agenda_for_next_meeting | |
| 16:03:02 | bauzas | #topic Bugs (stuck/critical) | |
| 16:03:07 | bauzas | #info No Critical bug | |
| 16:03:11 | bauzas | #link https://bugs.launchpad.net/nova/+bugs?search=Search&field.status=New 28 new untriaged bugs (+1 since the last meeting) | |
| 16:03:15 | bauzas | #info Add yourself in the team bug roster if you want to help https://etherpad.opendev.org/p/nova-bug-triage-roster | |
| 16:03:30 | bauzas | Uggla: fancy getting the bug triage baton for this week N | |
| 16:03:32 | bauzas | ? | |
| 16:04:02 | sean-k-mooney | o/ | |
| 16:04:09 | Uggla | I will be out next week so I would rather postponed if possible | |
| 16:04:49 | bauzas | ack, so artom would you want to continue having the triage baton for an extra week ? | |
| 16:04:59 | Uggla | If not I'll try to do my best till the end of the week. | |
| 16:05:13 | artom | Ah, I completely dropped the ball, didn't I? | |
| 16:05:18 | artom | Yeah, I can keep it | |
| 16:05:26 | bauzas | ++ | |
| 16:05:31 | bauzas | artom: no worries | |
| 16:05:37 | bauzas | and thanks | |
| 16:05:41 | gibi | o/ | |
| 16:06:20 | dansmith | o/ | |
| 16:06:28 | bauzas | ok moving on | |
| 16:06:34 | bauzas | #topic Gate status | |
| 16:06:39 | bauzas | #link https://bugs.launchpad.net/nova/+bugs?field.tag=gate-failure Nova gate bugs | |
| 16:06:42 | bauzas | new item | |
| 16:06:52 | bauzas | #link https://etherpad.opendev.org/p/nova-ci-failures Etherpad for tracking CI failures | |
| 16:07:14 | gibi | there is a fairly long list but please add to it if you see failures | |
| 16:07:18 | gibi | that are not on the list | |
| 16:07:31 | bauzas | we have some of them are hit us in some place between the chair and the man | |
| 16:08:05 | dansmith | oof yeah | |
| 16:08:05 | bauzas | I think the hardest one is at the bottom of the document | |
| 16:08:23 | bauzas | I had a lovely morning and a half-afternoon spent on that one | |
| 16:08:42 | bauzas | in the context of a soonish feature freeze, more hands are more than welcome | |