Merge "liblog: resolve deadlocks" am: 8f8a88cad3

am: 247e22090a

* commit '247e22090ad2f31423c59f97f70420cbee21edf9':
  liblog: resolve deadlocks

include/log/log.h

@@ -614,9 +614,11 @@ typedef enum log_id {
 
 /*
  * Use the per-tag properties "log.tag.<tagname>" to generate a runtime
- * result of non-zero to expose a log.
+ * result of non-zero to expose a log. prio is ANDROID_LOG_VERBOSE to
+ * ANDROID_LOG_FATAL. default_prio if no property. Undefined behavior if
+ * any other value.
  */
-int __android_log_is_loggable(int prio, const char *tag, int def);
+int __android_log_is_loggable(int prio, const char *tag, int default_prio);
 
 int __android_log_error_write(int tag, const char *subTag, int32_t uid, const char *data,
                               uint32_t dataLen);

liblog/fake_log_device.c

@@ -99,6 +99,10 @@ static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER;
 
 static void lock()
 {
+    /*
+     * If we trigger a signal handler in the middle of locked activity and the
+     * signal handler logs a message, we could get into a deadlock state.
+     */
     pthread_mutex_lock(&fakeLogDeviceLock);
 }
 
@@ -106,9 +110,12 @@ static void unlock()
 {
     pthread_mutex_unlock(&fakeLogDeviceLock);
 }
+
 #else   // !defined(_WIN32)
+
 #define lock() ((void)0)
 #define unlock() ((void)0)
+
 #endif  // !defined(_WIN32)
 
 

liblog/log_is_loggable.c

@@ -23,6 +23,22 @@
 
 #include <android/log.h>
 
+static pthread_mutex_t lock_loggable = PTHREAD_MUTEX_INITIALIZER;
+
+static void lock()
+{
+    /*
+     * If we trigger a signal handler in the middle of locked activity and the
+     * signal handler logs a message, we could get into a deadlock state.
+     */
+    pthread_mutex_lock(&lock_loggable);
+}
+
+static void unlock()
+{
+    pthread_mutex_unlock(&lock_loggable);
+}
+
 struct cache {
     const prop_info *pinfo;
     uint32_t serial;
@@ -49,9 +65,7 @@ static void refresh_cache(struct cache *cache, const char *key)
     cache->c = buf[0];
 }
 
-static pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER;
+static int __android_log_level(const char *tag, int default_prio)
-
-static int __android_log_level(const char *tag, int def)
 {
     /* sizeof() is used on this array below */
     static const char log_namespace[] = "persist.log.tag.";
@@ -86,7 +100,7 @@ static int __android_log_level(const char *tag, int def)
 
     strcpy(key, log_namespace);
 
-    pthread_mutex_lock(&lock);
+    lock();
 
     current_global_serial = __system_property_area_serial();
 
@@ -156,7 +170,7 @@ static int __android_log_level(const char *tag, int def)
 
     global_serial = current_global_serial;
 
-    pthread_mutex_unlock(&lock);
+    unlock();
 
     switch (toupper(c)) {
     case 'V': return ANDROID_LOG_VERBOSE;
@@ -168,36 +182,47 @@ static int __android_log_level(const char *tag, int def)
     case 'A': return ANDROID_LOG_FATAL;
     case 'S': return -1; /* ANDROID_LOG_SUPPRESS */
     }
-    return def;
+    return default_prio;
 }
 
-int __android_log_is_loggable(int prio, const char *tag, int def)
+int __android_log_is_loggable(int prio, const char *tag, int default_prio)
 {
-    int logLevel = __android_log_level(tag, def);
+    int logLevel = __android_log_level(tag, default_prio);
     return logLevel >= 0 && prio >= logLevel;
 }
 
+/*
+ * Timestamp state generally remains constant, since a change is
+ * rare, we can accept a trylock failure gracefully. Use a separate
+ * lock from is_loggable to keep contention down b/25563384.
+ */
+static pthread_mutex_t lock_timestamp = PTHREAD_MUTEX_INITIALIZER;
+
 char android_log_timestamp()
 {
     static struct cache r_time_cache = { NULL, -1, 0 };
     static struct cache p_time_cache = { NULL, -1, 0 };
-    static uint32_t serial;
-    uint32_t current_serial;
     char retval;
 
-    pthread_mutex_lock(&lock);
+    if (pthread_mutex_trylock(&lock_timestamp)) {
+        /* We are willing to accept some race in this context */
+        if (!(retval = p_time_cache.c)) {
+            retval = r_time_cache.c;
+        }
+    } else {
+        static uint32_t serial;
+        uint32_t current_serial = __system_property_area_serial();
+        if (current_serial != serial) {
+            refresh_cache(&r_time_cache, "ro.logd.timestamp");
+            refresh_cache(&p_time_cache, "persist.logd.timestamp");
+            serial = current_serial;
+        }
+        if (!(retval = p_time_cache.c)) {
+            retval = r_time_cache.c;
+        }
 
-    current_serial = __system_property_area_serial();
+        pthread_mutex_unlock(&lock_timestamp);
-    if (current_serial != serial) {
-        refresh_cache(&r_time_cache, "ro.logd.timestamp");
-        refresh_cache(&p_time_cache, "persist.logd.timestamp");
-        serial = current_serial;
     }
-    if (!(retval = p_time_cache.c)) {
-        retval = r_time_cache.c;
-    }
-
-    pthread_mutex_unlock(&lock);
 
     return tolower(retval ?: 'r');
 }

liblog/logd_write.c

@@ -54,14 +54,35 @@
 
 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;
-#if !defined(_WIN32)
-static pthread_mutex_t log_init_lock = PTHREAD_MUTEX_INITIALIZER;
-#endif
 
 #ifndef __unused
 #define __unused  __attribute__((__unused__))
 #endif
 
+#if !defined(_WIN32)
+static pthread_mutex_t log_init_lock = PTHREAD_MUTEX_INITIALIZER;
+
+static void lock()
+{
+    /*
+     * If we trigger a signal handler in the middle of locked activity and the
+     * signal handler logs a message, we could get into a deadlock state.
+     */
+    pthread_mutex_lock(&log_init_lock);
+}
+
+static void unlock()
+{
+    pthread_mutex_unlock(&log_init_lock);
+}
+
+#else   /* !defined(_WIN32) */
+
+#define lock() ((void)0)
+#define unlock() ((void)0)
+
+#endif  /* !defined(_WIN32) */
+
 #if FAKE_LOG_DEVICE
 static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 };
 #else
@@ -277,15 +298,11 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr)
     if (ret < 0) {
         ret = -errno;
         if (ret == -ENOTCONN) {
-#if !defined(_WIN32)
+            lock();
-            pthread_mutex_lock(&log_init_lock);
-#endif
             close(logd_fd);
             logd_fd = -1;
             ret = __write_to_log_initialize();
-#if !defined(_WIN32)
+            unlock();
-            pthread_mutex_unlock(&log_init_lock);
-#endif
 
             if (ret < 0) {
                 return ret;
@@ -329,18 +346,14 @@ const char *android_log_id_to_name(log_id_t log_id)
 
 static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr)
 {
-#if !defined(_WIN32)
+    lock();
-    pthread_mutex_lock(&log_init_lock);
-#endif
 
     if (write_to_log == __write_to_log_init) {
         int ret;
 
         ret = __write_to_log_initialize();
         if (ret < 0) {
-#if !defined(_WIN32)
+            unlock();
-            pthread_mutex_unlock(&log_init_lock);
-#endif
 #if (FAKE_LOG_DEVICE == 0)
             if (pstore_fd >= 0) {
                 __write_to_log_daemon(log_id, vec, nr);
@@ -352,9 +365,7 @@ static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr)
         write_to_log = __write_to_log_daemon;
     }
 
-#if !defined(_WIN32)
+    unlock();
-    pthread_mutex_unlock(&log_init_lock);
-#endif
 
     return write_to_log(log_id, vec, nr);
 }