| Message ID | 20230713105303.4105584-1-richard.purdie@linuxfoundation.org |
|---|---|
| State | Accepted, archived |
| Commit | a6056599922fb2fe3f54c5c86ac7ea604f469adc |
| Headers | show |
| Series | runqueue: Add pressure change logging | expand |
Hi Richard, how much logging is this generating for your local builds? I'm using BB_PRESSURE_MAX_CPU="500", and this patch generates hundreds of lines of logs during a typical build (on kirkstone 4.0.15). Is that the expected behavior? It makes it hard to read other logs. E.g. this incremental build with 300 tasks printed 280 lines of Pressure status change: ... NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 495.3/500.0, IO: 1723.0/None, Mem: 0.0/None) - using 1/48 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 985.3/500.0, IO: 2201.8/None, Mem: 176.8/None) - using 1/48 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 420.8/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 4049.8/500.0, IO: 14719.7/None, Mem: 0.0/None) - using 1/48 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads NOTE: Tasks Summary: Attempted 928 tasks of which 635 didn't need to be rerun and all succeeded. ... On Thu, Jul 13, 2023 at 12:53 PM Richard Purdie < richard.purdie@linuxfoundation.org> wrote: > It is currently hard to tell when bitbake is throttling task execution > due to system pressure changes. Add notes to the console output to make > this clearer, only generating output when the values change. > > Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org> > --- > lib/bb/runqueue.py | 4 ++++ > 1 file changed, 4 insertions(+) > > diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py > index 241a746ebb..020ad210d8 100644 > --- a/lib/bb/runqueue.py > +++ b/lib/bb/runqueue.py > @@ -212,6 +212,10 @@ class RunQueueScheduler(object): > exceeds_cpu_pressure = self.rq.max_cpu_pressure and > (float(curr_cpu_pressure) - float(self.prev_cpu_pressure)) > > self.rq.max_cpu_pressure > exceeds_io_pressure = self.rq.max_io_pressure and > (float(curr_io_pressure) - float(self.prev_io_pressure)) > > self.rq.max_io_pressure > exceeds_memory_pressure = self.rq.max_memory_pressure > and (float(curr_memory_pressure) - float(self.prev_memory_pressure)) > > self.rq.max_memory_pressure > + pressure_state = (exceeds_cpu_pressure, exceeds_io_pressure, > exceeds_memory_pressure) > + if hasattr(self, "pressure_state") and pressure_state != > self.pressure_state: > + bb.note("Pressure status changed to CPU: %s, IO: %s, Mem: > %s" % pressure_state) > + self.pressure_state = pressure_state > return (exceeds_cpu_pressure or exceeds_io_pressure or > exceeds_memory_pressure) > return False > > -- > 2.39.2 > > > -=-=-=-=-=-=-=-=-=-=-=- > Links: You receive all messages sent to this group. > View/Reply Online (#14881): > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_message_14881&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=2-D0LIZ9jb_OQ0moDf52X1uxL_mzlLgg8a-EtbfpZ_puk14Q5m5U-o6j9Z5SyEhW&s=Hjxf_Hw5nNdsxYpgqQ_Wqrx3puDIhkG90ziaM598yaA&e= > Mute This Topic: > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_mt_100117828_7048771&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=2-D0LIZ9jb_OQ0moDf52X1uxL_mzlLgg8a-EtbfpZ_puk14Q5m5U-o6j9Z5SyEhW&s=3oXO64d9MSfEwmmOaRSrprXDBuuz3pyuHrJ-kXt7UxA&e= > Group Owner: bitbake-devel+owner@lists.openembedded.org > Unsubscribe: > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_leave_12014517_7048771_89430669_xyzzy&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=2-D0LIZ9jb_OQ0moDf52X1uxL_mzlLgg8a-EtbfpZ_puk14Q5m5U-o6j9Z5SyEhW&s=jyn0SAZ3VS4StYDnGqsmCY4F29xjKG26cMKCObc1fxw&e= > [ecordonnier@snap.com] > -=-=-=-=-=-=-=-=-=-=-=- > >
On Tue, 2024-01-09 at 15:09 +0100, Etienne Cordonnier wrote: > how much logging is this generating for your local builds? I'm > using BB_PRESSURE_MAX_CPU="500", and this patch generates hundreds of > lines of logs during a typical build (on kirkstone 4.0.15). Is that > the expected behavior? It makes it hard to read other logs. > > E.g. this incremental build with 300 tasks printed 280 lines of > Pressure status change: > > ... > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 495.3/500.0, IO: 1723.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 985.3/500.0, IO: 2201.8/None, Mem: 176.8/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 420.8/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 4049.8/500.0, IO: 14719.7/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads > NOTE: Tasks Summary: Attempted 928 tasks of which 635 didn't need to be rerun and all succeeded. > ... It does add a lot of logging. I was torn on adding it but we have struggled to get the log levels right and this information is useful as you often need it to get the pressure values right. I'm torn on it. Cheers, Richard
On 2024-01-09 9:12 a.m., Richard Purdie wrote: > On Tue, 2024-01-09 at 15:09 +0100, Etienne Cordonnier wrote: >> how much logging is this generating for your local builds? I'm >> using BB_PRESSURE_MAX_CPU="500", and this patch generates hundreds of >> lines of logs during a typical build (on kirkstone 4.0.15). Is that >> the expected behavior? It makes it hard to read other logs. >> >> E.g. this incremental build with 300 tasks printed 280 lines of >> Pressure status change: >> >> ... >> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 495.3/500.0, IO: 1723.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 985.3/500.0, IO: 2201.8/None, Mem: 176.8/None) - using 1/48 bitbake threads >> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 420.8/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 4049.8/500.0, IO: 14719.7/None, Mem: 0.0/None) - using 1/48 bitbake threads >> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads In this case, you have up to 48 threads permitted yet the CPU is already overloaded based on the pressure logs. How many physical/virtual cores are actually available? Is some other activity doing CPU intensive work on the system? Is the one task running > 48 compile jobs and causing CPU contention in the system? I'd expect that for a modest update on a mostly 48 vCPU system, you would rarely see any pressure logs but I tested on my 24 vCPU system with CPU=500 and early in the builds as configure runs for various packags there are waves of tasks launched and then the system becomes congested: NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 8797.1/500.0, IO: 49.8/None, Mem: 0.0/None) - using 23/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 3720.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 533.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 19/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 693451.9/500.0, IO: 0.0/None, Mem: 32401.3/None) - using 20/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 39409.4/500.0, IO: 662.6/None, Mem: 155.6/None) - using 23/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 13/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 411246.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 531.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 494.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 514.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 497.2/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 501.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 497.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 501.6/500.0, IO: 0.0/None, Mem: 0.0/None) - using 17/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 36473.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 526.7/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 472.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 502.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 522.2/500.0, IO: 137.1/None, Mem: 0.0/None) - using 22/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 2192.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 529.0/500.0, IO: 64.8/None, Mem: 0.0/None) - using 21/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 4/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 2420.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 5/24 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 395.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 523.4/500.0, IO: 0.0/None, Mem: 0.0/None) - using 6/24 bitbake threads I've been trying to make time to improve the pressure regulation since we neglected the kernel devs advice that we should not sample the pressure info more than once every 50 ms or so. I'll try another build with the CPU pressure limit set higher, and I suggest you do the same. I still think your logs look 'interesting' so I look forward to hearing what your system is and what it's doing. Thanks, ../Randy >> NOTE: Tasks Summary: Attempted 928 tasks of which 635 didn't need to be rerun and all succeeded. >> ... > It does add a lot of logging. I was torn on adding it but we have > struggled to get the log levels right and this information is useful as > you often need it to get the pressure values right. I'm torn on it. > > Cheers, > > Richard > >
On 2024-01-09 4:49 p.m., Randy MacLeod wrote: > On 2024-01-09 9:12 a.m., Richard Purdie wrote: >> On Tue, 2024-01-09 at 15:09 +0100, Etienne Cordonnier wrote: >>> how much logging is this generating for your local builds? I'm >>> using BB_PRESSURE_MAX_CPU="500", and this patch generates hundreds of >>> lines of logs during a typical build (on kirkstone 4.0.15). Is that >>> the expected behavior? It makes it hard to read other logs. >>> >>> E.g. this incremental build with 300 tasks printed 280 lines of >>> Pressure status change: >>> >>> ... >>> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 495.3/500.0, IO: 1723.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >>> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 985.3/500.0, IO: 2201.8/None, Mem: 176.8/None) - using 1/48 bitbake threads >>> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 420.8/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >>> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 4049.8/500.0, IO: 14719.7/None, Mem: 0.0/None) - using 1/48 bitbake threads >>> NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads >>> NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads > > In this case, you have up to 48 threads permitted yet the CPU is > already overloaded > based on the pressure logs. > > How many physical/virtual cores are actually available? > > Is some other activity doing CPU intensive work on the system? > Is the one task running > 48 compile jobs and causing CPU contention > in the system? > > > I'd expect that for a modest update on a mostly 48 vCPU system, you > would rarely see any pressure logs but > I tested on my 24 vCPU system with CPU=500 and early in the builds as > configure runs for various packags there are waves of > tasks launched and then the system becomes congested: > > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 8797.1/500.0, IO: 49.8/None, Mem: 0.0/None) - using 23/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 3720.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 533.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 19/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 693451.9/500.0, IO: 0.0/None, Mem: 32401.3/None) - using 20/24 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 39409.4/500.0, IO: 662.6/None, Mem: 155.6/None) - using 23/24 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 13/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 411246.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 531.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 494.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 514.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 497.2/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 501.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 497.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 501.6/500.0, IO: 0.0/None, Mem: 0.0/None) - using 17/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 36473.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 526.7/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 472.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 502.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 522.2/500.0, IO: 137.1/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 2192.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 529.0/500.0, IO: 64.8/None, Mem: 0.0/None) - using 21/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 4/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 2420.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 5/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 395.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 523.4/500.0, IO: 0.0/None, Mem: 0.0/None) - using 6/24 bitbake threads > > I've been trying to make time to improve the pressure regulation since > we neglected > the kernel devs advice that we should not sample the pressure info more > than once every 50 ms or so. > > I'll try another build with the CPU pressure limit set higher, and I > suggest you do the same. > so with just the default config and BB_PRESSURE_MAX_CPU = "500" and $ bitbake core-image-minimal rmacleod@yow-rmacleod-lx3 b-poky/bb-sec $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* | wc -l 2355 NOTE: Tasks Summary: Attempted 4028 tasks of which 187 didn't need to be rerun and all succeeded. so ~1200 times when launching the 4000 tasks, the CPU was congested. The distribution of the number of tasks when CPU contention was noticed was somewhat higher: $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* | rg True | rev | cut -d" " -f -3 | rev | cut -d" " -f1 | sort -n | uniq -c 4 1/24 432 2/24 168 3/24 84 4/24 54 5/24 62 6/24 65 7/24 80 8/24 61 9/24 49 10/24 28 11/24 20 12/24 15 13/24 6 14/24 10 15/24 2 16/24 3 17/24 3 18/24 3 19/24 2 20/24 2 21/24 6 22/24 18 23/24 then when it abated: $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* | rg -v True | rev | cut -d" " -f -3 | rev | cut -d" " -f1 | sort -n | uniq -c 592 1/24 126 2/24 68 3/24 45 4/24 55 5/24 63 6/24 65 7/24 57 8/24 43 9/24 27 10/24 16 11/24 8 12/24 3 13/24 4 14/24 2 15/24 1 16/24 1 17/24 1 18/24 1 19/24 Pretty much what I'd expect. If you look at the CPU pressure values, and sort them out $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* \ | rg True | cut -d"(" -f 2 | cut -d":" -f 2 | cut -d"," -f1 | cut -d"/" -f1 | sort -n > /tmp/cpu-pressure.dat you see this distribution: Note that there are values over 1M and that's a bug that will be fixed. Oh and on a linear scale: so a MAX_CPU of say 1000 is probably better. All of this analysis is fun (for me!) but really, we need to get the job server in place and improve on the regulation algorithm based on a standardized test using stress-ng most liklely and then finally compare it to what happens in real builds and tune more. Thanks for the excuse to analyze some data and make some somewhat interesting, maybe useful graphs! All for tonight, ../Randy > I still think your logs look 'interesting' so I look forward to > hearing what your system is > and what it's doing. > > Thanks, > > ../Randy > > >>> NOTE: Tasks Summary: Attempted 928 tasks of which 635 didn't need to be rerun and all succeeded. >>> ... >> It does add a lot of logging. I was torn on adding it but we have >> struggled to get the log levels right and this information is useful as >> you often need it to get the pressure values right. I'm torn on it. >> >> Cheers, >> >> Richard >> >> > > -- > # Randy MacLeod > # Wind River Linux
"How many physical/virtual cores are actually available? Is some other activity doing CPU intensive work on the system? Is the one task running > 48 compile jobs and causing CPU contention in the system?" -> This is a physical PC with 24 physical cores and 48 cores when you take hyperthreading into account (Intel Xeon Gold 6240R) -> there is no other activity doing CPU intensive work -> some bitbake tasks can easily load 48 cores, yes (this is a custom image with some extra layers added) Etienne On Wed, Jan 10, 2024 at 3:20 AM Randy MacLeod via lists.openembedded.org <randy.macleod=windriver.com@lists.openembedded.org> wrote: > On 2024-01-09 4:49 p.m., Randy MacLeod wrote: > > On 2024-01-09 9:12 a.m., Richard Purdie wrote: > > On Tue, 2024-01-09 at 15:09 +0100, Etienne Cordonnier wrote: > > how much logging is this generating for your local builds? I'm > using BB_PRESSURE_MAX_CPU="500", and this patch generates hundreds of > lines of logs during a typical build (on kirkstone 4.0.15). Is that > the expected behavior? It makes it hard to read other logs. > > E.g. this incremental build with 300 tasks printed 280 lines of > Pressure status change: > > ... > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 495.3/500.0, IO: 1723.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 985.3/500.0, IO: 2201.8/None, Mem: 176.8/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 420.8/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 4049.8/500.0, IO: 14719.7/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/48 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads > > In this case, you have up to 48 threads permitted yet the CPU is already > overloaded > based on the pressure logs. > > How many physical/virtual cores are actually available? > > Is some other activity doing CPU intensive work on the system? > Is the one task running > 48 compile jobs and causing CPU contention in > the system? > > > I'd expect that for a modest update on a mostly 48 vCPU system, you would > rarely see any pressure logs but > I tested on my 24 vCPU system with CPU=500 and early in the builds as > configure runs for various packags there are waves of > tasks launched and then the system becomes congested: > > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 8797.1/500.0, IO: 49.8/None, Mem: 0.0/None) - using 23/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 3720.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 533.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 19/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 693451.9/500.0, IO: 0.0/None, Mem: 32401.3/None) - using 20/24 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 39409.4/500.0, IO: 662.6/None, Mem: 155.6/None) - using 23/24 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 13/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 411246.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 531.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 494.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 7/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 514.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 497.2/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 501.9/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 497.3/500.0, IO: 0.0/None, Mem: 0.0/None) - using 16/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 501.6/500.0, IO: 0.0/None, Mem: 0.0/None) - using 17/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 14/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 36473.5/500.0, IO: 0.0/None, Mem: 0.0/None) - using 15/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 526.7/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 472.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 502.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 522.2/500.0, IO: 137.1/None, Mem: 0.0/None) - using 22/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 2192.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 3/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 1/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 529.0/500.0, IO: 64.8/None, Mem: 0.0/None) - using 21/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 0.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 4/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 2420.0/500.0, IO: 0.0/None, Mem: 0.0/None) - using 5/24 bitbake threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 395.1/500.0, IO: 0.0/None, Mem: 0.0/None) - using 2/24 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 523.4/500.0, IO: 0.0/None, Mem: 0.0/None) - using 6/24 bitbake threads > > I've been trying to make time to improve the pressure regulation since we > neglected > the kernel devs advice that we should not sample the pressure info more > than once every 50 ms or so. > > I'll try another build with the CPU pressure limit set higher, and I > suggest you do the same. > > > so with just the default config and > > BB_PRESSURE_MAX_CPU = "500" > and > $ bitbake core-image-minimal > > rmacleod@yow-rmacleod-lx3 b-poky/bb-sec $ rg "Pressure status changed " > tmp/log/cooker/qemux86-64/202* | wc -l > 2355 > > NOTE: Tasks Summary: Attempted 4028 tasks of which 187 didn't need to be > rerun and all succeeded. > > so ~1200 times when launching the 4000 tasks, the CPU was congested. > > The distribution of the number of tasks when CPU contention was noticed > was somewhat higher: > > $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* | rg True | > rev | cut -d" " -f -3 | rev | cut -d" " -f1 | sort -n | uniq -c > > 4 1/24 > 432 2/24 > 168 3/24 > 84 4/24 > 54 5/24 > 62 6/24 > 65 7/24 > 80 8/24 > 61 9/24 > 49 10/24 > 28 11/24 > 20 12/24 > 15 13/24 > 6 14/24 > 10 15/24 > 2 16/24 > 3 17/24 > 3 18/24 > 3 19/24 > 2 20/24 > 2 21/24 > 6 22/24 > 18 23/24 > > then when it abated: > > $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* | rg -v > True | rev | cut -d" " -f -3 | rev | cut -d" " -f1 | sort -n | uniq -c > 592 1/24 > 126 2/24 > 68 3/24 > 45 4/24 > 55 5/24 > 63 6/24 > 65 7/24 > 57 8/24 > 43 9/24 > 27 10/24 > 16 11/24 > 8 12/24 > 3 13/24 > 4 14/24 > 2 15/24 > 1 16/24 > 1 17/24 > 1 18/24 > 1 19/24 > > Pretty much what I'd expect. > > > If you look at the CPU pressure values, and sort them out > > $ rg "Pressure status changed " tmp/log/cooker/qemux86-64/202* \ > > | rg True | cut -d"(" -f 2 | cut -d":" -f 2 | cut -d"," -f1 | cut > -d"/" -f1 | sort -n > /tmp/cpu-pressure.dat > > you see this distribution: > > Note that there are values over 1M and that's a bug that will be fixed. > > Oh and on a linear scale: > > > so a MAX_CPU of say 1000 is probably better. > > All of this analysis is fun (for me!) but really, we need to get the job > server in place > and improve on the regulation algorithm based on a standardized test using > stress-ng most liklely > and then finally compare it to what happens in real builds and tune more. > > > Thanks for the excuse to analyze some data and make some somewhat > interesting, maybe useful graphs! > > All for tonight, > > ../Randy > > > I still think your logs look 'interesting' so I look forward to hearing > what your system is > and what it's doing. > > Thanks, > > ../Randy > > > NOTE: Tasks Summary: Attempted 928 tasks of which 635 didn't need to be rerun and all succeeded. > ... > > It does add a lot of logging. I was torn on adding it but we have > struggled to get the log levels right and this information is useful as > you often need it to get the pressure values right. I'm torn on it. > > Cheers, > > Richard > > > > > -- > # Randy MacLeod > # Wind River Linux > > > -- > # Randy MacLeod > # Wind River Linux > > > -=-=-=-=-=-=-=-=-=-=-=- > Links: You receive all messages sent to this group. > View/Reply Online (#15776): > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_message_15776&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=jtfd4DbF9P05O3NOz5OO6LuF-oOhMFw_eih9SszsQQ5hO7GnpymSeSpAcd8lqi_b&s=_MFl5ovVE_VNDvrcRFWqHsz5dnRMO2KpNiLOCVE5nzA&e= > Mute This Topic: > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_mt_100117828_7048771&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=jtfd4DbF9P05O3NOz5OO6LuF-oOhMFw_eih9SszsQQ5hO7GnpymSeSpAcd8lqi_b&s=aW8uT4CX5OXe4qGNZBl8pJfOpMUsywJ1NVZKL71DX4w&e= > Group Owner: bitbake-devel+owner@lists.openembedded.org > Unsubscribe: > https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_unsub&d=DwIFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=jtfd4DbF9P05O3NOz5OO6LuF-oOhMFw_eih9SszsQQ5hO7GnpymSeSpAcd8lqi_b&s=Ahq1wP9wLfH-LXmundExXCmTp5TlZIpi8LK4ZnXDtfc&e= > [ecordonnier@snap.com] > -=-=-=-=-=-=-=-=-=-=-=- > >
Hi Etienne, On 2024-01-10 9:09 a.m., Etienne Cordonnier wrote: > "How many physical/virtual cores are actually available? > > Is some other activity doing CPU intensive work on the system? > Is the one task running > 48 compile jobs and causing CPU contention > in the system?" > > -> This is a physical PC with 24 physical cores and 48 cores when you > take hyperthreading into account (Intel Xeon Gold 6240R) > Thanks. > > -> there is no other activity doing CPU intensive work > -> some bitbake tasks can easily load 48 cores, yes (this is a custom > image with some extra layers added) > I see, then other than deferring new tasks, there's not much that pressure regulation can do to help once one of these CPU intensive tasks is started. Other than the log verbosity which we likely won't change for a while, did you have any PSI-related concerns? I did notice that your last log was: > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake threads When there's memory pressure, that's usually an indication that the system is paging to disk. Also, despite the logs, do you find that pressure regulation is useful for you? You can always leave it turned off and only rely on the task and job limits. Thanks, ../Randy > > Etienne >
I think your limit 500 is just too low after: https://lists.openembedded.org/g/bitbake-devel/message/15499 was backported (already included in kirkstone-4.0.15). FWIW: on 64 thread AMD Threadripper 3970X I'm using much higher CPU_MAX limit and much lower bitbake thread count and still trigger these messages (but I still find them useful). This was just "small incremental build" of "bitbake -k lib32-kmscube lib32-wavpack": Sstate summary: Wanted 62 Local 0 Mirrors 0 Missed 62 Current 431 (0% match, 87% complete) Removing 48 stale sstate objects for arch mach: 100% Removing 1 stale sstate objects for arch x86_64: 100% NOTE: Executing Tasks NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 533768.7/200000.0, IO: 3306.5/None, Mem: 2611.1/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 172224.8/200000.0, IO: 9830.9/None, Mem: 0.0/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 426774.0/200000.0, IO: 3229.3/None, Mem: 0.0/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 170159.7/200000.0, IO: 798.0/None, Mem: 0.0/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 201391.4/200000.0, IO: 132.8/None, Mem: 0.0/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 159116.4/200000.0, IO: 0.0/None, Mem: 0.0/None) - using 2/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 210248.5/200000.0, IO: 270.8/None, Mem: 0.0/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 198485.4/200000.0, IO: 1577.3/None, Mem: 0.0/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 219595.7/200000.0, IO: 3824.7/None, Mem: 0.0/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 199729.1/200000.0, IO: 1121.1/None, Mem: 0.0/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 304074.6/200000.0, IO: 5498.7/None, Mem: 44.2/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 194765.9/200000.0, IO: 2600.7/None, Mem: 0.0/None) - using 3/8 bitbake threads NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: 201263.5/200000.0, IO: 2437.4/None, Mem: 0.0/None) - using 4/8 bitbake threads NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: 195733.7/200000.0, IO: 2454.0/None, Mem: 0.0/None) - using 4/8 bitbake threads NOTE: Tasks Summary: Attempted 1473 tasks of which 1335 didn't need to be rerun and all succeeded. On Wed, Jan 10, 2024 at 4:28 PM Randy MacLeod via lists.openembedded.org <randy.macleod=windriver.com@lists.openembedded.org> wrote: > Hi Etienne, > > On 2024-01-10 9:09 a.m., Etienne Cordonnier wrote: > > "How many physical/virtual cores are actually available? > > Is some other activity doing CPU intensive work on the system? > Is the one task running > 48 compile jobs and causing CPU contention in > the system?" > > -> This is a physical PC with 24 physical cores and 48 cores when you take > hyperthreading into account (Intel Xeon Gold 6240R) > > Thanks. > > -> there is no other activity doing CPU intensive work > -> some bitbake tasks can easily load 48 cores, yes (this is a custom > image with some extra layers added) > > > I see, then other than deferring new tasks, there's not much that pressure > regulation can do to help once one of these > CPU intensive tasks is started. > > Other than the log verbosity which we likely won't change for a while, did > you have any PSI-related concerns? > > I did notice that your last log was: > > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake > threads > > When there's memory pressure, that's usually an indication that the system > is paging to disk. > > > Also, despite the logs, do you find that pressure regulation is useful for > you? > You can always leave it turned off and only rely on the task and job > limits. > > Thanks, > > ../Randy > > > > Etienne > > > -- > # Randy MacLeod > # Wind River Linux > > > -=-=-=-=-=-=-=-=-=-=-=- > Links: You receive all messages sent to this group. > View/Reply Online (#15779): > https://lists.openembedded.org/g/bitbake-devel/message/15779 > Mute This Topic: https://lists.openembedded.org/mt/100117828/3617156 > Group Owner: bitbake-devel+owner@lists.openembedded.org > Unsubscribe: https://lists.openembedded.org/g/bitbake-devel/unsub [ > martin.jansa@gmail.com] > -=-=-=-=-=-=-=-=-=-=-=- > >
@Randy: "Also, despite the logs, do you find that pressure regulation is useful for you?" -> yes, testing a while back showed that setting this value to 500 reduced the clean-build durations of several minutes, which is why I added this configuration a year ago @Martin: thanks for the info! I indeed configured the value to 500 after doing some testing while I was on kirkstone 4.0.4 (long before https://github.com/yoctoproject/poky/commit/a76bc698c43a3e9792ec0ff8c97c446a20c1439e which was added in 4.0.15), and missed that I needed to change the value after updating to 4.0.15. I'll test with higher values On Wed, Jan 10, 2024 at 5:47 PM Martin Jansa <martin.jansa@gmail.com> wrote: > I think your limit 500 is just too low after: > https://lists.openembedded.org/g/bitbake-devel/message/15499 > <https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_message_15499&d=DwMFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=XGfSv6zHSImmkkXtVGhYi8KvF7P-URlnWSS4yjgh00mSKcgkdUb_w74W6PwFLlOg&s=B4aqICG4GUIKccICnUztvgZdL24Ztt98IIZMsBNoUZk&e=> > was backported (already included in kirkstone-4.0.15). > > FWIW: on 64 thread AMD Threadripper 3970X I'm using much higher CPU_MAX > limit and much lower bitbake thread count and still trigger these messages > (but I still find them useful). > > This was just "small incremental build" of "bitbake -k lib32-kmscube > lib32-wavpack": > > Sstate summary: Wanted 62 Local 0 Mirrors 0 Missed 62 Current 431 (0% > match, 87% complete) > Removing 48 stale sstate objects for arch mach: 100% > Removing 1 stale sstate objects for arch x86_64: 100% > NOTE: Executing Tasks > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 533768.7/200000.0, IO: 3306.5/None, Mem: 2611.1/None) - using 2/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 172224.8/200000.0, IO: 9830.9/None, Mem: 0.0/None) - using 2/8 bitbake > threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 426774.0/200000.0, IO: 3229.3/None, Mem: 0.0/None) - using 2/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 170159.7/200000.0, IO: 798.0/None, Mem: 0.0/None) - using 2/8 bitbake > threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 201391.4/200000.0, IO: 132.8/None, Mem: 0.0/None) - using 2/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 159116.4/200000.0, IO: 0.0/None, Mem: 0.0/None) - using 2/8 bitbake threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 210248.5/200000.0, IO: 270.8/None, Mem: 0.0/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 198485.4/200000.0, IO: 1577.3/None, Mem: 0.0/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 219595.7/200000.0, IO: 3824.7/None, Mem: 0.0/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 199729.1/200000.0, IO: 1121.1/None, Mem: 0.0/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 304074.6/200000.0, IO: 5498.7/None, Mem: 44.2/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 194765.9/200000.0, IO: 2600.7/None, Mem: 0.0/None) - using 3/8 bitbake > threads > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: > 201263.5/200000.0, IO: 2437.4/None, Mem: 0.0/None) - using 4/8 bitbake > threads > NOTE: Pressure status changed to CPU: False, IO: None, Mem: None (CPU: > 195733.7/200000.0, IO: 2454.0/None, Mem: 0.0/None) - using 4/8 bitbake > threads > NOTE: Tasks Summary: Attempted 1473 tasks of which 1335 didn't need to be > rerun and all succeeded. > > On Wed, Jan 10, 2024 at 4:28 PM Randy MacLeod via lists.openembedded.org > <https://urldefense.proofpoint.com/v2/url?u=http-3A__lists.openembedded.org&d=DwMFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=XGfSv6zHSImmkkXtVGhYi8KvF7P-URlnWSS4yjgh00mSKcgkdUb_w74W6PwFLlOg&s=1CqYM87mmPOKlTX29Ag8j0-3WXx1ZhPx0vB9ZjrdApo&e=> > <randy.macleod=windriver.com@lists.openembedded.org> wrote: > >> Hi Etienne, >> >> On 2024-01-10 9:09 a.m., Etienne Cordonnier wrote: >> >> "How many physical/virtual cores are actually available? >> >> Is some other activity doing CPU intensive work on the system? >> Is the one task running > 48 compile jobs and causing CPU contention in >> the system?" >> >> -> This is a physical PC with 24 physical cores and 48 cores when you >> take hyperthreading into account (Intel Xeon Gold 6240R) >> >> Thanks. >> >> -> there is no other activity doing CPU intensive work >> -> some bitbake tasks can easily load 48 cores, yes (this is a custom >> image with some extra layers added) >> >> >> I see, then other than deferring new tasks, there's not much that >> pressure regulation can do to help once one of these >> CPU intensive tasks is started. >> >> Other than the log verbosity which we likely won't change for a while, >> did you have any PSI-related concerns? >> >> I did notice that your last log was: >> > NOTE: Pressure status changed to CPU: True, IO: None, Mem: None (CPU: >> 21922.9/500.0, IO: 10137.8/None, Mem: 194.8/None) - using 1/48 bitbake >> threads >> >> When there's memory pressure, that's usually an indication that the >> system is paging to disk. >> >> >> Also, despite the logs, do you find that pressure regulation is useful >> for you? >> You can always leave it turned off and only rely on the task and job >> limits. >> >> Thanks, >> >> ../Randy >> >> >> >> Etienne >> >> >> -- >> # Randy MacLeod >> # Wind River Linux >> >> >> -=-=-=-=-=-=-=-=-=-=-=- >> Links: You receive all messages sent to this group. >> View/Reply Online (#15779): >> https://lists.openembedded.org/g/bitbake-devel/message/15779 >> <https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_message_15779&d=DwMFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=XGfSv6zHSImmkkXtVGhYi8KvF7P-URlnWSS4yjgh00mSKcgkdUb_w74W6PwFLlOg&s=o0eGuVu9EDjTnjX6J0BuJ1YzBW3dlc3UVSYYslDY0gs&e=> >> Mute This Topic: https://lists.openembedded.org/mt/100117828/3617156 >> <https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_mt_100117828_3617156&d=DwMFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=XGfSv6zHSImmkkXtVGhYi8KvF7P-URlnWSS4yjgh00mSKcgkdUb_w74W6PwFLlOg&s=RWBsbi9oTfLo48SrGXNbjtF13PxjrJX1y-PoEimQFS4&e=> >> Group Owner: bitbake-devel+owner@lists.openembedded.org >> Unsubscribe: https://lists.openembedded.org/g/bitbake-devel/unsub >> <https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.openembedded.org_g_bitbake-2Ddevel_unsub&d=DwMFaQ&c=ncDTmphkJTvjIDPh0hpF_4vCHvabgGkICC2epckfdiw&r=AhkbNonVuMIGRfPx_Qj9TsRih1DULJTKUkSGa66m67E&m=XGfSv6zHSImmkkXtVGhYi8KvF7P-URlnWSS4yjgh00mSKcgkdUb_w74W6PwFLlOg&s=bpBRZ_4shRibijymE6MJZi-SHIkHCZMsixgigmP-rJ0&e=> >> [martin.jansa@gmail.com] >> -=-=-=-=-=-=-=-=-=-=-=- >> >>
diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py index 241a746ebb..020ad210d8 100644 --- a/lib/bb/runqueue.py +++ b/lib/bb/runqueue.py @@ -212,6 +212,10 @@ class RunQueueScheduler(object): exceeds_cpu_pressure = self.rq.max_cpu_pressure and (float(curr_cpu_pressure) - float(self.prev_cpu_pressure)) > self.rq.max_cpu_pressure exceeds_io_pressure = self.rq.max_io_pressure and (float(curr_io_pressure) - float(self.prev_io_pressure)) > self.rq.max_io_pressure exceeds_memory_pressure = self.rq.max_memory_pressure and (float(curr_memory_pressure) - float(self.prev_memory_pressure)) > self.rq.max_memory_pressure + pressure_state = (exceeds_cpu_pressure, exceeds_io_pressure, exceeds_memory_pressure) + if hasattr(self, "pressure_state") and pressure_state != self.pressure_state: + bb.note("Pressure status changed to CPU: %s, IO: %s, Mem: %s" % pressure_state) + self.pressure_state = pressure_state return (exceeds_cpu_pressure or exceeds_io_pressure or exceeds_memory_pressure) return False
It is currently hard to tell when bitbake is throttling task execution due to system pressure changes. Add notes to the console output to make this clearer, only generating output when the values change. Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org> --- lib/bb/runqueue.py | 4 ++++ 1 file changed, 4 insertions(+)