Android LOG系统原理剖析

引言

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

简介

Logcat的级别

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

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命令说明

代码逻辑分析

首先对于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;
        }
    }

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