| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2020-11-13 | |||
| 13:56:48 | f0o | how would I go about debugging this weird paused issue? | |
| 13:56:51 | f0o | where to start looking? | |
| 13:57:24 | sean-k-mooney | f0o: you should be looking at the nova-compute logs for the instance in question and seeing what actions cause the instance to be paused | |
| 13:57:50 | sean-k-mooney | e.g. did the compute agent recived an event form libvirt saying the guest is now paused | |
| 13:57:57 | sean-k-mooney | or did it call libvirt to pause it | |
| 13:58:09 | f0o | ok, will do | |
| 13:58:15 | f0o | thnkas :) | |
| 13:58:22 | f0o | thanks* | |
| 14:02:34 | f0o | I have a few entries that have VM Paused (Lifecycle Event) in them. just gonna spawn a new instance and reboot it to see all the logs it generates | |
| 14:19:02 | f0o | [instance: 4d131088-4ca6-47bd-ab5c-47b9e0a7c996] VM Paused (Lifecycle Event) & During _sync_instance_power_state the DB power_state (1) does not match the vm_power_state from the hypervisor (3). Updating power_state in the DB to match the hypervisor. | |
| 14:19:13 | f0o | [instance: 4d131088-4ca6-47bd-ab5c-47b9e0a7c996] Instance is paused unexpectedly. Ignore. | |
| 14:19:28 | f0o | so those 3 lines happen when I issue reboot inside the instance | |
| 14:20:16 | f0o | and now horizon shows it as Active/Paused and there's no resume action. I need to issue Hard-Reboot to kick it back alive | |
| 14:20:30 | sean-k-mooney | that look like libvirt is moving it to paused so | |
| 14:20:42 | sean-k-mooney | and then the compute agent is just updating the db to reflect that | |
| 14:22:41 | f0o | well /var/log/libvirt/qemu/instance-00000115.log sure is useless lol | |
| 14:26:50 | openstackgerrit | Radosław Piliszek proposed openstack/nova master: [docs] Fix a placement client's command https://review.opendev.org/762663 | |
| 14:29:54 | f0o | not sure where to go from here | |
| 14:30:14 | sean-k-mooney | can you paste the xml for the instace somewhere | |
| 14:30:19 | f0o | sure | |
| 14:30:47 | sean-k-mooney | there is an option to contol the reboot action but we dont set it but im just wondering if anything else is there that was generated by libvirt | |
| 14:31:11 | sean-k-mooney | libvirt modifies the xml we give it an fills in things like pci address automatically | |
| 14:31:56 | f0o | http://paste.openstack.org/show/oGhApPwoy0lNe5cKmV0G/ | |
| 14:32:35 | sean-k-mooney | <on_poweroff>destroy</on_poweroff> | |
| 14:32:36 | sean-k-mooney | <on_reboot>restart</on_reboot> | |
| 14:32:38 | sean-k-mooney | <on_crash>destroy</on_crash> | |
| 14:32:41 | sean-k-mooney | so those are what i expect | |
| 14:33:00 | sean-k-mooney | <on_reboot>restart</on_reboot> is what i was wondering about | |
| 14:33:16 | f0o | so that seems alright then? | |
| 14:33:55 | sean-k-mooney | yes so what could be happening is a race between the periodic task and the vm reboot | |
| 14:33:55 | f0o | nova-compute-kvm version 2:20.0.0~rc1-0ubuntu3~cloud0 and qemu-kvm version 1:4.0+dfsg-0ubuntu9~cloud0 (just in case) | |
| 14:34:10 | sean-k-mooney | is it happeing everytime | |
| 14:34:16 | sean-k-mooney | or jsut some times | |
| 14:34:29 | f0o | it's happening the majority of times | |
| 14:34:48 | f0o | there are some exceptions to it, but by now I'd wager that most times it gets stuck in paused | |
| 14:35:13 | sean-k-mooney | hum ok the interval is 10 minutes for the update by default | |
| 14:35:14 | sean-k-mooney | https://docs.openstack.org/nova/latest/configuration/config.html#DEFAULT.sync_power_state_interval | |
| 14:35:38 | sean-k-mooney | i assume you have not made that run faster | |
| 14:35:48 | f0o | nope | |
| 14:35:56 | f0o | config is very trivial, most are left as defaults | |
| 14:36:10 | sean-k-mooney | https://docs.openstack.org/nova/latest/configuration/config.html#workarounds.handle_virt_lifecycle_events | |
| 14:36:32 | sean-k-mooney | so you might want to set that to false | |
| 14:36:38 | sean-k-mooney | it look liek this is a know race | |
| 14:37:29 | f0o | ok let's give it a shot | |
| 14:37:35 | sean-k-mooney | if you have the interval at its default then setting that to false should be fine | |
| 14:38:21 | sean-k-mooney | that would have to be set on the compute nodes fyi | |
| 14:38:22 | f0o | set and restarting nova-compute | |
| 14:38:28 | sean-k-mooney | cool | |
| 14:38:45 | f0o | let's give it a shot | |
| 14:41:36 | sean-k-mooney | f0o: by the way the reason we default to haneling event i belive is for ironic | |
| 14:43:57 | f0o | makes sense | |
| 14:44:20 | f0o | at first I thought I was going insane but now that it became more frequent I figured I ask | |
| 14:47:04 | sean-k-mooney | hopefully that option will help | |
| 14:47:47 | sean-k-mooney | the main sideefct is that if you do poweroff in the guest then it wont be refected in the api/db until the interval expires | |
| 14:48:02 | sean-k-mooney | e.g. up to 10 mins form power off by efault | |
| 14:48:30 | f0o | that should be fine | |
| 14:48:37 | sean-k-mooney | that is genreally and ok tradeoff and you can adjust the interval if you want too | |
| 14:48:38 | f0o | worst case I lower the update interval | |
| 14:48:45 | sean-k-mooney | yep | |
| 14:53:00 | f0o | [ 652.025665] reboot: Restarting system .... let's hope it comes back up :D | |
| 14:56:10 | f0o | I can see the qemu process running and consuming 30% cpu but nothing seems alive in it | |
| 14:56:56 | f0o | vnc shows guest hasnt initialized display and view logs is only showing that reboot message | |
| 15:00:53 | f0o | During _sync_instance_power_state the DB power_state (1) does not match the vm_power_state from the hypervisor (3). Updating power_state in the DB to match the hypervisor / Instance is paused unexpectedly. Ignore. | |
| 15:00:55 | f0o | again :< | |
| 15:02:19 | f0o | process is still running and eating up 30% cpu tho, not sure what it's actually doing there | |
| 15:49:26 | sean-k-mooney | f0o: that is sounding more like a qemu bug then an openstack one | |
| 15:49:41 | sean-k-mooney | it sound like its not actully restating properly | |
| 15:50:58 | f0o | cool :D | |
| 15:51:06 | openstackgerrit | Ghanshyam Mann proposed openstack/nova master: DNM: Testing system scope in tempest https://review.opendev.org/740124 | |
| 15:51:11 | f0o | just my luck | |
| 15:52:09 | tacco | hey everyone. Anyone knows why i only get 64VCPUs on a HV with 256 CPU Cores? over commiting ratio is 1.0 :( | |
| 15:52:28 | tacco | AMD EPYC 7742 64-Core Processor | |
| 15:53:24 | gibi | dansmith: hi! Do I understand correctly that the service version check at https://review.opendev.org/#/c/729563/17/nova/compute/api.py@4162 can see version 54 and allowing the shelve call with accelerators while the RPC is still can be manually pinned to < 5.13 and therefore the compute will not the accel_uuids param and therefore not handle the acceleratos properly? | |
| 15:53:53 | gibi | * will not get the accel_uuids | |
| 15:54:23 | dansmith | I'll have to look at that decorator, I think that just got added, right? | |
| 15:54:38 | tacco | i see processor: 255 and cpu cores: 64 in /proc/cpuinfo is this something like HT on Intel CPUs? but only can provide the "real" cores to the VM? | |
| 15:54:54 | tacco | cause i have 250CPUs in my flavor | |
| 15:55:03 | tacco | the VM then spawns with 64CPus | |
| 15:55:10 | f0o | Uhm | |
| 15:55:18 | f0o | 7742 shows as 64 cores | |
| 15:55:26 | f0o | HT stuff doesnt really count afaik | |
| 15:55:53 | dansmith | gibi: yikes, that makes an uncached cross-cell db lookup for every single call of that method :( | |
| 15:56:05 | gibi | dansmith: not too long ago, but it basically calls get_minimum_version_all_cells | |
| 15:56:27 | f0o | tacco: inside the vm you dont see the HT threads? | |
| 15:57:06 | tacco | in the VM at proc/cpuinfo i see only 64 but the vm was spawned with a flavor with 250 vcpus | |
| 15:57:47 | tacco | thats kinda strange and cli hypervisor list also shows 256 CPUs | |
| 15:59:20 | dansmith | gibi: commented on that patch, see if that helps | |
| 15:59:34 | gibi | thanks | |
| 16:05:36 | tacco | i see this seems to be two physical CPUs with 64 cores and 128 threads. that makes sense. But no clue why the VM only got 64Cpus if in the flavor are 250 specified. anyway. will have to dive deeper :D | |
| 16:08:10 | f0o | I'm happy to swap issues with you tacoc :D | |
| 16:08:25 | f0o | other than my dyslexia today lol | |
| 16:09:47 | tacco | always nice to be a usefull person :D | |
| 16:12:30 | gibi | dansmith: you confirmed my fears, thanks | |
| 16:12:36 | dansmith | gibi: ack | |
| 16:12:54 | dansmith | gibi: honestly that decorator seems like a bad idea to me.. that's a lot of overhead hidden in a decorator | |
| 16:13:22 | dansmith | it should at least use a cached value, but I'd prefer we did things like I described, which is rely on the rpc version and a raise from rpcapi | |
| 16:13:30 | sean-k-mooney | tacco: there was a libvirt bug realted to numa reporting and amd but perhaps there are others | |
| 16:13:51 | sean-k-mooney | tacco: what do you see on the host if you do nprc | |
| 16:14:04 | gibi | dansmith: agree. I missed the heavy weightness of that decorator impl in previous reviews. | |
| 16:14:19 | sean-k-mooney | tacco: can you provide the output of virsh capabilities for me in a paste and ill quickly take a look | |