Log机制
APP打印日志,最简单的是使用Log类(android.util.Log),所以我就从一句简单的log.d开始我的路线。在APP中如果调用Log.d(“test”,“print test”); ,那么可以在Android中使用logcat看到一句我们打印的日志,如下:
01-01 00:03:35.122 2990 3505 D test: print test
那么这个过程是怎么样的呢,简单的看看Log.java
Log 写
Log.java中定义了log的buffer ID
/** @hide */ public static final int LOG_ID_MAIN = 0; 主要使用的类android.util.Log
/** @hide */ public static final int LOG_ID_RADIO = 1; 主要使用的类android.telephony.Rlog
/** @hide */ public static final int LOG_ID_EVENTS = 2; 主要使用的类android.util.EventLog
/** @hide */ public static final int LOG_ID_SYSTEM = 3; 主要使用的类android.util.Slog(hide)
/** @hide */ public static final int LOG_ID_CRASH = 4; 主要使用的类com.andoid.internal.os.RuntimeInit
和libdebugged/utility.cpp
简单的调用流程如下:
调用public static int d(String tag, String msg), 这方法调用的是println_native(LOG_ID_MAIN, DEBUG, tag, msg, tr),传入了一个LOG_ID_MAIN。然后println_native的实现交给了在frameworks/base/core/jni/android_util_Log.cpp中的android_util_Log_println_native
/*
* In class android.util.Log:
* public static native int println_native(int buffer, int priority, String tag, String 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/logger_write.c中(其他一些系统模块,例如debuggered等C++代码都会直接封装或者调用__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);
}
而static int (write_to_log)(log_id_t, struct iovec vec, size_t nr) = __write_to_log_init; 默认调用__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(); //点1
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); //点2
errno = save_errno;
return ret;
}
这个函数中有两个点,先看一下点1,里面为集合__android_log_transport_write设置各类writer,例如logdLoggerWrite,pmsgLoggerWrite等,然后依次调用writer的open方法,logdLoggerWrite#logdOpen方法,如果打开失败,则关闭。简单的看下logdLoggerWrite的实现在system/core/liblog/logd_writer.c中
static int logdOpen() {
...省略
strcpy(un.sun_path, "/dev/socket/logdw");
if (TEMP_FAILURE_RETRY(connect(sock, (struct sockaddr*)&un,
sizeof(struct sockaddr_un))) < 0) {
...省略
}
大概意思就是建立socket连接
然后继续看流程就走到了点2的地方,实际的实现是__write_to_log_daemon,这个函数比较长,看一下关键的几个点
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) {
if (vec[0].iov_len < 4) {
errno = save_errno;
return -EINVAL;
}
ret = __android_log_is_loggable_len(ANDROID_LOG_INFO, tag, len,
ANDROID_LOG_VERBOSE);
if (f) { /* local copy marked for close */
android_closeEventTagMap(f);
}
if (!ret) {
errno = save_errno;
return -EPERM;
}
} else {
/* Validate the incoming tag, tag content can not split across iovec */
char prio = ANDROID_LOG_VERBOSE;
const char* tag = vec[0].iov_base;
size_t len = vec[0].iov_len;
// 变量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,tag就是你Log.d(TAG,“”)一般来说使用方式为
adb shell setprop log.tag.<YOUR_LOG_TAG> <LEVEL>
...
// 以下是核心方法实现
ret = 0;
i = 1 << log_id;
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,对应的就是logdWrite,在之前socket已经open了,同样只看关键的地方,如果不仔细看的话,我是没看出来在哪
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;
}
}
...省略
return ret;
}
以上就是整个调用Log.d整个大概流程
Log 读
下面看一下我们是怎么通过logcat来找到我们通过log.d写的日志的,即Logd的逻辑分析,接收到socket通信传输后的数据
Logd进程是开机时由init进程启动,启动代码参考: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
service logd-reinit /system/bin/logd --reinit
oneshot
disabled
user logd
group logd
writepid /dev/cpuset/system-background/tasks
on fs
write /dev/event-log-tags "# content owned by logd
"
chown logd logd /dev/event-log-tags
chmod 0644 /dev/event-log-tags
进程启动后,入口方法:system/core/logd/main.cpp,其中入口的main方法实现不复杂,主要创建LogBuffer,然后启动5个listener,一般重要的是前三个:LogReader,LogListener,CommandListener,全部继承于SocketListener(system/core/libsysutils),另外还有2个listener:LogAudit(监听NETLINK_AUDIT,与selinux有关),LogKlog。看下main.cpp中的main函数
// Foreground waits for exit of the main persistent threads
// that are started here. The threads are created to manage
// UNIX domain client sockets for writing, reading and
// controlling the user space logger, and for any additional
// logging plugins like auditd and restart control. Additional
// transitory per-client threads are created for each reader.
int main(int argc, char* argv[]) {
// logd is written under the assumption that the timezone is UTC.
// If TZ is not set, persist.sys.timezone is looked up in some time utility
// libc functions, including mktime. It confuses the logd time handling,
// so here explicitly set TZ to UTC, which overrides the property.
setenv("TZ", "UTC", 1);
//......
// LogBuffer,作用:存储所有的日志信息
logBuf = new LogBuffer(times);
// LogReader listens on /dev/socket/logdr. When a client
// connects, log entries in the LogBuffer are written to the client.
//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 listens on /dev/socket/logdw for client
// initiated log messages. New log entries are added to LogBuffer
// and LogReader is notified to send updates to connected clients.
// LogListener监听Socket(/dev/socket/logdw),接收传来的日志信息,写入LogBuffer;同时LogReader将新的日志传给已连接的客户端。线程名:logd.writer
LogListener* swl = new LogListener(logBuf, reader);
// Backlog and /proc/sys/net/unix/max_dgram_qlen set to large value
if (swl->startListener(600)) {
exit(1);
}
// Command listener listens on /dev/socket/logd for incoming logd
// administrative commands.
//CommandListener监听Socket(/dev/socket/logd),作用:接收发来的命令。线程名:logd.control
CommandListener* cl = new CommandListener(logBuf, reader, swl);
if (cl->startListener()) {
exit(1);
}
//......
exit(0);
}
LogListener,startListener 在SocketListener.cpp中实现 startListener ->SocketListener::threadStart->me->runListener()->onDataAvailable然后当有对端进程通过Socket传递过来数据后,onDataAvailable方法被调用(实现在LogListener.cpp中),其中主要是解析数据、调用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<log_mask_t>(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<LogBufferElement*
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是需要裁剪的元素个数
}
}
目前,就是我自己整理的android log系统的一部分流程。
小总结
Android层调用Log/Slog/Rlog中的v/d方法打印log,最终会调用到
system/core/liblog/logger_write.c 中的__android_log_buf_write函数,调用流程如下:
__android_log_buf_write
->write_to_log
->__write_to_log_init
->__write_to_log_initialize
->logdOpen
->__write_to_log_daemon
->logdWrite
log信息最终写到 “/dev/socket/logdw”中,此时logd中的LogListener会监测到有log需写入,当log写入成功后,会通知LogReader将新保存的log传递给logcat等。
在system/core/lodgd/main.cpp文件的main函数中,创建了LogBuffer,LogReader,LogListener和CommandListener四个对象,
- LogBuffer用于管理log;
- LogReader用于将log传递给logcat;
- LogListener用于监听是否有log写入logd;
- CommandListener用于监听是否有命令发送给logd。
log的保存流程如下:
- 创建LogBuffer对象,在classLogBuffer类中,定义了一个list容器,保存了指向LogBufferElement对象的指针,创建LogBuffer对象时在其构造函数中会调用LogBuffer::init()函数初始化各log域,例如main/system/kernel/crash等的大小
- 创建LogListener对象并开始监听
LogListener *swl = newLogListener(logBuf, reader);
// Backlog and /proc/sys/net/unix/max_dgram_qlen set to large value
if(swl->startListener(600)) {
exit(1);
}
- 在startListener函数中创建线程,线程注册函数为SocketListener::threadStart;
- 执行runListener函数,如果socket监听到数据,则执行onDataAvailable函数进行处理;
- 调用logbuf->log(LogBuffer::log),这个函数很重要,新建一个LogBufferElement对象(用于保存log),调用mLogElements.insert将LogBufferElement加入list容器,实现log的保存。
Log使用
Log的buffer size
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
ro.logd.size
LOG_BUFFER_MIN_SIZE // 64K,条件是如果ro.config.low_ram是true,表示低内存手机
LOG_BUFFER_SIZE // 256K
logcat
源码位置system/core/logcat/下
执行adb logcat 即可查看log,通过logcat获取的log,并不完全是按照log分类来打印的,如在KERNEL log中可能存在MAIN log。logcat实现的大部分函数都在logcat/logcat.cpp文件中,其中__logcat函数是最重要的函数,其负责logcat 输入参数的解析以及log的处理。
logcat 最终读取log通过liblog/logd_reader.c 中的logdRead函数实现。此函数负责打开/dev/logdr,并通过socket获取log。
当同时启动6个线程分别获取main/kernel/system/crash/events等log时,由于启动的线程太多,然后就会有多个socket 与server 连接,可能会导致有log丢失。
logcat -h 查看帮助
logcat -b all 查看所有buffer的log,不加参数默认为main,system,crash
logcat -v threadtime 格式化时间方式
logcat -g 查看buffer size
logcat -G 2M 设置buffer size
logcat -r 10240 -n 10 -f xxx.log 一个文件10M,加上xxx.log一共11个文件,达到最大个数后自动替换最老的文件
logcat -s 可以加tag,过滤日志
logcat --pid=xx 指定pid的日志输出
logcat -S 在输出中包含统计信息
logcat -c 清楚日志
logcat -p 查看当前的黑白名单
logcat -P 设置黑白名单
每次执行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线程)来处理。
logcat源码
执行logcat后系统会起一个logcat进程,logcat进程启动时入口在logcat_main.cpp#main()
int main(int argc, char** argv, char** envp) {
android_logcat_context ctx = create_android_logcat();
if (!ctx) return -1;
signal(SIGPIPE, exit);
int retval = android_logcat_run_command(ctx, -1, -1, argc, argv, envp);
int ret = android_logcat_destroy(&ctx);
if (!ret) ret = retval;
return ret;
}
然后调用android_logcat_run_command,android_logcat_run_command的实现在logcat.cpp中(六个参数的函数)
// Can block
int android_logcat_run_command(android_logcat_context ctx,
int output, int error,
int argc, char* const* argv,
char* const* envp) {
android_logcat_context_internal* context = ctx;
context->output_fd = output;
context->error_fd = error;
context->argc = argc;
context->argv = argv;
context->envp = envp;
context->stop = false;
context->thread_stopped = false;
return __logcat(context);
}
一系列参数赋值之后我们看 __logcat 函数,先是判断参数中有没有 “>” 重定向符号,然后一个for循环,在for循环中getopt_long_r Parse argc/argv argument vector
参数都合法的话,就开始解析参数
-r -f -n
我这次重点关注的参数是 -r -f -n这三个参数的配合使用
case 'f':
if ((tail_time == log_time::EPOCH) && !tail_lines) {
tail_time = lastLogTime(optctx.optarg);
}
// redirect output to a file
context->outputFileName = optctx.optarg;
break;
case 'r':
if (!getSizeTArg(optctx.optarg, &context->logRotateSizeKBytes,
1)) {
logcat_panic(context, HELP_TRUE,
"Invalid parameter \"%s\" to -r\n",
optctx.optarg);
goto exit;
}
break;
case 'n':
if (!getSizeTArg(optctx.optarg, &context->maxRotatedLogs, 1)) {
logcat_panic(context, HELP_TRUE,
"Invalid parameter \"%s\" to -n\n",
optctx.optarg);
goto exit;
}
break;
-f 确定outputFileName, -r 确定单个文件大小logRotateSizeKBytes, -n 确定最大Rotate多少个文件maxRotatedLogs
然后确定需要获取的log devices有哪些
if (!context->devices) {
dev = context->devices = new log_device_t("main", false);
context->devCount = 1;
if (android_name_to_log_id("system") == LOG_ID_SYSTEM) {
dev = dev->next = new log_device_t("system", false);
context->devCount++;
}
if (android_name_to_log_id("crash") == LOG_ID_CRASH) {
dev = dev->next = new log_device_t("crash", false);
context->devCount++;
}
}
跳过中间部分,到__logcat 函数最后部分
if (context->printBinary) {
printBinary(context, &log_msg);
} else {
processBuffer(context, dev, &log_msg);
}
context->printBinary是加了 -B参数的时候为1,所以走的是processBuffer
static void processBuffer(android_logcat_context_internal* context,
log_device_t* dev, struct log_msg* buf) {
int bytesWritten = 0;
int err;
AndroidLogEntry entry;
char binaryMsgBuf[1024];
if (dev->binary) {
if (!context->eventTagMap && !context->hasOpenedEventTagMap) {
context->eventTagMap = android_openEventTagMap(nullptr);
context->hasOpenedEventTagMap = true;
}
err = android_log_processBinaryLogBuffer(
&buf->entry_v1, &entry, context->eventTagMap, binaryMsgBuf,
sizeof(binaryMsgBuf));
// printf(">>> pri=%d len=%d msg='%s'\n",
// entry.priority, entry.messageLen, entry.message);
} else {
err = android_log_processLogBuffer(&buf->entry_v1, &entry);
}
if ((err < 0) && !context->debug) return;
if (android_log_shouldPrintLine(
context->logformat, std::string(entry.tag, entry.tagLen).c_str(),
entry.priority)) {
bool match = regexOk(context, entry);
context->printCount += match;
if (match || context->printItAnyways) {
//根据过滤器返回写入的字节数
bytesWritten = android_log_printLogLine(context->logformat,
context->output_fd, &entry);
if (bytesWritten < 0) {
logcat_panic(context, HELP_FALSE, "output error");
return;
}
}
}
context->outByteCount += bytesWritten;
if (context->logRotateSizeKBytes > 0 &&
(context->outByteCount / 1024) >= context->logRotateSizeKBytes) {
rotateLogs(context);
}
}
满足条件的话,就会进入rotateLogs
static void rotateLogs(android_logcat_context_internal* context) {
int err;
// Can't rotate logs if we're not outputting to a file
if (!context->outputFileName) return;
close_output(context); //先close一下
// Compute the maximum number of digits needed to count up to
// maxRotatedLogs in decimal. eg:
// maxRotatedLogs == 30
// -> log10(30) == 1.477
// -> maxRotationCountDigits == 2
int maxRotationCountDigits =
(context->maxRotatedLogs > 0)
? (int)(floor(log10(context->maxRotatedLogs) + 1))
: 0;
for (int i = context->maxRotatedLogs; i > 0; i--) {
std::string file1 = android::base::StringPrintf(
"%s.%.*d", context->outputFileName, maxRotationCountDigits, i);
std::string file0;
if (!(i - 1)) {
file0 = android::base::StringPrintf("%s", context->outputFileName);
} else {
file0 =
android::base::StringPrintf("%s.%.*d", context->outputFileName,
maxRotationCountDigits, i - 1);
}
if (!file0.length() || !file1.length()) {
perror("while rotating log files");
break;
}
err = rename(file0.c_str(), file1.c_str()); //循环rename操作
if (err < 0 && errno != ENOENT) {
perror("while rotating log files");
}
}
context->output_fd = openLogFile(context->outputFileName); //重新打开outputFileName
if (context->output_fd < 0) {
logcat_panic(context, HELP_FALSE, "couldn't open output file");
return;
}
context->output = fdopen(context->output_fd, "web");
if (!context->output) {
logcat_panic(context, HELP_FALSE, "couldn't fdopen output file");
return;
}
if (context->stderr_stdout) {
close_error(context);
context->error = context->output;
context->error_fd = context->output_fd;
}
context->outByteCount = 0; //此次输出的log大小记为0,在之前android_log_printLogLine会根据过滤器返回写入的字节数
}
以上就是-f -r -n 在logcat中如何实现,按照给定的文件个数和单个文件大小来循环输出日志到文件的一个简单流程
目前用到了这些,后续持续更新
1万+

被折叠的 条评论
为什么被折叠?



