Android系统10 RK3399 init进程启动(十九) init进程日志重定向至内核

原创

旗浩QH 2022-06-29 10:33:40 ©著作权

文章标签 android Android系统 Android源码产品定制瑞星微RK3399 #define 文章分类 虚拟化云计算

©著作权归作者所有：来自51CTO博客作者旗浩QH的原创作品，请联系作者获取转载授权，否则将追究法律责任

说明

系统：Android10.0

设备： FireFly RK3399 （ROC-RK3399-PC-PLUS）

前言

本文重点介绍init进程在启动的时候使用的日志重定位技术，方便大家去理解init进程代码中关于日志重定向的逻辑。

一：介绍

Android系统init进程启动的时候，log子系统没有启动起来，但是我们仍然可以可以使用logcat -b kernel看到init进程的日志，这是怎么做到的呢？其实是通过日志重定向来完成的。在init进程中代码中,有如下：system/core/init/first_stage_init.cpp

SetStdioToDevNull(argv); 
// Now that tmpfs is mounted on /dev and we have /dev/kmsg, we can actually 
// talk to the outside world...
InitKernelLogging(argv);

LOG(INFO) << "init first stage started!";

意味着，如果我们需要在init进程中输出日志，只需要调用 LOG(pri)即可。

二，LOG()实现逻辑

在init进程中一般使用LOG()或者PLOG()宏定义来构造一个std::ostringstream 字符串流，将需要打印的数据写入流中，然后将io流重定向到内核日志buffer中去：

LOG(pri)<<”xxx” ；
// logging.h中声明，最终都是调用android::base::LogMessage(logging.cpp中实现)
#define LOG(severity) LOG_TO(DEFAULT, severity)
#define LOG_TO(dest, severity) \
LOGGING_PREAMBLE(severity) && LOG_STREAM_TO(dest, severity)
#define LOG_STREAM_TO(dest, severity)                                           \
  ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::dest,        \
                              SEVERITY_LAMBDA(severity), _LOG_TAG_INTERNAL, -1) \
      .stream() //出错码固定为-1

PLOG(pri)<<”xxx”;
// system/base/include/android-base/logging.h和logging.cpp定义
#define PLOG(severity) PLOG_TO(DEFAULT, severity)
#define PLOG_TO(dest, severity)                                                        \
  LOGGING_PREAMBLE(severity) &&                                                        \
      ::android::base::LogMessage(__FILE__, __LINE__, ::android::base::dest,           \
                                  SEVERITY_LAMBDA(severity), _LOG_TAG_INTERNAL, errno) \
          .stream() //得到ostringstream,并将调试日志写入到字符串流
//在LogMessage析构函数中，最终会调用Logger()对象, 默认为LogdLogger/StderrLogger
//而这个对象是可以在 android::base::InitLogging()
//去设置自定义的Logger对象(其实就是一个函数)

LOG(pri)和PLOG(pri)的不同在于， PLOG主要用于出错时打印，会将出错码打印出来sterror(errno)，平常日志打印用LOG(pri)即可，出错用PLOG(pri)。输出内容差不多，两者都可以用,类似与printf()和perror()

三，自定义实现日志重定向内核

#undef NDEBUG
#define LOG_NDEBUG 0

#include <stdio.h>
#define LOG_TAG "MyLogTest"
#include <log/log.h>


enum LogSeverity {
  VERBOSE,
  DEBUG,
  INFO,
  WARNING,
  ERROR,
  FATAL_WITHOUT_ABORT,
  FATAL,
};

void toKernel_log(int severity, const char* tag, const char* msg)
{
  // clang-format off
  static int kLogSeverityToKernelLogLevel[] = {
    [VERBOSE] = 7, // KERN_DEBUG (there is no verbose kernel log
    // level)
    [DEBUG] = 7, // KERN_DEBUG
    [INFO] = 6, // KERN_INFO
    [WARNING] = 4, // KERN_WARNING
    [ERROR] = 3, // KERN_ERROR
    [FATAL_WITHOUT_ABORT] = 2, // KERN_CRIT
    [FATAL] = 2, // KERN_CRIT
  };
  int klog_fd = open("/dev/kmsg", O_WRONLY | O_CLOEXEC);
  if (klog_fd == -1)
    return;
  int level = kLogSeverityToKernelLogLevel[severity];
  char buf[1024];
  size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %s\n", level, tag, msg);
  if (size > sizeof(buf)) {
    size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
        level, tag, size);
  } 
  struct iovec iov[1];
  iov[0].iov_base = buf;
  iov[0].iov_len = size;
  writev(klog_fd, iov, 1);
}


int main(int argc, char *argv[])
{ 

  toKernel_log(DEBUG, LOG_TAG, "tokernel log : debug");
  toKernel_log(INFO, LOG_TAG, "tokernel log : info");
  toKernel_log(ERROR, LOG_TAG, "tokernel log : error");

  while(1);

  return 0;
}

其实内部实现的原理很简单，就是将需要的日志写入到/dev/kmsg中去，并且将要输出的日志直接格式化成Android log系统所规定的格式。

Android.mk如下所示：

LOCAL_PATH:= $(call my-dir)
include $(CLEAR_VARS)

LOCAL_SRC_FILES:= \
  log_test.c

LOCAL_SHARED_LIBRARIES := \
        libcutils \
        liblog \

LOCAL_CFLAGS := \
  -Wno-unused-parameter \
  -Wno-implicit-function-declaration


#LOCAL_PROPRIETARY_MODULE := true
LOCAL_MODULE:= mylog_test

include $(BUILD_EXECUTABLE)

编译之后，执行./mytest_log, 然后使用logcat -b kernel就可以看到我代码中的写入的日志：

tokernel log : debug
tokernel log : error

四， init进程实现的日志重定向代码

init进程调用的就是如下函数实现：

static void KernelLogLine(const char* msg, int length, android::base::LogSeverity severity,
                          const char* tag) {
  // clang-format off
  static constexpr int kLogSeverityToKernelLogLevel[] = {
      [android::base::VERBOSE] = 7,              // KERN_DEBUG (there is no verbose kernel log
                                                 //             level)
      [android::base::DEBUG] = 7,                // KERN_DEBUG
      [android::base::INFO] = 6,                 // KERN_INFO
      [android::base::WARNING] = 4,              // KERN_WARNING
      [android::base::ERROR] = 3,                // KERN_ERROR
      [android::base::FATAL_WITHOUT_ABORT] = 2,  // KERN_CRIT
      [android::base::FATAL] = 2,                // KERN_CRIT
  };
  // clang-format on
  static_assert(arraysize(kLogSeverityToKernelLogLevel) == android::base::FATAL + 1,
                "Mismatch in size of kLogSeverityToKernelLogLevel and values in LogSeverity");

  static int klog_fd = OpenKmsg();
  if (klog_fd == -1) return;

  int level = kLogSeverityToKernelLogLevel[severity];

  // The kernel's printk buffer is only 1024 bytes.
  // TODO: should we automatically break up long lines into multiple lines?
  // Or we could log but with something like "..." at the end?
  char buf[1024] __attribute__((__uninitialized__));
  size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %.*s\n", level, tag, length, msg);
  if (size > sizeof(buf)) {
    size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
                    level, tag, size);
  }

  iovec iov[1];
  iov[0].iov_base = buf;
  iov[0].iov_len = size;
  TEMP_FAILURE_RETRY(writev(klog_fd, iov, 1));
}

void KernelLogger(android::base::LogId, android::base::LogSeverity severity, const char* tag,
                  const char*, unsigned int, const char* full_message) {
  SplitByLines(full_message, KernelLogLine, severity, tag);
}


void InitKernelLogging(char** argv) {
    SetFatalRebootTarget();
    android::base::InitLogging(argv, &android::base::KernelLogger, InitAborter);
}