From a09fe118b1a5eb876ddaa2620965c4a8fb8b007c Mon Sep 17 00:00:00 2001 From: Brigid Smith Date: Mon, 21 Jul 2014 15:38:06 -0700 Subject: [PATCH] Added a bionic systrace class and tracing to pthread_mutex.cpp. bionic_systrace.h contains an implementation of tracing that can be used with systrace.py and its associated viewer. pthread_mutex now uses this tracing to track pthread_mutex contention, which can be enabled by using the "bionic" command line option to systrace. Bug: 15116468 (cherry picked from commit a406ee6d5f616192e9a13afad6ac6a9969814fc1) Change-Id: Ic98fc303689fe9384974150d0d258c50806a55e4 --- libc/Android.mk | 1 + libc/bionic/bionic_systrace.cpp | 107 ++++++++++++++++++++++++++++++++ libc/bionic/pthread_mutex.cpp | 12 ++++ libc/private/bionic_systrace.h | 35 +++++++++++ 4 files changed, 155 insertions(+) create mode 100644 libc/bionic/bionic_systrace.cpp create mode 100644 libc/private/bionic_systrace.h diff --git a/libc/Android.mk b/libc/Android.mk index 1fb5e84ae..0487a8fc0 100644 --- a/libc/Android.mk +++ b/libc/Android.mk @@ -94,6 +94,7 @@ libc_bionic_src_files := \ bionic/access.cpp \ bionic/assert.cpp \ bionic/atof.cpp \ + bionic/bionic_systrace.cpp \ bionic/bionic_time_conversions.cpp \ bionic/brk.cpp \ bionic/c16rtomb.cpp \ diff --git a/libc/bionic/bionic_systrace.cpp b/libc/bionic/bionic_systrace.cpp new file mode 100644 index 000000000..b8e892e72 --- /dev/null +++ b/libc/bionic/bionic_systrace.cpp @@ -0,0 +1,107 @@ +/* + * Copyright (C) 2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include +#include +#include +#include + +#include "private/bionic_systrace.h" +#include "private/libc_logging.h" + +#define _REALLY_INCLUDE_SYS__SYSTEM_PROPERTIES_H_ +#include + +#define WRITE_OFFSET 32 + +static const prop_info* g_pinfo = NULL; +static uint32_t g_serial = -1; +static uint64_t g_tags = 0; +static int g_trace_marker_fd = -1; + +static bool should_trace() { + // 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 + // this costly find check each time, we set it to a non-tracing value so that next + // time, it will just check the serial to see if the value has been changed. + // 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. + if (g_pinfo == NULL) { + g_pinfo = __system_property_find("debug.atrace.tags.enableflags"); + if (g_pinfo == NULL) { + __system_property_set("debug.atrace.tags.enableflags", "0"); + g_pinfo = __system_property_find("debug.atrace.tags.enableflags"); + if (g_pinfo == NULL) { + return false; + } + } + } + + // 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 serial will also change, so the costly system_property_read function + // can be avoided by calling the much cheaper system_property_serial + // first. The values within pinfo may change, but its location is guaranteed + // not to move. + const uint32_t cur_serial = __system_property_serial(g_pinfo); + if (cur_serial != g_serial) { + g_serial = cur_serial; + char value[PROP_VALUE_MAX]; + __system_property_read(g_pinfo, 0, value); + g_tags = strtoull(value, NULL, 0); + } + + // Finally, verify that this tag value enables bionic tracing. + return ((g_tags & ATRACE_TAG_BIONIC) != 0); +} + +ScopedTrace::ScopedTrace(const char* message) { + if (!should_trace()) { + return; + } + + if (g_trace_marker_fd == -1) { + g_trace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); + if (g_trace_marker_fd == -1) { + __libc_fatal("Could not open kernel trace file: %s\n", strerror(errno)); + } + } + + // If bionic tracing has been enabled, then write the message to the + // kernel trace_marker. + int length = strlen(message); + char buf[length + WRITE_OFFSET]; + 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 + if (static_cast(wbytes) != len) { + __libc_fatal("Could not write to kernel trace file: %s\n", strerror(errno)); + } +} + +ScopedTrace::~ScopedTrace() { + if (!should_trace()) { + return; + } + + ssize_t wbytes = TEMP_FAILURE_RETRY(write(g_trace_marker_fd, "E", 1)); + + // Error while writing + if (static_cast(wbytes) != 1) { + __libc_fatal("Could not write to kernel trace file: %s\n", strerror(errno)); + } +} diff --git a/libc/bionic/pthread_mutex.cpp b/libc/bionic/pthread_mutex.cpp index 546166166..e00ffb437 100644 --- a/libc/bionic/pthread_mutex.cpp +++ b/libc/bionic/pthread_mutex.cpp @@ -39,6 +39,8 @@ #include "private/bionic_futex.h" #include "private/bionic_tls.h" +#include "private/bionic_systrace.h" + extern void pthread_debug_mutex_lock_check(pthread_mutex_t *mutex); extern void pthread_debug_mutex_unlock_check(pthread_mutex_t *mutex); @@ -333,6 +335,10 @@ static inline void _normal_lock(pthread_mutex_t* mutex, int shared) { * that the mutex is in state 2 when we go to sleep on it, which * guarantees a wake-up call. */ + + ScopedTrace trace("Contending for pthread mutex"); + + while (__bionic_swap(locked_contended, &mutex->value) != unlocked) { __futex_wait_ex(&mutex->value, shared, locked_contended, NULL); } @@ -473,6 +479,8 @@ int pthread_mutex_lock(pthread_mutex_t* mutex) { mvalue = mutex->value; } + ScopedTrace trace("Contending for pthread mutex"); + for (;;) { int newval; @@ -626,6 +634,8 @@ static int __pthread_mutex_timedlock(pthread_mutex_t* mutex, const timespec* abs return 0; } + ScopedTrace trace("Contending for timed pthread mutex"); + // Loop while needed. while (__bionic_swap(locked_contended, &mutex->value) != unlocked) { if (__timespec_from_absolute(&ts, abs_timeout, clock) < 0) { @@ -658,6 +668,8 @@ static int __pthread_mutex_timedlock(pthread_mutex_t* mutex, const timespec* abs mvalue = mutex->value; } + ScopedTrace trace("Contending for timed pthread mutex"); + while (true) { // If the value is 'unlocked', try to acquire it directly. // NOTE: put state to 2 since we know there is contention. diff --git a/libc/private/bionic_systrace.h b/libc/private/bionic_systrace.h new file mode 100644 index 000000000..ad9ff7f71 --- /dev/null +++ b/libc/private/bionic_systrace.h @@ -0,0 +1,35 @@ +/* + * Copyright (C) 2014 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef BIONIC_SYSTRACE_H +#define BIONIC_SYSTRACE_H + +#include "bionic_macros.h" + +// Tracing class for bionic. To begin a trace at a specified point: +// ScopedTrace("Trace message"); +// The trace will end when the contructor goes out of scope. + +class ScopedTrace { + public: + explicit ScopedTrace(const char* message); + ~ScopedTrace(); + + private: + DISALLOW_COPY_AND_ASSIGN(ScopedTrace); +}; + +#endif