| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2026-05-20 | |||
| 17:23:42 | melwitt | I'm not sure how or why it could be more common to cause a failure in nova-vtpm ... perhaps because there are so few tests total and two of them involve resizes which have to go to the other host | |
| 17:29:50 | sean-k-mooney | melwitt: if the libvirt connection is lost | |
| 17:30:05 | sean-k-mooney | melwitt: we mark the compute service as disabled automaticlly | |
| 17:30:13 | sean-k-mooney | and renableit when it comes back | |
| 17:30:43 | melwitt | sean-k-mooney: yes that's what I meant is I can see why it is causing the NoValidHost, if it happens at an inopportune time | |
| 17:31:10 | sean-k-mooney | so the question is why is that disconenct happening are there OOM events | |
| 17:31:24 | sean-k-mooney | that noramly only happens if libvirt restarts | |
| 17:31:51 | melwitt | hm ok, let me check that | |
| 17:32:50 | sean-k-mooney | the nova-vtpm job looks pretty stabel by the way | |
| 17:33:26 | sean-k-mooney | i assuem your debuging https://zuul.openstack.org/build/61181a17a11a41feb198f6d817337ca1 | |
| 17:33:53 | melwitt | yeah.. agreed. at the time I proposed the patch to reduce concurrency to 1, it was failing with NoValidHost more often and I had thought it was in part due to tests running in parallel. but now that I see this libvirt connection loss thing, I am questioning that thought | |
| 17:34:28 | melwitt | no I'm using https://zuul.opendev.org/t/openstack/build/1efc16477b414adbaf673b00520aa5cf bc that's where I see NoValidHost. the one you linked looked to be a different problem unless I missed something | |
| 17:34:29 | sean-k-mooney | well it could be concrance related | |
| 17:34:46 | melwitt | for the libvirt connection lost? | |
| 17:35:08 | sean-k-mooney | well if the conenction loos was because of an OOM | |
| 17:35:14 | sean-k-mooney | but i doen see that in the logs for that job | |
| 17:35:31 | melwitt | gotcha. yeah I'm not seeing something like that either so far | |
| 17:38:00 | sean-k-mooney | libvirt.libvirtError: internal error: client socket is closed | |
| 17:38:17 | sean-k-mooney | that is werid | |
| 17:39:05 | sean-k-mooney | taht is saying that nova could not create the vm in this case becaus the libvirt socket was closed form libivrts side | |
| 17:39:26 | sean-k-mooney | ot at least we recived a disconenct on the socket we had opened to talk to it | |
| 17:40:02 | sean-k-mooney | in this case it hapepns to be coming form libvirt_secret.undefine() | |
| 17:40:17 | sean-k-mooney | based on the trace back https://zuul.opendev.org/t/openstack/build/1efc16477b414adbaf673b00520aa5cf/log/compute-host/logs/screen-n-cpu.txt#5203 | |
| 17:43:53 | melwitt | this is the one I found that caused a NoValidHost https://zuul.opendev.org/t/openstack/build/1efc16477b414adbaf673b00520aa5cf/log/controller/logs/screen-n-cpu.txt#4543 | |
| 17:47:54 | sean-k-mooney | so i think the libvirt log time stampe are off by an hour form novas | |
| 17:47:58 | sean-k-mooney | 2026-05-12 22:08:17.608+0100: 29111: debug : virThreadJobClear:118 : Thread 29111 (rpc-libvirtd) finished job remoteDispatchNodeGetCPUMap with ret=0 │ | |
| 17:48:00 | sean-k-mooney | │2026-05-12 22:08:29.663+0100: 29119: debug : virThreadJobSet:93 : Thread 29119 (prio-rpc-libvirtd) is now running job remoteDispatchConnectGetLibVersion | |
| 17:48:10 | sean-k-mooney | but there appare to be a dead space in the log at that point | |
| 17:50:52 | sean-k-mooney | oh i was lookign at the compute | |
| 17:52:49 | sean-k-mooney | there is a 20 secodn gap just before then | |
| 17:52:58 | sean-k-mooney | but noting really stands out | |
| 17:56:38 | sean-k-mooney | i will sayits a liile stange that libvirt prints its verison | |
| 17:56:40 | sean-k-mooney | 2026-05-12 22:08:25.052+0100: 96003: info : libvirt version: 10.0.0, package: 10.0.0-2ubuntu8.13 (Ubuntu) | |
| 17:56:58 | sean-k-mooney | and then start loadinga lot of module and doign some netwrok config not long after | |
| 17:57:05 | sean-k-mooney | tha tkind of olooks like it restarted | |
| 17:59:32 | sean-k-mooney | melwitt: ok ya it was stoped and started | |
| 17:59:46 | sean-k-mooney | │May 12 21:08:38 npe61172270ee04 sudo[44964]: stack : PWD=/opt/stack ; USER=root ; COMMAND=/usr/bin/systemctl stop libvirtd │ | |
| 17:59:48 | sean-k-mooney | │May 12 21:08:38 npe61172270ee04 sudo[44964]: pam_unix(sudo:session): session opened for user root(uid=0) by stack(uid=1001) │ | |
| 17:59:50 | sean-k-mooney | │May 12 21:08:38 npe61172270ee04 sudo[44964]: pam_unix(sudo:session): session closed for user root │ | |
| 17:59:52 | sean-k-mooney | │May 12 21:08:39 npe61172270ee04 sudo[45008]: stack : PWD=/opt/stack ; USER=root ; COMMAND=/usr/bin/systemctl start libvirtd │ | |
| 17:59:54 | sean-k-mooney | │May 12 21:08:39 npe61172270ee04 sudo[45008]: pam_unix(sudo:session): session opened for user root(uid=0) by stack(uid=1001) | |
| 18:01:15 | sean-k-mooney | melwitt: so this is likely oen of 2 thing | |
| 18:01:45 | sean-k-mooney | the whitebox tempest plugin need to run in concrance 1 becasue it has test that do thing like restart libivirt | |
| 18:01:56 | sean-k-mooney | so it could be a whitbox test | |
| 18:02:14 | sean-k-mooney | or this could be beacuse fo a post playbook | |
| 18:02:19 | melwitt | sean-k-mooney: oh huh ok. let me check if there is that | |
| 18:02:38 | melwitt | thanks | |
| 18:03:08 | sean-k-mooney | i used `curl https://storage.bhs.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_1ef/openstack/1efc16477b414adbaf673b00520aa5cf/compute-host/logs/syslog.txt | zcat | lnav` | |
| 18:03:17 | sean-k-mooney | to look that the syslog locally | |
| 18:03:31 | sean-k-mooney | but tis clearlly shoing that sudo was use to invoke sysclt | |
| 18:03:40 | sean-k-mooney | *systemctl | |
| 18:04:28 | sean-k-mooney | test_vtpm_creation_after_virtqemud_restart | |
| 18:04:37 | sean-k-mooney | that is proably the test i would look at first | |
| 18:05:12 | sean-k-mooney | yep | |
| 18:05:14 | sean-k-mooney | https://opendev.org/openstack/whitebox-tempest-plugin/src/branch/master/whitebox_tempest_plugin/api/compute/test_vtpm.py#L168 | |
| 18:05:39 | melwitt | ugh ok | |
| 18:05:43 | sean-k-mooney | melwitt: gmaan so we have never gotten aroudn to makeign the serial decorator from tempet proper | |
| 18:05:46 | sean-k-mooney | work in whitebox | |
| 18:06:07 | melwitt | that makes it all make sense. thanks | |
| 18:06:18 | sean-k-mooney | so you either need to splity the job into 2 jobs or run it serially. | |
| 18:07:00 | sean-k-mooney | we have done both at diffent time but we currently set concrrency 1 | |
| 18:07:02 | sean-k-mooney | https://opendev.org/openstack/whitebox-tempest-plugin/src/branch/master/.zuul.yaml#L176 | |
| 18:08:00 | sean-k-mooney | ah https://github.com/openstack/nova/blob/master/.zuul.yaml#L484 | |
| 18:08:05 | melwitt | yeah, I had seen that but did not know the root reason why /facepalm. I'm gonna include this specifically in my code comment | |
| 18:08:32 | sean-k-mooney | we shoudl jsut make whitebox use the serial decorator properly eventully | |
| 18:08:40 | sean-k-mooney | maybe let ai spin on that for a while | |
| 18:08:50 | melwitt | yeah... I know. that was my bad. but I did not see why these would have to be serial, I completely missed the restart thing | |
| 18:09:10 | sean-k-mooney | but ya its one of those thing that you only know about because you have the scars | |
| 18:09:28 | sean-k-mooney | melwitt: not at all this is very easy to miss | |
| 18:10:15 | melwitt | "who wouldn't want concurrency!" "oh." | |
| 18:10:29 | gmaan | sean-k-mooney: yeah but is there any known issue for not using serial decorator in whitebox? | |
| 18:10:47 | melwitt | well, mystery solved haha | |
| 18:10:48 | sean-k-mooney | gmaan: jparker tried, hit an isssue and we never got around to it | |
| 18:10:54 | sean-k-mooney | so gmaan no | |
| 18:11:09 | sean-k-mooney | we tried it once there was a bug we reverted back to not using it | |
| 18:11:15 | gmaan | ohk, I can try but sometime start of next month or when get time | |
| 18:11:42 | sean-k-mooney | https://opendev.org/openstack/whitebox-tempest-plugin/commit/a8986a86c03e32daeebcf4e0fb65c91aede2248a | |
| 18:11:46 | melwitt | that means it would let one test be serial test without having to make all the others? | |
| 18:12:02 | sean-k-mooney | im not conviece it was enable properly in te first palce | |
| 18:12:19 | sean-k-mooney | # Decorator support for serial does not land into tempest until 34.0.0. | |
| 18:12:26 | sean-k-mooney | lol ok well that not a proplem any more | |
| 18:12:56 | sean-k-mooney | melwitt: yes | |
| 18:13:07 | melwitt | sounds like a good decorator | |
| 18:13:12 | gmaan | sean-k-mooney: ack, i was searching the link | |
| 18:13:16 | sean-k-mooney | melwitt: it uses a file based reder writere lock | |
| 18:13:58 | sean-k-mooney | melwitt: basiclly when you use this all the test that dont need to run serially acriore the reasder lock and hte ones that do aquire the writer lock | |
| 18:14:18 | sean-k-mooney | and hten the filesysem lock syncoised across the workers | |
| 18:14:29 | melwitt | makes sense | |
| 18:14:31 | sean-k-mooney | but in addtion ot that we run the serial tests last | |
| 18:14:40 | sean-k-mooney | becuase of how we order testes base don name | |
| 18:14:49 | sean-k-mooney | at least in upstream tempest | |
| 18:15:22 | sean-k-mooney | melwitt: https://github.com/openstack/tempest/commit/dfb304355b46882696ef26386637836577be8db7 | |
| 18:15:42 | sean-k-mooney | it was an optimisation that gibi help imeplemnta few years ago | |
| 18:16:39 | gmaan | yeah, that resolved the aggregates tests issue | |
| 18:16:40 | melwitt | very cool | |
| 18:16:45 | sean-k-mooney | hehe https://github.com/openstack/tempest/commit/73ba33773daf1df1be792b616842dd389fd325bc | |
| 18:16:50 | sean-k-mooney | looks like you have used it before | |
| 18:17:04 | melwitt | uhhh lol | |
| 18:17:06 | gmaan | so for now, concurrency=1 will work for VTPM case as they are from same test class | |
| 18:17:37 | sean-k-mooney | yep also we run like 8 tests in that job | |