commit b1eb731197f30319423e565ad5282e95f3dba320
author Tom Cherry <tomcherry@google.com> Tue Aug 11 22:15:09 2020 +0000
committer Tom Cherry <tomcherry@google.com> Tue Aug 11 22:15:09 2020 +0000
tree 2749848b50ac62a262485cfe2adbbc875980dc0f
parent 4af349b072f1cf8d2cf3ecaf0987612f2490d530

Revert "liblog: use a blocking socket for sending messages to logd"

This reverts commit 4af349b072f1cf8d2cf3ecaf0987612f2490d530.

Reason for revert: post submit test logs too much fails after this
Bug: 163611679

Change-Id: If9939f3c9864dad67536d0c5481f662b9d07c58e

liblog/logd_writer.cpp

diff --git a/liblog/logd_writer.cpp b/liblog/logd_writer.cpp
index f5d19ca..a230749 100644
--- a/liblog/logd_writer.cpp
+++ b/liblog/logd_writer.cpp
@@ -59,7 +59,8 @@
     return;
   }
 
-  int new_socket = TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0));
+  int new_socket =
+      TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0));
   if (new_socket <= 0) {
     return;
   }
@@ -90,6 +91,8 @@
   struct iovec newVec[nr + headerLength];
   android_log_header_t header;
   size_t i, payloadSize;
+  static atomic_int dropped;
+  static atomic_int droppedSecurity;
 
   GetSocket();
 
@@ -107,7 +110,6 @@
     return 0;
   }
 
-  header.id = logId;
   header.tid = gettid();
   header.realtime.tv_sec = ts->tv_sec;
   header.realtime.tv_nsec = ts->tv_nsec;
@@ -115,6 +117,44 @@
   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;
@@ -128,8 +168,11 @@
     }
   }
 
+  // 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) {
+  if (ret < 0 && errno != EAGAIN) {
     LogdConnect();
 
     ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i));
@@ -139,5 +182,14 @@
     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;
 }