Project

General

Profile

IPC Logging

This is a non-standard/non-mainline high-speed in-memory logging sub-system that is present in the Qualcomm Linux kernel variants to perform logging of the IPC (inter processor communication) related drivers.

User Interface

The user interface to obtain the logs is implemented via debugfs below /sys/kernel/debug/ipc_logging

For each ipc log context (see below) there is one sub-directory. On the EC25 this looks like:

root@mdm9607-perf:# ls /sys/kernel/debug/ipc_logging
78b1000.uart          sps_bam_0x04044000_0  sps_bam_0x078c4000_0
bam_dmux              sps_bam_0x04044000_1  sps_bam_0x078c4000_1
diag                  sps_bam_0x04044000_2  sps_bam_0x078c4000_2
glink                 sps_bam_0x04044000_3  sps_bam_0x078c4000_3
glink_ssr             sps_bam_0x04044000_4  sps_bam_0x078c4000_4
kqmi_ind              sps_bam_0x06084000_0  sps_bam_0x07984000_0
kqmi_req_resp         sps_bam_0x06084000_1  sps_bam_0x07984000_1
local_IPCRTR          sps_bam_0x06084000_2  sps_bam_0x07984000_2
modem_IPCRTR          sps_bam_0x06084000_3  sps_bam_0x07984000_3
smd                   sps_bam_0x06084000_4  sps_bam_0x07984000_4
smd_pkt               sps_bam_0x07884000_0  sps_ipc_log0
smd_tty               sps_bam_0x07884000_1  sps_ipc_log1
smem                  sps_bam_0x07884000_2  sps_ipc_log2
smp2p                 sps_bam_0x07884000_3  sps_ipc_log3
smsm                  sps_bam_0x07884000_4  sps_ipc_log4

Within each of those directories are two files: log and log_cont. Log shows you the log so far and then exits, while log_cont performs a blocking read semantic at the end, similar from what you would normally have when using tail -f on a classic log file.

The format of the log lines is like this:
[  4191.362072425/      0x12bec5ff43] [diag_state_open_smd] MODEM_DATA setting diag state to 1

where
  • 4191.362072425 is the number of seconds and nanoseconds since system boot
  • 0x12bec5ff43 is a QTimer Timestamp (presumably some hardware timer?)
  • diag_state_open_smd is the function name of the function issuing the ipc log statement
  • MODEM_DATA setting diag state to 1 is the format string that was printed, in this example "%s setting diag state to 1", smd_info->name from drivers/char/diag/diagfwd_smd.c

Official documentation

Below are excerpts from Documentation/arm/msm/msm_ipc_logging.txt:

Introduction

This module will be used to log the events by any module/driver which enables Inter Processor Communication (IPC). Some of the IPC drivers such as Message Routers, Multiplexers etc. which act as a passive pipe need some mechanism to log their events. Since all such IPC drivers handle a
large amount of traffic/events, using kernel logs renders kernel logs unusable by other drivers and also degrades the performance of IPC drivers. This new module will help in logging such high frequency IPC
driver events while keeping the standard kernel logging mechanism intact.

Hardware Description

This module does not drive any hardware resource and will only use the kernel memory-space to log the events.

Design Goals

This module is designed to
  • support logging for drivers handling large amount of traffic/events
  • define & differentiate events/logs from different drivers
  • support both id-based and stream-based logging
  • support extracting the logs from both live target & memory dump

IPC Log Context

This module will support logging by multiple drivers. To differentiate between the multiple drivers that are using this logging mechanism, each driver will be assigned a unique context by this module. Associated with each context is the logging space, dynamically allocated from the kernel memory-space, specific to that context so that the events logged using that context will not interfere with other contexts.

Event Logging

Every event will be logged as a <Type: Size: Value> combination. Type field identifies the type of the event that is logged. Size field represents the size of the log information. Value field represents the actual information being logged. This approach will support both id-based logging and stream-based logging. This approach will also support logging sub-events of an event. This module will provide helper routines to encode/decode the logs to/from this format.

Encode Context

Encode context is a temporary storage space that will be used by the client drivers to log the events in <Type: Size: Value> format. The client drivers will perform an encode start operation to initialize the encode context data structure. Then the client drivers will log their events into the encode context. Upon completion of event logging, the client drivers will perform an encode end operation to finalize the encode context data structure to be logged. Then this updated encode context data structure will be written into the client driver's IPC Log Context. The maximum event log size will be defined as 256 bytes.

Log Space

Each context (Figure 1) has an associated log space, which is dynamically allocated from the kernel memory-space. The log space is organized as a list of 1 or more kernel memory pages. Each page (Figure 2) contains header information which is used to differentiate the log kernel page from the other kernel pages.

      0 ---------------------------------
        |     magic_no = 0x25874452     |
        ---------------------------------
        |    nmagic_no = 0x52784425     |
        ---------------------------------
        |            version            |
        ---------------------------------
        |          user_version         |
        ---------------------------------
        |            log_id             |
        ---------------------------------
        |          header_size          |
        ---------------------------------
        |                               |
        |                               |
        |       name [20 chars]         |
        |                               |
        |                               |
        ---------------------------------
        |    run-time data structures   |
        ---------------------------------
         Figure 1 - Log Context Structure

        31                             0
      0 ---------------------------------
        |     magic_no = 0x52784425     |
        ---------------------------------
        |    nmagic_no = 0xAD87BBDA     |
        ---------------------------------
        |1|         page_num            |
        ---------------------------------
        |  read_offset  | write_offset  |
        ---------------------------------
        |            log_id             |
        ---------------------------------
        |     start_time low word       |
        |     start_time high word      |
        ---------------------------------
        |       end_time low word       |
        |       end_time high word      |
        ---------------------------------
        |         context offset        |
        ---------------------------------
        |    run-time data structures   |
        .            . . .              .
        ---------------------------------
        |                               |
        |           Log Data            |
        .              .                .
        .              .                .
        |                               |
        --------------------------------- PAGE_SIZE - 1
            Figure 2 - Log Page Structure

In addition to extracting logs at runtime through DebugFS, IPC Logging has been designed to allow extraction of logs from a memory dump. The magic numbers, timestamps, and context offset are all added to support the memory-dump extraction use case.

Design

Alternate solutions discussed include using kernel & SMEM logs which are limited in size and hence using them render them unusable by other drivers. Also kernel logging into serial console is slowing down the performance of the drivers by multiple times and sometimes lead to APPs watchdog bite.

SMP/multi-core

This module uses spinlocks & mutexes to handle multi-core safety.

Performance

This logging mechanism, based on experimental data, is not expected to cause a significant performance degradation. Under worst case, it can cause 1 - 2 percent degradation in the throughput of the IPC Drivers.

Dependencies

This module will partially depend on CONFIG_DEBUGFS, in order to dump the logs through debugfs. If CONFIG_DEBUGFS is disabled, the above mentioned helper functions will perform no operation and return appropriate error code if the return value is non void. Under such circumstances the logs can
only be extracted through the memory dump.

User space utilities

DEBUGFS

Kernel implementation

You can find related code in

./include/linux/ipc_logging.h
./drivers/char/diag/diag_ipc_logging.h
./kernel/trace/ipc_logging.c
./kernel/trace/ipc_logging_debug.c
./kernel/trace/ipc_logging_private.h