ASoC: SOF: add trace event support by bardliao · Pull Request #159 · thesofproject/linux

bardliao · 2018-09-25T09:49:31Z

Add trace event to show the trace log from firmware.

We call the trace event function when host_offset is updated since it indicates firmware flush the dma buffer.

lgirdwood · 2018-09-25T10:36:21Z

@@ -0,0 +1,138 @@
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM intel-sof


rename to sof.h

lgirdwood · 2018-09-25T10:36:38Z

+ * legitimate C variable. It is not exported to user space.
+ */
+#undef TRACE_SYSTEM_VAR
+#define TRACE_SYSTEM_VAR intel_sof


rename to sof

lgirdwood · 2018-09-25T10:37:16Z

+#undef TRACE_SYSTEM_VAR
+#define TRACE_SYSTEM_VAR intel_sof
+
+#if !defined(_TRACE_INTEL_SOF_H) || defined(TRACE_HEADER_MULTI_READ)


in general remove "intel" from this file and use sof instead.

lgirdwood · 2018-09-25T10:46:50Z

+#include <linux/tracepoint.h>
+
+/* should be the same as rmbox */
+#define TRACE_CLASS_IRQ (1 << 24)


We cant decode this here, it must be decoded in userspace. i.e. we should emit a timestamp and then ASCII HEX output of the data (unless it's common data among all trace). Please also see the lates tarce updates on master branch for ABI update.

@lgirdwood So the output data will look like "14ff3e 19259f", right? The first element is the timestamp and the second one is the data. Also we need an user space tool to parse these output data? Could you show me the commit id, please. I will look at it.

@bardliao rmbox does the parsing. its part of the soft repo

lgirdwood · 2018-09-25T10:48:19Z

 struct sof_ipc_dma_trace_posn *posn)
 {
 	if (sdev->dtrace_is_enabled && sdev->host_offset != posn->host_offset) {
+ snd_sof_trace_read_buf(sdev,


I would also expect code here to remove the debugFS trace file.

@lgirdwood Should we remove it after all trace_event function is ready? I.e. include the user space tool. Or can we let trace event and debugFS exist simultaneously for a while to make sure we didn't miss anything in trace event?

lets remove in the same PR, but have a new PR for soft that has the updates to decode the trace data.

Add trace event to show trace log from firmware. Signed-off-by: Bard liao <bard.liao@intel.com>

plbossart · 2018-10-22T20:39:53Z

is this PR still relevant? It's been stale for 27 days, either it's needed or it needs to be closed.

bardliao · 2018-10-23T00:53:04Z

@plbossart I think we can close it ATM.

…s/device_drivers/update_extra_exercises_testing Documentation: labs: device_drivers: Update extra exercises testing

We should check null before do x25_neigh_put in x25_disconnect, otherwise may cause null-ptr-deref like this: #include <sys/socket.h> #include <linux/x25.h> int main() { int sck_x25; sck_x25 = socket(AF_X25, SOCK_SEQPACKET, 0); close(sck_x25); return 0; } BUG: kernel NULL pointer dereference, address: 00000000000000d8 CPU: 0 PID: 4817 Comm: t2 Not tainted 5.7.0-rc3+ thesofproject#159 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.9.3- RIP: 0010:x25_disconnect+0x91/0xe0 Call Trace: x25_release+0x18a/0x1b0 __sock_release+0x3d/0xc0 sock_close+0x13/0x20 __fput+0x107/0x270 ____fput+0x9/0x10 task_work_run+0x6d/0xb0 exit_to_usermode_loop+0x102/0x110 do_syscall_64+0x23c/0x260 entry_SYSCALL_64_after_hwframe+0x49/0xb3 Reported-by: syzbot+6db548b615e5aeefdce2@syzkaller.appspotmail.com Fixes: 4becb7e ("net/x25: Fix x25_neigh refcnt leak when x25 disconnect") Signed-off-by: YueHaibing <yuehaibing@huawei.com> Signed-off-by: David S. Miller <davem@davemloft.net>

commit 8999dc8 upstream. We should check null before do x25_neigh_put in x25_disconnect, otherwise may cause null-ptr-deref like this: #include <sys/socket.h> #include <linux/x25.h> int main() { int sck_x25; sck_x25 = socket(AF_X25, SOCK_SEQPACKET, 0); close(sck_x25); return 0; } BUG: kernel NULL pointer dereference, address: 00000000000000d8 CPU: 0 PID: 4817 Comm: t2 Not tainted 5.7.0-rc3+ thesofproject#159 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.9.3- RIP: 0010:x25_disconnect+0x91/0xe0 Call Trace: x25_release+0x18a/0x1b0 __sock_release+0x3d/0xc0 sock_close+0x13/0x20 __fput+0x107/0x270 ____fput+0x9/0x10 task_work_run+0x6d/0xb0 exit_to_usermode_loop+0x102/0x110 do_syscall_64+0x23c/0x260 entry_SYSCALL_64_after_hwframe+0x49/0xb3 Reported-by: syzbot+6db548b615e5aeefdce2@syzkaller.appspotmail.com Fixes: 4becb7e ("net/x25: Fix x25_neigh refcnt leak when x25 disconnect") Signed-off-by: YueHaibing <yuehaibing@huawei.com> Signed-off-by: David S. Miller <davem@davemloft.net> Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

Move creation of `struct file_operations` to a const function.

Floating point instructions in userspace can crash some arm kernels built with clang/LLD 17.0.6: BUG: unsupported FP instruction in kernel mode FPEXC == 0xc0000780 Internal error: Oops - undefined instruction: 0 [thesofproject#1] ARM CPU: 0 PID: 196 Comm: vfp-reproducer Not tainted 6.10.0 thesofproject#1 Hardware name: BCM2835 PC is at vfp_support_entry+0xc8/0x2cc LR is at do_undefinstr+0xa8/0x250 pc : [<c0101d50>] lr : [<c010a80c>] psr: a0000013 sp : dc8d1f68 ip : 60000013 fp : bedea19c r10: ec532b17 r9 : 00000010 r8 : 0044766c r7 : c0000780 r6 : ec532b17 r5 : c1c13800 r4 : dc8d1fb0 r3 : c10072c4 r2 : c0101c88 r1 : ec532b17 r0 : 0044766c Flags: NzCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none Control: 00c5387d Table: 0251c008 DAC: 00000051 Register r0 information: non-paged memory Register r1 information: vmalloc memory Register r2 information: non-slab/vmalloc memory Register r3 information: non-slab/vmalloc memory Register r4 information: 2-page vmalloc region Register r5 information: slab kmalloc-cg-2k Register r6 information: vmalloc memory Register r7 information: non-slab/vmalloc memory Register r8 information: non-paged memory Register r9 information: zero-size pointer Register r10 information: vmalloc memory Register r11 information: non-paged memory Register r12 information: non-paged memory Process vfp-reproducer (pid: 196, stack limit = 0x61aaaf8b) Stack: (0xdc8d1f68 to 0xdc8d2000) 1f60: 0000081f b6f69300 0000000f c10073f4 c10072c4 dc8d1fb0 1f80: ec532b17 0c532b17 0044766c b6f9ccd8 00000000 c010a80c 00447670 60000010 1fa0: ffffffff c1c13800 00c5387d c0100f10 b6f68af8 00448fc0 00000000 bedea188 1fc0: bedea314 00000001 00448ebc b6f9d000 00447608 b6f9ccd8 00000000 bedea19c 1fe0: bede9198 bedea188 b6e1061c 0044766c 60000010 ffffffff 00000000 00000000 Call trace: [<c0101d50>] (vfp_support_entry) from [<c010a80c>] (do_undefinstr+0xa8/0x250) [<c010a80c>] (do_undefinstr) from [<c0100f10>] (__und_usr+0x70/0x80) Exception stack(0xdc8d1fb0 to 0xdc8d1ff8) 1fa0: b6f68af8 00448fc0 00000000 bedea188 1fc0: bedea314 00000001 00448ebc b6f9d000 00447608 b6f9ccd8 00000000 bedea19c 1fe0: bede9198 bedea188 b6e1061c 0044766c 60000010 ffffffff Code: 0a000061 e3877202 e594003c e3a0901 (eef16a10) ---[ end trace 0000000000000000 ]--- Kernel panic - not syncing: Fatal exception in interrupt ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]--- This is a minimal userspace reproducer on a Raspberry Pi Zero W: #include <stdio.h> #include <math.h> int main(void) { double v = 1.0; printf("%fn", NAN + *(volatile double *)&v); return 0; } Another way to consistently trigger the oops is: calvin@raspberry-pi-zero-w ~$ python -c "import json" The bug reproduces only when the kernel is built with DYNAMIC_DEBUG=n, because the pr_debug() calls act as barriers even when not activated. This is the output from the same kernel source built with the same compiler and DYNAMIC_DEBUG=y, where the userspace reproducer works as expected: VFP: bounce: trigger ec532b17 fpexc c0000780 VFP: emulate: INST=0xee377b06 SCR=0x00000000 VFP: bounce: trigger eef1fa10 fpexc c0000780 VFP: emulate: INST=0xeeb40b40 SCR=0x00000000 VFP: raising exceptions 30000000 calvin@raspberry-pi-zero-w ~$ ./vfp-reproducer nan Crudely grepping for vmsr/vmrs instructions in the otherwise nearly idential text for vfp_support_entry() makes the problem obvious: vmlinux.llvm.good [0xc0101cb8] <+48>: vmrs r7, fpexc vmlinux.llvm.good [0xc0101cd8] <+80>: vmsr fpexc, r0 vmlinux.llvm.good [0xc0101d20] <+152>: vmsr fpexc, r7 vmlinux.llvm.good [0xc0101d38] <+176>: vmrs r4, fpexc vmlinux.llvm.good [0xc0101d6c] <+228>: vmrs r0, fpscr vmlinux.llvm.good [0xc0101dc4] <+316>: vmsr fpexc, r0 vmlinux.llvm.good [0xc0101dc8] <+320>: vmrs r0, fpsid vmlinux.llvm.good [0xc0101dcc] <+324>: vmrs r6, fpscr vmlinux.llvm.good [0xc0101e10] <+392>: vmrs r10, fpinst vmlinux.llvm.good [0xc0101eb8] <+560>: vmrs r10, fpinst2 vmlinux.llvm.bad [0xc0101cb8] <+48>: vmrs r7, fpexc vmlinux.llvm.bad [0xc0101cd8] <+80>: vmsr fpexc, r0 vmlinux.llvm.bad [0xc0101d20] <+152>: vmsr fpexc, r7 vmlinux.llvm.bad [0xc0101d30] <+168>: vmrs r0, fpscr vmlinux.llvm.bad [0xc0101d50] <+200>: vmrs r6, fpscr <== BOOM! vmlinux.llvm.bad [0xc0101d6c] <+228>: vmsr fpexc, r0 vmlinux.llvm.bad [0xc0101d70] <+232>: vmrs r0, fpsid vmlinux.llvm.bad [0xc0101da4] <+284>: vmrs r10, fpinst vmlinux.llvm.bad [0xc0101df8] <+368>: vmrs r4, fpexc vmlinux.llvm.bad [0xc0101e5c] <+468>: vmrs r10, fpinst2 I think LLVM's reordering is valid as the code is currently written: the compiler doesn't know the instructions have side effects in hardware. Fix by using "asm volatile" in fmxr() and fmrx(), so they cannot be reordered with respect to each other. The original compiler now produces working kernels on my hardware with DYNAMIC_DEBUG=n. This is the relevant piece of the diff of the vfp_support_entry() text, from the original oopsing kernel to a working kernel with this patch: vmrs r0, fpscr tst r0, thesofproject#4096 bne 0xc0101d48 tst r0, #458752 beq 0xc0101ecc orr r7, r7, #536870912 ldr r0, [r4, #0x3c] mov r9, thesofproject#16 -vmrs r6, fpscr orr r9, r9, #251658240 add r0, r0, thesofproject#4 str r0, [r4, #0x3c] mvn r0, thesofproject#159 sub r0, r0, #-1207959552 and r0, r7, r0 vmsr fpexc, r0 vmrs r0, fpsid +vmrs r6, fpscr and r0, r0, #983040 cmp r0, #65536 bne 0xc0101d88 Fixes: 4708fb0 ("ARM: vfp: Reimplement VFP exception entry in C code") Signed-off-by: Calvin Owens <calvin@wbinvd.org> Signed-off-by: Russell King (Oracle) <rmk+kernel@armlinux.org.uk>

Lockdep thinks our seqcount_t usage is unsafe because the update path can be both from irq and worker context: [ ] ================================ [ ] WARNING: inconsistent lock state [ ] 6.10.3-v8-16k-numa thesofproject#159 Tainted: G WC [ ] -------------------------------- [ ] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. [ ] swapper/0/0 [HC1[1]:SC0[0]:HE0:SE1] takes: [ ] ffff80003d7c08d0 (&v3d_priv->stats[i].lock){?.+.}-{0:0}, at: v3d_irq+0xc8/0x660 [v3d] [ ] {HARDIRQ-ON-W} state was registered at: [ ] lock_acquire+0x1f8/0x328 [ ] v3d_job_start_stats.isra.0+0xd8/0x218 [v3d] [ ] v3d_bin_job_run+0x23c/0x388 [v3d] [ ] drm_sched_run_job_work+0x520/0x6d0 [gpu_sched] [ ] process_one_work+0x62c/0xb48 [ ] worker_thread+0x468/0x5b0 [ ] kthread+0x1c4/0x1e0 [ ] ret_from_fork+0x10/0x20 [ ] irq event stamp: 337094 [ ] hardirqs last enabled at (337093): [<ffffc0008144ce7c>] default_idle_call+0x11c/0x140 [ ] hardirqs last disabled at (337094): [<ffffc0008144a354>] el1_interrupt+0x24/0x58 [ ] softirqs last enabled at (337082): [<ffffc00080061d90>] handle_softirqs+0x4e0/0x538 [ ] softirqs last disabled at (337073): [<ffffc00080010364>] __do_softirq+0x1c/0x28 [ ] other info that might help us debug this: [ ] Possible unsafe locking scenario: [ ] CPU0 [ ] ---- [ ] lock(&v3d_priv->stats[i].lock); [ ] <Interrupt> [ ] lock(&v3d_priv->stats[i].lock); [ ] *** DEADLOCK *** [ ] no locks held by swapper/0/0. [ ] stack backtrace: [ ] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G WC 6.10.3-v8-16k-numa thesofproject#159 [ ] Hardware name: Raspberry Pi 5 Model B Rev 1.0 (DT) [ ] Call trace: [ ] dump_backtrace+0x170/0x1b8 [ ] show_stack+0x20/0x38 [ ] dump_stack_lvl+0xb4/0xd0 [ ] dump_stack+0x18/0x28 [ ] print_usage_bug+0x3cc/0x3f0 [ ] mark_lock+0x4d0/0x968 [ ] __lock_acquire+0x784/0x18c8 [ ] lock_acquire+0x1f8/0x328 [ ] v3d_job_update_stats+0xec/0x2e0 [v3d] [ ] v3d_irq+0xc8/0x660 [v3d] [ ] __handle_irq_event_percpu+0x1f8/0x488 [ ] handle_irq_event+0x88/0x128 [ ] handle_fasteoi_irq+0x298/0x408 [ ] generic_handle_domain_irq+0x50/0x78 But it is a false positive because all the queue-stats pairs have their own lock and jobs are also one at a time. Nevertheless we can appease lockdep by disabling local interrupts to make it see lock usage is consistent. Cc: Maíra Canal <mcanal@igalia.com> Fixes: 6abe93b ("drm/v3d: Fix race-condition between sysfs/fdinfo and interrupt handler") Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@igalia.com> Signed-off-by: Maíra Canal <mcanal@igalia.com> Link: https://patchwork.freedesktop.org/patch/msgid/20240813102505.80512-2-tursulin@igalia.com

bardliao requested review from lgirdwood and xiulipan September 25, 2018 09:49

lgirdwood requested changes Sep 25, 2018
View reviewed changes

ASoC: SOF: add trace event support
79e474c
Add trace event to show trace log from firmware. Signed-off-by: Bard liao <bard.liao@intel.com>

bardliao closed this Oct 23, 2018

paulstelian97 pushed a commit to paulstelian97/linux that referenced this pull request May 4, 2020
Merge pull requestthesofproject#159from valighita/documentation/lab…
aa67e2f
…s/device_drivers/update_extra_exercises_testing Documentation: labs: device_drivers: Update extra exercises testing

aiChaoSONG pushed a commit to aiChaoSONG/linux that referenced this pull request May 6, 2021
Merge pull requestthesofproject#159from wedsonaf/vtable
a629f05
Move creation of `struct file_operations` to a const function.

bardliao deleted the trace branch October 12, 2022 12:15

Navigation Menu

Uh oh!

ASoC: SOF: add trace event support - #159

ASoC: SOF: add trace event support#159
bardliao wants to merge 1 commit into
thesofproject:topic/sof-devfrom
bardliao:trace

bardliao commented Sep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

bardliaoSep 25, 2018

Uh oh!

ranj063Sep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

bardliaoSep 25, 2018

Uh oh!

lgirdwoodSep 25, 2018

Uh oh!

plbossart commented Oct 22, 2018

Uh oh!

bardliao commented Oct 23, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Uh oh!

Conversation

bardliao commented Sep 25, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

plbossart commented Oct 22, 2018

Uh oh!

bardliao commented Oct 23, 2018

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants