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