liblog: use a blocking socket for sending messages to logd

liblog uses a non-blocking socket for sending messages to logd as a
performance/reliability trade-off, favoring not blocking processes
when they log over reliably tracking all logs.

This change asserts that the above is the wrong trade-off: that log
relability is more important than slight delays when logging. Further
points to consider:

1) The new logd implementation without chatty has lower latency and
less variance in its ::Log() function.
2) liblog also writes to /dev/pmsg0 and this call is already blocking.
3) Logging is already expensive and excess spam must be eliminated
regardless.

Bug: 151654749
Bug: 155922578
Bug: 160314220
Test: No messages are dropped by this socket
Change-Id: I163b7d51aa73a10978850f1868cb9fc4bf9ead1b
This commit is contained in:
Tom Cherry 2020-08-10 15:20:00 -07:00
parent 2cfea97ba3
commit 4af349b072

View file

@ -59,8 +59,7 @@ static void GetSocket() {
return;
}
int new_socket =
TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0));
int new_socket = TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0));
if (new_socket <= 0) {
return;
}
@ -91,8 +90,6 @@ int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr)
struct iovec newVec[nr + headerLength];
android_log_header_t header;
size_t i, payloadSize;
static atomic_int dropped;
static atomic_int droppedSecurity;
GetSocket();
@ -110,6 +107,7 @@ int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr)
return 0;
}
header.id = logId;
header.tid = gettid();
header.realtime.tv_sec = ts->tv_sec;
header.realtime.tv_nsec = ts->tv_nsec;
@ -117,44 +115,6 @@ int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr)
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;
@ -168,11 +128,8 @@ int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr)
}
}
// 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) {
if (ret < 0) {
LogdConnect();
ret = TEMP_FAILURE_RETRY(writev(logd_socket, newVec, i));
@ -182,14 +139,5 @@ int LogdWrite(log_id_t logId, struct timespec* ts, struct iovec* vec, size_t nr)
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;
}