Android和DLT日志系统

1 Linux Android日志系统
1.1 内核logger机制
drivers/staging/android/logger.c
static size_t logger_offset(
    struct logger_log *log,
    size_t n)
{
    return n & (log->size - 1);
}
写的off存在logger_log中（即内核内存buffer），而r_off存在于读的进程中，所以执行两次不同的logcat，都是从头开始读的。

1.2 logd日志进程
1.2.1 Android 8.0 per-tag
setprop log.tag.<tagname> DEBUG
/data/local.prop

logcat <tagname>:D *:S &

1.2.2 logwrapper
logwrapper /system/bin/mytest
或者
service logwrapper /system/bin/logwrapper /system/bin/mytest
    user root
    group root
    seclabel u:r:init:s0
    oneshot

logwrapper - 将被执行进程的stdio重定向到logd进程，然后通过logcat查看log。

1.2.3 调整logcat打印时间
diff --git a/liblog/logprint.c b/liblog/logprint.c
index c2f1545..75d095d 100644
--- a/liblog/logprint.c
+++ b/liblog/logprint.c
@@ -907,7 +907,10 @@ char *android_log_formatLogLine (
      * brackets, asterisks, or other special chars here.
      */
 #if !defined(_WIN32)
-    ptm = localtime_r(&(entry->tv_sec), &tmBuf);
+    //ptm = localtime_r(&(entry->tv_sec), &tmBuf);
+    struct timeval tv;
+    gettimeofday(&tv, NULL);
+    ptm = localtime(&(tv.tv_sec));
 #else
     ptm = localtime(&(entry->tv_sec));
 #endif

1.2.4 logd不能打印dmesg
diff --git a/logd/main.cpp b/logd/main.cpp
index a3241d0..457be8e 100644
--- a/logd/main.cpp
+++ b/logd/main.cpp
@@ -277,6 +277,7 @@ static bool property_get_bool_svelte(const char *key) {
         property_get("ro.build.type", property, "");
         not_user = !!strcmp(property, "user");
     }
+    not_user = true;
     return property_get_bool(key, not_user
         && !property_get_bool("ro.config.low_ram", false));
 }

1.3 Linux printk
1.3.1 printk的原理
printk的实现原理很简单，在有了日志消息后，首先申请控制台的信号量，如果申请到，则调用控制台写方法，写控制台。

在内核源码树的kernel/printk.c中，使用宏DECLARE_MUTEX声明了一个互斥锁console_sem，他用于保护console驱动列表console_drivers及同步对整个console驱动系统的访问。其中定义了函数acquire_console_sem来获得互斥锁console_sem，定义了release_console_sem来释放互斥锁console_sem，定义了函数try_acquire_console_sem来尽力得到互斥锁console_sem。这三个函数实际上是分别对函数down，up和down_trylock的简单包装。需要访问console_drivers驱动列表时就需要使用acquire_console_sem来保护console_drivers列表，当访问完该列表后，就调用release_console_sem释放信号量console_sem。函数console_unblank，console_device，console_stop，console_start，register_console 和unregister_console都需要访问console_drivers，因此他们都使用函数对acquire_console_sem和release_console_sem来对console_drivers进行保护。

调试console_sem时，需要打开宏CONFIG_DEBUG_SPINLOCK以跟踪owner字段。

关闭kernel Log，通过bootchart.png可以看到启动init进程的时间明显提前，可以加快启动速度。
kernel/printk.c
int console_printk[4] = {
    DEFAULT_CONSOLE_LOGLEVEL,
    DEFAULT_MESSAGE_LOGLEVEL,
    MINIMUM_CONSOLE_LOGLEVEL,
    DEFAULT_CONSOLE_LOGLEVEL,
};
改为
int console_printk[4] = {
    0, //DEFAULT_CONSOLE_LOGLEVEL,
    0, //DEFAULT_MESSAGE_LOGLEVEL,
    0, //MINIMUM_CONSOLE_LOGLEVEL,
    0, //DEFAULT_CONSOLE_LOGLEVEL,
};
这四个值对应到路径proc/sys/kernel/printk，当printk()没有指定消息级别时，就采用DEFAULT_MESSAGE_LOGLEVEL（对应到KERN_WARNING = 4）。

echo "8 8 8 8" > /proc/sys/kernel/printk

Android中logcat读取dmesg后，不显示最前面的时间戳，所以不方便查找内核时间，可以使用如下的方式，在每次调用打印函数时，同时也打印下面的秒和微妙2个值，这样logcat读取的dmesg就不会丢失内核时间点 (28-Dec-2021)。
static void get_timestamp(
    u64 *sec, u64 *usec)
{
    u64 ts;
    u64 rem_ns;

    ts = local_clock();
    rem_ns = do_div(ts, 1000000000);
    /* %5lu */
    *sec = ts;
    /* %06lu */
    *usec = rem_ns / 1000;
}

1.3.2 修改Android Printk默认loglevel
修改这个值前，检查一下init中允许的最大值，否则改为8可能无效。

in init.rc
change
loglevel 3
to
loglevel 6

1.3.3 重定向服务stdio到/dev/console
init.xx.rc
service xxx /system/bin/xxx
    class main
    console # 将服务xxx的stdio定向到/dev/console，否则到/dev/null

1.3.4 pr_debug动态log
CONFIG_DEBUG_FS=y
CONFIG_DYNAMIC_DEBUG=y

echo "file my_drv.c +p" > \
/sys/kernel/debug/dynamic_debug/control

1.4 Linux pstore - Persistent Storage
主要用于存储内核异常时的log信息。实现方式是，管理一块“非易失性的存储空间”，如不断电的RAM或外部存储，当系统异常时，将log信息写到Pstore管理的存储空间，直到下一次系统正常时，再将log读出来，以文件形式提供给用户使用。

1.5 Linux logrotate
当第一次进行日志轮替时，当前的secure日志会自动改名为secure.1，然后新建secure日志，用来保存新的日志；当第二次进行日志轮替时，secure.1会自动改名为secure.2，当前的secure日志会自动改名为secure.1，然后也会新建secure日志，用来保存新的日志；以此类推。

2 GENIVI DLT
2.1 GENIVI systemd configuration file
/etc/systemd/system
/lib/systemd/system
/run/systemd/system
/usr/lib/systemd/user

2.2 commands
systemctl list-unit-files | grep enable

systemctl cat dlt-daemon.service
systemctl cat dlt-system.service

systemctl show dlt-daemon.service
systemctl show dlt-system.service

systemctl start dlt-recv-daemon.service

2.3 dlt viewer
/etc/dlt.conf
dlt viewer可以通过TCP、UDP和串口连接dlt daemon。

2.4 showcase
[21-Oct-2021]
dlt-receive -a localhost

2.5 DLT memory monitor
This is used to check OOM issue.
oom-killer: GFP_HIGHUSER_MOVABLE
Application ID: MON
Context ID: MSER
Context ID: THRD
The 1st para: timestamp
The 5th para: pgfault
The 8th para: active_anon

3 FreeRTOS简单log系统的实现
oem_log.c
#define USE_WAIT_QUEUE
#define TASK_BUF_SZ 2048

#define LINE_BUF_SZ 1024
#define LOG_BUF_SZ 4096
#define LOG_BUF_MASK  (LOG_BUF_SZ - 1)
#define LOG_BUF(idx)  (log_buf[(idx) & \
    LOG_BUF_MASK])

static unsigned char line_buf[LINE_BUF_SZ];
static unsigned char log_buf[LOG_BUF_SZ];
static unsigned int log_start = 0, con_start = 0;
static unsigned int log_end = 0;

/* char dropped count */
static unsigned int cdc = 0;
static SemaphoreHandle_t log_sem = NULL;

#if 1
#define log_lock() do {                \
    if (NULL != log_sem) {            \
        xSemaphoreTake(log_sem, \
            portMAX_DELAY);  \
    }                                              \
} while (0)
#define log_unlock() do {           \
    if (NULL != log_sem) {           \
        xSemaphoreGive(log_sem); \
    }                                             \
} while (0)
#else
#define log_lock() do {} while(0)
#define log_unlock() do {} while(0)
#endif

#if 1
static int do_write_log2emmc(const char *buf,
    const uint16_t nbytes)
{
    FIL fil;
    FRESULT fr;
    const char *bufp = buf;
    uint16_t nleft, nwritten = 0;
    uint8_t cnt = 0;

    if (NULL == buf) {
        return 0;
    }
    nleft = nbytes;

    fr = f_open(&fil,
        LOG_FNAME,
        FA_OPEN_APPEND | FA_WRITE);
    if (FR_OK == fr) {
        while ((nleft > 0) && (cnt++ < 5)) {
            fr = f_write(&fil, bufp, nleft, &nwritten);
            if ((FR_OK == fr) && (nwritten > 0)) {
                bufp += nwritten;
                nleft -= nwritten;
            }
        }
        cdc += nleft;
        f_close(&fil);
    }

    if (nbytes == nleft) {
        return -1;
    }
    return (nbytes - nleft);
}
#endif

static inline void emit_char(const uint8_t c)
{
    LOG_BUF(log_end) = c;
    log_end++;

    if ((log_end - log_start) > LOG_BUF_SZ) {
        log_start = log_end - LOG_BUF_SZ;
        cdc++;
    }

    if ((log_end - con_start) > LOG_BUF_SZ) {
        con_start = log_end - LOG_BUF_SZ;
    }
}

int oem_sh_log(const char *buf,
    const char *fmt,...)
{
    hal_rtc_time_t local_time = {0};
    int16_t i, n, ts_len = 0;
#if defined (USE_WAIT_QUEUE)
    uint8_t msg_id;
#endif
    static uint32_t nr_data = 0;
    va_list ap;

    log_lock();

    if (buf && (buf[0] != 0x55)) {
#if 1
        n = do_write_log2emmc(buf, strlen(buf));
#endif
    } else {
        if (buf && (buf[0] == 0x55)) {
        } else {
            hal_rtc_get_time(&local_time);
            ts_len = snprintf(line_buf,
            LINE_BUF_SZ,
            "[%d/%d/%d %02d:%02d:%02d]<%d> ",
                    local_time.rtc_year + 2000,
                    local_time.rtc_mon,
                    local_time.rtc_day,
                    local_time.rtc_hour,
                    local_time.rtc_min,
                    local_time.rtc_sec,
                    nr_data++);
        }
        va_start(ap, fmt);
        if (ts_len > 0) {
            n = vsnprintf(line_buf + ts_len,
                LINE_BUF_SZ - ts_len,
                fmt,
                ap);
        } else {
            n = vsnprintf(line_buf,
                LINE_BUF_SZ,
                fmt,
                ap);
        }
        va_end(ap);

        if (n > 0) {
            if (ts_len > 0) {
                n += ts_len;
            }

            for (i = 0; i < n; i++) {
                emit_char(line_buf[i]);
            }
        }
    }

#if defined (USE_WAIT_QUEUE)
    if ((log_end - log_start) >=
        (LOG_BUF_SZ - 1024)) {
        msg_id = 1;
        xQueueSend(task_wait_queue,
            &msg_id,
            0);
    }
#endif

    log_unlock();
    return n;
}

static void sh_log_task(void *data)
{
    bool to_send;
    unsigned char tbuf[TASK_BUF_SZ];
    uint16_t i;
#if defined (USE_WAIT_QUEUE)
    uint8_t msg_id;
#endif

    while (1) {
        log_lock();
#if 0
        if (1 == (log_end - log_start)) {
            log_start = 0;
            log_end = 0;
        } else
#endif
        if (log_start < log_end) {
            for (i = 0;
                (i < (TASK_BUF_SZ - 1)) &&
                (log_start < log_end);
                i++, log_start++) {
                tbuf[i] = LOG_BUF(log_start);
            }

            tbuf[i] = '\0';
            to_send = true;
        }
        log_unlock();

        if (to_send) {
            to_send = false;

            // oem_log("%s", tbuf);
#if 1
            do_write_log2emmc(tbuf,
                strlen(tbuf));
#endif
            tbuf[0] = '\0';
        }

#if defined (USE_WAIT_QUEUE)
        // block here, don't care return value
        xQueueReceive(
            p_slc_dev->task_wait_queue,
            &msg_id,
            (10000 / portTICK_PERIOD_MS));
#else
        vTaskDelay(100 / portTICK_PERIOD_MS);
#endif
    }
    vTaskDelete(NULL);
}

4 Abbreviations
bail out：跳伞
dlt: Diagnostic Log and Trace
Slog.wtf：what a terrible failure
usr: Unix System Resource