Android LOG系统原理剖析

引言

在我们android的开发过程中，最不可少的就是加Log，打印Log的操作。
这样可以帮助我们去查看各个变量，理清楚代码的逻辑。
而Android系统，提供了不同维度，不同层面，不同模块的Log的支持。
本文，将会分析Android Log系统的实现。

简介

Logcat的级别

使用android.util.Log的不同等级，可以在不同的阈值范围内打印出相对应的Log。

方法	描述
v(String,String) (vervbose)	显示全部信息
d(String,String)(debug)	显示调试信息
i(String,String)(information)	显示一般信息
w(String,String)(waning)	显示警告信息
e(String,String)(error)	显示错误信息

logcat缓冲区

android log输出量巨大，特别是通信系统的log。

因此，android把log输出到不同的缓冲区中，目前定义了四个log缓冲区：

1）Radio：输出通信系统的log
2）System：输出系统组件的log
3）Event：输出event模块的log
4）Main：所有java层的log，以及不属于上面3层的log，应用的log都输出到main缓冲区中

其中，默认log输出（不指定缓冲区的情况下）是输出System和Main缓冲区的log

指定缓冲区的命令为：

adb logcat –b radio
adb logcat –b system
adb logcat –b events
adb logcat –b main

Logcat命令说明

参数	描述
-b	加载一个可使用的日志缓冲区供查看，比如event和radio。默认值是main
-c	清除缓冲区中的全部日志并退出（清除完后可以使用-g查看缓冲区）
-d	将缓冲区的log转存到屏幕中然后退出
-f	将log输出到指定的文件中<文件名>.默认为标准输出（stdout）
-g	打印日志缓冲区的大小并退出
-n	设置日志的最大数目，默认值是4，需要和-r选项一起使用
-r	没时输出日志，默认值是16，需要和-f选项一起使用
-s	设置过滤器
-v	设置输出格式的日志消息。默认是短暂的格式。支持的格式列表

代码逻辑分析

首先对于FW来说，主要的接口类是在android.util.Log。
我们可以看一下简单的举例：

    /**
     * Send a {@link #VERBOSE} log message.
     * @param tag Used to identify the source of a log message.  It usually identifies
     *        the class or activity where the log call occurs.
     * @param msg The message you would like logged.
     */
    public static int v(@Nullable String tag, @NonNull String msg) {
        return println_native(LOG_ID_MAIN, VERBOSE, tag, msg);
    }

    /**
     * Send a {@link #VERBOSE} log message and log the exception.
     * @param tag Used to identify the source of a log message.  It usually identifies
     *        the class or activity where the log call occurs.
     * @param msg The message you would like logged.
     * @param tr An exception to log
     */
    public static int v(@Nullable String tag, @Nullable String msg, @Nullable Throwable tr) {
        return printlns(LOG_ID_MAIN, VERBOSE, tag, msg, tr);
    }

    /**
     * Send a {@link #DEBUG} log message.
     * @param tag Used to identify the source of a log message.  It usually identifies
     *        the class or activity where the log call occurs.
     * @param msg The message you would like logged.
     */
    public static int d(@Nullable String tag, @NonNull String msg) {
        return println_native(LOG_ID_MAIN, DEBUG, tag, msg);
    }

    /**
     * Send a {@link #DEBUG} log message and log the exception.
     * @param tag Used to identify the source of a log message.  It usually identifies
     *        the class or activity where the log call occurs.
     * @param msg The message you would like logged.
     * @param tr An exception to log
     */
    public static int d(@Nullable String tag, @Nullable String msg, @Nullable Throwable tr) {
        return printlns(LOG_ID_MAIN, DEBUG, tag, msg, tr);
    }

可以看到，这边不论是Log.v还是Lod.d其实都是对APP层的一层封装，真正的实现其实是printlns，和println_native函数。

println_native函数实现

println_native是一个native的方法，我们估计要去lib中去寻找一下它的影子。

    /** @hide */
    @UnsupportedAppUsage
    public static native int println_native(int bufID, int priority, String tag, String msg);

我们可以在frameworks/base/core/jni/android_util_Log.cpp中，看到相应的封装。

/*
 * JNI registration.
 */
static const JNINativeMethod gMethods[] = {
    /* name, signature, funcPtr */
    { "isLoggable",      "(Ljava/lang/String;I)Z", (void*) android_util_Log_isLoggable },
    { "println_native",  "(IILjava/lang/String;Ljava/lang/String;)I", (void*) android_util_Log_println_native },
    { "logger_entry_max_payload_native",  "()I", (void*) android_util_Log_logger_entry_max_payload_native },
};

println_native的具体实现是在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)
{
    const char* tag = NULL;
    const char* msg = NULL;

    if (msgObj == NULL) {
        jniThrowNullPointerException(env, "println needs a message");
        return -1;
    }

    if (bufID < 0 || bufID >= LOG_ID_MAX) {
        jniThrowNullPointerException(env, "bad bufID");
        return -1;
    }

    if (tagObj != NULL)
        tag = env->GetStringUTFChars(tagObj, NULL);
    msg = env->GetStringUTFChars(msgObj, NULL);

    int res = __android_log_buf_write(bufID, (android_LogPriority)priority, tag, msg);

    if (tag != NULL)
        env->ReleaseStringUTFChars(tagObj, tag);
    env->ReleaseStringUTFChars(msgObj, msg);

    return res;
}

在这边，除了进行一些参数的检查，会继续调用__android_log_buf_write来进行Log的输出。
其他一些系统模块，例如debuggered等C++代码都会直接封装or调用__android_log_buf_write来打印日志。
我们来看下__android_log_buf_write的实现，实现位于system/core/liblog/logger_write.cpp中：

int __android_log_buf_write(int bufID, int prio, const char* tag, const char* msg) {
  ErrnoRestorer errno_restorer;

  if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) {
    return -EPERM;
  }

  __android_log_message log_message = {
      sizeof(__android_log_message), bufID, prio, tag, nullptr, 0, msg};
  __android_log_write_log_message(&log_message);
  return 1;
}

初始化了Log_message的变量，将其往下导入：

void __android_log_write_log_message(__android_log_message* log_message) {
  ErrnoRestorer errno_restorer;

  if (log_message->buffer_id != LOG_ID_DEFAULT && log_message->buffer_id != LOG_ID_MAIN &&
      log_message->buffer_id != LOG_ID_SYSTEM && log_message->buffer_id != LOG_ID_RADIO &&
      log_message->buffer_id != LOG_ID_CRASH) {
    return;
  }

  if (log_message->tag == nullptr) {
    log_message->tag = GetDefaultTag().c_str();
  }

#if __BIONIC__
  if (log_message->priority == ANDROID_LOG_FATAL) {
    android_set_abort_message(log_message->message);
  }
#endif

  logger_function(log_message);
}

Logger_function的实现如下：

#ifdef __ANDROID__
static __android_logger_function logger_function = __android_log_logd_logger;
#else
static __android_logger_function logger_function = __android_log_stderr_logger;
#endif

我们再看下具体的实现：

void __android_log_logd_logger(const struct __android_log_message* log_message) {
  int buffer_id = log_message->buffer_id == LOG_ID_DEFAULT ? LOG_ID_MAIN : log_message->buffer_id;

  struct iovec vec[3];
  vec[0].iov_base =
      const_cast<unsigned char*>(reinterpret_cast<const unsigned char*>(&log_message->priority));
  vec[0].iov_len = 1;
  vec[1].iov_base = const_cast<void*>(static_cast<const void*>(log_message->tag));
  vec[1].iov_len = strlen(log_message->tag) + 1;
  vec[2].iov_base = const_cast<void*>(static_cast<const void*>(log_message->message));
  vec[2].iov_len = strlen(log_message->message) + 1;

  write_to_log(static_cast<log_id_t>(buffer_id), vec, 3);
}

这里的，iov_base，其实就是priority，例如通过Log.v调用过来，这里是2（VERBOSE）。
然后继续去调用write_to_log方法去进行实现。

#ifdef __ANDROID__
static int write_to_log(log_id_t log_id, struct iovec* vec, size_t nr) {
  int ret;
  struct timespec ts;

  if (log_id == LOG_ID_KERNEL) {
    return -EINVAL;
  }

  clock_gettime(android_log_clockid(), &ts);

  if (log_id == LOG_ID_SECURITY) {
    if (vec[0].iov_len < 4) {
      return -EINVAL;
    }

    ret = check_log_uid_permissions();
    if (ret < 0) {
      return ret;
    }
    if (!__android_log_security()) {
      /* If only we could reset downstream logd counter */
      return -EPERM;
    }
  } else if (log_id == LOG_ID_EVENTS || log_id == LOG_ID_STATS) {
    if (vec[0].iov_len < 4) {
      return -EINVAL;
    }
  }

  ret = LogdWrite(log_id, &ts, vec, nr);
  PmsgWrite(log_id, &ts, vec, nr);

  return ret;
}
#else
static int write_to_log(log_id_t, struct iovec*, size_t) {
  // Non-Android text logs should go to __android_log_stderr_logger, not here.
  // Non-Android binary logs are always dropped.
  return 1;
}
#endif

LogWriter的实现为：

int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr) {
  ssize_t ret;
  static const unsigned headerLength = 1;
  struct iovec newVec[nr + headerLength];
  android_log_header_t header;
  size_t i, payloadSize;
  static atomic_int dropped;
  static atomic_int droppedSecurity;

  GetSocket();

  if (logd_socket <= 0) {
    return -EBADF;
  }

  /* logd, after initialization and priv drop */
  if (getuid() == AID_LOGD) {
    /*
     * ignore log messages we send to ourself (logd).
     * Such log messages are often generated by libraries we depend on
     * which use standard Android logging.
     */
    return 0;
  }

  header.tid = gettid();
  header.realtime.tv_sec = ts->tv_sec;
  header.realtime.tv_nsec = ts->tv_nsec;

  newVec[0].iov_base = (unsigned char*)&header;
  newVec[0].iov_len = sizeof(header);

  int32_t snapshot = atomic_exchange_explicit(&droppedSecurity, 0, memory_order_relaxed);
  if (snapshot) {
    android_log_event_int_t buffer;

    header.id = LOG_ID_SECURITY;
    buffer.header.tag = LIBLOG_LOG_TAG;
    buffer.payload.type = EVENT_TYPE_INT;
    buffer.payload.data = snapshot;

    newVec[headerLength].iov_base = &buffer;
    newVec[headerLength].iov_len = sizeof(buffer);

    ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, 2));
    if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) {
      atomic_fetch_add_explicit(&droppedSecurity, snapshot, memory_order_relaxed);
    }
  }
  snapshot = atomic_exchange_explicit(&dropped, 0, memory_order_relaxed);
  if (snapshot && __android_log_is_loggable_len(ANDROID_LOG_INFO, "liblog", strlen("liblog"),
                                                ANDROID_LOG_VERBOSE)) {
    android_log_event_int_t buffer;

    header.id = LOG_ID_EVENTS;
    buffer.header.tag = LIBLOG_LOG_TAG;
    buffer.payload.type = EVENT_TYPE_INT;
    buffer.payload.data = snapshot;

    newVec[headerLength].iov_base = &buffer;
    newVec[headerLength].iov_len = sizeof(buffer);

    ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, 2));
    if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) {
      atomic_fetch_add_explicit(&dropped, snapshot, memory_order_relaxed);
    }
  }

  header.id = logId;

  for (payloadSize = 0, i = headerLength; i < nr + headerLength; i++) {
    newVec[i].iov_base = vec[i - headerLength].iov_base;
    payloadSize += newVec[i].iov_len = vec[i - headerLength].iov_len;

    if (payloadSize > LOGGER_ENTRY_MAX_PAYLOAD) {
      newVec[i].iov_len -= payloadSize - LOGGER_ENTRY_MAX_PAYLOAD;
      if (newVec[i].iov_len) {
        ++i;
      }
      break;
    }
  }

  // The write below could be lost, but will never block.
  // EAGAIN occurs if logd is overloaded, other errors indicate that something went wrong with
  // the connection, so we reset it and try again.
  ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i));
  if (ret < 0 && errno != EAGAIN) {
    LogdConnect();

    ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i));
  }

  if (ret < 0) {
    ret = -errno;
  }

  if (ret > (ssize_t)sizeof(header)) {
    ret -= sizeof(header);
  } else if (ret < 0) {
    atomic_fetch_add_explicit(&dropped, 1, memory_order_relaxed);
    if (logId == LOG_ID_SECURITY) {
      atomic_fetch_add_explicit(&droppedSecurity, 1, memory_order_relaxed);
    }
  }

  return ret;
}

我们从这个函数可以看到，这边其实执行的就是socket的操作。
但是socket操作是怎么初始化和建立的呢？我们稍后进行分析。

printlns函数实现

    /**
     * Helper function for long messages. Uses the LineBreakBufferedWriter to break
     * up long messages and stacktraces along newlines, but tries to write in large
     * chunks. This is to avoid truncation.
     * @hide
     */
    public static int printlns(int bufID, int priority, @Nullable String tag, @NonNull String msg,
            @Nullable Throwable tr) {
        ImmediateLogWriter logWriter = new ImmediateLogWriter(bufID, priority, tag);
        // Acceptable buffer size. Get the native buffer size, subtract two zero terminators,
        // and the length of the tag.
        // Note: we implicitly accept possible truncation for Modified-UTF8 differences. It
        //       is too expensive to compute that ahead of time.
        int bufferSize = PreloadHolder.LOGGER_ENTRY_MAX_PAYLOAD    // Base.
                - 2                                                // Two terminators.
                - (tag != null ? tag.length() : 0)                 // Tag length.
                - 32;                                              // Some slack.
        // At least assume you can print *some* characters (tag is not too large).
        bufferSize = Math.max(bufferSize, 100);

        LineBreakBufferedWriter lbbw = new LineBreakBufferedWriter(logWriter, bufferSize);

        lbbw.println(msg);

        if (tr != null) {
            // This is to reduce the amount of log spew that apps do in the non-error
            // condition of the network being unavailable.
            Throwable t = tr;
            while (t != null) {
                if (t instanceof UnknownHostException) {
                    break;
                }
                if (t instanceof DeadSystemException) {
                    lbbw.println("DeadSystemException: The system died; "
                            + "earlier logs will point to the root cause");
                    break;
                }
                t = t.getCause();
            }
            if (t == null) {
                tr.printStackTrace(lbbw);
            }
        }

        lbbw.flush();

        return logWriter.getWritten();
    }

首先看一下ImmediateLogWriter的封装, 这个类是一个内部的静态类，主要是初始化一些变量和方法。

    /**
     * Helper class to write to the logcat. Different from LogWriter, this writes
     * the whole given buffer and does not break along newlines.
     */
    private static class ImmediateLogWriter extends Writer {

        private int bufID;
        private int priority;
        private String tag;

        private int written = 0;

        /**
         * Create a writer that immediately writes to the log, using the given
         * parameters.
         */
        public ImmediateLogWriter(int bufID, int priority, String tag) {
            this.bufID = bufID;
            this.priority = priority;
            this.tag = tag;
        }

        public int getWritten() {
            return written;
        }

        @Override
        public void write(char[] cbuf, int off, int len) {
            // Note: using String here has a bit of overhead as a Java object is created,
            //       but using the char[] directly is not easier, as it needs to be translated
            //       to a C char[] for logging.
            written += println_native(bufID, priority, tag, new String(cbuf, off, len));
        }

        @Override
        public void flush() {
            // Ignored.
        }

        @Override
        public void close() {
            // Ignored.
        }
    }

然后在设置了buffersize的大小后，将其传入LineBreakBufferedWriter进行初始化。
LineBreakBufferedWriter类的声明如下：

/**
 * A writer that breaks up its output into chunks before writing to its out writer,
 * and which is linebreak aware, i.e., chunks will created along line breaks, if
 * possible.
 *
 * Note: this class is not thread-safe.
 */
public class LineBreakBufferedWriter extends PrintWriter {
}

接下来就会调用lbbw.println(msg)的方法。

    @Override
    public void println() {
        write(lineSeparator);
    }

这边主要是write的实现：

    @Override
    public void write(int c) {
        if (bufferIndex < buffer.length) {
            buffer[bufferIndex] = (char)c;
            bufferIndex++;
            if ((char)c == '\n') {
                lastNewline = bufferIndex;
            }
        } else {
            // This should be an uncommon case, we mostly expect char[] and String. So
            // let the chunking be handled by the char[] case.
            write(new char[] { (char)c }, 0 ,1);
        }
    }

这边的简单封装以后，就会继续调用write的方法：

    @Override
    public void write(char[] buf, int off, int len) {
        while (bufferIndex + len > bufferSize) {
            // Find the next newline in the buffer, see if that's below the limit.
            // Repeat.
            int nextNewLine = -1;
            int maxLength = bufferSize - bufferIndex;
            for (int i = 0; i < maxLength; i++) {
                if (buf[off + i] == '\n') {
                    if (bufferIndex + i < bufferSize) {
                        nextNewLine = i;
                    } else {
                        break;
                    }
                }
            }

            if (nextNewLine != -1) {
                // We can add some more data.
                appendToBuffer(buf, off, nextNewLine);
                writeBuffer(bufferIndex);
                bufferIndex = 0;
                lastNewline = -1;
                off += nextNewLine + 1;
                len -= nextNewLine + 1;
            } else if (lastNewline != -1) {
                // Use the last newline.
                writeBuffer(lastNewline);
                removeFromBuffer(lastNewline + 1);
                lastNewline = -1;
            } else {
                // OK, there was no newline, break at a full buffer.
                int rest = bufferSize - bufferIndex;
                appendToBuffer(buf, off, rest);
                writeBuffer(bufferIndex);
                bufferIndex = 0;
                off += rest;
                len -= rest;
            }
        }

        // Add to the buffer, this will fit.
        if (len > 0) {
            // Add the chars, find the last newline.
            appendToBuffer(buf, off, len);
            for (int i = len - 1; i >= 0; i--) {
                if (buf[off + i] == '\n') {
                    lastNewline = bufferIndex - len + i;
                    break;
                }
            }
        }
    }

这边的writeBuffer主要的实现为：

    /**
     * Helper method, write the given part of the buffer, [start,length), to the output.
     * @param length The number of characters to flush.
     */
    private void writeBuffer(int length) {
        if (length > 0) {
            super.write(buffer, 0, length);
        }
    }

父类的实现为：

    /*
     * Exception-catching, synchronized output operations,
     * which also implement the write() methods of Writer
     */

    /**
     * Writes a single character.
     * @param c int specifying a character to be written.
     */
    public void write(int c) {
        try {
            synchronized (lock) {
                ensureOpen();
                out.write(c);
            }
        }
        catch (InterruptedIOException x) {
            Thread.currentThread().interrupt();
        }
        catch (IOException x) {
            trouble = true;
        }
    }

而这边，就会去判断是不是有中端的发生。