Merge "libcutils: write trace event into socket in container" am: 59b33cb01c am: 08d9cc3744
am: 6cc4df26d6
Change-Id: Ib4a23ef6f3644afe76e6615bdc1be0e4fd7f909c
diff --git a/libcutils/trace-container.c b/libcutils/trace-container.c
new file mode 100644
index 0000000..03e91b1
--- /dev/null
+++ b/libcutils/trace-container.c
@@ -0,0 +1,231 @@
+/*
+ * Copyright (C) 2017 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 "trace-dev.inc"
+
+#include <cutils/sockets.h>
+#include <sys/stat.h>
+#include <time.h>
+
+/**
+ * For tracing in container, tags are written into a socket
+ * instead of ftrace. Additional data is appended so we need extra space.
+ */
+#define CONTAINER_ATRACE_MESSAGE_LENGTH (ATRACE_MESSAGE_LENGTH + 512)
+
+static pthread_once_t atrace_once_control = PTHREAD_ONCE_INIT;
+
+// Variables used for tracing in container with socket.
+// Note that we need to manually close and reopen socket when Zygote is forking. This requires
+// writing and closing sockets on multiple threads. A rwlock is used for avoiding concurrent
+// operation on the file descriptor.
+static bool atrace_use_container_sock = false;
+static int atrace_container_sock_fd = -1;
+static pthread_mutex_t atrace_enabling_mutex = PTHREAD_MUTEX_INITIALIZER;
+static pthread_rwlock_t atrace_container_sock_rwlock = PTHREAD_RWLOCK_INITIALIZER;
+
+static bool atrace_init_container_sock()
+{
+ pthread_rwlock_wrlock(&atrace_container_sock_rwlock);
+ atrace_container_sock_fd =
+ socket_local_client("trace", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET);
+ if (atrace_container_sock_fd < 0) {
+ ALOGE("Error opening container trace socket: %s (%d)", strerror(errno), errno);
+ }
+ pthread_rwlock_unlock(&atrace_container_sock_rwlock);
+ return atrace_container_sock_fd != -1;
+}
+
+static void atrace_close_container_sock()
+{
+ pthread_rwlock_wrlock(&atrace_container_sock_rwlock);
+ if (atrace_container_sock_fd != -1) close(atrace_container_sock_fd);
+ atrace_container_sock_fd = -1;
+ pthread_rwlock_unlock(&atrace_container_sock_rwlock);
+}
+
+// Set whether tracing is enabled in this process. This is used to prevent
+// the Zygote process from tracing. We need to close the socket in the container when tracing is
+// disabled, and reopen it again after Zygote forking.
+void atrace_set_tracing_enabled(bool enabled)
+{
+ pthread_mutex_lock(&atrace_enabling_mutex);
+ if (atrace_use_container_sock) {
+ bool already_enabled = atomic_load_explicit(&atrace_is_enabled, memory_order_acquire);
+ if (enabled && !already_enabled) {
+ // Trace was disabled previously. Re-initialize container socket.
+ atrace_init_container_sock();
+ } else if (!enabled && already_enabled) {
+ // Trace was enabled previously. Close container socket.
+ atrace_close_container_sock();
+ }
+ }
+ atomic_store_explicit(&atrace_is_enabled, enabled, memory_order_release);
+ pthread_mutex_unlock(&atrace_enabling_mutex);
+ atrace_update_tags();
+}
+
+static void atrace_init_once()
+{
+ atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC);
+ if (atrace_marker_fd < 0) {
+ // We're in container, ftrace may be disabled. In such case, we use the
+ // socket to write trace event.
+
+ // Protect the initialization of container socket from
+ // atrace_set_tracing_enabled.
+ pthread_mutex_lock(&atrace_enabling_mutex);
+ atrace_use_container_sock = true;
+ bool success = false;
+ if (atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) {
+ success = atrace_init_container_sock();
+ }
+ pthread_mutex_unlock(&atrace_enabling_mutex);
+
+ if (!success) {
+ atrace_enabled_tags = 0;
+ goto done;
+ }
+ }
+ atrace_enabled_tags = atrace_get_property();
+
+done:
+ atomic_store_explicit(&atrace_is_ready, true, memory_order_release);
+}
+
+void atrace_setup()
+{
+ pthread_once(&atrace_once_control, atrace_init_once);
+}
+
+static inline uint64_t gettime(clockid_t clk_id)
+{
+ struct timespec ts;
+ clock_gettime(clk_id, &ts);
+ return ts.tv_sec * 1000000 + ts.tv_nsec / 1000;
+}
+
+// Write trace events to container trace file. Note that we need to amend tid and time information
+// here comparing to normal ftrace, where those informations are added by kernel.
+#define WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value) { \
+ char buf[CONTAINER_ATRACE_MESSAGE_LENGTH]; \
+ int pid = getpid(); \
+ int tid = gettid(); \
+ uint64_t ts = gettime(CLOCK_MONOTONIC); \
+ uint64_t tts = gettime(CLOCK_THREAD_CPUTIME_ID); \
+ int len = snprintf( \
+ buf, sizeof(buf), \
+ ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%s" value_format, \
+ pid, tid, ts, tts, name, value); \
+ if (len >= (int) sizeof(buf)) { \
+ int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
+ /* Truncate the name to make the message fit. */ \
+ if (name_len > 0) { \
+ ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
+ len = snprintf( \
+ buf, sizeof(buf), \
+ ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%.*s" value_format, \
+ pid, tid, ts, tts, name_len, name, value); \
+ } else { \
+ /* Data is still too long. Drop it. */ \
+ ALOGW("Data is too long in %s: %s\n", __FUNCTION__, name); \
+ len = 0; \
+ } \
+ } \
+ if (len > 0) { \
+ write(atrace_container_sock_fd, buf, len); \
+ } \
+}
+
+#define WRITE_MSG_IN_CONTAINER(ph, sep_before_name, value_format, name, value) { \
+ pthread_rwlock_rdlock(&atrace_container_sock_rwlock); \
+ if (atrace_container_sock_fd != -1) { \
+ WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value); \
+ } \
+ pthread_rwlock_unlock(&atrace_container_sock_rwlock); \
+}
+
+void atrace_begin_body(const char* name)
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("B", "|", "%s", name, "");
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("B|%d|", "%s", name, "");
+}
+
+void atrace_end_body()
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("E", "", "%s", "", "");
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("E|%d", "%s", "", "");
+}
+
+void atrace_async_begin_body(const char* name, int32_t cookie)
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("S", "|", "|%d", name, cookie);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("S|%d|", "|%" PRId32, name, cookie);
+}
+
+void atrace_async_end_body(const char* name, int32_t cookie)
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("F", "|", "|%d", name, cookie);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("F|%d|", "|%" PRId32, name, cookie);
+}
+
+void atrace_int_body(const char* name, int32_t value)
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId32, name, value);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("C|%d|", "|%" PRId32, name, value);
+}
+
+void atrace_int64_body(const char* name, int64_t value)
+{
+ if (CC_LIKELY(atrace_use_container_sock)) {
+ WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId64, name, value);
+ return;
+ }
+
+ if (atrace_marker_fd < 0) return;
+
+ WRITE_MSG("C|%d|", "|%" PRId64, name, value);
+}
diff --git a/libcutils/trace-dev.c b/libcutils/trace-dev.c
index d45e5a9..4468e83 100644
--- a/libcutils/trace-dev.c
+++ b/libcutils/trace-dev.c
@@ -14,47 +14,9 @@
* limitations under the License.
*/
-#define LOG_TAG "cutils-trace"
+#include "trace-dev.inc"
-#include <errno.h>
-#include <fcntl.h>
-#include <limits.h>
-#include <pthread.h>
-#include <stdatomic.h>
-#include <stdbool.h>
-#include <stdlib.h>
-#include <string.h>
-#include <sys/types.h>
-
-#include <cutils/compiler.h>
-#include <cutils/properties.h>
-#include <cutils/trace.h>
-#include <log/log.h>
-#include <log/log_properties.h>
-
-/**
- * Maximum size of a message that can be logged to the trace buffer.
- * Note this message includes a tag, the pid, and the string given as the name.
- * Names should be kept short to get the most use of the trace buffer.
- */
-#define ATRACE_MESSAGE_LENGTH 1024
-
-atomic_bool atrace_is_ready = ATOMIC_VAR_INIT(false);
-int atrace_marker_fd = -1;
-uint64_t atrace_enabled_tags = ATRACE_TAG_NOT_READY;
-static bool atrace_is_debuggable = false;
-static atomic_bool atrace_is_enabled = ATOMIC_VAR_INIT(true);
-static pthread_once_t atrace_once_control = PTHREAD_ONCE_INIT;
-static pthread_mutex_t atrace_tags_mutex = PTHREAD_MUTEX_INITIALIZER;
-
-// Set whether this process is debuggable, which determines whether
-// application-level tracing is allowed when the ro.debuggable system property
-// is not set to '1'.
-void atrace_set_debuggable(bool debuggable)
-{
- atrace_is_debuggable = debuggable;
- atrace_update_tags();
-}
+static pthread_once_t atrace_once_control = PTHREAD_ONCE_INIT;
// Set whether tracing is enabled in this process. This is used to prevent
// the Zygote process from tracing.
@@ -64,101 +26,6 @@
atrace_update_tags();
}
-// Check whether the given command line matches one of the comma-separated
-// values listed in the app_cmdlines property.
-static bool atrace_is_cmdline_match(const char* cmdline)
-{
- int count = property_get_int32("debug.atrace.app_number", 0);
-
- char buf[PROPERTY_KEY_MAX];
- char value[PROPERTY_VALUE_MAX];
-
- for (int i = 0; i < count; i++) {
- snprintf(buf, sizeof(buf), "debug.atrace.app_%d", i);
- property_get(buf, value, "");
- if (strcmp(value, cmdline) == 0) {
- return true;
- }
- }
-
- return false;
-}
-
-// Determine whether application-level tracing is enabled for this process.
-static bool atrace_is_app_tracing_enabled()
-{
- bool sys_debuggable = __android_log_is_debuggable();
- bool result = false;
-
- if (sys_debuggable || atrace_is_debuggable) {
- // Check whether tracing is enabled for this process.
- FILE * file = fopen("/proc/self/cmdline", "re");
- if (file) {
- char cmdline[4096];
- if (fgets(cmdline, sizeof(cmdline), file)) {
- result = atrace_is_cmdline_match(cmdline);
- } else {
- ALOGE("Error reading cmdline: %s (%d)", strerror(errno), errno);
- }
- fclose(file);
- } else {
- ALOGE("Error opening /proc/self/cmdline: %s (%d)", strerror(errno),
- errno);
- }
- }
-
- return result;
-}
-
-// Read the sysprop and return the value tags should be set to
-static uint64_t atrace_get_property()
-{
- char value[PROPERTY_VALUE_MAX];
- char *endptr;
- uint64_t tags;
-
- property_get("debug.atrace.tags.enableflags", value, "0");
- errno = 0;
- tags = strtoull(value, &endptr, 0);
- if (value[0] == '\0' || *endptr != '\0') {
- ALOGE("Error parsing trace property: Not a number: %s", value);
- return 0;
- } else if (errno == ERANGE || tags == ULLONG_MAX) {
- ALOGE("Error parsing trace property: Number too large: %s", value);
- return 0;
- }
-
- // Only set the "app" tag if this process was selected for app-level debug
- // tracing.
- if (atrace_is_app_tracing_enabled()) {
- tags |= ATRACE_TAG_APP;
- } else {
- tags &= ~ATRACE_TAG_APP;
- }
-
- return (tags | ATRACE_TAG_ALWAYS) & ATRACE_TAG_VALID_MASK;
-}
-
-// Update tags if tracing is ready. Useful as a sysprop change callback.
-void atrace_update_tags()
-{
- uint64_t tags;
- if (CC_UNLIKELY(atomic_load_explicit(&atrace_is_ready, memory_order_acquire))) {
- if (atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) {
- tags = atrace_get_property();
- pthread_mutex_lock(&atrace_tags_mutex);
- atrace_enabled_tags = tags;
- pthread_mutex_unlock(&atrace_tags_mutex);
- } else {
- // Tracing is disabled for this process, so we simply don't
- // initialize the tags.
- pthread_mutex_lock(&atrace_tags_mutex);
- atrace_enabled_tags = ATRACE_TAG_NOT_READY;
- pthread_mutex_unlock(&atrace_tags_mutex);
- }
- }
-}
-
static void atrace_init_once()
{
atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC);
@@ -181,54 +48,30 @@
void atrace_begin_body(const char* name)
{
- char buf[ATRACE_MESSAGE_LENGTH];
-
- int len = snprintf(buf, sizeof(buf), "B|%d|%s", getpid(), name);
- if (len >= (int) sizeof(buf)) {
- ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name);
- len = sizeof(buf) - 1;
- }
- write(atrace_marker_fd, buf, len);
+ WRITE_MSG("B|%d|", "%s", name, "");
}
void atrace_end_body()
{
- char c = 'E';
- write(atrace_marker_fd, &c, 1);
-}
-
-#define WRITE_MSG(format_begin, format_end, pid, name, value) { \
- char buf[ATRACE_MESSAGE_LENGTH]; \
- int len = snprintf(buf, sizeof(buf), format_begin "%s" format_end, pid, \
- name, value); \
- if (len >= (int) sizeof(buf)) { \
- /* Given the sizeof(buf), and all of the current format buffers, \
- * it is impossible for name_len to be < 0 if len >= sizeof(buf). */ \
- int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
- /* Truncate the name to make the message fit. */ \
- ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
- len = snprintf(buf, sizeof(buf), format_begin "%.*s" format_end, pid, \
- name_len, name, value); \
- } \
- write(atrace_marker_fd, buf, len); \
+ WRITE_MSG("E|%d", "%s", "", "");
}
void atrace_async_begin_body(const char* name, int32_t cookie)
{
- WRITE_MSG("S|%d|", "|%" PRId32, getpid(), name, cookie);
+ WRITE_MSG("S|%d|", "|%" PRId32, name, cookie);
}
void atrace_async_end_body(const char* name, int32_t cookie)
{
- WRITE_MSG("F|%d|", "|%" PRId32, getpid(), name, cookie);
+ WRITE_MSG("F|%d|", "|%" PRId32, name, cookie);
}
void atrace_int_body(const char* name, int32_t value)
{
- WRITE_MSG("C|%d|", "|%" PRId32, getpid(), name, value);
+ WRITE_MSG("C|%d|", "|%" PRId32, name, value);
}
void atrace_int64_body(const char* name, int64_t value)
{
- WRITE_MSG("C|%d|", "|%" PRId64, getpid(), name, value);
+ WRITE_MSG("C|%d|", "|%" PRId64, name, value);
}
diff --git a/libcutils/trace-dev.inc b/libcutils/trace-dev.inc
new file mode 100644
index 0000000..f32330a
--- /dev/null
+++ b/libcutils/trace-dev.inc
@@ -0,0 +1,173 @@
+/*
+ * Copyright (C) 2017 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 __TRACE_DEV_INC
+#define __TRACE_DEV_INC
+
+#define LOG_TAG "cutils-trace"
+
+#include <errno.h>
+#include <fcntl.h>
+#include <limits.h>
+#include <pthread.h>
+#include <stdatomic.h>
+#include <stdbool.h>
+#include <stdlib.h>
+#include <string.h>
+#include <sys/types.h>
+
+#include <cutils/compiler.h>
+#include <cutils/properties.h>
+#include <cutils/trace.h>
+#include <log/log.h>
+#include <log/log_properties.h>
+
+/**
+ * Maximum size of a message that can be logged to the trace buffer.
+ * Note this message includes a tag, the pid, and the string given as the name.
+ * Names should be kept short to get the most use of the trace buffer.
+ */
+#define ATRACE_MESSAGE_LENGTH 1024
+
+atomic_bool atrace_is_ready = ATOMIC_VAR_INIT(false);
+int atrace_marker_fd = -1;
+uint64_t atrace_enabled_tags = ATRACE_TAG_NOT_READY;
+static bool atrace_is_debuggable = false;
+static atomic_bool atrace_is_enabled = ATOMIC_VAR_INIT(true);
+static pthread_mutex_t atrace_tags_mutex = PTHREAD_MUTEX_INITIALIZER;
+
+// Set whether this process is debuggable, which determines whether
+// application-level tracing is allowed when the ro.debuggable system property
+// is not set to '1'.
+void atrace_set_debuggable(bool debuggable)
+{
+ atrace_is_debuggable = debuggable;
+ atrace_update_tags();
+}
+
+// Check whether the given command line matches one of the comma-separated
+// values listed in the app_cmdlines property.
+static bool atrace_is_cmdline_match(const char* cmdline)
+{
+ int count = property_get_int32("debug.atrace.app_number", 0);
+
+ char buf[PROPERTY_KEY_MAX];
+ char value[PROPERTY_VALUE_MAX];
+
+ for (int i = 0; i < count; i++) {
+ snprintf(buf, sizeof(buf), "debug.atrace.app_%d", i);
+ property_get(buf, value, "");
+ if (strcmp(value, cmdline) == 0) {
+ return true;
+ }
+ }
+
+ return false;
+}
+
+// Determine whether application-level tracing is enabled for this process.
+static bool atrace_is_app_tracing_enabled()
+{
+ bool sys_debuggable = __android_log_is_debuggable();
+ bool result = false;
+
+ if (sys_debuggable || atrace_is_debuggable) {
+ // Check whether tracing is enabled for this process.
+ FILE * file = fopen("/proc/self/cmdline", "re");
+ if (file) {
+ char cmdline[4096];
+ if (fgets(cmdline, sizeof(cmdline), file)) {
+ result = atrace_is_cmdline_match(cmdline);
+ } else {
+ ALOGE("Error reading cmdline: %s (%d)", strerror(errno), errno);
+ }
+ fclose(file);
+ } else {
+ ALOGE("Error opening /proc/self/cmdline: %s (%d)", strerror(errno),
+ errno);
+ }
+ }
+
+ return result;
+}
+
+// Read the sysprop and return the value tags should be set to
+static uint64_t atrace_get_property()
+{
+ char value[PROPERTY_VALUE_MAX];
+ char *endptr;
+ uint64_t tags;
+
+ property_get("debug.atrace.tags.enableflags", value, "0");
+ errno = 0;
+ tags = strtoull(value, &endptr, 0);
+ if (value[0] == '\0' || *endptr != '\0') {
+ ALOGE("Error parsing trace property: Not a number: %s", value);
+ return 0;
+ } else if (errno == ERANGE || tags == ULLONG_MAX) {
+ ALOGE("Error parsing trace property: Number too large: %s", value);
+ return 0;
+ }
+
+ // Only set the "app" tag if this process was selected for app-level debug
+ // tracing.
+ if (atrace_is_app_tracing_enabled()) {
+ tags |= ATRACE_TAG_APP;
+ } else {
+ tags &= ~ATRACE_TAG_APP;
+ }
+
+ return (tags | ATRACE_TAG_ALWAYS) & ATRACE_TAG_VALID_MASK;
+}
+
+// Update tags if tracing is ready. Useful as a sysprop change callback.
+void atrace_update_tags()
+{
+ uint64_t tags;
+ if (CC_UNLIKELY(atomic_load_explicit(&atrace_is_ready, memory_order_acquire))) {
+ if (atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) {
+ tags = atrace_get_property();
+ pthread_mutex_lock(&atrace_tags_mutex);
+ atrace_enabled_tags = tags;
+ pthread_mutex_unlock(&atrace_tags_mutex);
+ } else {
+ // Tracing is disabled for this process, so we simply don't
+ // initialize the tags.
+ pthread_mutex_lock(&atrace_tags_mutex);
+ atrace_enabled_tags = ATRACE_TAG_NOT_READY;
+ pthread_mutex_unlock(&atrace_tags_mutex);
+ }
+ }
+}
+
+#define WRITE_MSG(format_begin, format_end, name, value) { \
+ char buf[ATRACE_MESSAGE_LENGTH]; \
+ int pid = getpid(); \
+ int len = snprintf(buf, sizeof(buf), format_begin "%s" format_end, pid, \
+ name, value); \
+ if (len >= (int) sizeof(buf)) { \
+ /* Given the sizeof(buf), and all of the current format buffers, \
+ * it is impossible for name_len to be < 0 if len >= sizeof(buf). */ \
+ int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
+ /* Truncate the name to make the message fit. */ \
+ ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
+ len = snprintf(buf, sizeof(buf), format_begin "%.*s" format_end, pid, \
+ name_len, name, value); \
+ } \
+ write(atrace_marker_fd, buf, len); \
+}
+
+#endif // __TRACE_DEV_INC