Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
From:   Nadav Amit <nadav.amit@gmail.com>
Content-Type: text/plain;
        charset=us-ascii
Content-Transfer-Encoding: quoted-printable
Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3731.500.231\))
Subject: Problem running perf using Intel-PT with snapshots
Message-Id: <6325A777-706E-462A-8931-59E16D4E37A5@gmail.com>
Date:   Wed, 17 May 2023 21:26:28 -0700
Cc:     LKML <linux-kernel@vger.kernel.org>,
        Peter Zijlstra <peterz@infradead.org>,
        Adrian Hunter <adrian.hunter@intel.com>,
        Namhyung Kim <namhyung@kernel.org>
To:     linux-perf-users@vger.kernel.org
Precedence: bulk

Hello perf masters,

I am running perf with Intel PT with snapshot mode and the result makes =
no
sense. I tried to figure it out myself but failed.

Excluding the first data file, the rest seem messed up in various ways. =
The
only thing that repeatedly shows are calls to __fentry__+0x0. I would =
note
that ftrace is not enabled, and I turned off mitigations as I thought it
might somehow be related, but it did not help.

Here is an example for execution and output. In between I ran
`kill -SIGUSR2 [perf-pid]`. To dump some traces.

Any ideas what it might be?

Thanks,
Nadav

--

$ perf record -e intel_pt/noretcomp=3D1/k --kcore --timestamp -a =
--snapshot=3De262144 --switch-output -m,64
[ perf record: dump data: Woken up 2 times ]
[ perf record: Dump perf.data.2023051804132358 ]
[ perf record: dump data: Woken up 1 times ]
[ perf record: Dump perf.data.2023051804132537 ]
[ perf record: dump data: Woken up 1 times ]
[ perf record: Dump perf.data.2023051804132689 ]
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Dump perf.data.2023051804132829 ]
[ perf record: Captured and wrote 14.330 MB perf.data.<timestamp> ]


$ sudo perf script -i  perf.data.2023051804004293

             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff81096125 ept_page_fault+0x3f5 ([kernel.kallsyms]) =
=3D> ffffffff8108f1d0 kvm_mmu_get_child_sp+0x0 ([kernel.kallsyms])
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff8108f1d0 kvm_mmu_get_child_sp+0x0 =
([kernel.kallsyms]) =3D> ffffffff81131190 __fentry__+0x0 =
([kernel.kallsyms])
 instruction trace error type 1 time 78.287624064 cpu 6 pid -1 tid -1 ip =
0xffffffff8101c4fd code 6: Trace doesn't match instruction
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff81296e14 futex_unlock_pi+0x184 ([kernel.kallsyms]) =
=3D> ffffffff81294120 futex_cmpxchg_value_locked+0x0 ([kernel.kallsyms])
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff81294124 futex_cmpxchg_value_locked+0x4 =
([kernel.kallsyms]) =3D> ffffffff81131190 __fentry__+0x0 =
([kernel.kallsyms])
 instruction trace error type 1 time 78.287624104 cpu 6 pid -1 tid -1 ip =
0xffffffff824c7a44 code 6: Trace doesn't match instruction
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff812909c4 __tick_broadcast_oneshot_control+0x1d4 =
([kernel.kallsyms]) =3D> ffffffff8128f720 tick_broadcast_set_event+0x0 =
([kernel.kallsyms])
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff8128f720 tick_broadcast_set_event+0x0 =
([kernel.kallsyms]) =3D> ffffffff81131190 __fentry__+0x0 =
([kernel.kallsyms])
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff81296e8e futex_unlock_pi+0x1fe ([kernel.kallsyms]) =
=3D> ffffffff812961d0 put_pi_state+0x0 ([kernel.kallsyms])
             :-1    -1 [006]    78.287624:          1             =
branches:k:  ffffffff812961d4 put_pi_state+0x4 ([kernel.kallsyms]) =3D> =
ffffffff81131190 __fentry__+0x0 ([kernel.kallsyms])
 instruction trace error type 1 time 78.287624208 cpu 6 pid -1 tid -1 ip =
0xffffffff824c7a44 code 6: Trace doesn't match instruction