Verbose tracing breaks new logger

Enabling TRACEV in the firmware causes the logger to output absolutely nothing. Firmware appears to operating just fine according to dmesg otherwise.

Observed at:
Kernel: 1 commit off 93853cbf8f8252ec04dd8b70328cb004d1d4566a to patch glk dialog max codec for 4.18
SOF: ccaff5c
SOFT: 2d7a933 (dirty, but only with regards to some m4 files)

I think this might be related to a larger issue in the system due to something like memory corruption as I'm still experiencing trace issues with a dirty build. But I can fix them by adding a trace in weird spot in the code (host_copy_int) (tested 5X to be sure adding and removing the trace was fixing the logging.) Without the additional trace I only get the first 3 traces out of the dsp even though according to dmesg there is plenty of communication going on. If I add the trace I get plenty of pages worth of traces.

If you want to get an idea of where I am, I am checked out on master in my own sof repo (inital new component in the branch) cujomalainey@71d75ae
As you can see all I have is the skeleton on a new component, not really much going on. Not sure what could cause this behaviour in my code. The TRACEV bug still exists though on a clean repo.

@keqiaozhang

@keqiaozhang Could you try to reproduce this issue?

@mengdonglin

@mengdonglin
We can reproduce this issue with logger. Even IPC error, there's still nothing in memory window.
Only when firmware panic, logger will shows some trace log.

With respect to my second comment, I no longer am seeing tracing fail just from my own code with the code I pulled in from last night, but if its a memory corruption issue it could have been the memory map readjusting. The TRACEV bug is still reproducible.

@akloniex

@akloniex commented "logger tool by default (without additional parameters) reads /sys/kernel/debug/sof/etrace file which might be empty, yielding no output

Just as with rmbox earlier, -t parameter changes behaviour to read /sys/kernel/debug/sof/trace which contains all traces."

@keqiaozhang Can you still the issue with -t parameter?

@cujomalainey

@cujomalainey @mengdonglin @keqiaozhang
Enabling TRACEV and rebuilding FW causes .ldc file to regenerate. Please make sure that it's the dictionary file that you feed logger with, through -l paramter.

Also make sure that input file is correctly specified.
With no additional parameters, logger defaults to /sys/kernel/debug/sof/etrace,
with -p logger reads from stdin, (e.g. piping from other process),
with -t it's /sys/kernel/debug/sof/trace,
with -i you may specify file to read explicitly (e.g. for offline purposes).

@akloniex

@akloniex @mengdonglin
Confirmed that logger works well with -t parameter.
Command: sudo logger -l sof-apl.ldc -t

@akloniex

@akloniex I am using the new ldc on tracev enabling and I forgot to mention all of these trace failures are with the -t parameter

@keqiaozhang

@keqiaozhang could you provide the commits of 3 repo that logger can work with -t parameter on your Yorp? So we can align test result with @cujomalainey and @akloniex

I re-tested it with top sof-master and enabled tracev, logger works well with -t parameter.
Here are my test steps:

Enable tracev(trace.h):
-#define TRACEV 0
+#define TRACEV 1
make sof and copy the new sof-apl.ldc and sof-apl.ri to Yorp
make soft and copy the new topology and logger to Yorp
reboot Yorp
run audio playback: aplay -Dhw:0,5 audio.wav
sudo logger -l sof-apl.ldc -t
BTW, without step 4, there's no trace output.

kernel-cros-sof-v4.14-rebase: 274bfc6
sof-master: 1024e94
soft-master: c0a881a

@cujomalainey

@cujomalainey good to know it works now.
Are you run topic/sof-dev directly on chrome? or Ubuntu?

@keyonjie

@keyonjie I'm running it on chrome, but I have the bxt_da7219_max####a driver patched for glk. You can see the modification here cujomalainey/linux@6000068

@cujomalainey

@cujomalainey thanks, I am thinking if it is possible to run thesofproject/linux topic/sof-dev directly on chrome book(thesofproject/linux topic/cros-sof-v4.14-rebase works for that).

We just need that driver patched and we can run sof-dev no problem. I can send a pull request if we want to do that. It is slightly buggy though. Left channel on speaker only works for about 500ms before cutting out but it appears to be a UCM issue that is setting the left volume to 0 and headset isnt working currently.

If I could work off sof-dev without constantly rebasing patches that would make debugging and my filter development go much faster.

@cujomalainey

@cujomalainey yes please send a PR. Fwiw, I think it will be tricky to run from sof-dev atm since it's a couple of versions newer then the Chrome kernel, @ranj063 does test and rebase patches from sof-dev onto the Chrome kernel. Lets discuss next week as @ranj063 will also be at ELCE.

@lgirdwood

@lgirdwood sounds good. I'll clean up my patch I have locally and send it off soon. The 4.18 kernel on yorp boots and is debugable, it just takes the UI forever to get going. But if you are using ssh it's completely functional. Its how I have been working on building my filter additions since the effect topology commits are not in the cros-rebase branch last time I check

This issue cannot be reproduced with kernel branch topic/sof-dev, on APL UP2 platfrom.

0      2     HOST  56308262.447917         2.395833               host.c:650        cpy
0      2     HOST  56308265.312500         2.864583            hda-dma.c:229        GwU
0      2     HOST  56308268.802083         3.489583               host.c:145        irq
0      2   BUFFER  56308272.291667         3.489583             buffer.c:145        pro
0      2  unknown  56308274.843750         2.552083             buffer.c:146        value 25165824
0      2  unknown  56308277.291667         2.447917             buffer.c:147        value 131456
0      2  unknown  56308279.635417         2.343750             buffer.c:148        value 12583104
0      2    POWER  56308282.552083         2.916667         pm_runtime.c:78         put
0      2     PIPE  56308317.135417        34.583332           pipeline.c:914        CD+
0      2   VOLUME  56308319.739583         2.604167             volume.c:445        cpy
0      2   BUFFER  56308350.781250        31.041666             buffer.c:145        pro
0      2  unknown  56308353.281250         2.500000             buffer.c:146        value 50331648
0      2  unknown  56308355.729167         2.447917             buffer.c:147        value 197376
0      2  unknown  56308358.072917         2.343750             buffer.c:148        value 25166208

STEP:
1.Enable tracev(trace.h):
-#define TRACEV 0
+#define TRACEV 1
2.re-make sof、soft、logger and replace them on UP2
3.reboot
4.aplay -Dhw:0,0 audio.wav
5.sudo sof-logger -l sof-apl.ldc -t -o logger.log

Test env:
hardware version: UP2
sof-master: b793f0c
soft-master: c9a4c87
kernel sof-dev: fe8404a
tplg: sof-apl-pcm512x.tplg

Please follow up in kernel repo thesofproject/linux#214

Navigation Menu

Repository navigation

Verbose tracing breaks new logger #473

8 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Verbose tracing breaks new logger #473

Description

Activity

cujomalainey commented on Oct 9, 2018

mengdonglin commented on Oct 10, 2018

keqiaozhang commented on Oct 10, 2018

cujomalainey commented on Oct 10, 2018

mengdonglin commented on Oct 11, 2018

akloniex commented on Oct 11, 2018

keqiaozhang commented on Oct 11, 2018

cujomalainey commented on Oct 11, 2018

mengdonglin commented on Oct 12, 2018

keqiaozhang commented on Oct 15, 2018

8 remaining items

keyonjie commented on Oct 19, 2018

cujomalainey commented on Oct 19, 2018

keyonjie commented on Oct 19, 2018

cujomalainey commented on Oct 19, 2018

lgirdwood commented on Oct 19, 2018

cujomalainey commented on Oct 19, 2018

Jiangxinx commented on Oct 25, 2018

mengdonglin commented on Oct 25, 2018

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions