linux-kernel - Re: [PATCH v3] perf sched: Fix sched latency analysis incorrect

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:   Tue, 21 Mar 2023 08:32:32 +0100
From:   Mike Galbraith <efault@....de>
To:     Chunxin Zang <zangchunxin@...iang.com>, namhyung@...nel.org,
        peterz@...radead.org, mingo@...hat.com, acme@...nel.org
Cc:     mark.rutland@....com, alexander.shishkin@...ux.intel.com,
        jolsa@...nel.org, irogers@...gle.com,
        linux-perf-users@...r.kernel.org, linux-kernel@...r.kernel.org,
        Jerry Zhou <zhouchunhua@...iang.com>
Subject: Re: [PATCH v3] perf sched: Fix sched latency analysis incorrect

On Fri, 2023-03-17 at 14:32 +0800, Chunxin Zang wrote:
> 'perf sched latency' is incorrect to get process schedule latency
> when it used 'sched:sched_wakeup' to analysis perf.data.
>
> Because 'perf record' prefer use 'sched:sched_waking' to
> 'sched:sched_wakeup' since commit d566a9c2d482 ("perf sched: Prefer
> sched_waking event when it exists"). It's very reasonable to
> evaluate process schedule latency.

Yeah, that makes a.. not so tiny difference.  Thanks.
(off to flush large pile of.. not data)

su - mikeg -c 'google-chrome-stable https://www.youtube.com/watch?v=aqz-KE-bpKQ > /dev/null 2>&1'&
massive_intr 8 9999&
# allow time to select display size/res
sleep 10
perf sched record -a -- cyclictest -Smqi 1234 -d 0&
sleep 300
killall cyclictest
sleep 1
killall massive_intr chrome

cyclictest output
T: 0 (10255) P: 0 I:1234 C: 194367 Min:      4 Act:   55 Avg:  484 Max:   22776
T: 1 (10256) P: 0 I:1234 C: 194346 Min:      6 Act:   57 Avg:  480 Max:   18589
T: 2 (10257) P: 0 I:1234 C: 194034 Min:      5 Act: 5214 Avg:  482 Max:   18530
T: 3 (10258) P: 0 I:1234 C: 192263 Min:      5 Act:   54 Avg:  513 Max:   19385
T: 4 (10259) P: 0 I:1234 C: 193350 Min:      6 Act:  728 Avg:  492 Max:   15951
T: 5 (10260) P: 0 I:1234 C: 196233 Min:      6 Act:   56 Avg:  469 Max:   17905
T: 6 (10261) P: 0 I:1234 C: 194181 Min:      5 Act:   67 Avg:  482 Max:   17997
T: 7 (10262) P: 0 I:1234 C: 196756 Min:      7 Act:  284 Avg:  468 Max:   16287

cyclictest bits of perf sched lat -p output, sorted ala cyclictest (local hackletlet sums delay)
 -----------------------------------------------------------------------------------------------------------
  Task                  |   Runtime ms  | Switches | Avg delay ms    | Max delay ms    | Sum delay ms     |
 -----------------------------------------------------------------------------------------------------------
  cyclictest:10255      |   1280.359 ms |      294 | avg:   0.238 ms | max:   4.929 ms | sum:   69.921 ms |
  cyclictest:10256      |   1293.976 ms |      163 | avg:   0.463 ms | max:   6.619 ms | sum:   75.497 ms |
  cyclictest:10257      |   1259.701 ms |      206 | avg:   0.371 ms | max:   5.659 ms | sum:   76.453 ms |
  cyclictest:10258      |   1299.337 ms |      171 | avg:   0.440 ms | max:   4.210 ms | sum:   75.267 ms |
  cyclictest:10259      |   1436.543 ms |      181 | avg:   0.472 ms | max:   8.466 ms | sum:   85.473 ms |
  cyclictest:10260      |   1401.824 ms |      210 | avg:   0.386 ms | max:   7.007 ms | sum:   81.036 ms |
  cyclictest:10261      |   1336.621 ms |      190 | avg:   0.387 ms | max:   4.244 ms | sum:   73.593 ms |
  cyclictest:10262      |   1393.249 ms |      283 | avg:   0.268 ms | max:   4.381 ms | sum:   75.778 ms |
+patchlet
  cyclictest:10252      |    218.546 ms |    28657 | avg:   0.437 ms | max:  12.616 ms | sum:12514.777 ms | <== *poof*
  cyclictest:10255      |   1280.359 ms |   194661 | avg:   0.431 ms | max:  22.722 ms | sum:83954.384 ms |
  cyclictest:10256      |   1293.976 ms |   194509 | avg:   0.427 ms | max:  18.537 ms | sum:83115.895 ms |
  cyclictest:10257      |   1259.701 ms |   194240 | avg:   0.429 ms | max:  18.509 ms | sum:83408.424 ms |
  cyclictest:10258      |   1299.337 ms |   192434 | avg:   0.460 ms | max:  19.331 ms | sum:88555.775 ms |
  cyclictest:10259      |   1436.543 ms |   193531 | avg:   0.439 ms | max:  15.897 ms | sum:84989.121 ms |
  cyclictest:10260      |   1401.824 ms |   196443 | avg:   0.417 ms | max:  17.852 ms | sum:81818.898 ms |
  cyclictest:10261      |   1336.621 ms |   194371 | avg:   0.429 ms | max:  17.944 ms | sum:83443.732 ms |
  cyclictest:10262      |   1393.249 ms |   197039 | avg:   0.415 ms | max:  16.232 ms | sum:81752.473 ms |


	-Mike