Message-ID: <a32fe0a9986451d8713fced841df7d4b941f14f1.camel@gmx.de>
Subject: Re: [PATCH v3] perf sched: Fix sched latency analysis incorrect
From:   Mike Galbraith <efault@gmx.de>
To:     Chunxin Zang <zangchunxin@lixiang.com>, namhyung@kernel.org,
        peterz@infradead.org, mingo@redhat.com, acme@kernel.org
Cc:     mark.rutland@arm.com, alexander.shishkin@linux.intel.com,
        jolsa@kernel.org, irogers@google.com,
        linux-perf-users@vger.kernel.org, linux-kernel@vger.kernel.org,
        Jerry Zhou <zhouchunhua@lixiang.com>
Date:   Tue, 21 Mar 2023 08:32:32 +0100
In-Reply-To: <20230317063246.1128219-1-zangchunxin@lixiang.com>
References: <20230317063246.1128219-1-zangchunxin@lixiang.com>
Content-Type: text/plain; charset="UTF-8"
User-Agent: Evolution 3.42.4 
MIME-Version: 1.0
Content-Transfer-Encoding: quoted-printable
UI-OutboundReport: notjunk:1;M01:P0:E6P9AvnU8BM=;cdC2BDuPxKpczD3tIeZUAWmv1Jl
 XRwKM9N+loJck0EC54RaT9dJGyeFlrUaJZe5RGRx6l5/3T3C77yXoM1gkPkyOCXlewQiwmsw/
 FPcZq+eV94lS3KG0OSOHnFCMJQVD2NpblQZdL7kgJAJKRqZ4nkEVNIthmJ8KpLmwUimjohRnV
 LGBWJHsDgdKFLOJ8VNlNMJQAujuZZXSE3uPy25eg2oQAs2GT+mej7WvLx0IZGlPj2qmitOG0Y
 A+G1WO3Hq/XN+VjrP1OPz6QHhkeYN/y/mo3XliX5NhH4Cb9/p6/h+3NjF89iDa6UmgeXE2u1j
 rdu650zmihnWHdrRf8c0l17TZbc1utkXytRxL1MPShhko03TCh9afHiXdEkFBhNQQFbT0zzXK
 le+XhhBBKm4dKgRpB23Idq7C8b12twajkoFlNgNq9AToOs04rXWXEBqnN0BCTL1qPlDrXszdx
 fdR4rr0whQc3cRQTI2reepXTryaDw2qmGEVEAUghIEEpkxtIxKZRJd9DljndnqQYwjKNCj70Q
 BeOviAPqgc6089LIbQa1vXYtmJCNhJxf/LP9NTmhuqRbPaBELoQ23XTh0/VipjW1iVQB1uBKo
 YRy/l3zKOctW5TuNIkZ2P/Veb7rZxD8/lIOYLdNoKAjmp+m46LW94idy0rZQTALlquFS+KJlr
 5ZEIjIQcd5iY2deAwkBb9xFgRaW8ztloz9oH03XtUC106WPSQAPqptxrAEgZhqEYEnAH8kAY3
 KR6i4P9yBL3Y1kGk+V4jZ0MPepHaNgHy0P5F+dwvTQ55iH16UHN50DsOwVUh3WBaA8vyLzWWg
 vakh4iYL4K8m9hReRe91fI3szGeUXCyoPZOhwe9NZgeYxnZzDLM/7GleBxNbRjXQLXyWU4uML
 f5dcIchWo8o+oNkf7iA/y5n4MPrIiKSWR2P7r6d2KJi5Jz9lh0KNZC+7bTq4MKCZB0s7WLJ2c
 oHUXeTkUMd06XX+Lsdo0SgYHijk=
Precedence: bulk

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=3Daqz-=
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 | <=3D=3D *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