Merge "Revert "liblog: resolve deadlocks""

am: e6cf1c6372

* commit 'e6cf1c63726bee6b7ca69d68775f79e16f756ba6':
  Revert "liblog: resolve deadlocks"
This commit is contained in:
Mark Salyzyn 2015-11-16 19:11:39 +00:00 committed by android-build-merger
commit 52b9f02076
6 changed files with 53 additions and 141 deletions

View file

@ -616,12 +616,7 @@ typedef enum log_id {
* Use the per-tag properties "log.tag.<tagname>" to generate a runtime * Use the per-tag properties "log.tag.<tagname>" to generate a runtime
* result of non-zero to expose a log. * result of non-zero to expose a log.
*/ */
/* default prio ANDROID_LOG_VERBOSE to ANDROID_LOG_FATAL if no property */ int __android_log_is_loggable(int prio, const char *tag, int def);
#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, int __android_log_error_write(int tag, const char *subTag, int32_t uid, const char *data,
uint32_t dataLen); uint32_t dataLen);

View file

@ -24,7 +24,6 @@
#include <ctype.h> #include <ctype.h>
#include <errno.h> #include <errno.h>
#include <fcntl.h> #include <fcntl.h>
#include <signal.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
@ -98,33 +97,18 @@ typedef struct LogState {
*/ */
static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER; static pthread_mutex_t fakeLogDeviceLock = PTHREAD_MUTEX_INITIALIZER;
static void lock(sigset_t *sigflags) 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.
*/
sigset_t all;
sigfillset(&all);
pthread_sigmask(SIG_BLOCK, &all, sigflags);
pthread_mutex_lock(&fakeLogDeviceLock); pthread_mutex_lock(&fakeLogDeviceLock);
} }
static void unlock(sigset_t *sigflags) static void unlock()
{ {
pthread_mutex_unlock(&fakeLogDeviceLock); pthread_mutex_unlock(&fakeLogDeviceLock);
pthread_sigmask(SIG_UNBLOCK, sigflags, NULL);
} }
#define DECLARE_SIGSET(name) sigset_t name
#else // !defined(_WIN32) #else // !defined(_WIN32)
#define lock() ((void)0)
#define lock(sigflags) ((void)0) #define unlock() ((void)0)
#define unlock(sigflags) ((void)0)
#define DECLARE_SIGSET(name)
#endif // !defined(_WIN32) #endif // !defined(_WIN32)
@ -170,9 +154,8 @@ static LogState *fdToLogState(int fd)
static void deleteFakeFd(int fd) static void deleteFakeFd(int fd)
{ {
LogState *ls; LogState *ls;
DECLARE_SIGSET(sigflags);
lock(&sigflags); lock();
ls = fdToLogState(fd); ls = fdToLogState(fd);
if (ls != NULL) { if (ls != NULL) {
@ -181,7 +164,7 @@ static void deleteFakeFd(int fd)
free(ls); free(ls);
} }
unlock(&sigflags); unlock();
} }
/* /*
@ -565,13 +548,12 @@ static void showLog(LogState *state,
static ssize_t logWritev(int fd, const struct iovec* vector, int count) static ssize_t logWritev(int fd, const struct iovec* vector, int count)
{ {
LogState* state; LogState* state;
DECLARE_SIGSET(sigflags);
/* Make sure that no-one frees the LogState while we're using it. /* 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 * Also guarantees that only one thread is in showLog() at a given
* time (if it matters). * time (if it matters).
*/ */
lock(&sigflags); lock();
state = fdToLogState(fd); state = fdToLogState(fd);
if (state == NULL) { if (state == NULL) {
@ -616,10 +598,10 @@ static ssize_t logWritev(int fd, const struct iovec* vector, int count)
} }
bail: bail:
unlock(&sigflags); unlock();
return vector[0].iov_len + vector[1].iov_len + vector[2].iov_len; return vector[0].iov_len + vector[1].iov_len + vector[2].iov_len;
error: error:
unlock(&sigflags); unlock();
return -1; return -1;
} }
@ -639,9 +621,8 @@ static int logOpen(const char* pathName, int flags __unused)
{ {
LogState *logState; LogState *logState;
int fd = -1; int fd = -1;
DECLARE_SIGSET(sigflags);
lock(&sigflags); lock();
logState = createLogState(); logState = createLogState();
if (logState != NULL) { if (logState != NULL) {
@ -651,7 +632,7 @@ static int logOpen(const char* pathName, int flags __unused)
errno = ENFILE; errno = ENFILE;
} }
unlock(&sigflags); unlock();
return fd; return fd;
} }

View file

@ -16,39 +16,12 @@
#include <ctype.h> #include <ctype.h>
#include <pthread.h> #include <pthread.h>
#include <signal.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_ #define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_
#include <sys/_system_properties.h> #include <sys/_system_properties.h>
#include <android/log.h> #include <android/log.h>
#include <log/log.h>
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 { struct cache {
const prop_info *pinfo; const prop_info *pinfo;
@ -76,7 +49,9 @@ static void refresh_cache(struct cache *cache, const char *key)
cache->c = buf[0]; cache->c = buf[0];
} }
static int __android_log_level(const char *tag, int flag) static pthread_mutex_t lock = PTHREAD_MUTEX_INITIALIZER;
static int __android_log_level(const char *tag, int def)
{ {
/* sizeof() is used on this array below */ /* sizeof() is used on this array below */
static const char log_namespace[] = "persist.log.tag."; static const char log_namespace[] = "persist.log.tag.";
@ -108,11 +83,10 @@ static int __android_log_level(const char *tag, int flag)
{ NULL, -1, 0 }, { NULL, -1, 0 },
{ NULL, -1, 0 } { NULL, -1, 0 }
}; };
sigset_t sigflags;
strcpy(key, log_namespace); strcpy(key, log_namespace);
lock((flag & ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL) ? NULL : &sigflags); pthread_mutex_lock(&lock);
current_global_serial = __system_property_area_serial(); current_global_serial = __system_property_area_serial();
@ -182,7 +156,7 @@ static int __android_log_level(const char *tag, int flag)
global_serial = current_global_serial; global_serial = current_global_serial;
unlock((flag & ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL) ? NULL : &sigflags); pthread_mutex_unlock(&lock);
switch (toupper(c)) { switch (toupper(c)) {
case 'V': return ANDROID_LOG_VERBOSE; case 'V': return ANDROID_LOG_VERBOSE;
@ -194,46 +168,36 @@ static int __android_log_level(const char *tag, int flag)
case 'A': return ANDROID_LOG_FATAL; case 'A': return ANDROID_LOG_FATAL;
case 'S': return -1; /* ANDROID_LOG_SUPPRESS */ case 'S': return -1; /* ANDROID_LOG_SUPPRESS */
} }
return flag & ANDROID_LOGGABLE_FLAG_DEFAULT_MASK; return def;
} }
int __android_log_is_loggable(int prio, const char *tag, int flag) int __android_log_is_loggable(int prio, const char *tag, int def)
{ {
int logLevel = __android_log_level(tag, flag); int logLevel = __android_log_level(tag, def);
return logLevel >= 0 && prio >= logLevel; 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() char android_log_timestamp()
{ {
static struct cache r_time_cache = { NULL, -1, 0 }; static struct cache r_time_cache = { NULL, -1, 0 };
static struct cache p_time_cache = { NULL, -1, 0 }; static struct cache p_time_cache = { NULL, -1, 0 };
static uint32_t serial;
uint32_t current_serial;
char retval; char retval;
if (pthread_mutex_trylock(&lock_timestamp)) { pthread_mutex_lock(&lock);
/* 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;
}
pthread_mutex_unlock(&lock_timestamp); 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;
}
pthread_mutex_unlock(&lock);
return tolower(retval ?: 'r'); return tolower(retval ?: 'r');
} }

View file

@ -20,7 +20,6 @@
#include <fcntl.h> #include <fcntl.h>
#if !defined(_WIN32) #if !defined(_WIN32)
#include <pthread.h> #include <pthread.h>
#include <signal.h>
#endif #endif
#include <stdarg.h> #include <stdarg.h>
#include <stdatomic.h> #include <stdatomic.h>
@ -55,43 +54,14 @@
static int __write_to_log_init(log_id_t, struct iovec *vec, size_t nr); 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; 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 #ifndef __unused
#define __unused __attribute__((__unused__)) #define __unused __attribute__((__unused__))
#endif #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 #if FAKE_LOG_DEVICE
static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 }; static int log_fds[(int)LOG_ID_MAX] = { -1, -1, -1, -1, -1 };
#else #else
@ -305,15 +275,17 @@ 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)); ret = TEMP_FAILURE_RETRY(writev(logd_fd, newVec + 1, i - 1));
if (ret < 0) { if (ret < 0) {
DECLARE_SIGSET(sigflags);
ret = -errno; ret = -errno;
if (ret == -ENOTCONN) { if (ret == -ENOTCONN) {
lock(&sigflags); #if !defined(_WIN32)
pthread_mutex_lock(&log_init_lock);
#endif
close(logd_fd); close(logd_fd);
logd_fd = -1; logd_fd = -1;
ret = __write_to_log_initialize(); ret = __write_to_log_initialize();
unlock(&sigflags); #if !defined(_WIN32)
pthread_mutex_unlock(&log_init_lock);
#endif
if (ret < 0) { if (ret < 0) {
return ret; return ret;
@ -357,16 +329,18 @@ 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) static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr)
{ {
DECLARE_SIGSET(sigflags); #if !defined(_WIN32)
pthread_mutex_lock(&log_init_lock);
lock(&sigflags); #endif
if (write_to_log == __write_to_log_init) { if (write_to_log == __write_to_log_init) {
int ret; int ret;
ret = __write_to_log_initialize(); ret = __write_to_log_initialize();
if (ret < 0) { if (ret < 0) {
unlock(&sigflags); #if !defined(_WIN32)
pthread_mutex_unlock(&log_init_lock);
#endif
#if (FAKE_LOG_DEVICE == 0) #if (FAKE_LOG_DEVICE == 0)
if (pstore_fd >= 0) { if (pstore_fd >= 0) {
__write_to_log_daemon(log_id, vec, nr); __write_to_log_daemon(log_id, vec, nr);
@ -378,7 +352,9 @@ static int __write_to_log_init(log_id_t log_id, struct iovec *vec, size_t nr)
write_to_log = __write_to_log_daemon; write_to_log = __write_to_log_daemon;
} }
unlock(&sigflags); #if !defined(_WIN32)
pthread_mutex_unlock(&log_init_lock);
#endif
return write_to_log(log_id, vec, nr); return write_to_log(log_id, vec, nr);
} }

View file

@ -191,9 +191,7 @@ int LogBuffer::log(log_id_t log_id, log_time realtime,
prio = *msg; prio = *msg;
tag = msg + 1; tag = msg + 1;
} }
if (!__android_log_is_loggable(prio, tag, if (!__android_log_is_loggable(prio, tag, ANDROID_LOG_VERBOSE)) {
ANDROID_LOG_VERBOSE |
ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL)) {
// Log traffic received to total // Log traffic received to total
pthread_mutex_lock(&mLogElementsLock); pthread_mutex_lock(&mLogElementsLock);
stats.add(elem); stats.add(elem);

View file

@ -107,9 +107,7 @@ size_t LogBufferElement::populateDroppedMessage(char *&buffer,
LogBuffer *parent) { LogBuffer *parent) {
static const char tag[] = "chatty"; static const char tag[] = "chatty";
if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag, if (!__android_log_is_loggable(ANDROID_LOG_INFO, tag, ANDROID_LOG_VERBOSE)) {
ANDROID_LOG_VERBOSE |
ANDROID_LOGGABLE_FLAG_NOT_WITHIN_SIGNAL)) {
return 0; return 0;
} }