Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2023-07-27
17:09:45 melwitt so the parsing it's doing is not finding the console path
17:11:32 melwitt before the instance is stopped, there's <source path='/dev/pts/3'/> under console. after the instance is stopped there is not
17:11:34 melwitt and it's looking for this ('pty', "./devices/console[@type='pty']/source[@path]", 'path')
17:11:48 sean-k-mooney https://paste.opendev.org/show/bU3Vb2zX0TgOqU42xBAV/
17:12:11 sean-k-mooney it is be we have the log file line in both cases
17:12:26 sean-k-mooney so we shoudl be usign that not source
17:12:57 sean-k-mooney or at least falling back to the log line if source is not found
17:13:07 melwitt https://paste.openstack.org/show/bnLH5aJxsHlzXdZS455s/
17:13:30 melwitt yeah, I think that's the bug
17:13:35 melwitt it's not falling back
17:13:51 sean-k-mooney well i think log is alwasy where to im not sure if the fallback is ever needed
17:14:14 sean-k-mooney i woudl be incliend to prefer log and fallback ot source if its not there
17:14:44 melwitt the log file is always there. it's just using source only
17:15:22 melwitt it looks like the code intends to fall back to the file but it's not working
17:15:30 sean-k-mooney we also have https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L4577C1-L4580C43
17:15:36 sean-k-mooney we are generating what that will be
17:15:42 sean-k-mooney we dont ever need to parse the xml
17:15:46 dansmith so the test not waiting for sshable was actually the reason this never failed? because we were racing with the shutdown?
17:16:04 melwitt hah probably
17:16:11 melwitt I dunno
17:16:20 dansmith I guess I don't know why this is only failing lvm still, unless it's just lvm being slower or faster about something?
17:16:31 melwitt yeah that's what I don't understand
17:17:37 melwitt I would have wondered if console type is not pty if not lvm but my setup is rbd and I get console type pty.. and the ceph job isn't failing this test iiuc
17:18:11 dansmith right
17:18:14 sean-k-mooney i think its a pty when virtlogd is installed and running
17:18:36 sean-k-mooney qemu is using the pty to talk to virtlogd which is writing to the file
17:18:38 sean-k-mooney i think
17:19:15 sean-k-mooney but i dont see why we woudl ever need to read form that. we can simplfy this code by using
17:19:20 sean-k-mooney _get_console_log_path(instance)
17:19:28 sean-k-mooney to return the log file and just read directly form that
17:20:21 melwitt yeah I dunno if there is or was a reason for doing the reading from pty
17:21:19 sean-k-mooney https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L4462-L4488
17:21:31 sean-k-mooney so this is doub
17:21:43 sean-k-mooney we use console_log = self._get_console_log_path(instance)
17:22:00 sean-k-mooney to get the path which is to the file but that not the path we check for at the start
17:22:31 sean-k-mooney oh actully
17:23:01 sean-k-mooney https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L4487-L4502
17:23:34 sean-k-mooney we read form the pty and write to the log and then read form the log again but this time without privsep
17:24:29 melwitt this is like rube goldberg
17:24:51 sean-k-mooney ok so if i tail the log file and start the vm it gets the stream
17:25:01 sean-k-mooney so we dont actully need to write to the logfile
17:25:12 sean-k-mooney it already has the data form the pty
17:25:53 sean-k-mooney and shutting off the instance dow not affect the data
17:26:34 melwitt what about if the compute host were to be rebooted? just trying to think if there's any case where we need the file
17:26:58 sean-k-mooney the file is beiing wrttien by qemu/virtlogd
17:27:16 sean-k-mooney its only written by use if we do a console log show
17:27:27 melwitt oh ok
17:27:36 sean-k-mooney so if we removed that code from nova it would already have the data
17:28:19 sean-k-mooney i did sudo tail -F console.log to confirm that
17:28:32 dansmith sean-k-mooney: certainly we need to not be reading from that pty if virtlogd is already doing it
17:28:34 sean-k-mooney when the vm starts it recreates the file
17:28:51 dansmith so where in there are we only doing that if virtlogd is not?
17:29:25 sean-k-mooney so is this part of the xml generated by libvirt or us
17:29:53 sean-k-mooney i tought we were just setting the log location and libvirt filled in the rest based on if virtlogd was deployed and how it was configured
17:30:21 dansmith not sure that matters, since this is on get and doesn't know if we added it or libvirt itself did right?
17:30:44 sean-k-mooney well we are specifying the location of the file
17:30:53 sean-k-mooney so my point is i think we can ignore if its a pty or not
17:30:58 sean-k-mooney and alwasy just go to the file
17:31:09 dansmith not here.. here we're just looking at the state of the xml
17:31:23 sean-k-mooney but we dont need to look at the xml at all
17:31:39 sean-k-mooney thats my point we have a function that takes the instance and returs the log path to use
17:31:49 sean-k-mooney its always called consol.log in the instnace dir
17:31:54 dansmith I know that's your point, I'm just not sure it's right :)
17:32:04 sean-k-mooney ok :)
17:32:14 dansmith I want to know how we're not tripping over us reading from the pty when virtlogd already is
17:32:40 sean-k-mooney ah good question
17:32:46 dansmith I mean I guess if virtlogd is select()ing from it then it has already read everything we potentially could have from the pty each time we go to read from it, and we just get lucky that we never compete
17:33:01 dansmith but I would expect to occasionally see some corruption there
17:33:26 dansmith and is virtlogd always a thing in libvirt now, or is it optional?
17:33:37 dansmith and even still,
17:33:54 dansmith it looks to me like we *are* always returning the contents of the file at the bottom of that function,
17:34:09 sean-k-mooney https://paste.opendev.org/show/bW8SNwHjfUFkOMv4gp5N/
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

Earlier   Later