Merge "liblog: __android_log_pmsg_file_write() cleanup"

am: 6da1ea0e48

Change-Id: I795733c69d5dd4be515358900fee0cdb8d5e44b9
This commit is contained in:
Mark Salyzyn 2016-10-17 14:22:51 +00:00 committed by android-build-merger
commit 07f2357b56
6 changed files with 226 additions and 60 deletions

View file

@ -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);
}
}

View file

@ -31,7 +31,6 @@
#include <time.h>
#include <unistd.h>
#include <android/log.h>
#include <cutils/sockets.h>
#include <log/logger.h>
#include <private/android_filesystem_config.h>
@ -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;
}

View file

@ -17,6 +17,7 @@
#ifndef _LIBLOG_LOGGER_H__
#define _LIBLOG_LOGGER_H__
#include <stdatomic.h>
#include <stdbool.h>
#include <log/uio.h>
@ -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 {

View file

@ -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(

View file

@ -20,6 +20,7 @@
#include <errno.h>
#include <fcntl.h>
#include <stdbool.h>
#include <stdlib.h>
#include <string.h>
#include <sys/types.h>
@ -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;
}

View file

@ -20,6 +20,7 @@
#include <inttypes.h>
#include <semaphore.h>
#include <signal.h>
#include <stdio.h>
#include <string.h>
#include <sys/types.h>
#include <unistd.h>
@ -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 "