.. _dbg-logger: 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 -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 .. code-block:: bash 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 .. code-block:: bash sof-logger -l ldc_file -v ver_file - Get traces from the "/sys/kernel/debug/sof/etrace" file and prints logs to stdout .. code-block:: bash sof-logger -l ldc_file - Get traces from the "/sys/kernel/debug/sof/etrace" file and prints logs to the out_file file .. code-block:: bash sof-logger -l ldc_file -o out_file - Get traces from the "/sys/kernel/debug/sof/trace" file and prints logs to stdout .. code-block:: bash sof-logger -l ldc_file -t - Get traces from the "/sys/kernel/debug/sof/trace" file and prints logs to the out_file file .. code-block:: bash sof-logger -l ldc_file -t -o out_file - Get traces from stdin and prints logs to stdout .. code-block:: bash sof-logger -l ldc_file -p - Get traces from stdin and prints logs to the out_file file .. code-block:: bash sof-logger -l ldc_file -p -o out_file - Get traces from the trace_dump file and prints logs to stdout .. code-block:: bash sof-logger -l ldc_file -i trace_dump - Get traces from the trace_dump file and prints logs to the out_file file .. code-block:: bash 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). .. code-block:: bash 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 .. code-block:: bash 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: ="[, ]" Where ** 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 :ref:`uuid-api` for more detailed information. Use the ``-d`` flag in the logger to list component names from the ``ldc`` file content. Example output: .. code-block:: bash $./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 pipe-task 0x1FFFA03C <34dc0385-fc2f-4f7f-82d2-6cee444533e0> volume-task 0x1FFFA05C volume 0x1FFFA078 src 0x1FFFA134 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.* .. note:: To track a verbose message, select the "Trace verbose" option under the "Trace" menu from the firmware build. Active trace filters are stored in the firmware runtime memory, so after a firmware restart (such as after power gating in sleep mode) filters settings will be reset. Consider disabling power gating during your debug session by entering the following: .. code:: bash sudo su echo on >/sys/devices/pci0000\:00/0000\:$(lspci -nn | grep "audio contoller" | awk '{print $1;}')/power/control .. note:: The current device power status can be read by entering this command: .. code:: bash cat /sys/devices/pci0000\:00/0000\:$(lspci -nn | grep "audio controller" | awk '{print $1;}')/power/runtime_status The logger trace filtration affects only traces sent after the filter setup, so traces already stored on the kernel side are not affected. Filters are set up incrementally, so when loggers are run twice with different settings, then filters from the first run will not be restored to the default state but will be replaced by a new one. To reset filters to the default state, a firmware reset is needed. Detailed description -------------------- The filtration mechanism occurs on the firmware side so, after changing the log level to verbose for each component, the DSP can be overhelmed by tracing. Core functionality is provided by the DSP, so filtration does not work in offline mode - during conversion in a previously saved input file. Communication between the firmware and logger is occurs 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.