Don't abort when failed to write tracing message.

Also make the code thread-safe with lock.

Bug: 20666100
Change-Id: I0f331a617b75280f36179c187418450230d713ef
(cherry picked from commit 1661125315)
This commit is contained in:
Yabin Cui 2015-07-21 17:27:54 -07:00
parent 7e52dbe4d2
commit b8320b8021

View file

@ -21,6 +21,7 @@
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
#include "private/bionic_lock.h"
#include "private/bionic_systrace.h" #include "private/bionic_systrace.h"
#include "private/libc_logging.h" #include "private/libc_logging.h"
@ -29,12 +30,17 @@
#define WRITE_OFFSET 32 #define WRITE_OFFSET 32
static const prop_info* g_pinfo = NULL; constexpr char SYSTRACE_PROPERTY_NAME[] = "debug.atrace.tags.enableflags";
static Lock g_lock;
static const prop_info* g_pinfo;
static uint32_t g_serial = -1; static uint32_t g_serial = -1;
static uint64_t g_tags = 0; static uint64_t g_tags;
static int g_trace_marker_fd = -1; static int g_trace_marker_fd = -1;
static bool should_trace() { static bool should_trace() {
bool result = false;
g_lock.lock();
// If g_pinfo is null, this means that systrace hasn't been run and it's safe to // If g_pinfo is null, this means that systrace hasn't been run and it's safe to
// assume that no trace writing will need to take place. However, to avoid running // assume that no trace writing will need to take place. However, to avoid running
// this costly find check each time, we set it to a non-tracing value so that next // this costly find check each time, we set it to a non-tracing value so that next
@ -42,32 +48,39 @@ static bool should_trace() {
// this function also deals with the bootup case, during which the call to property // this function also deals with the bootup case, during which the call to property
// set will fail if the property server hasn't yet started. // set will fail if the property server hasn't yet started.
if (g_pinfo == NULL) { if (g_pinfo == NULL) {
g_pinfo = __system_property_find("debug.atrace.tags.enableflags"); g_pinfo = __system_property_find(SYSTRACE_PROPERTY_NAME);
if (g_pinfo == NULL) { if (g_pinfo == NULL) {
__system_property_set("debug.atrace.tags.enableflags", "0"); __system_property_set(SYSTRACE_PROPERTY_NAME, "0");
g_pinfo = __system_property_find("debug.atrace.tags.enableflags"); g_pinfo = __system_property_find(SYSTRACE_PROPERTY_NAME);
if (g_pinfo == NULL) {
return false;
}
} }
} }
if (g_pinfo != NULL) {
// Find out which tags have been enabled on the command line and set // Find out which tags have been enabled on the command line and set
// the value of tags accordingly. If the value of the property changes, // the value of tags accordingly. If the value of the property changes,
// the serial will also change, so the costly system_property_read function // the serial will also change, so the costly system_property_read function
// can be avoided by calling the much cheaper system_property_serial // can be avoided by calling the much cheaper system_property_serial
// first. The values within pinfo may change, but its location is guaranteed // first. The values within pinfo may change, but its location is guaranteed
// not to move. // not to move.
const uint32_t cur_serial = __system_property_serial(g_pinfo); uint32_t cur_serial = __system_property_serial(g_pinfo);
if (cur_serial != g_serial) { if (cur_serial != g_serial) {
g_serial = cur_serial; g_serial = cur_serial;
char value[PROP_VALUE_MAX]; char value[PROP_VALUE_MAX];
__system_property_read(g_pinfo, 0, value); __system_property_read(g_pinfo, 0, value);
g_tags = strtoull(value, NULL, 0); g_tags = strtoull(value, NULL, 0);
}
result = ((g_tags & ATRACE_TAG_BIONIC) != 0);
} }
g_lock.unlock();
return result;
}
// Finally, verify that this tag value enables bionic tracing. static int get_trace_marker_fd() {
return ((g_tags & ATRACE_TAG_BIONIC) != 0); g_lock.lock();
if (g_trace_marker_fd == -1) {
g_trace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_CLOEXEC | O_WRONLY);
}
g_lock.unlock();
return g_trace_marker_fd;
} }
ScopedTrace::ScopedTrace(const char* message) { ScopedTrace::ScopedTrace(const char* message) {
@ -75,11 +88,9 @@ ScopedTrace::ScopedTrace(const char* message) {
return; return;
} }
if (g_trace_marker_fd == -1) { int trace_marker_fd = get_trace_marker_fd();
g_trace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_CLOEXEC | O_WRONLY); if (trace_marker_fd == -1) {
if (g_trace_marker_fd == -1) { return;
__libc_fatal("Could not open kernel trace file: %s\n", strerror(errno));
}
} }
// If bionic tracing has been enabled, then write the message to the // If bionic tracing has been enabled, then write the message to the
@ -87,12 +98,10 @@ ScopedTrace::ScopedTrace(const char* message) {
int length = strlen(message); int length = strlen(message);
char buf[length + WRITE_OFFSET]; char buf[length + WRITE_OFFSET];
size_t len = snprintf(buf, length + WRITE_OFFSET, "B|%d|%s", getpid(), message); size_t len = snprintf(buf, length + WRITE_OFFSET, "B|%d|%s", getpid(), message);
ssize_t wbytes = TEMP_FAILURE_RETRY(write(g_trace_marker_fd, buf, len));
// Error while writing // Tracing may stop just after checking property and before writing the message.
if (static_cast<size_t>(wbytes) != len) { // So the write is acceptable to fail. See b/20666100.
__libc_fatal("Could not write to kernel trace file: %s\n", strerror(errno)); TEMP_FAILURE_RETRY(write(trace_marker_fd, buf, len));
}
} }
ScopedTrace::~ScopedTrace() { ScopedTrace::~ScopedTrace() {
@ -100,10 +109,10 @@ ScopedTrace::~ScopedTrace() {
return; return;
} }
ssize_t wbytes = TEMP_FAILURE_RETRY(write(g_trace_marker_fd, "E", 1)); int trace_marker_fd = get_trace_marker_fd();
if (trace_marker_fd == -1) {
// Error while writing return;
if (static_cast<size_t>(wbytes) != 1) {
__libc_fatal("Could not write to kernel trace file: %s\n", strerror(errno));
} }
TEMP_FAILURE_RETRY(write(trace_marker_fd, "E", 1));
} }