| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2023-07-27 | |||
| 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 | |
| 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 | |