All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-26  3:21 ` Yang Jihong
  0 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-26  3:21 UTC (permalink / raw)
  To: john.garry, will, mathieu.poirier, leo.yan, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel
  Cc: yangjihong1

When use perf script to parse ARM SPE data, sample timestamp does not match
the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
"samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
buffer uses the same timestamp.

Before:

  # perf record -e arm_spe_0/ts_enable=1,branch_filter=1/ ls
  perf.data
  [ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 0.029 MB perf.data ]
  [ perf record: Captured and wrote 1.429 MB perf.data ]
  # perf script -D
  [...]
  0 0 0x31b0 [0x30]: PERF_RECORD_AUXTRACE size: 0x44f0  offset: 0  ref: 0x3a50d  idx: 5  tid: 107690  cpu: 5
  .
  [...]
  .  00000108:  b0 00 82 f3 29 ee b7 ff c0                      PC 0xffb7ee29f38200 el2 ns=1
  .  00000111:  99 02 00                                        LAT 2 ISSUE
  .  00000114:  98 03 00                                        LAT 3 TOT
  .  00000117:  52 82 00                                        EV RETIRED MISPRED
  .  0000011a:  4a 01                                           B COND
  .  0000011c:  b1 24 82 f3 29 ee b7 ff c0                      TGT 0xffb7ee29f38224 el2 ns=1
  .  00000125:  00 00 00 00 00 00                               PAD
  .  0000012b:  71 32 a0 d6 78 3f 07 00 00                      TS 7969191665714
  [...]
  .  0000018c:  b0 0c e1 20 2a ee b7 ff c0                      PC 0xffb7ee2a20e10c el2 ns=1
  .  00000195:  99 02 00                                        LAT 2 ISSUE
  .  00000198:  98 03 00                                        LAT 3 TOT
  .  0000019b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000019e:  4a 01                                           B COND
  .  000001a0:  b1 10 e1 20 2a ee b7 ff c0                      TGT 0xffb7ee2a20e110 el2 ns=1
  .  000001a9:  00 00 00 00 00 00                               PAD
  .  000001af:  71 bc a4 d6 78 3f 07 00 00                      TS 7969191666876
  [...]
  .  00000ef4:  b0 44 3a fe 29 ee b7 ff c0                      PC 0xffb7ee29fe3a44 el2 ns=1
  .  00000efd:  99 07 00                                        LAT 7 ISSUE
  .  00000f00:  98 08 00                                        LAT 8 TOT
  .  00000f03:  52 82 00                                        EV RETIRED MISPRED
  .  00000f06:  4a 01                                           B COND
  .  00000f08:  b1 20 3a fe 29 ee b7 ff c0                      TGT 0xffb7ee29fe3a20 el2 ns=1
  .  00000f11:  00 00 00 00 00 00                               PAD
  .  00000f17:  71 1e 06 d7 78 3f 07 00 00                      TS 7969191691806
  [...]
  .  00000f20:  b0 fc 87 fc 29 ee b7 ff c0                      PC 0xffb7ee29fc87fc el2 ns=1
  .  00000f29:  99 06 00                                        LAT 6 ISSUE
  .  00000f2c:  98 07 00                                        LAT 7 TOT
  .  00000f2f:  52 82 00                                        EV RETIRED MISPRED
  .  00000f32:  4a 01                                           B COND
  .  00000f34:  b1 08 88 fc 29 ee b7 ff c0                      TGT 0xffb7ee29fc8808 el2 ns=1
  .  00000f3d:  00 00 00 00 00 00                               PAD
  .  00000f43:  71 e1 07 d7 78 3f 07 00 00                      TS 7969191692257
  [...]
  .  00000ffc:  b0 18 24 fd 29 ee b7 ff c0                      PC 0xffb7ee29fd2418 el2 ns=1
  .  00001005:  99 02 00                                        LAT 2 ISSUE
  .  00001008:  98 03 00                                        LAT 3 TOT
  .  0000100b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000100e:  4a 01                                           B COND
  .  00001010:  b1 1c 24 fd 29 ee b7 ff c0                      TGT 0xffb7ee29fd241c el2 ns=1
  .  00001019:  00 00 00 00 00 00                               PAD
  .  0000101f:  71 e9 11 d7 78 3f 07 00 00                      TS 7969191694825
  [...]
  .  00001188:  b0 c0 e0 20 2a ee b7 ff c0                      PC 0xffb7ee2a20e0c0 el2 ns=1
  .  00001191:  99 02 00                                        LAT 2 ISSUE
  .  00001194:  98 03 00                                        LAT 3 TOT
  .  00001197:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000119a:  4a 01                                           B COND
  .  0000119c:  b1 c4 e0 20 2a ee b7 ff c0                      TGT 0xffb7ee2a20e0c4 el2 ns=1
  .  000011a5:  00 00 00 00 00 00                               PAD
  .  000011ab:  71 40 1e d7 78 3f 07 00 00                      TS 7969191697984
  [...]
  .  00001c5c:  b0 2c 8c fd 6c fd ff 00 80                      PC 0xfffd6cfd8c2c el0 ns=1
  .  00001c65:  99 02 00                                        LAT 2 ISSUE
  .  00001c68:  98 03 00                                        LAT 3 TOT
  .  00001c6b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  00001c6e:  4a 01                                           B COND
  .  00001c70:  b1 30 8c fd 6c fd ff 00 80                      TGT 0xfffd6cfd8c30 el0 ns=1
  .  00001c79:  00 00 00 00 00 00                               PAD
  .  00001c7f:  71 36 03 d8 78 3f 07 00 00                      TS 7969191756598
  [...]
  .  00001e40:  b0 00 0b de 6c fd ff 00 80                      PC 0xfffd6cde0b00 el0 ns=1
  .  00001e49:  99 02 00                                        LAT 2 ISSUE
  .  00001e4c:  98 03 00                                        LAT 3 TOT
  .  00001e4f:  52 82 00                                        EV RETIRED MISPRED
  .  00001e52:  4a 01                                           B COND
  .  00001e54:  b1 50 0b de 6c fd ff 00 80                      TGT 0xfffd6cde0b50 el0 ns=1
  .  00001e5d:  00 00 00 00 00 00                               PAD
  .  00001e63:  71 0f 1d d8 78 3f 07 00 00                      TS 7969191763215
  [...]
  .  00002234:  b0 e0 60 f3 29 ee b7 ff c0                      PC 0xffb7ee29f360e0 el2 ns=1
  .  0000223d:  99 02 00                                        LAT 2 ISSUE
  .  00002240:  98 03 00                                        LAT 3 TOT
  .  00002243:  52 82 00                                        EV RETIRED MISPRED
  .  00002246:  4a 01                                           B COND
  .  00002248:  b1 68 61 f3 29 ee b7 ff c0                      TGT 0xffb7ee29f36168 el2 ns=1
  .  00002251:  00 00 00 00 00 00                               PAD
  .  00002257:  71 7d 27 d8 78 3f 07 00 00                      TS 7969191765885
  [...]
  .  0000228c:  b0 60 b0 fd 6c fd ff 00 80                      PC 0xfffd6cfdb060 el0 ns=1
  .  00002295:  99 0e 00                                        LAT 14 ISSUE
  .  00002298:  98 0f 00                                        LAT 15 TOT
  .  0000229b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000229e:  4a 01                                           B COND
  .  000022a0:  b1 64 b0 fd 6c fd ff 00 80                      TGT 0xfffd6cfdb064 el0 ns=1
  .  000022a9:  00 00 00 00 00 00                               PAD
  .  000022af:  71 af 2b d8 78 3f 07 00 00                      TS 7969191766959
  [...]
  .  00002af8:  b0 28 7a fe 6c fd ff 00 80                      PC 0xfffd6cfe7a28 el0 ns=1
  .  00002b01:  99 03 00                                        LAT 3 ISSUE
  .  00002b04:  98 04 00                                        LAT 4 TOT
  .  00002b07:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  00002b0a:  4a 01                                           B COND
  .  00002b0c:  b1 2c 7a fe 6c fd ff 00 80                      TGT 0xfffd6cfe7a2c el0 ns=1
  .  00002b15:  00 00 00 00 00 00                               PAD
  .  00002b1b:  71 95 50 d8 78 3f 07 00 00                      TS 7969191776405
  [...]
  .  00002b50:  b0 28 7a fe 6c fd ff 00 80                      PC 0xfffd6cfe7a28 el0 ns=1
  .  00002b59:  99 05 00                                        LAT 5 ISSUE
  .  00002b5c:  98 06 00                                        LAT 6 TOT
  .  00002b5f:  52 02 00                                        EV RETIRED
  .  00002b62:  4a 01                                           B COND
  .  00002b64:  b1 10 7a fe 6c fd ff 00 80                      TGT 0xfffd6cfe7a10 el0 ns=1
  .  00002b6d:  00 00 00 00 00 00                               PAD
  .  00002b73:  71 f3 51 d8 78 3f 07 00 00                      TS 7969191776755
  [...]
  .  00003498:  b0 30 29 e7 6c fd ff 00 80                      PC 0xfffd6ce72930 el0 ns=1
  .  000034a1:  99 0b 00                                        LAT 11 ISSUE
  .  000034a4:  98 0c 00                                        LAT 12 TOT
  .  000034a7:  52 42 00                                        EV RETIRED NOT-TAKEN
  .  000034aa:  4a 01                                           B COND
  .  000034ac:  b1 34 29 e7 6c fd ff 00 80                      TGT 0xfffd6ce72934 el0 ns=1
  .  000034b5:  00 00 00 00 00 00                               PAD
  .  000034bb:  71 ea 86 d8 78 3f 07 00 00                      TS 7969191790314
  [...]
  .  00003ba4:  b0 78 95 fe 29 ee b7 ff c0                      PC 0xffb7ee29fe9578 el2 ns=1
  .  00003bad:  99 02 00                                        LAT 2 ISSUE
  .  00003bb0:  98 03 00                                        LAT 3 TOT
  .  00003bb3:  52 82 00                                        EV RETIRED MISPRED
  .  00003bb6:  4a 01                                           B COND
  .  00003bb8:  b1 2c 95 fe 29 ee b7 ff c0                      TGT 0xffb7ee29fe952c el2 ns=1
  .  00003bc1:  00 00 00 00 00 00                               PAD
  .  00003bc7:  71 3a b0 d8 78 3f 07 00 00                      TS 7969191800890
  [...]
  .  00003d04:  b0 14 c0 d8 6c fd ff 00 80                      PC 0xfffd6cd8c014 el0 ns=1
  .  00003d0d:  99 02 00                                        LAT 2 ISSUE
  .  00003d10:  98 03 00                                        LAT 3 TOT
  .  00003d13:  52 82 00                                        EV RETIRED MISPRED
  .  00003d16:  4a 01                                           B COND
  .  00003d18:  b1 e8 c0 d8 6c fd ff 00 80                      TGT 0xfffd6cd8c0e8 el0 ns=1
  .  00003d21:  00 00 00 00 00 00                               PAD
  .  00003d27:  71 51 ba d8 78 3f 07 00 00                      TS 7969191803473
  [...]
  .  00003ff0:  b0 60 0e dd 6c fd ff 00 80                      PC 0xfffd6cdd0e60 el0 ns=1
  .  00003ff9:  99 03 00                                        LAT 3 ISSUE
  .  00003ffc:  98 04 00                                        LAT 4 TOT
  .  00003fff:  52 82 00                                        EV RETIRED MISPRED
  .  00004002:  4a 01                                           B COND
  .  00004004:  b1 d8 0e dd 6c fd ff 00 80                      TGT 0xfffd6cdd0ed8 el0 ns=1
  .  0000400d:  00 00 00 00 00 00                               PAD
  .  00004013:  71 e0 d2 d8 78 3f 07 00 00                      TS 7969191809760
  [...]
  # perf script
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29f38200 do_mmap+0x60 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fe3a44 __d_lookup_rcu+0xe4 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fc87fc cp_new_stat+0x11c ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fd2418 link_path_walk.part.35+0x198 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfd8c2c [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cde0b00 memset+0x18 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfdb060 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6ce72930 _dl_addr+0x110 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fe9578 atime_needs_update+0x120 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cd8c014 [unknown] (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cdd0e60 [unknown] (/usr/lib64/libc-2.28.so)

Solution:
  Set "sample->time" to the timestamp corresponding to each packet in auxtrace.

After:

  # perf script
              ls 107690 [005]  7969.191665:          1                            branch-miss:  ffffb7ee29f38200 do_mmap+0x60 ([kernel.kallsyms])
              ls 107690 [005]  7969.191666:          1                            branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c ([kernel.kallsyms])
              ls 107690 [005]  7969.191691:          1                            branch-miss:  ffffb7ee29fe3a44 __d_lookup_rcu+0xe4 ([kernel.kallsyms])
              ls 107690 [005]  7969.191692:          1                            branch-miss:  ffffb7ee29fc87fc cp_new_stat+0x11c ([kernel.kallsyms])
              ls 107690 [005]  7969.191694:          1                            branch-miss:  ffffb7ee29fd2418 link_path_walk.part.35+0x198 ([kernel.kallsyms])
              ls 107690 [005]  7969.191697:          1                            branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 ([kernel.kallsyms])
              ls 107690 [005]  7969.191756:          1                            branch-miss:      fffd6cfd8c2c [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191763:          1                            branch-miss:      fffd6cde0b00 memset+0x18 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191765:          1                            branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 ([kernel.kallsyms])
              ls 107690 [005]  7969.191766:          1                            branch-miss:      fffd6cfdb060 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191776:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191782:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191791:          1                            branch-miss:      fffd6ce72930 _dl_addr+0x110 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191800:          1                            branch-miss:  ffffb7ee29fe9578 atime_needs_update+0x120 ([kernel.kallsyms])
              ls 107690 [005]  7969.191803:          1                            branch-miss:      fffd6cd8c014 [unknown] (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191809:          1                            branch-miss:      fffd6cdd0e60 [unknown] (/usr/lib64/libc-2.28.so)

Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
---
 tools/perf/util/arm-spe.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/perf/util/arm-spe.c b/tools/perf/util/arm-spe.c
index 2539d4baec44..c4550cc1b248 100644
--- a/tools/perf/util/arm-spe.c
+++ b/tools/perf/util/arm-spe.c
@@ -231,7 +231,7 @@ static void arm_spe_prep_sample(struct arm_spe *spe,
 	struct arm_spe_record *record = &speq->decoder->record;
 
 	if (!spe->timeless_decoding)
-		sample->time = speq->timestamp;
+		sample->time = record->timestamp;
 
 	sample->ip = record->from_ip;
 	sample->cpumode = arm_spe_cpumode(spe, sample->ip);
-- 
2.30.GIT


^ permalink raw reply related	[flat|nested] 14+ messages in thread

* [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-26  3:21 ` Yang Jihong
  0 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-26  3:21 UTC (permalink / raw)
  To: john.garry, will, mathieu.poirier, leo.yan, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel
  Cc: yangjihong1

When use perf script to parse ARM SPE data, sample timestamp does not match
the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
"samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
buffer uses the same timestamp.

Before:

  # perf record -e arm_spe_0/ts_enable=1,branch_filter=1/ ls
  perf.data
  [ perf record: Woken up 1 times to write data ]
  [ perf record: Captured and wrote 0.029 MB perf.data ]
  [ perf record: Captured and wrote 1.429 MB perf.data ]
  # perf script -D
  [...]
  0 0 0x31b0 [0x30]: PERF_RECORD_AUXTRACE size: 0x44f0  offset: 0  ref: 0x3a50d  idx: 5  tid: 107690  cpu: 5
  .
  [...]
  .  00000108:  b0 00 82 f3 29 ee b7 ff c0                      PC 0xffb7ee29f38200 el2 ns=1
  .  00000111:  99 02 00                                        LAT 2 ISSUE
  .  00000114:  98 03 00                                        LAT 3 TOT
  .  00000117:  52 82 00                                        EV RETIRED MISPRED
  .  0000011a:  4a 01                                           B COND
  .  0000011c:  b1 24 82 f3 29 ee b7 ff c0                      TGT 0xffb7ee29f38224 el2 ns=1
  .  00000125:  00 00 00 00 00 00                               PAD
  .  0000012b:  71 32 a0 d6 78 3f 07 00 00                      TS 7969191665714
  [...]
  .  0000018c:  b0 0c e1 20 2a ee b7 ff c0                      PC 0xffb7ee2a20e10c el2 ns=1
  .  00000195:  99 02 00                                        LAT 2 ISSUE
  .  00000198:  98 03 00                                        LAT 3 TOT
  .  0000019b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000019e:  4a 01                                           B COND
  .  000001a0:  b1 10 e1 20 2a ee b7 ff c0                      TGT 0xffb7ee2a20e110 el2 ns=1
  .  000001a9:  00 00 00 00 00 00                               PAD
  .  000001af:  71 bc a4 d6 78 3f 07 00 00                      TS 7969191666876
  [...]
  .  00000ef4:  b0 44 3a fe 29 ee b7 ff c0                      PC 0xffb7ee29fe3a44 el2 ns=1
  .  00000efd:  99 07 00                                        LAT 7 ISSUE
  .  00000f00:  98 08 00                                        LAT 8 TOT
  .  00000f03:  52 82 00                                        EV RETIRED MISPRED
  .  00000f06:  4a 01                                           B COND
  .  00000f08:  b1 20 3a fe 29 ee b7 ff c0                      TGT 0xffb7ee29fe3a20 el2 ns=1
  .  00000f11:  00 00 00 00 00 00                               PAD
  .  00000f17:  71 1e 06 d7 78 3f 07 00 00                      TS 7969191691806
  [...]
  .  00000f20:  b0 fc 87 fc 29 ee b7 ff c0                      PC 0xffb7ee29fc87fc el2 ns=1
  .  00000f29:  99 06 00                                        LAT 6 ISSUE
  .  00000f2c:  98 07 00                                        LAT 7 TOT
  .  00000f2f:  52 82 00                                        EV RETIRED MISPRED
  .  00000f32:  4a 01                                           B COND
  .  00000f34:  b1 08 88 fc 29 ee b7 ff c0                      TGT 0xffb7ee29fc8808 el2 ns=1
  .  00000f3d:  00 00 00 00 00 00                               PAD
  .  00000f43:  71 e1 07 d7 78 3f 07 00 00                      TS 7969191692257
  [...]
  .  00000ffc:  b0 18 24 fd 29 ee b7 ff c0                      PC 0xffb7ee29fd2418 el2 ns=1
  .  00001005:  99 02 00                                        LAT 2 ISSUE
  .  00001008:  98 03 00                                        LAT 3 TOT
  .  0000100b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000100e:  4a 01                                           B COND
  .  00001010:  b1 1c 24 fd 29 ee b7 ff c0                      TGT 0xffb7ee29fd241c el2 ns=1
  .  00001019:  00 00 00 00 00 00                               PAD
  .  0000101f:  71 e9 11 d7 78 3f 07 00 00                      TS 7969191694825
  [...]
  .  00001188:  b0 c0 e0 20 2a ee b7 ff c0                      PC 0xffb7ee2a20e0c0 el2 ns=1
  .  00001191:  99 02 00                                        LAT 2 ISSUE
  .  00001194:  98 03 00                                        LAT 3 TOT
  .  00001197:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000119a:  4a 01                                           B COND
  .  0000119c:  b1 c4 e0 20 2a ee b7 ff c0                      TGT 0xffb7ee2a20e0c4 el2 ns=1
  .  000011a5:  00 00 00 00 00 00                               PAD
  .  000011ab:  71 40 1e d7 78 3f 07 00 00                      TS 7969191697984
  [...]
  .  00001c5c:  b0 2c 8c fd 6c fd ff 00 80                      PC 0xfffd6cfd8c2c el0 ns=1
  .  00001c65:  99 02 00                                        LAT 2 ISSUE
  .  00001c68:  98 03 00                                        LAT 3 TOT
  .  00001c6b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  00001c6e:  4a 01                                           B COND
  .  00001c70:  b1 30 8c fd 6c fd ff 00 80                      TGT 0xfffd6cfd8c30 el0 ns=1
  .  00001c79:  00 00 00 00 00 00                               PAD
  .  00001c7f:  71 36 03 d8 78 3f 07 00 00                      TS 7969191756598
  [...]
  .  00001e40:  b0 00 0b de 6c fd ff 00 80                      PC 0xfffd6cde0b00 el0 ns=1
  .  00001e49:  99 02 00                                        LAT 2 ISSUE
  .  00001e4c:  98 03 00                                        LAT 3 TOT
  .  00001e4f:  52 82 00                                        EV RETIRED MISPRED
  .  00001e52:  4a 01                                           B COND
  .  00001e54:  b1 50 0b de 6c fd ff 00 80                      TGT 0xfffd6cde0b50 el0 ns=1
  .  00001e5d:  00 00 00 00 00 00                               PAD
  .  00001e63:  71 0f 1d d8 78 3f 07 00 00                      TS 7969191763215
  [...]
  .  00002234:  b0 e0 60 f3 29 ee b7 ff c0                      PC 0xffb7ee29f360e0 el2 ns=1
  .  0000223d:  99 02 00                                        LAT 2 ISSUE
  .  00002240:  98 03 00                                        LAT 3 TOT
  .  00002243:  52 82 00                                        EV RETIRED MISPRED
  .  00002246:  4a 01                                           B COND
  .  00002248:  b1 68 61 f3 29 ee b7 ff c0                      TGT 0xffb7ee29f36168 el2 ns=1
  .  00002251:  00 00 00 00 00 00                               PAD
  .  00002257:  71 7d 27 d8 78 3f 07 00 00                      TS 7969191765885
  [...]
  .  0000228c:  b0 60 b0 fd 6c fd ff 00 80                      PC 0xfffd6cfdb060 el0 ns=1
  .  00002295:  99 0e 00                                        LAT 14 ISSUE
  .  00002298:  98 0f 00                                        LAT 15 TOT
  .  0000229b:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  0000229e:  4a 01                                           B COND
  .  000022a0:  b1 64 b0 fd 6c fd ff 00 80                      TGT 0xfffd6cfdb064 el0 ns=1
  .  000022a9:  00 00 00 00 00 00                               PAD
  .  000022af:  71 af 2b d8 78 3f 07 00 00                      TS 7969191766959
  [...]
  .  00002af8:  b0 28 7a fe 6c fd ff 00 80                      PC 0xfffd6cfe7a28 el0 ns=1
  .  00002b01:  99 03 00                                        LAT 3 ISSUE
  .  00002b04:  98 04 00                                        LAT 4 TOT
  .  00002b07:  52 c2 00                                        EV RETIRED NOT-TAKEN MISPRED
  .  00002b0a:  4a 01                                           B COND
  .  00002b0c:  b1 2c 7a fe 6c fd ff 00 80                      TGT 0xfffd6cfe7a2c el0 ns=1
  .  00002b15:  00 00 00 00 00 00                               PAD
  .  00002b1b:  71 95 50 d8 78 3f 07 00 00                      TS 7969191776405
  [...]
  .  00002b50:  b0 28 7a fe 6c fd ff 00 80                      PC 0xfffd6cfe7a28 el0 ns=1
  .  00002b59:  99 05 00                                        LAT 5 ISSUE
  .  00002b5c:  98 06 00                                        LAT 6 TOT
  .  00002b5f:  52 02 00                                        EV RETIRED
  .  00002b62:  4a 01                                           B COND
  .  00002b64:  b1 10 7a fe 6c fd ff 00 80                      TGT 0xfffd6cfe7a10 el0 ns=1
  .  00002b6d:  00 00 00 00 00 00                               PAD
  .  00002b73:  71 f3 51 d8 78 3f 07 00 00                      TS 7969191776755
  [...]
  .  00003498:  b0 30 29 e7 6c fd ff 00 80                      PC 0xfffd6ce72930 el0 ns=1
  .  000034a1:  99 0b 00                                        LAT 11 ISSUE
  .  000034a4:  98 0c 00                                        LAT 12 TOT
  .  000034a7:  52 42 00                                        EV RETIRED NOT-TAKEN
  .  000034aa:  4a 01                                           B COND
  .  000034ac:  b1 34 29 e7 6c fd ff 00 80                      TGT 0xfffd6ce72934 el0 ns=1
  .  000034b5:  00 00 00 00 00 00                               PAD
  .  000034bb:  71 ea 86 d8 78 3f 07 00 00                      TS 7969191790314
  [...]
  .  00003ba4:  b0 78 95 fe 29 ee b7 ff c0                      PC 0xffb7ee29fe9578 el2 ns=1
  .  00003bad:  99 02 00                                        LAT 2 ISSUE
  .  00003bb0:  98 03 00                                        LAT 3 TOT
  .  00003bb3:  52 82 00                                        EV RETIRED MISPRED
  .  00003bb6:  4a 01                                           B COND
  .  00003bb8:  b1 2c 95 fe 29 ee b7 ff c0                      TGT 0xffb7ee29fe952c el2 ns=1
  .  00003bc1:  00 00 00 00 00 00                               PAD
  .  00003bc7:  71 3a b0 d8 78 3f 07 00 00                      TS 7969191800890
  [...]
  .  00003d04:  b0 14 c0 d8 6c fd ff 00 80                      PC 0xfffd6cd8c014 el0 ns=1
  .  00003d0d:  99 02 00                                        LAT 2 ISSUE
  .  00003d10:  98 03 00                                        LAT 3 TOT
  .  00003d13:  52 82 00                                        EV RETIRED MISPRED
  .  00003d16:  4a 01                                           B COND
  .  00003d18:  b1 e8 c0 d8 6c fd ff 00 80                      TGT 0xfffd6cd8c0e8 el0 ns=1
  .  00003d21:  00 00 00 00 00 00                               PAD
  .  00003d27:  71 51 ba d8 78 3f 07 00 00                      TS 7969191803473
  [...]
  .  00003ff0:  b0 60 0e dd 6c fd ff 00 80                      PC 0xfffd6cdd0e60 el0 ns=1
  .  00003ff9:  99 03 00                                        LAT 3 ISSUE
  .  00003ffc:  98 04 00                                        LAT 4 TOT
  .  00003fff:  52 82 00                                        EV RETIRED MISPRED
  .  00004002:  4a 01                                           B COND
  .  00004004:  b1 d8 0e dd 6c fd ff 00 80                      TGT 0xfffd6cdd0ed8 el0 ns=1
  .  0000400d:  00 00 00 00 00 00                               PAD
  .  00004013:  71 e0 d2 d8 78 3f 07 00 00                      TS 7969191809760
  [...]
  # perf script
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29f38200 do_mmap+0x60 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fe3a44 __d_lookup_rcu+0xe4 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fc87fc cp_new_stat+0x11c ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fd2418 link_path_walk.part.35+0x198 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfd8c2c [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cde0b00 memset+0x18 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfdb060 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6ce72930 _dl_addr+0x110 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:  ffffb7ee29fe9578 atime_needs_update+0x120 ([kernel.kallsyms])
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cd8c014 [unknown] (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191661:          1                            branch-miss:      fffd6cdd0e60 [unknown] (/usr/lib64/libc-2.28.so)

Solution:
  Set "sample->time" to the timestamp corresponding to each packet in auxtrace.

After:

  # perf script
              ls 107690 [005]  7969.191665:          1                            branch-miss:  ffffb7ee29f38200 do_mmap+0x60 ([kernel.kallsyms])
              ls 107690 [005]  7969.191666:          1                            branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c ([kernel.kallsyms])
              ls 107690 [005]  7969.191691:          1                            branch-miss:  ffffb7ee29fe3a44 __d_lookup_rcu+0xe4 ([kernel.kallsyms])
              ls 107690 [005]  7969.191692:          1                            branch-miss:  ffffb7ee29fc87fc cp_new_stat+0x11c ([kernel.kallsyms])
              ls 107690 [005]  7969.191694:          1                            branch-miss:  ffffb7ee29fd2418 link_path_walk.part.35+0x198 ([kernel.kallsyms])
              ls 107690 [005]  7969.191697:          1                            branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 ([kernel.kallsyms])
              ls 107690 [005]  7969.191756:          1                            branch-miss:      fffd6cfd8c2c [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191763:          1                            branch-miss:      fffd6cde0b00 memset+0x18 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191765:          1                            branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 ([kernel.kallsyms])
              ls 107690 [005]  7969.191766:          1                            branch-miss:      fffd6cfdb060 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191776:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191782:          1                            branch-miss:      fffd6cfe7a28 [unknown] (/usr/lib64/ld-2.28.so)
              ls 107690 [005]  7969.191791:          1                            branch-miss:      fffd6ce72930 _dl_addr+0x110 (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191800:          1                            branch-miss:  ffffb7ee29fe9578 atime_needs_update+0x120 ([kernel.kallsyms])
              ls 107690 [005]  7969.191803:          1                            branch-miss:      fffd6cd8c014 [unknown] (/usr/lib64/libc-2.28.so)
              ls 107690 [005]  7969.191809:          1                            branch-miss:      fffd6cdd0e60 [unknown] (/usr/lib64/libc-2.28.so)

Signed-off-by: Yang Jihong <yangjihong1@huawei.com>
---
 tools/perf/util/arm-spe.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/tools/perf/util/arm-spe.c b/tools/perf/util/arm-spe.c
index 2539d4baec44..c4550cc1b248 100644
--- a/tools/perf/util/arm-spe.c
+++ b/tools/perf/util/arm-spe.c
@@ -231,7 +231,7 @@ static void arm_spe_prep_sample(struct arm_spe *spe,
 	struct arm_spe_record *record = &speq->decoder->record;
 
 	if (!spe->timeless_decoding)
-		sample->time = speq->timestamp;
+		sample->time = record->timestamp;
 
 	sample->ip = record->from_ip;
 	sample->cpumode = arm_spe_cpumode(spe, sample->ip);
-- 
2.30.GIT


_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply related	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-26  3:21 ` Yang Jihong
@ 2021-06-28  1:49   ` Leo Yan
  -1 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  1:49 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hi Jihong,

On Sat, Jun 26, 2021 at 11:21:15AM +0800, Yang Jihong wrote:
> When use perf script to parse ARM SPE data, sample timestamp does not match
> the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
> "samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
> packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
> buffer uses the same timestamp.

Could you confirm if the patch set [1] can fix your issue?

Thanks,
Leo

[1] https://lore.kernel.org/patchwork/cover/1431624/

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-28  1:49   ` Leo Yan
  0 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  1:49 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hi Jihong,

On Sat, Jun 26, 2021 at 11:21:15AM +0800, Yang Jihong wrote:
> When use perf script to parse ARM SPE data, sample timestamp does not match
> the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
> "samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
> packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
> buffer uses the same timestamp.

Could you confirm if the patch set [1] can fix your issue?

Thanks,
Leo

[1] https://lore.kernel.org/patchwork/cover/1431624/

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-28  1:49   ` Leo Yan
@ 2021-06-28  3:45     ` Yang Jihong
  -1 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-28  3:45 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 9:49, Leo Yan wrote:
> Hi Jihong,
> 
> On Sat, Jun 26, 2021 at 11:21:15AM +0800, Yang Jihong wrote:
>> When use perf script to parse ARM SPE data, sample timestamp does not match
>> the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
>> "samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
>> packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
>> buffer uses the same timestamp.
> 
> Could you confirm if the patch set [1] can fix your issue?
> 
After I apply this patch set, and verify it as follows:

# ./perf/perf record -e arm_spe_0/ts_enable=1,branch_filter=1/ ls
accounting  bootconfig  build   debugging  elf.s     firmware  hv 
include   kvm     leds  Makefile      objtool  pcmcia  perf.data 
scripts  testing  time     usb     vm
arch        bpf         cgroup  edid       firewire  gpio      iio 
io_uring  laptop  lib   memory-model  pci      perf    power      spi 
    thermal  tracing  virtio  wmi
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.031 MB perf.data ]
# ./perf/perf script --ns
               ls 23104 [030] 314938.859071370:          1 
               branch-miss:  ffffb7ee2a20e100 __pi_memcpy+0x80 
([kernel.kallsyms])
               ls 23104 [030] 314938.859753820:          1 
               branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 
([kernel.kallsyms])
               ls 23104 [030] 314938.859820430:          1 
               branch-miss:      fffe85dd87e0 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859941110:          1 
               branch-miss:      fffe85dd7a28 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859948890:          1 
               branch-miss:      fffe85dd7a28 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859953610:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859955730:          1 
               branch-miss:  ffffb7ee2a12856c common_mmap.part.23+0x34 
([kernel.kallsyms])
               ls 23104 [030] 314938.860059900:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860095470:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860105460:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860111870:          1 
               branch-miss:      fffe85dd7a20 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860237310:          1 
               branch-miss:      fffe85bc8e00 [unknown] 
(/usr/lib64/libc-2.28.so)
               ls 23104 [030] 314938.860419000:          1 
               branch-miss:      fffe85bd4638 __strcoll_l+0xc58 
(/usr/lib64/libc-2.28.so)
               ls 23104 [030] 314938.860455790:          1 
               branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c 
([kernel.kallsyms])
               ls 23104 [030] 314938.860473730:          1 
               branch-miss:  ffffb7ee29d0af50 __queue_work+0x1a8 
([kernel.kallsyms])
               ls 23104 [030] 314938.860485020:          1 
               branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 
([kernel.kallsyms])
               ls 23104 [030] 314938.860533380:          1 
               branch-miss:  ffffb7ee29f39158 tlb_flush+0x30 
([kernel.kallsyms])
# ./perf/perf script -D
[...]
.  00000a7c:  b0 00 e1 20 2a ee b7 ff c0                      PC 
0xffb7ee2a20e100 el2 ns=1
.  00000a85:  99 02 00                                        LAT 2 ISSUE
.  00000a88:  98 03 00                                        LAT 3 TOT
.  00000a8b:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00000a8e:  4a 01                                           B COND
.  00000a90:  b1 04 e1 20 2a ee b7 ff c0                      TGT 
0xffb7ee2a20e104 el2 ns=1
.  00000a99:  00 00 00 00 00 00                               PAD
.  00000a9f:  71 3f e9 51 b9 a9 1c 00 00                      TS 
31515284203839
[...]
.  000018c0:  b0 e0 60 f3 29 ee b7 ff c0                      PC 
0xffb7ee29f360e0 el2 ns=1
.  000018c9:  99 02 00                                        LAT 2 ISSUE
.  000018cc:  98 03 00                                        LAT 3 TOT
.  000018cf:  52 82 00                                        EV RETIRED 
MISPRED
.  000018d2:  4a 01                                           B COND
.  000018d4:  b1 68 61 f3 29 ee b7 ff c0                      TGT 
0xffb7ee29f36168 el2 ns=1
.  000018dd:  00 00 00 00 00 00                               PAD
.  000018e3:  71 d4 f3 52 b9 a9 1c 00 00                      TS 
31515284272084
[...]
.  000019f4:  b0 e0 87 dd 85 fe ff 00 80                      PC 
0xfffe85dd87e0 el0 ns=1
.  000019fd:  99 02 00                                        LAT 2 ISSUE
.  00001a00:  98 03 00                                        LAT 3 TOT
.  00001a03:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00001a06:  4a 01                                           B COND
.  00001a08:  b1 e4 87 dd 85 fe ff 00 80                      TGT 
0xfffe85dd87e4 el0 ns=1
.  00001a11:  00 00 00 00 00 00                               PAD
.  00001a17:  71 d9 0d 53 b9 a9 1c 00 00                      TS 
31515284278745
[...]
.  00001f48:  b0 28 7a dd 85 fe ff 00 80                      PC 
0xfffe85dd7a28 el0 ns=1
.  00001f51:  99 07 00                                        LAT 7 ISSUE
.  00001f54:  98 08 00                                        LAT 8 TOT
.  00001f57:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00001f5a:  4a 01                                           B COND
.  00001f5c:  b1 2c 7a dd 85 fe ff 00 80                      TGT 
0xfffe85dd7a2c el0 ns=1
.  00001f65:  00 00 00 00 00 00                               PAD
.  00001f6b:  71 fd 3c 53 b9 a9 1c 00 00                      TS 
31515284290813
[...]
.  00001fcc:  b0 28 7a dd 85 fe ff 00 80                      PC 
0xfffe85dd7a28 el0 ns=1
.  00001fd5:  99 08 00                                        LAT 8 ISSUE
.  00001fd8:  98 09 00                                        LAT 9 TOT
.  00001fdb:  52 82 00                                        EV RETIRED 
MISPRED
.  00001fde:  4a 01                                           B COND
.  00001fe0:  b1 10 7a dd 85 fe ff 00 80                      TGT 
0xfffe85dd7a10 el0 ns=1
.  00001fe9:  00 00 00 00 00 00                               PAD
.  00001fef:  71 07 40 53 b9 a9 1c 00 00                      TS 
31515284291591
[...]
.  00002050:  b0 58 8f dc 85 fe ff 00 80                      PC 
0xfffe85dc8f58 el0 ns=1
.  00002059:  99 22 00                                        LAT 34 ISSUE
.  0000205c:  98 23 00                                        LAT 35 TOT
.  0000205f:  52 82 00                                        EV RETIRED 
MISPRED
.  00002062:  4a 01                                           B COND
.  00002064:  b1 40 8f dc 85 fe ff 00 80                      TGT 
0xfffe85dc8f40 el0 ns=1
.  0000206d:  00 00 00 00 00 00                               PAD
.  00002073:  71 df 41 53 b9 a9 1c 00 00                      TS 
31515284292063
[...]

The timestamp does not match. Each timestamp has a difference of 
213.98296702 seconds. Is the command I executed wrong?

|symbol_address|perf script| perf script -D|
|ffffb7ee2a20e100|314938.859071370|31515284203839|
|ffffb7ee29f360e0|314938.859753820|31515284272084|
|fffe85dd87e0|314938.859820430|31515284278745|
|fffe85dd7a28|314938.859941110|31515284290813|
|fffe85dd7a28|314938.859948890|31515284291591|
|fffe85dc8f58|314938.859953610|31515284292063|

Thanks,
Jihong
> Thanks,
> Leo
> 
> [1] https://lore.kernel.org/patchwork/cover/1431624/
> .
> 

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-28  3:45     ` Yang Jihong
  0 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-28  3:45 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 9:49, Leo Yan wrote:
> Hi Jihong,
> 
> On Sat, Jun 26, 2021 at 11:21:15AM +0800, Yang Jihong wrote:
>> When use perf script to parse ARM SPE data, sample timestamp does not match
>> the timestamp stored in the AUX buffer, arm_spe_prep_sample function set
>> "samlpe->time = speq->timestamp", "speq->timestamp" is the timestamp of first
>> packet in auxtrace buffer. As a result, the time of all samples in a auxtrace
>> buffer uses the same timestamp.
> 
> Could you confirm if the patch set [1] can fix your issue?
> 
After I apply this patch set, and verify it as follows:

# ./perf/perf record -e arm_spe_0/ts_enable=1,branch_filter=1/ ls
accounting  bootconfig  build   debugging  elf.s     firmware  hv 
include   kvm     leds  Makefile      objtool  pcmcia  perf.data 
scripts  testing  time     usb     vm
arch        bpf         cgroup  edid       firewire  gpio      iio 
io_uring  laptop  lib   memory-model  pci      perf    power      spi 
    thermal  tracing  virtio  wmi
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.031 MB perf.data ]
# ./perf/perf script --ns
               ls 23104 [030] 314938.859071370:          1 
               branch-miss:  ffffb7ee2a20e100 __pi_memcpy+0x80 
([kernel.kallsyms])
               ls 23104 [030] 314938.859753820:          1 
               branch-miss:  ffffb7ee29f360e0 __split_vma+0x110 
([kernel.kallsyms])
               ls 23104 [030] 314938.859820430:          1 
               branch-miss:      fffe85dd87e0 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859941110:          1 
               branch-miss:      fffe85dd7a28 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859948890:          1 
               branch-miss:      fffe85dd7a28 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859953610:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.859955730:          1 
               branch-miss:  ffffb7ee2a12856c common_mmap.part.23+0x34 
([kernel.kallsyms])
               ls 23104 [030] 314938.860059900:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860095470:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860105460:          1 
               branch-miss:      fffe85dc8f58 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860111870:          1 
               branch-miss:      fffe85dd7a20 [unknown] 
(/usr/lib64/ld-2.28.so)
               ls 23104 [030] 314938.860237310:          1 
               branch-miss:      fffe85bc8e00 [unknown] 
(/usr/lib64/libc-2.28.so)
               ls 23104 [030] 314938.860419000:          1 
               branch-miss:      fffe85bd4638 __strcoll_l+0xc58 
(/usr/lib64/libc-2.28.so)
               ls 23104 [030] 314938.860455790:          1 
               branch-miss:  ffffb7ee2a20e10c __pi_memcpy+0x8c 
([kernel.kallsyms])
               ls 23104 [030] 314938.860473730:          1 
               branch-miss:  ffffb7ee29d0af50 __queue_work+0x1a8 
([kernel.kallsyms])
               ls 23104 [030] 314938.860485020:          1 
               branch-miss:  ffffb7ee2a20e0c0 __pi_memcpy+0x40 
([kernel.kallsyms])
               ls 23104 [030] 314938.860533380:          1 
               branch-miss:  ffffb7ee29f39158 tlb_flush+0x30 
([kernel.kallsyms])
# ./perf/perf script -D
[...]
.  00000a7c:  b0 00 e1 20 2a ee b7 ff c0                      PC 
0xffb7ee2a20e100 el2 ns=1
.  00000a85:  99 02 00                                        LAT 2 ISSUE
.  00000a88:  98 03 00                                        LAT 3 TOT
.  00000a8b:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00000a8e:  4a 01                                           B COND
.  00000a90:  b1 04 e1 20 2a ee b7 ff c0                      TGT 
0xffb7ee2a20e104 el2 ns=1
.  00000a99:  00 00 00 00 00 00                               PAD
.  00000a9f:  71 3f e9 51 b9 a9 1c 00 00                      TS 
31515284203839
[...]
.  000018c0:  b0 e0 60 f3 29 ee b7 ff c0                      PC 
0xffb7ee29f360e0 el2 ns=1
.  000018c9:  99 02 00                                        LAT 2 ISSUE
.  000018cc:  98 03 00                                        LAT 3 TOT
.  000018cf:  52 82 00                                        EV RETIRED 
MISPRED
.  000018d2:  4a 01                                           B COND
.  000018d4:  b1 68 61 f3 29 ee b7 ff c0                      TGT 
0xffb7ee29f36168 el2 ns=1
.  000018dd:  00 00 00 00 00 00                               PAD
.  000018e3:  71 d4 f3 52 b9 a9 1c 00 00                      TS 
31515284272084
[...]
.  000019f4:  b0 e0 87 dd 85 fe ff 00 80                      PC 
0xfffe85dd87e0 el0 ns=1
.  000019fd:  99 02 00                                        LAT 2 ISSUE
.  00001a00:  98 03 00                                        LAT 3 TOT
.  00001a03:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00001a06:  4a 01                                           B COND
.  00001a08:  b1 e4 87 dd 85 fe ff 00 80                      TGT 
0xfffe85dd87e4 el0 ns=1
.  00001a11:  00 00 00 00 00 00                               PAD
.  00001a17:  71 d9 0d 53 b9 a9 1c 00 00                      TS 
31515284278745
[...]
.  00001f48:  b0 28 7a dd 85 fe ff 00 80                      PC 
0xfffe85dd7a28 el0 ns=1
.  00001f51:  99 07 00                                        LAT 7 ISSUE
.  00001f54:  98 08 00                                        LAT 8 TOT
.  00001f57:  52 c2 00                                        EV RETIRED 
NOT-TAKEN MISPRED
.  00001f5a:  4a 01                                           B COND
.  00001f5c:  b1 2c 7a dd 85 fe ff 00 80                      TGT 
0xfffe85dd7a2c el0 ns=1
.  00001f65:  00 00 00 00 00 00                               PAD
.  00001f6b:  71 fd 3c 53 b9 a9 1c 00 00                      TS 
31515284290813
[...]
.  00001fcc:  b0 28 7a dd 85 fe ff 00 80                      PC 
0xfffe85dd7a28 el0 ns=1
.  00001fd5:  99 08 00                                        LAT 8 ISSUE
.  00001fd8:  98 09 00                                        LAT 9 TOT
.  00001fdb:  52 82 00                                        EV RETIRED 
MISPRED
.  00001fde:  4a 01                                           B COND
.  00001fe0:  b1 10 7a dd 85 fe ff 00 80                      TGT 
0xfffe85dd7a10 el0 ns=1
.  00001fe9:  00 00 00 00 00 00                               PAD
.  00001fef:  71 07 40 53 b9 a9 1c 00 00                      TS 
31515284291591
[...]
.  00002050:  b0 58 8f dc 85 fe ff 00 80                      PC 
0xfffe85dc8f58 el0 ns=1
.  00002059:  99 22 00                                        LAT 34 ISSUE
.  0000205c:  98 23 00                                        LAT 35 TOT
.  0000205f:  52 82 00                                        EV RETIRED 
MISPRED
.  00002062:  4a 01                                           B COND
.  00002064:  b1 40 8f dc 85 fe ff 00 80                      TGT 
0xfffe85dc8f40 el0 ns=1
.  0000206d:  00 00 00 00 00 00                               PAD
.  00002073:  71 df 41 53 b9 a9 1c 00 00                      TS 
31515284292063
[...]

The timestamp does not match. Each timestamp has a difference of 
213.98296702 seconds. Is the command I executed wrong?

|symbol_address|perf script| perf script -D|
|ffffb7ee2a20e100|314938.859071370|31515284203839|
|ffffb7ee29f360e0|314938.859753820|31515284272084|
|fffe85dd87e0|314938.859820430|31515284278745|
|fffe85dd7a28|314938.859941110|31515284290813|
|fffe85dd7a28|314938.859948890|31515284291591|
|fffe85dc8f58|314938.859953610|31515284292063|

Thanks,
Jihong
> Thanks,
> Leo
> 
> [1] https://lore.kernel.org/patchwork/cover/1431624/
> .
> 

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-28  3:45     ` Yang Jihong
@ 2021-06-28  4:07       ` Leo Yan
  -1 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  4:07 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:

[...]

> The timestamp does not match. Each timestamp has a difference of
> 213.98296702 seconds. Is the command I executed wrong?

I don't understand what's your meaning "a difference of 213.98296702
seconds".

But let me give an explaination with your below examples.  You could
the command "perf script" outputs the timestamp 314938.859071370 which
is the kernel's timestamp, if using the command "perf script -D", it
outputs the value 31515284203839 which is the Arch timer's raw counter
value.

In theory, the arch timer's counter is enabled at the very early
time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
the kernel's timestamp, it should calibrate the timestamp and reduce
the offset prior to the kernel's booting.  I think this is the reason
why you observed 213.98296702 seconds difference (if compared with
your own patch?)

If still see any issue, please let me know.  Thanks a lot for the
testing!

Leo

> |symbol_address|perf script| perf script -D|
> |ffffb7ee2a20e100|314938.859071370|31515284203839|
> |ffffb7ee29f360e0|314938.859753820|31515284272084|
> |fffe85dd87e0|314938.859820430|31515284278745|
> |fffe85dd7a28|314938.859941110|31515284290813|
> |fffe85dd7a28|314938.859948890|31515284291591|
> |fffe85dc8f58|314938.859953610|31515284292063|

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-28  4:07       ` Leo Yan
  0 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  4:07 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:

[...]

> The timestamp does not match. Each timestamp has a difference of
> 213.98296702 seconds. Is the command I executed wrong?

I don't understand what's your meaning "a difference of 213.98296702
seconds".

But let me give an explaination with your below examples.  You could
the command "perf script" outputs the timestamp 314938.859071370 which
is the kernel's timestamp, if using the command "perf script -D", it
outputs the value 31515284203839 which is the Arch timer's raw counter
value.

In theory, the arch timer's counter is enabled at the very early
time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
the kernel's timestamp, it should calibrate the timestamp and reduce
the offset prior to the kernel's booting.  I think this is the reason
why you observed 213.98296702 seconds difference (if compared with
your own patch?)

If still see any issue, please let me know.  Thanks a lot for the
testing!

Leo

> |symbol_address|perf script| perf script -D|
> |ffffb7ee2a20e100|314938.859071370|31515284203839|
> |ffffb7ee29f360e0|314938.859753820|31515284272084|
> |fffe85dd87e0|314938.859820430|31515284278745|
> |fffe85dd7a28|314938.859941110|31515284290813|
> |fffe85dd7a28|314938.859948890|31515284291591|
> |fffe85dc8f58|314938.859953610|31515284292063|

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-28  4:07       ` Leo Yan
@ 2021-06-28  6:30         ` Yang Jihong
  -1 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-28  6:30 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 12:07, Leo Yan wrote:
> On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
> 
> [...]
> 
>> The timestamp does not match. Each timestamp has a difference of
>> 213.98296702 seconds. Is the command I executed wrong?
> 
> I don't understand what's your meaning "a difference of 213.98296702
> seconds".
> 
> But let me give an explaination with your below examples.  You could
> the command "perf script" outputs the timestamp 314938.859071370 which
> is the kernel's timestamp, if using the command "perf script -D", it
> outputs the value 31515284203839 which is the Arch timer's raw counter
> value.
> 
> In theory, the arch timer's counter is enabled at the very early
> time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
> the kernel's timestamp, it should calibrate the timestamp and reduce
> the offset prior to the kernel's booting.  I think this is the reason
> why you observed 213.98296702 seconds difference (if compared with
> your own patch?)
> 
> If still see any issue, please let me know.  Thanks a lot for the
> testing!
> 
Thanks for the very detailed explanation.
To keep the correct relative time sequence between events in SPE and 
other events, we should use kernel timestamp instead of arch time. 
Therefore, we need to calibrate the time. Is this correct?

Thanks,
Jihong.
> Leo
> 
>> |symbol_address|perf script| perf script -D|
>> |ffffb7ee2a20e100|314938.859071370|31515284203839|
>> |ffffb7ee29f360e0|314938.859753820|31515284272084|
>> |fffe85dd87e0|314938.859820430|31515284278745|
>> |fffe85dd7a28|314938.859941110|31515284290813|
>> |fffe85dd7a28|314938.859948890|31515284291591|
>> |fffe85dc8f58|314938.859953610|31515284292063|
> .
> 

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-28  6:30         ` Yang Jihong
  0 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-28  6:30 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 12:07, Leo Yan wrote:
> On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
> 
> [...]
> 
>> The timestamp does not match. Each timestamp has a difference of
>> 213.98296702 seconds. Is the command I executed wrong?
> 
> I don't understand what's your meaning "a difference of 213.98296702
> seconds".
> 
> But let me give an explaination with your below examples.  You could
> the command "perf script" outputs the timestamp 314938.859071370 which
> is the kernel's timestamp, if using the command "perf script -D", it
> outputs the value 31515284203839 which is the Arch timer's raw counter
> value.
> 
> In theory, the arch timer's counter is enabled at the very early
> time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
> the kernel's timestamp, it should calibrate the timestamp and reduce
> the offset prior to the kernel's booting.  I think this is the reason
> why you observed 213.98296702 seconds difference (if compared with
> your own patch?)
> 
> If still see any issue, please let me know.  Thanks a lot for the
> testing!
> 
Thanks for the very detailed explanation.
To keep the correct relative time sequence between events in SPE and 
other events, we should use kernel timestamp instead of arch time. 
Therefore, we need to calibrate the time. Is this correct?

Thanks,
Jihong.
> Leo
> 
>> |symbol_address|perf script| perf script -D|
>> |ffffb7ee2a20e100|314938.859071370|31515284203839|
>> |ffffb7ee29f360e0|314938.859753820|31515284272084|
>> |fffe85dd87e0|314938.859820430|31515284278745|
>> |fffe85dd7a28|314938.859941110|31515284290813|
>> |fffe85dd7a28|314938.859948890|31515284291591|
>> |fffe85dc8f58|314938.859953610|31515284292063|
> .
> 

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-28  6:30         ` Yang Jihong
@ 2021-06-28  7:29           ` Leo Yan
  -1 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  7:29 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

On Mon, Jun 28, 2021 at 02:30:56PM +0800, Yang Jihong wrote:
> Hello Leo,
> 
> On 2021/6/28 12:07, Leo Yan wrote:
> > On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
> > 
> > [...]
> > 
> > > The timestamp does not match. Each timestamp has a difference of
> > > 213.98296702 seconds. Is the command I executed wrong?
> > 
> > I don't understand what's your meaning "a difference of 213.98296702
> > seconds".
> > 
> > But let me give an explaination with your below examples.  You could
> > the command "perf script" outputs the timestamp 314938.859071370 which
> > is the kernel's timestamp, if using the command "perf script -D", it
> > outputs the value 31515284203839 which is the Arch timer's raw counter
> > value.
> > 
> > In theory, the arch timer's counter is enabled at the very early
> > time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
> > the kernel's timestamp, it should calibrate the timestamp and reduce
> > the offset prior to the kernel's booting.  I think this is the reason
> > why you observed 213.98296702 seconds difference (if compared with
> > your own patch?)
> > 
> > If still see any issue, please let me know.  Thanks a lot for the
> > testing!
> > 
> Thanks for the very detailed explanation.
> To keep the correct relative time sequence between events in SPE and other
> events, we should use kernel timestamp instead of arch time. Therefore, we
> need to calibrate the time. Is this correct?

Yes, correct!

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-28  7:29           ` Leo Yan
  0 siblings, 0 replies; 14+ messages in thread
From: Leo Yan @ 2021-06-28  7:29 UTC (permalink / raw)
  To: Yang Jihong
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

On Mon, Jun 28, 2021 at 02:30:56PM +0800, Yang Jihong wrote:
> Hello Leo,
> 
> On 2021/6/28 12:07, Leo Yan wrote:
> > On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
> > 
> > [...]
> > 
> > > The timestamp does not match. Each timestamp has a difference of
> > > 213.98296702 seconds. Is the command I executed wrong?
> > 
> > I don't understand what's your meaning "a difference of 213.98296702
> > seconds".
> > 
> > But let me give an explaination with your below examples.  You could
> > the command "perf script" outputs the timestamp 314938.859071370 which
> > is the kernel's timestamp, if using the command "perf script -D", it
> > outputs the value 31515284203839 which is the Arch timer's raw counter
> > value.
> > 
> > In theory, the arch timer's counter is enabled at the very early
> > time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
> > the kernel's timestamp, it should calibrate the timestamp and reduce
> > the offset prior to the kernel's booting.  I think this is the reason
> > why you observed 213.98296702 seconds difference (if compared with
> > your own patch?)
> > 
> > If still see any issue, please let me know.  Thanks a lot for the
> > testing!
> > 
> Thanks for the very detailed explanation.
> To keep the correct relative time sequence between events in SPE and other
> events, we should use kernel timestamp instead of arch time. Therefore, we
> need to calibrate the time. Is this correct?

Yes, correct!

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
  2021-06-28  7:29           ` Leo Yan
@ 2021-06-29  0:53             ` Yang Jihong
  -1 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-29  0:53 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 15:29, Leo Yan wrote:
> On Mon, Jun 28, 2021 at 02:30:56PM +0800, Yang Jihong wrote:
>> Hello Leo,
>>
>> On 2021/6/28 12:07, Leo Yan wrote:
>>> On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
>>>
>>> [...]
>>>
>>>> The timestamp does not match. Each timestamp has a difference of
>>>> 213.98296702 seconds. Is the command I executed wrong?
>>>
>>> I don't understand what's your meaning "a difference of 213.98296702
>>> seconds".
>>>
>>> But let me give an explaination with your below examples.  You could
>>> the command "perf script" outputs the timestamp 314938.859071370 which
>>> is the kernel's timestamp, if using the command "perf script -D", it
>>> outputs the value 31515284203839 which is the Arch timer's raw counter
>>> value.
>>>
>>> In theory, the arch timer's counter is enabled at the very early
>>> time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
>>> the kernel's timestamp, it should calibrate the timestamp and reduce
>>> the offset prior to the kernel's booting.  I think this is the reason
>>> why you observed 213.98296702 seconds difference (if compared with
>>> your own patch?)
>>>
>>> If still see any issue, please let me know.  Thanks a lot for the
>>> testing!
>>>
>> Thanks for the very detailed explanation.
>> To keep the correct relative time sequence between events in SPE and other
>> events, we should use kernel timestamp instead of arch time. Therefore, we
>> need to calibrate the time. Is this correct?
> 
> Yes, correct!
I see. Thank you for your answer.:)

Jihong
> .
> 

^ permalink raw reply	[flat|nested] 14+ messages in thread

* Re: [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script
@ 2021-06-29  0:53             ` Yang Jihong
  0 siblings, 0 replies; 14+ messages in thread
From: Yang Jihong @ 2021-06-29  0:53 UTC (permalink / raw)
  To: Leo Yan
  Cc: john.garry, will, mathieu.poirier, peterz, mingo, acme,
	mark.rutland, alexander.shishkin, jolsa, namhyung, james.clark,
	andre.przywara, linux-arm-kernel, linux-perf-users, linux-kernel

Hello Leo,

On 2021/6/28 15:29, Leo Yan wrote:
> On Mon, Jun 28, 2021 at 02:30:56PM +0800, Yang Jihong wrote:
>> Hello Leo,
>>
>> On 2021/6/28 12:07, Leo Yan wrote:
>>> On Mon, Jun 28, 2021 at 11:45:07AM +0800, Yang Jihong wrote:
>>>
>>> [...]
>>>
>>>> The timestamp does not match. Each timestamp has a difference of
>>>> 213.98296702 seconds. Is the command I executed wrong?
>>>
>>> I don't understand what's your meaning "a difference of 213.98296702
>>> seconds".
>>>
>>> But let me give an explaination with your below examples.  You could
>>> the command "perf script" outputs the timestamp 314938.859071370 which
>>> is the kernel's timestamp, if using the command "perf script -D", it
>>> outputs the value 31515284203839 which is the Arch timer's raw counter
>>> value.
>>>
>>> In theory, the arch timer's counter is enabled at the very early
>>> time before kernel's booting (e.g. bootloaders, UEFI, etc...).  So for
>>> the kernel's timestamp, it should calibrate the timestamp and reduce
>>> the offset prior to the kernel's booting.  I think this is the reason
>>> why you observed 213.98296702 seconds difference (if compared with
>>> your own patch?)
>>>
>>> If still see any issue, please let me know.  Thanks a lot for the
>>> testing!
>>>
>> Thanks for the very detailed explanation.
>> To keep the correct relative time sequence between events in SPE and other
>> events, we should use kernel timestamp instead of arch time. Therefore, we
>> need to calibrate the time. Is this correct?
> 
> Yes, correct!
I see. Thank you for your answer.:)

Jihong
> .
> 

_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

^ permalink raw reply	[flat|nested] 14+ messages in thread

end of thread, other threads:[~2021-06-29  0:56 UTC | newest]

Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-06-26  3:21 [PATCH] perf arm-spe: Fix incorrect sample timestamp in perf script Yang Jihong
2021-06-26  3:21 ` Yang Jihong
2021-06-28  1:49 ` Leo Yan
2021-06-28  1:49   ` Leo Yan
2021-06-28  3:45   ` Yang Jihong
2021-06-28  3:45     ` Yang Jihong
2021-06-28  4:07     ` Leo Yan
2021-06-28  4:07       ` Leo Yan
2021-06-28  6:30       ` Yang Jihong
2021-06-28  6:30         ` Yang Jihong
2021-06-28  7:29         ` Leo Yan
2021-06-28  7:29           ` Leo Yan
2021-06-29  0:53           ` Yang Jihong
2021-06-29  0:53             ` Yang Jihong

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.