diff --git a/include/log/log.h b/include/log/log.h index 1cdf7bc49..086d7427b 100644 --- a/include/log/log.h +++ b/include/log/log.h @@ -614,9 +614,11 @@ typedef enum log_id { /* * Use the per-tag properties "log.tag." to generate a runtime - * result of non-zero to expose a log. + * result of non-zero to expose a log. prio is ANDROID_LOG_VERBOSE to + * ANDROID_LOG_FATAL. default_prio if no property. Undefined behavior if + * any other value. */ -int __android_log_is_loggable(int prio, const char *tag, int def); +int __android_log_is_loggable(int prio, const char *tag, int default_prio); 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..cb80ee63c 100644 --- a/liblog/fake_log_device.c +++ b/liblog/fake_log_device.c @@ -99,6 +99,10 @@ static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER; static void lock() { + /* + * 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. + */ pthread_mutex_lock(&fakeLogDeviceLock); } @@ -106,9 +110,12 @@ static void unlock() { pthread_mutex_unlock(&fakeLogDeviceLock); } + #else // !defined(_WIN32) + #define lock() ((void)0) #define unlock() ((void)0) + #endif // !defined(_WIN32) diff --git a/liblog/log_is_loggable.c b/liblog/log_is_loggable.c index 814d96d09..e128edbd8 100644 --- a/liblog/log_is_loggable.c +++ b/liblog/log_is_loggable.c @@ -23,6 +23,22 @@ #include +static pthread_mutex_t lock_loggable = PTHREAD_MUTEX_INITIALIZER; + +static void lock() +{ + /* + * 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. + */ + pthread_mutex_lock(&lock_loggable); +} + +static void unlock() +{ + pthread_mutex_unlock(&lock_loggable); +} + struct cache { const prop_info *pinfo; uint32_t serial; @@ -49,9 +65,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 default_prio) { /* sizeof() is used on this array below */ static const char log_namespace[] = "persist.log.tag."; @@ -86,7 +100,7 @@ static int __android_log_level(const char *tag, int def) strcpy(key, log_namespace); - pthread_mutex_lock(&lock); + lock(); current_global_serial = __system_property_area_serial(); @@ -156,7 +170,7 @@ static int __android_log_level(const char *tag, int def) global_serial = current_global_serial; - pthread_mutex_unlock(&lock); + unlock(); switch (toupper(c)) { case 'V': return ANDROID_LOG_VERBOSE; @@ -168,36 +182,47 @@ 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 default_prio; } -int __android_log_is_loggable(int prio, const char *tag, int def) +int __android_log_is_loggable(int prio, const char *tag, int default_prio) { - int logLevel = __android_log_level(tag, def); + int logLevel = __android_log_level(tag, default_prio); return logLevel >= 0 && prio >= logLevel; } +/* + * Timestamp state generally remains constant, since a change is + * rare, we can accept a trylock failure gracefully. Use a separate + * lock from is_loggable to keep contention down b/25563384. + */ +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..83c6dc296 100644 --- a/liblog/logd_write.c +++ b/liblog/logd_write.c @@ -54,14 +54,35 @@ 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() +{ + /* + * 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. + */ + pthread_mutex_lock(&log_init_lock); +} + +static void unlock() +{ + pthread_mutex_unlock(&log_init_lock); +} + +#else /* !defined(_WIN32) */ + +#define lock() ((void)0) +#define unlock() ((void)0) + +#endif /* !defined(_WIN32) */ + #if FAKE_LOG_DEVICE static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 }; #else @@ -277,15 +298,11 @@ static int __write_to_log_daemon(log_id_t log_id, struct iovec *vec, size_t nr) if (ret < 0) { ret = -errno; if (ret == -ENOTCONN) { -#if !defined(_WIN32) - pthread_mutex_lock(&log_init_lock); -#endif + lock(); close(logd_fd); logd_fd = -1; ret = __write_to_log_initialize(); -#if !defined(_WIN32) - pthread_mutex_unlock(&log_init_lock); -#endif + unlock(); if (ret < 0) { return ret; @@ -329,18 +346,14 @@ 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 + lock(); 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(); #if (FAKE_LOG_DEVICE == 0) if (pstore_fd >= 0) { __write_to_log_daemon(log_id, vec, nr); @@ -352,9 +365,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(); return write_to_log(log_id, vec, nr); }