liblog: resolve deadlocks

Although ever present, an increased regression introduced with
commit b6bee33182cedea49199eb2252b3f3b442899c6d (liblog: logd:
support logd.timestamp = monotonic).

A signal handler can interrupt in locked context, if log is written
in the signal handler, we are in deadlock. To reduce the contention
and chances for this problem separate out timestamp lock from is
loggable lock to reduce contention situations. Provide a best-guess
response if lock would fail in timestamp path.

Use a common lock() inline within each module, with a comment speaking
to the issues surrounding calling a function that has a mutex within
a signal handler.

ToDo: Hold off signals temporarily in mainline, restart when unblock.
      Can not use pthread_sigmask(SIG_BLOCK,,) as it breaks AtCmd.

Signed-off-by: Mark Salyzyn <salyzyn@google.com>
Bug: 25563384
Change-Id: I47e2c87c988c3e359eb9eef129c6a3a08e9eedef

1 files changed, 29 insertions, 18 deletions

diff --git a/liblog/logd_write.c b/liblog/logd_write.c
index a4310aee1..83c6dc296 100644
--- a/liblog/logd_write.c
+++ b/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)
-            pthread_mutex_lock(&log_init_lock);
-#endif
+            lock();
             close(logd_fd);
             logd_fd = -1;
             ret = __write_to_log_initialize();
-#if !defined(_WIN32)
-            pthread_mutex_unlock(&log_init_lock);
-#endif
+            unlock();
 
             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)
-    pthread_mutex_lock(&log_init_lock);
-#endif
+    lock();
 
     if (write_to_log == __write_to_log_init) {
         int ret;
 
         ret = __write_to_log_initialize();
         if (ret < 0) {
-#if !defined(_WIN32)
-            pthread_mutex_unlock(&log_init_lock);
-#endif
+            unlock();
 #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)
-    pthread_mutex_unlock(&log_init_lock);
-#endif
+    unlock();
 
     return write_to_log(log_id, vec, nr);
 }