Logger

The sof-logger is used to print logs delivered from the FW dma_trace mechanism by searching log entries in the ldc file (logs dictionary) that are generated by the SMEX (Sof Metadata Extractor) tool. Every entry declared in the FW is placed in an elf output file (e.g. sof-apl) in the .static_log_entries section in a struct form that is defined in sof/src/include/sof/trace.h in the sof fw repo.

The ldc file contains snd_sof_logs_header and snd_sof_uids_header (defined in smex/ldc.h). snd_sof_logs_header is followed by a .static_log_entries section incorporated from the FW elf file (e.g. sof-apl). snd_sof_logs_header contains basic information about the .static_log_entries section such as base_address and data_length. The sof-logger works by reading entry parameters values and entries addresses from the FW dma_trace mechanism and searching for suitable entries in the ldc file by its address. The snd_sof_uids_header struct is followed by the .static_uuid_entries section content from the FW elf file. A single uuid entry is defined in sof/src/include/sof/lib/uuid.h in the sof fw repo.

Logger usage

Usage sof-logger <option(s)> <file(s)>

-h

help

-l ldc_file

Specify the ldc file (debugging information and strings)

-i in_file

Get traces from the in_file instead of from the default “/sys/kernel/debug/sof/etrace”

-o out_file

Specify the output file instead of the default stdout

-t

Get traces from “/sys/kernel/debug/sof/trace” instead of from the default “/sys/kernel/debug/sof/etrace”

-p

Get traces from stdin instead of the default “/sys/kernel/debug/sof/etrace”

-c clock

Set the timestamp clock in MHz

-n

Disable checking the firmware version with the default verification file “/sys/kernel/debug/sof/fw_version”

-v ver_file

Enable checking the firmware version with the ver_file file instead of the default: “/sys/kernel/debug/sof/fw_version”

-s

Take a snapshot of state

-r

Less formatted output for chained log processors

-L

Hide log location in source code

-f precision

Set timestamp precision

-g

Hide timestamp

-d

Dump ldc information

-F filter

Update trace filtering

Examples

  • Gets traces from the “/sys/kernel/debug/sof/etrace” file; disable compatibility check between given ldc_file with fw_version saved in default location and prints logs to stdout

    sof-logger -l ldc_file -n
    
  • Gets traces from the “/sys/kernel/debug/sof/etrace” file; verifies the fw_version with the ver_file file and prints logs to stdout

    sof-logger -l ldc_file -v ver_file
    
  • Get traces from the “/sys/kernel/debug/sof/etrace” file and prints logs to stdout

    sof-logger -l ldc_file
    
  • Get traces from the “/sys/kernel/debug/sof/etrace” file and prints logs to the out_file file

    sof-logger -l ldc_file -o out_file
    
  • Get traces from the “/sys/kernel/debug/sof/trace” file and prints logs to stdout

    sof-logger -l ldc_file -t
    
  • Get traces from the “/sys/kernel/debug/sof/trace” file and prints logs to the out_file file

    sof-logger -l ldc_file -t -o out_file
    
  • Get traces from stdin and prints logs to stdout

    sof-logger -l ldc_file -p
    
  • Get traces from stdin and prints logs to the out_file file

    sof-logger -l ldc_file -p -o out_file
    
  • Get traces from the trace_dump file and prints logs to stdout

    sof-logger -l ldc_file -i trace_dump
    
  • Get traces from the trace_dump file and prints logs to the out_file file

    sof-logger -l ldc_file -i trace_dump -o out_file
    
  • c flag defines the clock value (in MHz) used to format log timestamps. By default, the clock value is set to 19.2 (MHz). The below example sets the clock value to 19.9 (MHz).

    sof-logger -l ldc_file -i trace_dump -o out_file -c 19.9
    
  • Dump information from the ldc file (such as the ABI version and the uuid dictionary) to stdout

    sof-logger -l ldc_file -d
    

Trace filtering

Current log levels can be changed for any instance of a component at runtime. To do so, use the -F option and the following argument format:

<log_level>=”<component1>[, <component2>]”

Where <log_level> can be one of the following:

  • c / critical

  • e / error

  • w / warning

  • i / info

  • d / debug

  • v / verbose

After the = character, all components are listed in a comma-separated format. Each component begins with name followed by an optional instance description.

The list of possible component names comes from the UUID declaration. Refer to the UUID API for more detailed information. Use the -d flag in the logger to list component names from the ldc file content.

Example output:

$./sof-logger -d log/sof-cnl.ldc
logger ABI Version is   5:2:0
ldc_file ABI Version is 5:2:0

Components uuid dictionary size:        824 bytes
Components uuid base address:           0x1FFFA000
Components uuid entries:
         ADDRESS                                    UUID NAME
      0x1FFFA000  <8b9d100c-6d78-418f-90a3-e0e805d0852b> host
      0x1FFFA01C  <f11818eb-e92e-4082-82a3-dc54c604ebb3> pipe-task
      0x1FFFA03C  <34dc0385-fc2f-4f7f-82d2-6cee444533e0> volume-task
      0x1FFFA05C  <b77e677e-5ff4-4188-af14-fba8bdbf8682> volume
      0x1FFFA078  <c1c5326d-8390-46b4-aa47-95c3beca6550> src
      0x1FFFA134  <c2b00d27-ffbc-4150-a51a-245c79c5e54b> dai
      -------------------------------------------------- cnt: 6

A special wildcard - * - can be used to apply a given trace level to each component.

Instance descriptions can have one of the following forms:

  • * - each component instance

  • X.* - each component on selected pipeline X

  • X.Y - component on pipeline X with id Y

Trace level changes works in the same order as options given in a command line, and a new set overwrites old values. It allows you to easily enable verbose logs only for selected components and keep the lowest possible log level (critical) for others, as shown in the following example:

sof-logger -l ldc_file -t -Fcritical=* -Fverbose=”dai*, volume1.1”

A similar example may be prepared for components on a particular pipeline:

sof-loggerr -l ldc_file -t -Fc=* -Fv=*1.*

Detailed description

Filtration mechanism is realized on the firmware side so, after changing the log level to verbose for each component, the DSP may be overhelmed by tracing.

Core functionality is provided by DSP, so filtration does not work in offline mode - during conversion previously saved input file.

Communication between the firmware and logger is realized through driver debug file systems. The logger writes new trace settings to sys/kernel/debug/sof/filter. These will be used to create IPC messages with new trace levels. A simple text data format is used:

log1_level uuid1_id pipe1_id comp1_id; [log2_level uuid2_id pipe2_id comp2_id;]\n

Any unused uuid_id should be set here to 0; other unused fields should be set to -1. log_level must always be set to a valid value that represents LOG_LEVEL_* defined values.