diff --git a/include/log/log.h b/include/log/log.h index 1cdf7bc49..e0dc3a3d0 100644 --- a/include/log/log.h +++ b/include/log/log.h @@ -616,7 +616,12 @@ typedef enum log_id { * Use the per-tag properties "log.tag." to generate a runtime * result of non-zero to expose a log. */ -int __android_log_is_loggable(int prio, const char *tag, int def); +/* default prio ANDROID_LOG_VERBOSE to ANDROID_LOG_FATAL if no property */ +#define ANDROID_LOGGABLE_FLAG_DEFAULT_MASK 0x000F +/* Save 2 syscalls if caller guarantees to never call within signal handler */ +#define ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL 0x8000 + +int __android_log_is_loggable(int prio, const char *tag, int flag); int __android_log_error_write(int tag, const char *subTag, int32_t uid, const char *data, uint32_t dataLen); diff --git a/liblog/fake_log_device.c b/liblog/fake_log_device.c index 8a8ece250..fcdb6c928 100644 --- a/liblog/fake_log_device.c +++ b/liblog/fake_log_device.c @@ -24,6 +24,7 @@ #include #include #include +#include #include #include @@ -97,18 +98,33 @@ typedef struct LogState { */ static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER; -static void lock() +static void lock(sigset_t *sigflags) { + /* + * 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. + */ + sigset_t all; + + sigfillset(&all); + pthread_sigmask(SIG_BLOCK, &all, sigflags); pthread_mutex_lock(&fakeLogDeviceLock); } -static void unlock() +static void unlock(sigset_t *sigflags) { pthread_mutex_unlock(&fakeLogDeviceLock); + pthread_sigmask(SIG_UNBLOCK, sigflags, NULL); } + +#define DECLARE_SIGSET(name) sigset_t name + #else // !defined(_WIN32) -#define lock() ((void)0) -#define unlock() ((void)0) + +#define lock(sigflags) ((void)0) +#define unlock(sigflags) ((void)0) +#define DECLARE_SIGSET(name) + #endif // !defined(_WIN32) @@ -154,8 +170,9 @@ static LogState *fdToLogState(int fd) static void deleteFakeFd(int fd) { LogState *ls; + DECLARE_SIGSET(sigflags); - lock(); + lock(&sigflags); ls = fdToLogState(fd); if (ls != NULL) { @@ -164,7 +181,7 @@ static void deleteFakeFd(int fd) free(ls); } - unlock(); + unlock(&sigflags); } /* @@ -548,12 +565,13 @@ static void showLog(LogState *state, static ssize_t logWritev(int fd, const struct iovec* vector, int count) { LogState* state; + DECLARE_SIGSET(sigflags); /* Make sure that no-one frees the LogState while we're using it. * Also guarantees that only one thread is in showLog() at a given * time (if it matters). */ - lock(); + lock(&sigflags); state = fdToLogState(fd); if (state == NULL) { @@ -598,10 +616,10 @@ static ssize_t logWritev(int fd, const struct iovec* vector, int count) } bail: - unlock(); + unlock(&sigflags); return vector[0].iov_len + vector[1].iov_len + vector[2].iov_len; error: - unlock(); + unlock(&sigflags); return -1; } @@ -621,8 +639,9 @@ static int logOpen(const char* pathName, int flags __unused) { LogState *logState; int fd = -1; + DECLARE_SIGSET(sigflags); - lock(); + lock(&sigflags); logState = createLogState(); if (logState != NULL) { @@ -632,7 +651,7 @@ static int logOpen(const char* pathName, int flags __unused) errno = ENFILE; } - unlock(); + unlock(&sigflags); return fd; } diff --git a/liblog/log_is_loggable.c b/liblog/log_is_loggable.c index 814d96d09..9d043ff48 100644 --- a/liblog/log_is_loggable.c +++ b/liblog/log_is_loggable.c @@ -16,12 +16,39 @@ #include #include +#include #include #include #define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_ #include #include +#include + +static pthread_mutex_t lock_loggable = PTHREAD_MUTEX_INITIALIZER; + +static void lock(sigset_t *sigflags) +{ + /* + * 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. + */ + if (sigflags) { + sigset_t all; + + sigfillset(&all); + pthread_sigmask(SIG_BLOCK, &all, sigflags); + } + pthread_mutex_lock(&lock_loggable); +} + +static void unlock(sigset_t *sigflags) +{ + pthread_mutex_unlock(&lock_loggable); + if (sigflags) { + pthread_sigmask(SIG_UNBLOCK, sigflags, NULL); + } +} struct cache { const prop_info *pinfo; @@ -49,9 +76,7 @@ static void refresh_cache(struct cache *cache, const char *key) cache->c = buf[0]; } -static pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER; - -static int __android_log_level(const char *tag, int def) +static int __android_log_level(const char *tag, int flag) { /* sizeof() is used on this array below */ static const char log_namespace[] = "persist.log.tag."; @@ -83,10 +108,11 @@ static int __android_log_level(const char *tag, int def) { NULL, -1, 0 }, { NULL, -1, 0 } }; + sigset_t sigflags; strcpy(key, log_namespace); - pthread_mutex_lock(&lock); + lock((flag & ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL) ? NULL : &sigflags); current_global_serial = __system_property_area_serial(); @@ -156,7 +182,7 @@ static int __android_log_level(const char *tag, int def) global_serial = current_global_serial; - pthread_mutex_unlock(&lock); + unlock((flag & ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL) ? NULL : &sigflags); switch (toupper(c)) { case 'V': return ANDROID_LOG_VERBOSE; @@ -168,36 +194,46 @@ static int __android_log_level(const char *tag, int def) case 'A': return ANDROID_LOG_FATAL; case 'S': return -1; /* ANDROID_LOG_SUPPRESS */ } - return def; + return flag & ANDROID_LOGGABLE_FLAG_DEFAULT_MASK; } -int __android_log_is_loggable(int prio, const char *tag, int def) +int __android_log_is_loggable(int prio, const char *tag, int flag) { - int logLevel = __android_log_level(tag, def); + int logLevel = __android_log_level(tag, flag); return logLevel >= 0 && prio >= logLevel; } +/* + * Timestamp state generally remains constant, since a change is + * rare, we can accept a trylock failure gracefully. + */ +static pthread_mutex_t lock_timestamp = PTHREAD_MUTEX_INITIALIZER; + char android_log_timestamp() { static struct cache r_time_cache = { NULL, -1, 0 }; static struct cache p_time_cache = { NULL, -1, 0 }; - static uint32_t serial; - uint32_t current_serial; char retval; - pthread_mutex_lock(&lock); + if (pthread_mutex_trylock(&lock_timestamp)) { + /* We are willing to accept some race in this context */ + if (!(retval = p_time_cache.c)) { + retval = r_time_cache.c; + } + } else { + static uint32_t serial; + uint32_t current_serial = __system_property_area_serial(); + if (current_serial != serial) { + refresh_cache(&r_time_cache, "ro.logd.timestamp"); + refresh_cache(&p_time_cache, "persist.logd.timestamp"); + serial = current_serial; + } + if (!(retval = p_time_cache.c)) { + retval = r_time_cache.c; + } - current_serial = __system_property_area_serial(); - if (current_serial != serial) { - refresh_cache(&r_time_cache, "ro.logd.timestamp"); - refresh_cache(&p_time_cache, "persist.logd.timestamp"); - serial = current_serial; + pthread_mutex_unlock(&lock_timestamp); } - if (!(retval = p_time_cache.c)) { - retval = r_time_cache.c; - } - - pthread_mutex_unlock(&lock); return tolower(retval ?: 'r'); } diff --git a/liblog/logd_write.c b/liblog/logd_write.c index a4310aee1..a8ecc8d45 100644 --- a/liblog/logd_write.c +++ b/liblog/logd_write.c @@ -20,6 +20,7 @@ #include #if !defined(_WIN32) #include +#include #endif #include #include @@ -54,14 +55,43 @@ 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(sigset_t *sigflags) +{ + /* + * 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. + */ + sigset_t all; + + sigfillset(&all); + pthread_sigmask(SIG_BLOCK, &all, sigflags); + pthread_mutex_lock(&log_init_lock); +} + +static void unlock(sigset_t *sigflags) +{ + pthread_mutex_unlock(&log_init_lock); + pthread_sigmask(SIG_UNBLOCK, sigflags, NULL); +} + +#define DECLARE_SIGSET(name) sigset_t name + +#else /* !defined(_WIN32) */ + +#define lock(sigflags) ((void)0) +#define unlock(sigflags) ((void)0) +#define DECLARE_SIGSET(name) + +#endif /* !defined(_WIN32) */ + #if FAKE_LOG_DEVICE static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 }; #else @@ -275,17 +305,15 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) */ ret = TEMP_FAILURE_RETRY(writev(logd_fd, newVec + 1, i - 1)); if (ret < 0) { + DECLARE_SIGSET(sigflags); + ret = -errno; if (ret == -ENOTCONN) { -#if !defined(_WIN32) - pthread_mutex_lock(&log_init_lock); -#endif + lock(&sigflags); close(logd_fd); logd_fd = -1; ret = __write_to_log_initialize(); -#if !defined(_WIN32) - pthread_mutex_unlock(&log_init_lock); -#endif + unlock(&sigflags); if (ret < 0) { return ret; @@ -329,18 +357,16 @@ 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 + DECLARE_SIGSET(sigflags); + + lock(&sigflags); 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(&sigflags); #if (FAKE_LOG_DEVICE == 0) if (pstore_fd >= 0) { __write_to_log_daemon(log_id, vec, nr); @@ -352,9 +378,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(&sigflags); return write_to_log(log_id, vec, nr); } diff --git a/logd/LogBuffer.cpp b/logd/LogBuffer.cpp index fd5c066ac..c2f71d149 100644 --- a/logd/LogBuffer.cpp +++ b/logd/LogBuffer.cpp @@ -191,7 +191,9 @@ int LogBuffer::log(log_id_t log_id, log_time realtime, prio = *msg; tag = msg + 1; } - if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) { + if (!__android_log_is_loggable(prio, tag, + ANDROID_LOG_VERBOSE | + ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL)) { // Log traffic received to total pthread_mutex_lock(&mLogElementsLock); stats.add(elem); diff --git a/logd/LogBufferElement.cpp b/logd/LogBufferElement.cpp index c4c302b0a..f10dccfee 100644 --- a/logd/LogBufferElement.cpp +++ b/logd/LogBufferElement.cpp @@ -107,7 +107,9 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer, LogBuffer *parent) { static const char tag[] = "chatty"; - if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag, ANDROID_LOG_VERBOSE)) { + if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag, + ANDROID_LOG_VERBOSE | + ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL)) { return 0; }