Android|Android Log机制的原理学习

应用程序的运行与维护,离不开日志。APP开发者们有很多选择,例如微信的xlog(高可靠性高性能的运行期日志组件)等,同样也离不开原生的日志机制支持。所以我们从原生Android Log机制开始学起:
一. Android Log机制(基于Android P原生代码) APP打印日志,最简单的是使用Log类(android.util.Log),如下例子:

import android.util.Log; public class MainActivity extends Activity { @Override protected void onCreate(Bundle savedInstanceState) { super.onCreate(savedInstanceState); setContentView(R.layout.activity_main); Log.d("kevintest", "onCreate"); } // ... }

APP运行,进入页面后,通过adb logcat命令,会看到有一行日志打印出:
Android|Android Log机制的原理学习
文章图片


1. 日志类型有5类
Android|Android Log机制的原理学习
文章图片


2. 上述类型中,LOG_ID_MAIN、LOG_ID_RADIO、LOG_ID_SYSTEM的优先级有6种
Android|Android Log机制的原理学习
文章图片
一般使用时,级别值越高,打印的日志越重要,从变量字面意思也可理解。Google官方文档中有这样的建议:VERBOSE日志只建议用于开发调试的版本,不能被编译入其他版本,如release版本;DEBUG日志可用于release版本产品,但默认不会打印;INFO、WARN、ERROR日志建议在release版本中使用与保存。手机中一般默认的日志打印级别是INFO(包括INFO、WARN、ERROR),可参考:开发者选项-选择日志级别



3. 原生代码分析 首先我们重点看下android.util.Log类:
Log类定义较简单,无父类,final修饰,不可继承。构造函数是private,不可实例化。举例,APP调用Log.v方法打印VERBOSE日志时,其方法实现是:
public static int v(String tag, String msg) { return println_native(LOG_ID_MAIN, VERBOSE, tag, msg); }

其中关键的方法是println_native,方法实现位于:frameworks/base/core/jni/android_util_Log.cpp,传入的三个参数分别是:LOG_ID_MAIN(类型),VERBOSE(级别),tag(标签),msg(日志信息),实现如下:
static jint android_util_Log_println_native(JNIEnv* env, jobject clazz, jint bufID, jint priority, jstring tagObj, jstring msgObj) { // ... int res = __android_log_buf_write(bufID, (android_LogPriority)priority, tag, msg); // ... return res; }

继续调用__android_log_buf_write方法,方法定义:system/core/liblog/include/android/log.h,实现:system/core/liblog/logger_write.c,其中核心部分:
注意:其他一些系统模块,例如debuggered等C++代码都会直接封装or调用__android_log_buf_write来打印日志
LIBLOG_ABI_PUBLIC int __android_log_buf_write(int bufID, int prio, const char* tag, const char* msg) { struct iovec vec[3]; // ...... vec[0].iov_base = (unsigned char*)&prio; // 例如通过Log.v调用过来,这里是2(VERBOSE) vec[0].iov_len = 1; vec[1].iov_base = (void*)tag; vec[1].iov_len = strlen(tag) + 1; vec[2].iov_base = (void*)msg; vec[2].iov_len = strlen(msg) + 1; return write_to_log(bufID, vec, 3); }

继续调用write_to_log方法,实现:system/core/liblog/logger_write.c,其中核心部分:
注意:第一次真正执行的方法是:__write_to_log_init,初始化后write_to_log的的方法实现变为:__write_to_log_daemon。详细参见__write_to_log_init的方法实现
static int __write_to_log_init(log_id_t, struct iovec* vec, size_t nr); static int (*write_to_log)(log_id_t, struct iovec* vec, size_t nr) = __write_to_log_init; // ... static int __write_to_log_init(log_id_t log_id, struct iovec* vec, size_t nr) { int ret, save_errno = errno; __android_log_lock(); // 加锁 if (write_to_log == __write_to_log_init) { ret = __write_to_log_initialize(); if (ret < 0) { __android_log_unlock(); if (!list_empty(&__android_log_persist_write)) { __write_to_log_daemon(log_id, vec, nr); } errno = save_errno; return ret; } write_to_log = __write_to_log_daemon; } __android_log_unlock(); // 去锁 ret = write_to_log(log_id, vec, nr); errno = save_errno; return ret; }

首先会执行初始化方法__write_to_log_initialize,作用是:为集合__android_log_transport_write设置各类writer,例如logdLoggerWrite,pmsgLoggerWrite等,然后依次调用writer的open方法,例如logdLoggerWrite#logdOpen方法,如果打开失败,则关闭。
logdLoggerWrite#logdOpen方法,代码位置:system/core/liblog/logd_writer.c,其实现是:
/* log_init_lock assumed */ static int logdOpen() { // ... int sock = TEMP_FAILURE_RETRY( socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0)); // 注意:SOCK_DGRAM代表着UDP通信,SOCK_NONBLOCK非阻塞式(效率高) // ... strcpy(un.sun_path, "/dev/socket/logdw"); if (TEMP_FAILURE_RETRY(connect(sock, (struct sockaddr*)&un, sizeof(struct sockaddr_un))) < 0) { // ... }

继续调用__write_to_log_daemon方法,实现:system/core/liblog/logger_write.c,其中核心部分:
static int __write_to_log_daemon(log_id_t log_id, struct iovec* vec, size_t nr) { struct android_log_transport_write* node; int ret, save_errno; struct timespec ts; size_t len, i; // ... clock_gettime(android_log_clockid(), &ts); // 获得日志时间戳if (log_id == LOG_ID_SECURITY) { // ... } else if (log_id == LOG_ID_EVENTS || log_id == LOG_ID_STATS) { // ... } else { /* Validate the incoming tag, tag content can not split across iovec */ char prio = ANDROID_LOG_VERBOSE; const char* tag = vec[0].iov_base; // ... // 变量prio存储vec[0].iov_base,例如2(VERBOSE),tag存储vec[1].iov_base if (!__android_log_is_loggable_len(prio, tag, len - 1, ANDROID_LOG_VERBOSE)) {//如果当前打印的log级别低于系统设置的级别,会直接返回,不会打印。默认是:ANDROID_LOG_VERBOSE(2),系统设置的级别来自于属性:persist.log.tag 或 log.tag errno = save_errno; return -EPERM; } } //.... // 以下是核心方法实现 write_transport_for_each(node, &__android_log_transport_write) { if (node->logMask & i) { ssize_t retval; retval = (*node->write)(log_id, &ts, vec, nr); if (ret >= 0) { ret = retval; } } } write_transport_for_each(node, &__android_log_persist_write) { if (node->logMask & i) { (void)(*node->write)(log_id, &ts, vec, nr); } } errno = save_errno; return ret; }

在上面会看到将循环调用所有writer的write方法来传输日志,举个例子logdLoggerWrite的write方法(之前已调用其logdOpen方法:建立Socket连接,path:/dev/socket/logdw):
static int logdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr) { // ... /* * The write below could be lost, but will never block. * * ENOTCONN occurs if logd has died. * ENOENT occurs if logd is not running and socket is missing. * ECONNREFUSED occurs if we can not reconnect to logd. * EAGAIN occurs if logd is overloaded. */ if (sock < 0) { ret = sock; } else { ret = TEMP_FAILURE_RETRY(writev(sock, newVec, i)); // 通过socket写数据 if (ret < 0) { ret = -errno; } } // ... }



下一步是Logd的逻辑分析,即接收到socket通信传输后的数据,该如何处理:
Logd进程是开机时由init进程启动,启动代码参考:system/core/rootdir/init.rc。Logd进程启动时创建3个Socket通道通信,代码实现:system/core/logd/logd.rc,如下:
service logd /system/bin/logd socket logd stream 0666 logd logd socket logdr seqpacket 0666 logd logd socket logdw dgram+passcred 0222 logd logd file /proc/kmsg r file /dev/kmsg w user logd group logd system package_info readproc writepid /dev/cpuset/system-background/tasks //...



例如adb shell连接手机,通过ss -pl查看socket连接: Android|Android Log机制的原理学习
文章图片

进程启动后,入口方法:system/core/logd/main.cpp,其中入口的main方法实现不复杂,主要创建LogBuffer,然后启动5个listener,一般重要的是前三个:LogReader,LogListener,CommandListener,全部继承于SocketListener(system/core/libsysutils),另外还有2个listener:LogAudit(监听NETLINK_AUDIT,与selinux有关),LogKlog,这里不做深究。
int main(int argc, char* argv[]) { // ...// LogBuffer,作用:存储所有的日志信息 logBuf = new LogBuffer(times); // LogReader监听Socket(/dev/socket/logdr),作用:当客户端连接logd后,LogReader将LogBuffer中的日志写给客户端。线程名:logd.reader,通过prctl(PR_SET_NAME, "logd.reader"); 设定 LogReader* reader = new LogReader(logBuf); if (reader->startListener()) { exit(1); } // LogListener监听Socket(/dev/socket/logdw),作用:接收传来的日志信息,写入LogBuffer;同时LogReader将新的日志传给已连接的客户端。线程名:logd.writer LogListener* swl = new LogListener(logBuf, reader); if (swl->startListener(600)) { exit(1); } //CommandListener监听Socket(/dev/socket/logd),作用:接收发来的命令。线程名:logd.control CommandListener* cl = new CommandListener(logBuf, reader, swl); if (cl->startListener()) { exit(1); } // ... exit(0); }

首先看LogListener,当有对端进程通过Socket传递过来数据后,onDataAvailable方法被调用,其中主要是解析数据、调用LogBuffer->log方法存储日志信息,调用LogReader→notifyNewLog方法通知有新的日志信息,以便发送给其客户端。如下:
bool LogListener::onDataAvailable(SocketClient* cli) { // ... // 1. 调用LogBuffer->log方法存储日志信息 int res = logbuf->log( logId, header->realtime, cred->uid, cred->pid, header->tid, msg, ((size_t)n <= USHRT_MAX) ? (unsigned short)n : USHRT_MAX); // 2. 调用LogReader→notifyNewLog方法通知有新的日志信息,以便发送给其客户端 if (res > 0 && reader != nullptr) { reader->notifyNewLog(static_cast(1 << logId)); } // ... }

继续看LogBuffer的log方法,代码位置:system/core/logd/LogBuffer.cpp
int LogBuffer::log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, const char* msg, unsigned short len) { // ... // 低于当前设定的日志优先级,返回 if (!__android_log_is_loggable_len(prio, tag, tag_len, ANDROID_LOG_VERBOSE)) { // Log traffic received to total wrlock(); stats.addTotal(elem); unlock(); delete elem; return -EACCES; } // 调用重载的log方法 log(elem); unlock(); return len; }

继续log方法,主要作用是通过比对新进日志信息的时间,将其插入到正确的存储位置。所有日志存储在mLogElements变量中,其类型是:typedef std::list
void LogBuffer::log(LogBufferElement* elem) { // 插入正确位置,逻辑相对复杂,摘取其中关键一段 do { last = it; if (__predict_false(it == mLogElements.begin())) { break; } --it; } while (((*it)->getRealTime() > elem->getRealTime()) && (!end_set || (end <= (*it)->getRealTime()))); mLogElements.insert(last, elem); } // ... stats.add(elem); // 初步看做一些统计工作,例如通过数组,统计不同类型日志的打印次数,不同类型日志的字符串总长度等,并且将日志信息以uid, pid, tid, tag等为单位,保存elem信息至不同的hashtable中 maybePrune(elem->getLogId()); }

其中maybePrune方法的作用很重要,当不同类型的log日志size超过最大限制时,会触发对已保存日志信息的裁剪,一次裁剪量约为10%:
void LogBuffer::maybePrune(log_id_t id) { size_t sizes = stats.sizes(id); // 来自LogStatistics->mSizes[id]变量的值,统计不同日志类型的当前日志长度(msg) unsigned long maxSize = log_buffer_size(id); // 取不同日志类型的日志长度最大值 if (sizes > maxSize) { size_t sizeOver = sizes - ((maxSize * 9) / 10); size_t elements = stats.realElements(id); size_t minElements = elements / 100; if (minElements < minPrune) {// minPrune值是4 minElements = minPrune; // minElements默认是全部日志元素数的百分之一,最小值是4 } unsigned long pruneRows = elements * sizeOver / sizes; // 需要裁剪的元素个数,最小值是4个,最大值是256个,正常是总元素的比例:1 - (maxSize/sizes)* 0.9 = 约等于10% if (pruneRows < minElements) { pruneRows = minElements; } if (pruneRows > maxPrune) {// maxPrune值是256 pruneRows = maxPrune; } prune(id, pruneRows); // 如果日志存储已越界,则最终走到prune裁剪函数中处理,pruneRows是需要裁剪的元素个数 } }

重要备注:不同日志类型的日志长度最大值,由上到下取值顺序:
persist.logd.size.* // 例如:persist.logd.size.main、persist.logd.size.radio、persist.logd.size.events、persist.logd.size.system、persist.logd.size.crash、persist.logd.size.stats、persist.logd.size.security、persist.logd.size.kernel
ro.logd.size.* // 例如:ro.logd.size.main、ro.logd.size.radio、ro.logd.size.events、ro.logd.size.system、ro.logd.size.crash、ro.logd.size.stats、ro.logd.size.security、ro.logd.size.kernel
persist.logd.size // 设置APP:开发者选项-日志记录器缓冲区大小,默认256K
ro.logd.size
LOG_BUFFER_MIN_SIZE // 64K,条件是如果ro.config.low_ram是true,表示低内存手机
LOG_BUFFER_SIZE // 256K
另外可以用adb logcat -g命令查看缓冲区大小
具体执行的prune裁剪方法这里没有深究,感兴趣的同学可以看下system/core/logd/LogBuffer.cpp#prune方法,大致思路是:
a. 支持黑/白名单(详见LogWhiteBlackList.cpp,uid + pid。注意:adb logcat -P可设置),白名单中不裁剪
b. 优先裁剪黑名单、打印日志最多的uid,system uid中打印日志最多的pid
至此一次完整的:APP调用Log.v方法打印VERBOSE日志,调用执行过程完毕!




二. Logcat命令行工具 官方定义:
Logcat 是一个命令行工具,用于转储系统消息日志,包括设备抛出错误时的堆栈轨迹,以及从您的应用中使用 Log 类写入的消息。


常用命令: Android|Android Log机制的原理学习
文章图片

代码位置:system/core/logcat/,可执行文件位于:/system/bin/logcat,每次执行adb shell logcat命令后,系统会新起一个logcat进程,用来处理命令,父进程是adbd进程。adb shell logcat命令退出后,进程退出。
logcat进程启动时入口在logcat_main.cpp#main()方法,其中核心android_logcat_run_command方法中调用__logcat方法来解析命令参数,最终通过Socket发送给logd处理等,例如clear命令会通过发送给logd的CommandListener类(logd.control线程)来处理。




三. 参考资料
  1. https://developer.android.com/reference/android/util/Log
  2. https://developer.android.com/studio/command-line/logcat?hl=zh_cn,logcat命令行工具
  3. https://developer.android.com/studio/debug/am-logcat,使用logcat写入和查看日志
  4. http://gityuan.com/2018/01/27/android-log/,Android logd日志原理
  5. https://developer.android.com/studio/command-line/logcat
【Android|Android Log机制的原理学习】



作者:kevin song,2019.10.14于南京建邺区

    推荐阅读