When analyzing the logcat data from Android devices, I found that sometimes the log line get truncated, especially when it's quite long. This causes trouble because the logged information are in JSON format, which gets broken after (even one character) truncated. In this post, I'll explain how did the truncation happen, and how to fix it.
Android Logging
This page gives an detailed explanation of Android logging system. In short, three parts are working together to make Android logcat work.
loggerdevice driver in kernel (kernel/drivers/stagging/android). Which serves read/write request from user space and also buffer the log content.android.util.Logclass (framework/base/core/java/android/util/Log.java), a Java wrapper to write tologgerdevice.logcat(system/core/log), a native tool to read logs fromloggerdevice.
Truncating
Let's follow the flow when Log.v is called with a log message, and find out
who truncated the log message (if it's too long).
In framework/base/core/java/android/util/Log.java, when Log.v is called, it
just call the native method called println_native with to extra arguments,
LOG_ID_MAIN and VERBOSE. The first specify the log device to write to, and
the second tells the log level.
In println_native, defined in framework/base/core/jni/android_util_Log.cpp,
it just calls the function named __android_log_buf_write. So far, nobody
changed the log message yet.
__android_log_buf_write is defined in system/core/liblog/logd_write.c, it
first detect a few special tags to redirect them to radio log device, and then
it packs the log message in to struct iovec data structures and passes them on
to write_to_log, which is initialized as _write_to_log_kernel. Eventually,
these iovec go to writev in system/core/liblog/uio.c, which call syscall
write on the log device.
Thus, log line content is still sane before entering kernel space.
Next, the write request will be directed to logger_aio_write function defined
in kernel/drivers/staging/android/logger.c. One line (462) raised my
attention:
header.len = min_t(size_t, iocb->ki_left, LOGGER_ENTRY_MAX_PAYLOAD);
This is where the truncating happens!
How to Fix
LOGGER_ENTRY_MAX_PAYLOAD is defined in
kernel/drivers/stagging/android/logger.h as 4076, which I guess is
(4096-20), where 20 is the log header structure size.
We can not actually eliminate truncating completely, the buffer size is limited after all. But we can enlarge the payload limit a bit to prevent some unnecessary truncating. I changed it to 65516 (65536-20), which should be large enough.
Also, logger device maintains a ring buffer for each log device, which are
defined in kernel/drivers/stagging/android/logger.c. The default buffer size
is 256K. I changed the buffer size for main device to 4MB, while leave
others unchanged. (I also tried 32MB, yet apparently it's far too large and the
kernel refused to boot up.)
UPDATE
To make Android logcat tool working properly, we'll also need to modify
system/core/include/log/logger.h in AOSP source tree, which is a mirror to the
logger.h in kernel. LOGGER_ENTRY_MAX_PAYLOAD needs to be the same with the
one in kernel, and LOGGER_ENTRY_MAX_LEN needs to be a bit larger than
LOGGER_ENTRY_MAX_PAYLOAD. In my case, I set the former to 65516 and latter to
(64*1024).