Loading libcutils/trace-container.c 0 → 100644 +231 −0 Original line number Original line Diff line number Diff line /* * 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); } libcutils/trace-dev.c +8 −165 Original line number Original line Diff line number Diff line Loading @@ -14,47 +14,9 @@ * limitations under the License. * 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_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(); } // Set whether tracing is enabled in this process. This is used to prevent // Set whether tracing is enabled in this process. This is used to prevent // the Zygote process from tracing. // the Zygote process from tracing. Loading @@ -64,101 +26,6 @@ void atrace_set_tracing_enabled(bool enabled) atrace_update_tags(); 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() static void atrace_init_once() { { atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); Loading @@ -181,54 +48,30 @@ void atrace_setup() void atrace_begin_body(const char* name) void atrace_begin_body(const char* name) { { char buf[ATRACE_MESSAGE_LENGTH]; WRITE_MSG("B|%d|", "%s", name, ""); 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); } } void atrace_end_body() void atrace_end_body() { { char c = 'E'; WRITE_MSG("E|%d", "%s", "", ""); 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); \ } } void atrace_async_begin_body(const char* name, int32_t cookie) 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) 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) 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) 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); } } libcutils/trace-dev.inc 0 → 100644 +173 −0 Original line number Original line Diff line number Diff line /* * 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 Loading
libcutils/trace-container.c 0 → 100644 +231 −0 Original line number Original line Diff line number Diff line /* * 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); }
libcutils/trace-dev.c +8 −165 Original line number Original line Diff line number Diff line Loading @@ -14,47 +14,9 @@ * limitations under the License. * 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_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(); } // Set whether tracing is enabled in this process. This is used to prevent // Set whether tracing is enabled in this process. This is used to prevent // the Zygote process from tracing. // the Zygote process from tracing. Loading @@ -64,101 +26,6 @@ void atrace_set_tracing_enabled(bool enabled) atrace_update_tags(); 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() static void atrace_init_once() { { atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); Loading @@ -181,54 +48,30 @@ void atrace_setup() void atrace_begin_body(const char* name) void atrace_begin_body(const char* name) { { char buf[ATRACE_MESSAGE_LENGTH]; WRITE_MSG("B|%d|", "%s", name, ""); 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); } } void atrace_end_body() void atrace_end_body() { { char c = 'E'; WRITE_MSG("E|%d", "%s", "", ""); 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); \ } } void atrace_async_begin_body(const char* name, int32_t cookie) 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) 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) 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) 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); } }
libcutils/trace-dev.inc 0 → 100644 +173 −0 Original line number Original line Diff line number Diff line /* * 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
