Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2023-07-27
17:34:10 dansmith so why are we getting blank log output when the file on disk clearly has stuff in it?
17:34:15 sean-k-mooney that is the orginal xml we generate
17:34:38 sean-k-mooney there is no console element at all we just set the serial port and pass the log path
17:34:40 dansmith that has no console stuff in it and is not complete
17:34:51 sean-k-mooney no i just didn copy it all one sec
17:35:09 dansmith but I don't see what it matters what we generate
17:35:15 sean-k-mooney https://paste.opendev.org/show/bdwD3vAg5f6D6iNsIHk1/
17:35:33 melwitt it's relying on <source> in the xml to get the console path, so it gets no path at all
17:36:01 sean-k-mooney we are telling libvirt to do whatever it need to to make sure teh serial console is in a given file
17:36:03 dansmith melwitt: oh okay, gotcha you said that earlier I think
17:36:30 dansmith okay, so if we ask for pty/logfile and rely on virtlogd now it sounds like
17:36:33 sean-k-mooney i think we shoudl be changing this code to only use that instaed
17:36:46 dansmith so the comment in the code there about ptys says something about container types,
17:36:57 dansmith presumably because they will hang a process if something doesn't consume their pty
17:37:17 dansmith so perhaps that code is leftover from long ago before we moved to virtlogd everywhere, and that all needs to be ripped out?
17:37:20 melwitt I did but I know it's hard to visualize. here's my dumb print statements showing how it goes https://paste.openstack.org/show/bpovXD89OL2QzukI3BWi/
17:37:26 sean-k-mooney he virt_types kvm and qemu are the only ones
17:37:28 sean-k-mooney # which create a dedicated file device for the console logging.
17:37:33 sean-k-mooney ok
17:37:35 dansmith keep reaing
17:37:38 dansmith *reading
17:37:46 sean-k-mooney so the pty fallback is for other virt drivers
17:37:58 sean-k-mooney not driver virt types like lxc
17:38:10 dansmith it says "like lxc"
17:38:15 sean-k-mooney yep
17:38:28 dansmith you said "not virt types like lxc"
17:38:37 sean-k-mooney so if virt_type not in (qemu,kvm)
17:38:47 sean-k-mooney then we need to read from the pty
17:38:51 sean-k-mooney and save it to a file
17:38:57 sean-k-mooney but for qemu/kvm we dont
17:39:22 dansmith anyway, it makes me super nervous to mess with stuff like this without a very clear understanding of what is going on, and I *still* don't understand why this isn't always failing especially after sean-k-mooney's change to the test
17:39:29 sean-k-mooney so i think hte fix is to wrap that cod in an if/else based on the virt_type
17:39:46 melwitt +1 to be really careful messing with this
17:39:56 dansmith sean-k-mooney: why do those virt types not also benefit from virtlogd? if anything, moving to the pty and daemon would make qemu/kvm more like lxc
17:40:03 sean-k-mooney ya im not sure why ceph is not exploding
17:40:12 dansmith ceph or any of the other jobns
17:40:41 sean-k-mooney so they might but i wonder if this comment predates the creation of virtlogd
17:41:00 sean-k-mooney i could try deploying with lxc and find out
17:41:07 dansmith the fact that we don't (that we know of) see corruption of console logs due to us sometimes reading from the pty also just makes me sus that this is not actually happening
17:41:22 sean-k-mooney before virtlogd was a thing qemu used to write to the file itself
17:41:35 dansmith sean-k-mooney: right that's my point. maybe this all needs to go, not preserve some of it for lxc
17:41:56 dansmith sean-k-mooney: right I know, and virtlogd should have made them all effectively the same
17:42:05 sean-k-mooney ok so there are a couple of thing i can try ill add some logs to the fucntion and see if we are hitting this
17:42:13 sean-k-mooney then i can spin up another vm with nova and lxc
17:42:36 sean-k-mooney do you know if stoping virtlogd would be enough to change libvirt behavior
17:42:44 sean-k-mooney i coudl also try that
17:42:54 dansmith ohhh hang on
17:43:11 dansmith melwitt: does the running instance have a source= tag in the console/pty element?
17:43:25 dansmith if not, then it's never finding this console_type==pty thing because the xpath won't match
17:44:01 melwitt dansmith: it does after the initial create. I haven't checked if it does after I start it after stopping it. checking now
17:44:10 dansmith okay I thought you said it didn't on stop
17:44:11 sean-k-mooney it does
17:44:22 sean-k-mooney after we stop it it goes away
17:44:40 melwitt dansmith: ? I said it has <source> before stop and then it does not have <source> after stop
17:44:42 sean-k-mooney when we do a dumpxml we are not actully reading a file
17:44:51 sean-k-mooney we are geting the responce form the libvirt deamon
17:45:02 dansmith so after stop we should be getting the actual file on disk without the pty messing it up
17:45:07 sean-k-mooney i dont know if the console is ever on the file on disk
17:45:31 sean-k-mooney ya proably does anyoen know where that file is and we can check
17:46:13 melwitt if I start it again it has <source> agian
17:46:14 sean-k-mooney ah its in /etc/libvirt/qemu/instance-00000001.xml
17:46:16 melwitt *again
17:46:24 dansmith okay, so
17:46:34 dansmith after we shutdown,
17:46:49 dansmith we match neither pty or file, the path.exists fails and we just return "" for the console log
17:47:02 dansmith is that the thinking?
17:47:19 dansmith (sorry if I'm just being slow)
17:47:33 melwitt (and console log get works again)
17:47:54 dansmith I just so don't see how this is working for the non-lvm cases
17:47:56 melwitt no it's bailing before it ever gets to the log file part
17:48:03 sean-k-mooney so so the file on disk is not updated with the souce element when its running so its only updated in the trainient domain while its running
17:48:09 dansmith melwitt: right, so here right? https://github.com/openstack/nova/blame/master/nova/virt/libvirt/driver.py#L4483
17:48:11 melwitt because it doesn't parse <source>. I don't think that's intended probably
17:48:34 melwitt no, like this https://paste.openstack.org/show/bpovXD89OL2QzukI3BWi/
17:49:10 melwitt fails (returns) before that
17:49:39 dansmith melwitt: shouldn't that return an error through the api then?
17:49:41 sean-k-mooney oh interesting https://termbin.com/0qcj
17:49:54 dansmith tempest is getting blank logs not an error, AFAIK
17:51:07 sean-k-mooney ya the error iss """AssertionError: '' is not true : Console output was empty."""
17:51:33 dansmith unless we're not actually raising that, but I thought we were in one case you pasted earleir
17:51:35 sean-k-mooney the test is doing self.assertTrue(output, "Console output was empty.")
17:51:46 dansmith wait what
17:51:47 melwitt yeah... looking to see if I can see how. for me I think it goes here and raises HTTPNotFound https://github.com/openstack/nova/blob/master/nova/api/openstack/compute/console_output.py#L58
17:51:53 sean-k-mooney no i think the test is not checking the return code
17:52:01 melwitt so it must be something the client is doing?
17:52:34 dansmith omh
17:52:48 dansmith sean-k-mooney: it's checking to see that the console is actually empty in shutoff state/
17:53:16 sean-k-mooney no output will be true if its not the empty string
17:53:33 melwitt on the command line I get "ResourceNotFound: 404: Client Error for url: http://127.0.0.1/compute/v2.1/servers/68b8344b-10dc-4a84-90e4-ad8be7a2bb60/action, Guest does not have a console available."
17:53:37 melwitt osc
17:53:48 dansmith wtf
17:54:00 dansmith so I guess I totally misread the test
17:54:02 sean-k-mooney ya thats what i get too
17:54:09 sean-k-mooney 404
17:54:22 sean-k-mooney but i think the 404 has an empy body
17:54:33 melwitt raise webob.exc.HTTPNotFound(explanation=e.format_message())
17:54:33 melwitt exception.ConsoleNotAvailable) as e:
17:54:33 melwitt except (exception.InstanceNotFound,
17:54:33 melwitt yeah and it's bc
17:54:33 dansmith I thought the test was asserting that the console was *still* available

Earlier   Later