| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2022-11-29 | |||
| 16:35:34 | sean-k-mooney | clarkb: we tend to be seeing an avgerate runtime at about 75% or less of the job timeout in my experince | |
| 16:35:42 | clarkb | and I know nova tempest jobs have a large number of other slowness problems | |
| 16:35:55 | clarkb | sean-k-mooney: yes, but if a job digs deeply into swap its all downhill from there | |
| 16:35:56 | sean-k-mooney | we have 2 hour timeouts on our tempest jobs and we rarly go above about 90 mins | |
| 16:35:56 | bauzas | clarkb: that's a fair point | |
| 16:36:05 | clarkb | suddenly your 75% typical runtime can balloon to 200% | |
| 16:36:08 | bauzas | except the fips one | |
| 16:36:14 | sean-k-mooney | clarkb: sure but i dont think we are | |
| 16:36:25 | sean-k-mooney | but its somethign we can look at | |
| 16:36:40 | sean-k-mooney | auniyal: the best thing you can do is provide us an example and we can look into it | |
| 16:36:46 | clarkb | ++ to looking at it | |
| 16:36:47 | sean-k-mooney | and then see if there is a trend | |
| 16:37:10 | auniyal | ack | |
| 16:38:36 | bauzas | I actually wonder how we can track the trend | |
| 16:38:50 | sean-k-mooney | https://zuul.openstack.org/builds?project=openstack%2Fnova&result=TIMED_OUT&skip=0 | |
| 16:38:56 | sean-k-mooney | that but its currently loading | |
| 16:39:17 | sean-k-mooney | we have a couple every few days | |
| 16:39:18 | bauzas | sure, but you don't have the time a SUCCESS job runs | |
| 16:39:28 | bauzas | which is what we should track | |
| 16:39:29 | clarkb | you can show both success and timeouts in a listing | |
| 16:39:35 | clarkb | (and failures, etc) | |
| 16:39:37 | sean-k-mooney | well we can change the result to filter both | |
| 16:39:51 | bauzas | the duration field, shit, missed it | |
| 16:40:01 | sean-k-mooney | we also hav ento fixed the fips job | |
| 16:40:09 | sean-k-mooney | ill create a patch for that i think | |
| 16:40:16 | bauzas | sean-k-mooney: I said I should do it | |
| 16:40:27 | sean-k-mooney | bauzas: ok please do | |
| 16:40:33 | bauzas | sean-k-mooney: that's simple to do and that's like 4 weeks I promised it | |
| 16:41:13 | bauzas | sean-k-mooney: you know what ? I'll end this meeting by now so everyone can do what they want, including me writing a zuul patch :) | |
| 16:41:25 | sean-k-mooney | :) | |
| 16:41:35 | bauzas | having said it, | |
| 16:41:39 | bauzas | thanks folks | |
| 16:41:43 | opendevmeet | Log: https://meetings.opendev.org/meetings/nova/2022/nova.2022-11-29-16.00.log.html | |
| 16:41:43 | opendevmeet | Minutes (text): https://meetings.opendev.org/meetings/nova/2022/nova.2022-11-29-16.00.txt | |
| 16:41:43 | opendevmeet | Minutes: https://meetings.opendev.org/meetings/nova/2022/nova.2022-11-29-16.00.html | |
| 16:41:43 | opendevmeet | Meeting ended Tue Nov 29 16:41:43 2022 UTC. Information about MeetBot at http://wiki.debian.org/MeetBot . (v 0.1.4) | |
| 16:41:43 | bauzas | #endmeeting | |
| 16:42:03 | gibi | o/ | |
| 16:42:22 | chateaulav | o/ | |
| 16:42:29 | elodilles | o/ | |
| 16:44:07 | bauzas | like, https://zuul.openstack.org/job/tempest-centos9-stream-fips | |
| 16:48:28 | clarkb | sean-k-mooney: one thing I've found is fairly consistent for our systemic job timeouts is that we've got a number of steps to each job: base setup (configuring mirrors, configuring ssh keys, configuring git repos), test env setup (tox/devstack/whatever), actual testing, and log collection. Each of these tends to have unnecessary slow bits that add up over the course of a job. | |
| 16:48:30 | clarkb | When you then run into something like a slower node or swapping or slowness fetching an external resource it is very easy to tip over the timeout | |
| 16:49:00 | clarkb | sean-k-mooney: imo it would be helpful for us to try and whittle away at that accumulated slowness tech debt to make us less susceptible when we run into an overall slower situation. | |
| 16:49:27 | clarkb | I've worked on that a bit in the base jobs and log collection side of things as that has broad impact. But the downsides here are that it has broad impact so I have to be extremely careful to maintain backward compatibility | |
| 16:49:44 | clarkb | but the same approaches can be taken to improve things like devstack (did you know it installs tempest 3 times!) | |
| 16:50:26 | clarkb | I think improving memory consumption would also help avoid slowness caused by swapping. privsep is a fairly outsized offender here | |
| 16:53:16 | bauzas | clarkb: I'm curious about privsep being memory greedy | |
| 16:53:30 | bauzas | and I wonder why | |
| 16:53:43 | clarkb | I suspect because it grows buffers to handle all the input and output sent through it | |
| 16:54:05 | clarkb | one way to maybe improve things is to stop running a different privsep for each service whcih creates a bunch of large buffers. We might be able to get away with one large buffer | |
| 16:54:05 | bauzas | our internal customers haven't reported such problem, but I guess because of lack of evidence rather than not having a problem | |
| 16:54:29 | clarkb | or buffer things with intentionally smaller buffers | |
| 16:54:40 | bauzas | agreed | |
| 16:54:48 | bauzas | a stream is costly | |
| 16:57:01 | sean-k-mooney | clarkb: yep although we have enough fo a buffer in the nova project that we get a time out failure only 1 or twice a week | |
| 16:57:18 | clarkb | sean-k-mooney: yes, but you've also set your timeout to two hours | |
| 16:57:36 | clarkb | (one hour was the goal once upon a time) | |
| 16:57:50 | sean-k-mooney | ack | |
| 16:58:03 | sean-k-mooney | shareing privesep is a security issue | |
| 16:58:09 | sean-k-mooney | so i dont think we can ever do that | |
| 16:58:22 | sean-k-mooney | nova will have more privespe deamons eventurlaly | |
| 16:59:16 | clarkb | does privsep prevent random processes from connecting to it? If not this is equivalent. If so it could also apply restrictions on what a specific process can do (granted this is maybe a larger attack surface than refusing to talk at all) | |
| 16:59:42 | sean-k-mooney | you are ment to use file permissiosn to limit access at the file system level | |
| 16:59:53 | sean-k-mooney | but no | |
| 17:00:00 | sean-k-mooney | not as part of privsep itself | |
| 17:00:25 | sean-k-mooney | clarkb: you need one privsep deamon per privsep context currently | |
| 17:00:42 | sean-k-mooney | for it to proplry provide the correct permission enforcement/escalation | |
| 17:00:57 | clarkb | sean-k-mooney: in that case my suggestion would be to investigate optimizing privsep memory usage | |
| 17:01:14 | sean-k-mooney | we might be able to reduce it in ci | |
| 17:01:22 | sean-k-mooney | by limiting it to one process | |
| 17:01:31 | clarkb | or just bound your buffers | |
| 17:01:34 | clarkb | and read in chunks | |
| 17:01:54 | sean-k-mooney | maybe i havent really looked at the channel implemenation closely | |
| 17:02:07 | clarkb | I suspect this is a case of python makes it easy to read abritrary sized buffers into memroy without much fuss | |
| 17:02:24 | clarkb | it might also be inefficient compilation of the ruleset | |
| 17:02:28 | clarkb | (regexes aren't free either) | |
| 17:02:54 | sean-k-mooney | the impelmation is here https://github.com/openstack/oslo.privsep/blob/83870bd2655f3250bb5d5aed7c9865ba0b5e4770/oslo_privsep/comm.py | |
| 17:03:41 | sean-k-mooney | self.writesock.sendall(buf) | |
| 17:03:53 | sean-k-mooney | so its takeign the serialsed payload and sending it | |
| 17:04:13 | sean-k-mooney | using the msgpack format for serialisation | |
| 17:05:40 | sean-k-mooney | its using 4k buffers https://github.com/openstack/oslo.privsep/blob/83870bd2655f3250bb5d5aed7c9865ba0b5e4770/oslo_privsep/comm.py#L81 | |
| 17:08:35 | sean-k-mooney | clarkb: honestly i have looked at privsep a couple of time but dont have enough context of the code to have a feel for how much memory it shoudl be using and if its bounded or not | |
| 17:09:02 | dansmith | also not sure what we might be calling via privsep that would return large buffers | |
| 17:09:04 | sean-k-mooney | clarkb: but i suspect that if we are using it ofr any file operatiosn then it might need to process guest images | |
| 17:09:14 | dansmith | it's mostly for doing things and maybe pulling the qemu-img info blob | |
| 17:09:23 | bauzas | sean-k-mooney: https://review.opendev.org/c/openstack/tempest/+/866049 | |
| 17:09:27 | sean-k-mooney | dansmith: the console log or writing images to disk would be the two the come to mind | |
| 17:10:01 | dansmith | I don't think we write images to disk via privsep. console log.. maybe? I thought we can get that via libvirt | |
| 17:10:10 | clarkb | ya I'm not sure. Its just in aggregate privsep uses more memory than most other openstack services | |
| 17:10:30 | sean-k-mooney | dansmith: no we read the file that is written to disk im pretty sure | |
| 17:10:34 | clarkb | I think cinder? and neutron use more then privsep is next. Its been a while since I looked at hte memory profiling though | |
| 17:11:01 | bauzas | I don't know if we could somehow pdb the running privsep process thru a backdoor, because if we could, like we do with nova services, then we could monitor the growing memory | |
| 17:11:24 | sean-k-mooney | dansmith: i would hope for the images that we write it to somewhere we own then move it and change the permission if needed | |
| 17:11:33 | bauzas | I personnally use tracemalloc to persist the memory state and compare between snapshots | |
| 17:11:51 | sean-k-mooney | like in most case i woudl expect nova to put it in the image cache then use qemu-image to create a qcow with the iamge as the backing file | |
| 17:11:52 | bauzas | but this requires access to the process | |
| 17:12:16 | sean-k-mooney | so privsep shoudl only be needed for invokeign qemu-img and not the actul image downlaod | |
| 17:12:29 | sean-k-mooney | but not sure about the same codepath for raw images | |
| 17:13:11 | sean-k-mooney | bauzas: you coudl do that locally but i dont think privsep uses eventlet | |