Windows users building with MSYS2 need to provide additional include
path to the POSIX standard headers to build sof-logger with GCC.
Added this include directory when environmental variable
MSYS_INSTALL_DIR is set.
Signed-off-by: Andrey Borisovich <andrey.borisovich@intel.com>
Newer gcc compilers 9.1+ issue a W-char-subscripts warning when argument
type passed to isspace is not explicitly int. Added cast to int.
Signed-off-by: Andrey Borisovich <andrey.borisovich@intel.com>
Sample output:
logger ABI Version is 5:3:0
ldc_file ABI Version is 5:3:0
ldc_file src checksum 0x07d4f1ad
Loaded FW expects chksum 0x07d4f1ad <=== NEW!
Components uuid dictionary size: 2400 bytes
Components uuid base address: 0x1fffa000
...
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Since commit 901f991eee ("logger: Validate by src_hash instead of abi
version from fw_ready") the dictionary checksum has become the most
important information.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Fixes commit 901f991eee ("logger: Validate by src_hash instead of abi
version from fw_ready") that changed the feature without updating the
name.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Rename asprintf and vasprintf into log_asprintf and log_vasprintf as the
names could clash with the standard libc ones. These functions are there
originally done because of windows compatibility, but the naming was not
thought through carefully.
Signed-off-by: Jaska Uimonen <jaska.uimonen@intel.com>
Set the error code in "ret" and only exit the loop so we don't lose the
optional warnings at the end of the loop.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
gcc does not know that we already filtered unreasonable precision
values.
Increase the size of the temporary string from 32 bytes to 64
bytes. We're running on the host, memory is cheap.
Fixes commit d6f6a456c1 ("logger: fix column and header alignments")
For some reason CMake uses -Werror=format-truncation only in Release
mode.
Avoids the following warning:
```
sof/tools/logger/convert.c: In function ‘fetch_entry’:
sof/tools/logger/convert.c:514:27: error: ‘%d’ directive output may be
truncated writing between 1 and 10 bytes into a region of size
between 0 and 18 [-Werror=format-truncation=]
514 | "%%s[%%%d.%df] (%%%d.%df)%%s ",
| ^~
sof/tools/logger/convert.c:514:6: note: directive argument in the
range [0, 2147483647]
514 | "%%s[%%%d.%df] (%%%d.%df)%%s ",
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
In file included from /usr/include/stdio.h:867,
from sof/tools/logger/convert.h:13,
from sof/tools/logger/convert.c:21:
/usr/include/x86_64-linux-gnu/bits/stdio2.h:67:10:
note: ‘__builtin___snprintf_chk’ output between 21 and 59 bytes into
a destination of size 32
67 | return __builtin___snprintf_chk (__s, __n, __USE_FORTIFY_LEVEL - 1,
| ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
68 | __bos (__s), __fmt, __va_arg_pack ());
| ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
cc1: all warnings being treated as errors
```
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Failing _in the middle of one log entry_ should really not be treated as
a normal event. The purpose of a logging tool is to find issues, not
hide them.
Don't abort on EOF because of valid use cases like device suspend but
don't do it quietly.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Add a few missing log_err().
Remove calls to ferror() because:
- its return value is a meaningless "non-zero" boolean,
- we don't really care whether the dictionary file is in an error state
or not; an unexpected end of dictionary file is just as bad.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
In general the DMA trace runs until interrupted but there are cases
where it can exit "normally": when reading from a file or stdin, when
some error happens,....
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Every log file should have a date.
ktime can be related to the TIMESTAMP column. It is especially useful to
spot logs delayed or stuck.
Some logs use ktime while others use a date and it can be sometimes
difficult to connect them with one another. This header can help.
Before:
TIMESTAMP (us) DELTA C# COMPONENT CONTENT
[ 5120116529] ( 0) c0 dma-trace ERROR FW ABI 0x3012001 ...
After:
TIMESTAMP (us) DELTA C# COMPONENT \
CONTENT ktime=5132.663s @ 2021-04-27 14:36:09 -0700 PDT
[ 5120116529] ( 0) c0 dma-trace ERROR FW ABI 0x3012001 ...
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Learned the hard way. Will help refactoring or duplicated
"reverse-engineering" effort.
Zero code change, pure comments: no functional change.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Increase default width from 10 to 12 to stop common misalignment,
especially in relative mode.
New timestamp_width() function to avoid duplication and
divergence.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
This makes the display of the mailbox ring buffer log much less
confusing. It should not happen with the DMA trace but will behave the
same in case something goes wrong.
Before this commit the only clue that wrapping had happened was a NaN in
the delta column (instead of the negative value).
The "other?" is because the start of the mailbox is sometimes corrupted,
or the timestamp goes sometimes back at boot for no obvious reason. In
other words this new separator is useful to highlight bugs too.
Absolute mode -e 0 with this commit:
TIMESTAMP DELTA C# COMPONENT LOCATION
[22598174808] ( 11) c0 ipc src/ipc/....
[22598174824] ( 15) c0 ipc src/ipc/....
[22598443257] ( 268433) c0 dma-trace src/trace/....
[22598443271] ( 14) c0 dma-trace src/trace/....
[22598443286] ( 14) c0 dma-trace src/trace/....
[22598943257] ( 499971) c0 dma-trace src/trace/....
--- negative DELTA: wrap, IPC_TRACE, other? ---
[22430943257] ( 0) c0 dma-trace src/trace/....
[22530943257] ( 100000000) c0 dma-trace src/trace/....
[22542943257] ( 12000000) c0 dma-trace src/trace/....
[22542943271] ( 14) c0 dma-trace src/trace/....
[22542943285] ( 14) c0 dma-trace src/trace/....
Relative mode -e 1 with this commit:
TIMESTAMP DELTA C# COMPONENT LOCATION
[ 3080783.6] ( 11.4) c0 ipc src/ipc/....
[ 3080799.1] ( 15.5) c0 ipc src/ipc/....
[ 3349232.5] ( 268433.4) c0 dma-trace src/trace/....
[ 3349246.8] ( 14.3) c0 dma-trace src/trace/....
[ 3349261.2] ( 14.4) c0 dma-trace src/trace/....
[ 3849232.4] ( 499971.2) c0 dma-trace src/trace/....
--- negative DELTA: wrap, IPC_TRACE, other? ---
[22430943257.0] ( 0.0) c0 dma-trace src/trace/....
[100000000.0] (100000000.0) c0 dma-trace src/trace/....
[111999999.5] ( 12000000.0) c0 dma-trace src/trace/....
[112000013.9] ( 14.4) c0 dma-trace src/trace/....
[112000028.2] ( 14.3) c0 dma-trace src/trace/....
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Add missing "break" so the -e option stops spilling on the -f precision
option. Fixes commit 53ce8b9d9f ("logger: new relative timestamps
option, relative to first entry seen"). Since that commit the -e option
was wrongly assigned to the precision too.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Useful error messages when forgetting to use "sudo" or to change
permissions in udev.
Some places were printing the errno decimal. Others no specific error
at all.
Sample outputs:
error: Unable to open version file /sys/kernel/debug/sof/fw_version: \
Permission denied
error: Unable to open version file /sys/kernel/debug/sof/fw_version: \
No such file or directory
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
There is one extra level of identation for all the
code inside format_file_name function.
Remove that to enhance readability.
Signed-off-by: Daniel Baluta <daniel.baluta@nxp.com>
To allow proper display of suppressed message info traces, %pQ specifier
was chosen to decode pointers to log entries.
Helper function asprintf_entry_text() is used to handle the log entry
text for display.
Signed-off-by: Artur Kloniecki <arturx.kloniecki@linux.intel.com>
There is no place for unused arguments, their are consequence of invalid
argument list as usual.
Such an situation is highly possible especially during defining trace
filters, eg `-Fv=mux 4.1` instead `-F"v=mux 4.1"` or `-Fv=mux4.1`.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
'p + 2' should be smaller than end pointer, bigger value may leads
to undefined memory region read.
Memmove should include last '\0' char.
Without this fix output looks like:
task add 0xbe070600 pipe-task 0x1fffa0f0U
After changes:
task add 0xbe070600 pipe-task <f11818eb-e92e-4082-82a3-dc54c604ebb3>
Fixes: 12f2d9b2c8 logger: Refactor UUID parsing
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
config->uids_dict has never been freed before.
`out` label has been added to perform `uuid_dict`
free before function return.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
Passing %s with random address leads to logger crash.
It's especially important right now, after changing
print formatter for UUID from %s to %pU. It's why
DBG_ABI patch number has been updated.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
Split UUID formatter parsing from general formatter parser,
to make functions shorter and less complicated.
By the way reduce number of loops.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
LDC with FW compatibility check has no sens for ldc dump operation,
because ldc dump reads only information provided in ldc file,
without engaging any information from FW - can be done offline as well.
Logger and ldc file DBG_ABI compatibility check is still active.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
fread() returns number of readed blocks, 0 when nothing read.
Comparison fread return value with "!ret" is quite misleading -
may suggests that negative value is returrned after fail.
Swapping if content makes flow easier, then first is error check,
and eventyally return statement, next try to reopen file.
It allows to check error condition only in one place, so there
won't be possibility to use different error checks in subsequent
stages (like ferror() and errno).
in_file alignment with trace entry size check has been added,
to warn about corrupted file.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
log format text comes from ldc file (may be invalid),
so error check is needed. Don't treat it as fatal error,
because this error may not impact following logs, when
formatting text is root cause of the issue.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
fread may return 0 when some error occurred or nothig has been reded.
Moreover errno may not be set on Windows plaform, use ferror
instead. See:
https://www.gnu.org/software/gnulib/manual/html_node/fread.html
Fixes: 337afc4f3809: ("logger: add error message when reading sof/etrace instead of sof/trace")
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
For first run, allocated memory pointer has been written twice to
config->filter_config but freed only once - memory leak.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
Reported by VERBOSE=1 CMAKE_BUILD_TYPE=Release ./scripts/build-tools.sh -l
and gcc version 9.3.0-10ubuntu2:
tools/logger/convert.c:630:5: error: ignoring return value of ‘freopen’,
declared with attribute warn_unused_result [-Werror=unused-result]
Tested with sof-test/test-case/check-suspend-resume-with-audio.sh
Fixes commit 6a84b4e945 ("sof: logger: reopen trace file upon EOF")
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Reported by VERBOSE=1 CMAKE_BUILD_TYPE=Release ./scripts/build-tools.sh -l
and gcc version 9.3.0-10ubuntu2.
out_fd is not initialized on the first "goto err:" and this can result in
trying to close a random file descriptor.
Fixes commit 126060ae63 ("logger: Send parsed runtime log levels to FW
via debugFS")
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
As reported by gcc 9.3.0-10ubuntu2 and
VERBOSE=1 CMAKE_BUILD_TYPE=Release ./scripts/build-tools.sh -l
‘__builtin___snprintf_chk’ output between 23 and 57 bytes
into a time_fmt destination of size 32
Fixes commit d7b535e282 ("logger: Add option to set timestamp
precision")
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
Failing silently is not nice. Now prints instead:
TIMESTAMP DELTA C# COMPONENT LOCATION CONTENT
error: in logger_read(), fread(..., /sys/kernel/debug/sof/etrace) \
failed: Invalid argument(22)
Also make logger_read() and the process return [-]errno which can have
different values and some information instead of -ferror() which has
only one value (non-zero in theory, 1 in practice) hence no information.
Signed-off-by: Marc Herbert <marc.herbert@intel.com>
In case we ever needed to load the entry from ldc file, without params
processing and printing.
Signed-off-by: Artur Kloniecki <arturx.kloniecki@linux.intel.com>
It may be needed for situation when user have firmware after
small fixes without updated ldc file or fw_ready file is not
accessible. Option dedicated for advanced users.
Signed-off-by: Karol Trzcinski <karolx.trzcinski@linux.intel.com>
Andrey Borisovich