[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <Z3zLQObsD42R6Nwz@xsang-OptiPlex-9020>
Date: Tue, 7 Jan 2025 14:35:44 +0800
From: Oliver Sang <oliver.sang@...el.com>
To: Breno Leitao <leitao@...ian.org>
CC: <lkp@...el.com>, <oe-lkp@...ts.linux.dev>, <linux-crypto@...r.kernel.org>,
Herbert Xu <herbert@...dor.apana.org.au>, Tejun Heo <tj@...nel.org>,
<netdev@...r.kernel.org>, <oliver.sang@...el.com>
Subject: Re: [herbert-cryptodev-2.6:master] [rhashtable] e1d3422c95:
stress-ng.syscall.ops_per_sec 98.9% regression
hi, Breno Leitao,
On Fri, Jan 03, 2025 at 05:41:56AM -0800, Breno Leitao wrote:
> Hello "kernel robot" team,
>
> First of all, thank you very much for running these tests against the
> linux kernel.
you are welcome!
>
> I am trying to reproduce this report, and I would appreciate some help
> to understand what is being measured, and try to reproduce the reported
> problem.
>
> On Fri, Dec 27, 2024 at 11:10:11AM +0800, kernel test robot wrote:
> > kernel test robot noticed a 98.9% regression of stress-ng.syscall.ops_per_sec on:
>
> Is this metric coming from `bogo ops/s` from stress-ng?
yes, it's from bogo ops/s (real time).
one thing we want to mention is the test runs unstably upon e1d3422c95.
as below, %stddev for it reaches 67%.
not very stable for parent, either, but 7% is much better.
f916e44487f56df4 e1d3422c95f003eba241c176adf
---------------- ---------------------------
%stddev %change %stddev
\ | \
4115705 ± 7% -98.9% 45562 ± 67% stress-ng.syscall.ops_per_sec
below is the raw data of 6 runs for e1d3422c95 in our tests.
"stress-ng.syscall.ops_per_sec": [
12892.83,
98074.65,
65206.14,
11507.57,
55012.11,
30684.44
],
take that 55012.11 as example, (part of) the stress-ng output is:
stress-ng: metrc: [6604] stressor bogo ops real time usr time sys time bogo ops/s bogo ops/s CPU used per RSS Max
stress-ng: metrc: [6604] (secs) (secs) (secs) (real time) (usr+sys time) instance (%) (KB)
stress-ng: metrc: [6604] syscall 8878630 161.39 9.86 31058.22 55012.11 285.78 85.94 10512
another thing we want to mention is we also notice a WARNING for this commit in
another test, so we reported
"[herbert-cryptodev-2.6:master] [rhashtable] e1d3422c95: WARNING:at_mm/util.c:#__kvmalloc_node_noprof"
in
https://lore.kernel.org/all/202412311213.4e69877e-lkp@intel.com/
not sure if it's related or could supply any hint?
>
> I am trying to reproduce this problem, running the following script:
> https://download.01.org/0day-ci/archive/20241227/202412271017.cad7675-lkp@intel.com/repro-script
>
> And I see the output like the one below, but, it is unclear to me what
> metric regressed stress-ng.syscall.ops_per_sec means exactly. Would you
> mind helping me to understand what is stress-ng.syscall.ops_per_sec and
> how it maps to stress-ng metrics?
>
> Output of `stress-ng --timeout 60 --times --verify --metrics --no-rand-seed --syscall 224`:
>
> stress-ng: info: [59621] setting to a 1 min, 0 secs run per stressor
> stress-ng: info: [59621] dispatching hogs: 224 syscall
> stress-ng: info: [59647] syscall: using method 'fast75'
> stress-ng: info: [59647] syscall: 292 system call tests, 219 (75.0%) fastest non-failing tests fully exercised
> stress-ng: info: [59647] syscall: Top 10 fastest system calls (timings in nanosecs):
> stress-ng: info: [59647] syscall: System Call Avg (ns) Min (ns) Max (ns)
> stress-ng: info: [59647] syscall: pkey_get 156.0 127 185
> stress-ng: info: [59647] syscall: time 212.5 195 230
> stress-ng: info: [59647] syscall: pkey_set 235.5 193 278
> stress-ng: info: [59647] syscall: gettimeofday 282.5 255 310
> stress-ng: info: [59647] syscall: getcpu 457.0 388 526
> stress-ng: info: [59647] syscall: set_robust_list 791.5 745 838
> stress-ng: info: [59647] syscall: getgid 1137.0 974 1300
> stress-ng: info: [59647] syscall: setresuid 1146.0 1070 1222
> stress-ng: info: [59647] syscall: getuid 1162.5 902 1423
> stress-ng: info: [59647] syscall: setresgid 1211.5 1159 1264
> stress-ng: metrc: [59621] stressor bogo ops real time usr time sys time bogo ops/s bogo ops/s CPU used per RSS Max
> stress-ng: metrc: [59621] (secs) (secs) (secs) (real time) (usr+sys time) instance (%) (KB)
> stress-ng: metrc: [59621] syscall 114464 86.78 1.27 364.05 1318.95 313.33 1.88 4500
> stress-ng: info: [59621] for a 98.30s run time:
> stress-ng: info: [59621] 3538.93s available CPU time
> stress-ng: info: [59621] 1.26s user time ( 0.04%)
> stress-ng: info: [59621] 366.66s system time ( 10.36%)
> stress-ng: info: [59621] 367.92s total time ( 10.40%)
> stress-ng: info: [59621] load average: 80.45 43.94 20.82
> stress-ng: info: [59621] skipped: 0
> stress-ng: info: [59621] passed: 224: syscall (224)
> stress-ng: info: [59621] failed: 0
> stress-ng: info: [59621] metrics untrustworthy: 0
> stress-ng: info: [59621] successful run completed in 1 min, 38.30 secs
>
> Thank you!
> --breno
>
Powered by blists - more mailing lists