diff --git a/liblog/logd_reader.c b/liblog/logd_reader.c index 563b5c750..71ff0752a 100644 --- a/liblog/logd_reader.c +++ b/liblog/logd_reader.c @@ -482,17 +482,17 @@ static int logdOpen(struct android_log_logger_list *logger_list, struct sigaction old_sigaction; unsigned int old_alarm = 0; char buffer[256], *cp, c; - int e, ret, remaining; - - int sock = transp->context.sock; - if (sock > 0) { - return sock; - } + int e, ret, remaining, sock; if (!logger_list) { return -EINVAL; } + sock = atomic_load(&transp->context.sock); + if (sock > 0) { + return sock; + } + sock = socket_local_client("logdr", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET); @@ -587,7 +587,11 @@ static int logdOpen(struct android_log_logger_list *logger_list, return ret; } - return transp->context.sock = sock; + ret = atomic_exchange(&transp->context.sock, sock); + if ((ret > 0) && (ret != sock)) { + close(ret); + } + return sock; } /* Read from the selected logs */ @@ -662,8 +666,8 @@ static int logdPoll(struct android_log_logger_list *logger_list, static void logdClose(struct android_log_logger_list *logger_list __unused, struct android_log_transport_context *transp) { - if (transp->context.sock > 0) { - close (transp->context.sock); - transp->context.sock = -1; + int sock = atomic_exchange(&transp->context.sock, -1); + if (sock > 0) { + close (sock); } } diff --git a/liblog/logd_writer.c b/liblog/logd_writer.c index e8e392d24..2913507c2 100644 --- a/liblog/logd_writer.c +++ b/liblog/logd_writer.c @@ -31,7 +31,6 @@ #include #include -#include #include #include #include @@ -65,7 +64,8 @@ static int logdOpen() { int i, ret = 0; - if (logdLoggerWrite.context.sock < 0) { + i = atomic_load(&logdLoggerWrite.context.sock); + if (i < 0) { i = TEMP_FAILURE_RETRY(socket(PF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0)); if (i < 0) { ret = -errno; @@ -80,7 +80,11 @@ static int logdOpen() ret = -errno; close(i); } else { - logdLoggerWrite.context.sock = i; + ret = atomic_exchange(&logdLoggerWrite.context.sock, i); + if ((ret >= 0) && (ret != i)) { + close(ret); + } + ret = 0; } } } @@ -90,9 +94,9 @@ static int logdOpen() static void logdClose() { - if (logdLoggerWrite.context.sock >= 0) { - close(logdLoggerWrite.context.sock); - logdLoggerWrite.context.sock = -1; + int sock = atomic_exchange(&logdLoggerWrite.context.sock, -1); + if (sock >= 0) { + close(sock); } } @@ -101,7 +105,7 @@ static int logdAvailable(log_id_t logId) if (logId > LOG_ID_SECURITY) { return -EINVAL; } - if (logdLoggerWrite.context.sock < 0) { + if (atomic_load(&logdLoggerWrite.context.sock) < 0) { if (access("/dev/socket/logdw", W_OK) == 0) { return 0; } @@ -121,7 +125,7 @@ static int logdWrite(log_id_t logId, struct timespec *ts, static atomic_int_fast32_t dropped; static atomic_int_fast32_t droppedSecurity; - if (logdLoggerWrite.context.sock < 0) { + if (atomic_load(&logdLoggerWrite.context.sock) < 0) { return -EBADF; } @@ -160,7 +164,7 @@ static int logdWrite(log_id_t logId, struct timespec *ts, newVec[0].iov_base = (unsigned char *)&header; newVec[0].iov_len = sizeof(header); - if (logdLoggerWrite.context.sock > 0) { + if (atomic_load(&logdLoggerWrite.context.sock) > 0) { int32_t snapshot = atomic_exchange_explicit(&droppedSecurity, 0, memory_order_relaxed); if (snapshot) { @@ -174,7 +178,8 @@ static int logdWrite(log_id_t logId, struct timespec *ts, newVec[headerLength].iov_base = &buffer; newVec[headerLength].iov_len = sizeof(buffer); - ret = TEMP_FAILURE_RETRY(writev(logdLoggerWrite.context.sock, newVec, 2)); + ret = TEMP_FAILURE_RETRY(writev( + atomic_load(&logdLoggerWrite.context.sock), newVec, 2)); if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) { atomic_fetch_add_explicit(&droppedSecurity, snapshot, memory_order_relaxed); @@ -194,7 +199,8 @@ static int logdWrite(log_id_t logId, struct timespec *ts, newVec[headerLength].iov_base = &buffer; newVec[headerLength].iov_len = sizeof(buffer); - ret = TEMP_FAILURE_RETRY(writev(logdLoggerWrite.context.sock, newVec, 2)); + ret = TEMP_FAILURE_RETRY(writev( + atomic_load(&logdLoggerWrite.context.sock), newVec, 2)); if (ret != (ssize_t)(sizeof(header) + sizeof(buffer))) { atomic_fetch_add_explicit(&dropped, snapshot, memory_order_relaxed); @@ -223,7 +229,8 @@ static int logdWrite(log_id_t logId, struct timespec *ts, * ENOTCONN occurs if logd dies. * EAGAIN occurs if logd is overloaded. */ - ret = TEMP_FAILURE_RETRY(writev(logdLoggerWrite.context.sock, newVec, i)); + ret = TEMP_FAILURE_RETRY(writev( + atomic_load(&logdLoggerWrite.context.sock), newVec, i)); if (ret < 0) { ret = -errno; if (ret == -ENOTCONN) { @@ -236,7 +243,8 @@ static int logdWrite(log_id_t logId, struct timespec *ts, return ret; } - ret = TEMP_FAILURE_RETRY(writev(logdLoggerWrite.context.sock, newVec, i)); + ret = TEMP_FAILURE_RETRY(writev( + atomic_load(&logdLoggerWrite.context.sock), newVec, i)); if (ret < 0) { ret = -errno; } diff --git a/liblog/logger.h b/liblog/logger.h index 8fb2b4d47..d4f243ab2 100644 --- a/liblog/logger.h +++ b/liblog/logger.h @@ -17,6 +17,7 @@ #ifndef _LIBLOG_LOGGER_H__ #define _LIBLOG_LOGGER_H__ +#include #include #include @@ -31,9 +32,10 @@ __BEGIN_DECLS /* Union, sock or fd of zero is not allowed unless static initialized */ union android_log_context { void *private; - int sock; - int fd; + atomic_int sock; + atomic_int fd; struct listnode *node; + atomic_uintptr_t atomic_pointer; }; struct android_log_transport_write { diff --git a/liblog/pmsg_reader.c b/liblog/pmsg_reader.c index 679c15957..a0a69c189 100644 --- a/liblog/pmsg_reader.c +++ b/liblog/pmsg_reader.c @@ -151,8 +151,8 @@ static int pmsgRead(struct android_log_logger_list *logger_list, memset(log_msg, 0, sizeof(*log_msg)); - if (transp->context.fd <= 0) { - int fd = open("/sys/fs/pstore/pmsg-ramoops-0", O_RDONLY | O_CLOEXEC); + if (atomic_load(&transp->context.fd) <= 0) { + int i, fd = open("/sys/fs/pstore/pmsg-ramoops-0", O_RDONLY | O_CLOEXEC); if (fd < 0) { return -errno; @@ -164,13 +164,22 @@ static int pmsgRead(struct android_log_logger_list *logger_list, return -errno; } } - transp->context.fd = fd; + i = atomic_exchange(&transp->context.fd, fd); + if ((i > 0) && (i != fd)) { + close(i); + } preread_count = 0; } while(1) { + int fd; + if (preread_count < sizeof(buf)) { - ret = TEMP_FAILURE_RETRY(read(transp->context.fd, + fd = atomic_load(&transp->context.fd); + if (fd <= 0) { + return -EBADF; + } + ret = TEMP_FAILURE_RETRY(read(fd, &buf.p.magic + preread_count, sizeof(buf) - preread_count)); if (ret < 0) { @@ -212,9 +221,13 @@ static int pmsgRead(struct android_log_logger_list *logger_list, log_msg->entry_v4.msg : log_msg->entry_v3.msg; *msg = buf.prio; - ret = TEMP_FAILURE_RETRY(read(transp->context.fd, - msg + sizeof(buf.prio), - buf.p.len - sizeof(buf))); + fd = atomic_load(&transp->context.fd); + if (fd <= 0) { + return -EBADF; + } + ret = TEMP_FAILURE_RETRY(read(fd, + msg + sizeof(buf.prio), + buf.p.len - sizeof(buf))); if (ret < 0) { return -errno; } @@ -239,12 +252,19 @@ static int pmsgRead(struct android_log_logger_list *logger_list, } } - current = TEMP_FAILURE_RETRY(lseek(transp->context.fd, - (off_t)0, SEEK_CUR)); + fd = atomic_load(&transp->context.fd); + if (fd <= 0) { + return -EBADF; + } + current = TEMP_FAILURE_RETRY(lseek(fd, (off_t)0, SEEK_CUR)); if (current < 0) { return -errno; } - next = TEMP_FAILURE_RETRY(lseek(transp->context.fd, + fd = atomic_load(&transp->context.fd); + if (fd <= 0) { + return -EBADF; + } + next = TEMP_FAILURE_RETRY(lseek(fd, (off_t)(buf.p.len - sizeof(buf)), SEEK_CUR)); if (next < 0) { @@ -258,10 +278,10 @@ static int pmsgRead(struct android_log_logger_list *logger_list, static void pmsgClose(struct android_log_logger_list *logger_list __unused, struct android_log_transport_context *transp) { - if (transp->context.fd > 0) { - close (transp->context.fd); + int fd = atomic_exchange(&transp->context.fd, 0); + if (fd > 0) { + close (fd); } - transp->context.fd = 0; } LIBLOG_ABI_PRIVATE ssize_t __android_log_pmsg_file_read( diff --git a/liblog/pmsg_writer.c b/liblog/pmsg_writer.c index 06652f3c1..b3c4a1a04 100644 --- a/liblog/pmsg_writer.c +++ b/liblog/pmsg_writer.c @@ -20,6 +20,7 @@ #include #include +#include #include #include #include @@ -53,18 +54,25 @@ LIBLOG_HIDDEN struct android_log_transport_write pmsgLoggerWrite = { static int pmsgOpen() { - if (pmsgLoggerWrite.context.fd < 0) { - pmsgLoggerWrite.context.fd = TEMP_FAILURE_RETRY(open("/dev/pmsg0", O_WRONLY | O_CLOEXEC)); + int fd = atomic_load(&pmsgLoggerWrite.context.fd); + if (fd < 0) { + int i; + + fd = TEMP_FAILURE_RETRY(open("/dev/pmsg0", O_WRONLY | O_CLOEXEC)); + i = atomic_exchange(&pmsgLoggerWrite.context.fd, fd); + if ((i >= 0) && (i != fd)) { + close(i); + } } - return pmsgLoggerWrite.context.fd; + return fd; } static void pmsgClose() { - if (pmsgLoggerWrite.context.fd >= 0) { - close(pmsgLoggerWrite.context.fd); - pmsgLoggerWrite.context.fd = -1; + int fd = atomic_exchange(&pmsgLoggerWrite.context.fd, -1); + if (fd >= 0) { + close(fd); } } @@ -78,7 +86,7 @@ static int pmsgAvailable(log_id_t logId) !__android_log_is_debuggable()) { return -EINVAL; } - if (pmsgLoggerWrite.context.fd < 0) { + if (atomic_load(&pmsgLoggerWrite.context.fd) < 0) { if (access("/dev/pmsg0", W_OK) == 0) { return 0; } @@ -115,7 +123,7 @@ static int pmsgWrite(log_id_t logId, struct timespec *ts, } } - if (pmsgLoggerWrite.context.fd < 0) { + if (atomic_load(&pmsgLoggerWrite.context.fd) < 0) { return -EBADF; } @@ -169,7 +177,8 @@ static int pmsgWrite(log_id_t logId, struct timespec *ts, } pmsgHeader.len += payloadSize; - ret = TEMP_FAILURE_RETRY(writev(pmsgLoggerWrite.context.fd, newVec, i)); + ret = TEMP_FAILURE_RETRY(writev(atomic_load(&pmsgLoggerWrite.context.fd), + newVec, i)); if (ret < 0) { ret = errno ? -errno : -ENOTCONN; } @@ -206,7 +215,7 @@ LIBLOG_ABI_PRIVATE ssize_t __android_log_pmsg_file_write( char prio, const char *filename, const char *buf, size_t len) { - int fd; + bool weOpened; size_t length, packet_len; const char *tag; char *cp, *slash; @@ -228,16 +237,6 @@ LIBLOG_ABI_PRIVATE ssize_t __android_log_pmsg_file_write( return -ENOMEM; } - fd = pmsgLoggerWrite.context.fd; - if (fd < 0) { - __android_log_lock(); - fd = pmsgOpen(); - __android_log_unlock(); - if (fd < 0) { - return -EBADF; - } - } - tag = cp; slash = strrchr(cp, '/'); if (slash) { @@ -256,6 +255,7 @@ LIBLOG_ABI_PRIVATE ssize_t __android_log_pmsg_file_write( vec[1].iov_base = (unsigned char *)tag; vec[1].iov_len = length; + weOpened = false; for (ts.tv_nsec = 0, length = len; length; ts.tv_nsec += ANDROID_LOG_PMSG_FILE_SEQUENCE) { @@ -279,15 +279,36 @@ LIBLOG_ABI_PRIVATE ssize_t __android_log_pmsg_file_write( vec[2].iov_base = (unsigned char *)buf; vec[2].iov_len = transfer; + if (atomic_load(&pmsgLoggerWrite.context.fd) < 0) { + if (!weOpened) { /* Impossible for weOpened = true here */ + __android_log_lock(); + } + weOpened = atomic_load(&pmsgLoggerWrite.context.fd) < 0; + if (!weOpened) { + __android_log_unlock(); + } else if (pmsgOpen() < 0) { + __android_log_unlock(); + return -EBADF; + } + } + ret = pmsgWrite(logId, &ts, vec, sizeof(vec) / sizeof(vec[0])); if (ret <= 0) { + if (weOpened) { + pmsgClose(); + __android_log_unlock(); + } free(cp); - return ret; + return ret ? ret : (len - length); } length -= transfer; buf += transfer; } + if (weOpened) { + pmsgClose(); + __android_log_unlock(); + } free(cp); return len; } diff --git a/liblog/tests/liblog_test.cpp b/liblog/tests/liblog_test.cpp index b1dae9ebe..7db048d20 100644 --- a/liblog/tests/liblog_test.cpp +++ b/liblog/tests/liblog_test.cpp @@ -20,6 +20,7 @@ #include #include #include +#include #include #include #include @@ -129,6 +130,70 @@ TEST(liblog, concurrent_name(__android_log_buf_print, NUM_CONCURRENT)) { ASSERT_LT(0, ret); } +std::string popenToString(std::string command) { + std::string ret; + + FILE* fp = popen(command.c_str(), "r"); + if (fp) { + if (!android::base::ReadFdToString(fileno(fp), &ret)) ret = ""; + pclose(fp); + } + return ret; +} + +static bool isPmsgActive() { + pid_t pid = getpid(); + + std::string myPidFds = popenToString(android::base::StringPrintf( + "ls -l /proc/%d/fd", pid)); + if (myPidFds.length() == 0) return true; // guess it is? + + return std::string::npos != myPidFds.find(" -> /dev/pmsg0"); +} + +static bool isLogdwActive() { + std::string logdwSignature = popenToString( + "grep /dev/socket/logdw /proc/net/unix"); + size_t beginning = logdwSignature.find(" "); + if (beginning == std::string::npos) return true; + beginning = logdwSignature.find(" ", beginning + 1); + if (beginning == std::string::npos) return true; + size_t end = logdwSignature.find(" ", beginning + 1); + if (end == std::string::npos) return true; + end = logdwSignature.find(" ", end + 1); + if (end == std::string::npos) return true; + end = logdwSignature.find(" ", end + 1); + if (end == std::string::npos) return true; + end = logdwSignature.find(" ", end + 1); + if (end == std::string::npos) return true; + std::string allLogdwEndpoints = popenToString( + "grep ' 00000002" + + logdwSignature.substr(beginning, end - beginning) + + " ' /proc/net/unix | " + + "sed -n 's/.* \\([0-9][0-9]*\\)$/ -> socket:[\\1]/p'"); + if (allLogdwEndpoints.length() == 0) return true; + + // NB: allLogdwEndpoints has some false positives in it, but those + // strangers do not overlap with the simplistic activities inside this + // test suite. + + pid_t pid = getpid(); + + std::string myPidFds = popenToString(android::base::StringPrintf( + "ls -l /proc/%d/fd", pid)); + if (myPidFds.length() == 0) return true; + + // NB: fgrep with multiple strings is broken in Android + for (beginning = 0; + (end = allLogdwEndpoints.find("\n", beginning)) != std::string::npos; + beginning = end + 1) { + if (myPidFds.find(allLogdwEndpoints.substr(beginning, + end - beginning)) != + std::string::npos) return true; + } + return false; +} + TEST(liblog, __android_log_btwrite__android_logger_list_read) { struct logger_list *logger_list; @@ -140,10 +205,22 @@ TEST(liblog, __android_log_btwrite__android_logger_list_read) { // Check that we can close and reopen the logger log_time ts(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts, sizeof(ts))); + bool pmsgActiveAfter__android_log_btwrite = isPmsgActive(); + bool logdwActiveAfter__android_log_btwrite = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); + EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); __android_log_close(); + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); log_time ts1(CLOCK_MONOTONIC); ASSERT_LT(0, __android_log_btwrite(0, EVENT_TYPE_LONG, &ts1, sizeof(ts1))); + pmsgActiveAfter__android_log_btwrite = isPmsgActive(); + logdwActiveAfter__android_log_btwrite = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_btwrite); + EXPECT_TRUE(logdwActiveAfter__android_log_btwrite); usleep(1000000); int count = 0; @@ -2575,12 +2652,35 @@ static const char __pmsg_file[] = "/data/william-shakespeare/MuchAdoAboutNothing.txt"; TEST(liblog, __android_log_pmsg_file_write) { + __android_log_close(); + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); EXPECT_LT(0, __android_log_pmsg_file_write( LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, max_payload_buf, sizeof(max_payload_buf))); fprintf(stderr, "Reboot, ensure file %s matches\n" "with liblog.__android_log_msg_file_read test\n", __pmsg_file); + bool pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); + bool logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_pmsg_file_write); + EXPECT_FALSE(logdwActiveAfter__android_pmsg_file_write); + EXPECT_LT(0, __android_log_buf_print(LOG_ID_MAIN, ANDROID_LOG_INFO, + "TEST__android_log_pmsg_file_write", + "main")); + bool pmsgActiveAfter__android_log_buf_print = isPmsgActive(); + bool logdwActiveAfter__android_log_buf_print = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_log_buf_print); + EXPECT_TRUE(logdwActiveAfter__android_log_buf_print); + EXPECT_LT(0, __android_log_pmsg_file_write( + LOG_ID_CRASH, ANDROID_LOG_VERBOSE, + __pmsg_file, max_payload_buf, sizeof(max_payload_buf))); + pmsgActiveAfter__android_pmsg_file_write = isPmsgActive(); + logdwActiveAfter__android_pmsg_file_write = isLogdwActive(); + EXPECT_TRUE(pmsgActiveAfter__android_pmsg_file_write); + EXPECT_TRUE(logdwActiveAfter__android_pmsg_file_write); } ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, @@ -2597,7 +2697,7 @@ ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, strcmp(max_payload_buf, buf)) { fprintf(stderr, "comparison fails on content \"%s\"\n", buf); } - return !arg || + return arg || (LOG_ID_CRASH != logId) || (ANDROID_LOG_VERBOSE != prio) || !strstr(__pmsg_file, filename) || @@ -2608,10 +2708,21 @@ ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, TEST(liblog, __android_log_pmsg_file_read) { signaled = 0; + __android_log_close(); + bool pmsgActiveAfter__android_log_close = isPmsgActive(); + bool logdwActiveAfter__android_log_close = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_close); + EXPECT_FALSE(logdwActiveAfter__android_log_close); + ssize_t ret = __android_log_pmsg_file_read( LOG_ID_CRASH, ANDROID_LOG_VERBOSE, __pmsg_file, __pmsg_fn, NULL); + bool pmsgActiveAfter__android_log_pmsg_file_read = isPmsgActive(); + bool logdwActiveAfter__android_log_pmsg_file_read = isLogdwActive(); + EXPECT_FALSE(pmsgActiveAfter__android_log_pmsg_file_read); + EXPECT_FALSE(logdwActiveAfter__android_log_pmsg_file_read); + if (ret == -ENOENT) { fprintf(stderr, "No pre-boot results of liblog.__android_log_mesg_file_write to "