1/* 2 * Copyright (C) 2017 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17#include <cutils/trace.h> 18 19#include "trace-dev.inc" 20 21#include <cutils/sockets.h> 22#include <sys/stat.h> 23#include <time.h> 24 25/** 26 * For tracing in container, tags are written into a socket 27 * instead of ftrace. Additional data is appended so we need extra space. 28 */ 29#define CONTAINER_ATRACE_MESSAGE_LENGTH (ATRACE_MESSAGE_LENGTH + 512) 30 31static pthread_once_t atrace_once_control = PTHREAD_ONCE_INIT; 32 33// Variables used for tracing in container with socket. 34// Note that we need to manually close and reopen socket when Zygote is forking. This requires 35// writing and closing sockets on multiple threads. A rwlock is used for avoiding concurrent 36// operation on the file descriptor. 37static bool atrace_use_container_sock = false; 38static int atrace_container_sock_fd = -1; 39static pthread_mutex_t atrace_enabling_mutex = PTHREAD_MUTEX_INITIALIZER; 40static pthread_rwlock_t atrace_container_sock_rwlock = PTHREAD_RWLOCK_INITIALIZER; 41 42static bool atrace_init_container_sock() 43{ 44 pthread_rwlock_wrlock(&atrace_container_sock_rwlock); 45 atrace_container_sock_fd = 46 socket_local_client("trace", ANDROID_SOCKET_NAMESPACE_RESERVED, SOCK_SEQPACKET); 47 if (atrace_container_sock_fd < 0) { 48 ALOGE("Error opening container trace socket: %s (%d)", strerror(errno), errno); 49 } 50 pthread_rwlock_unlock(&atrace_container_sock_rwlock); 51 return atrace_container_sock_fd != -1; 52} 53 54static void atrace_close_container_sock() 55{ 56 pthread_rwlock_wrlock(&atrace_container_sock_rwlock); 57 if (atrace_container_sock_fd != -1) close(atrace_container_sock_fd); 58 atrace_container_sock_fd = -1; 59 pthread_rwlock_unlock(&atrace_container_sock_rwlock); 60} 61 62// Set whether tracing is enabled in this process. This is used to prevent 63// the Zygote process from tracing. We need to close the socket in the container when tracing is 64// disabled, and reopen it again after Zygote forking. 65void atrace_set_tracing_enabled(bool enabled) 66{ 67 pthread_mutex_lock(&atrace_enabling_mutex); 68 if (atrace_use_container_sock) { 69 bool already_enabled = atomic_load_explicit(&atrace_is_enabled, memory_order_acquire); 70 if (enabled && !already_enabled) { 71 // Trace was disabled previously. Re-initialize container socket. 72 atrace_init_container_sock(); 73 } else if (!enabled && already_enabled) { 74 // Trace was enabled previously. Close container socket. 75 atrace_close_container_sock(); 76 } 77 } 78 atomic_store_explicit(&atrace_is_enabled, enabled, memory_order_release); 79 pthread_mutex_unlock(&atrace_enabling_mutex); 80 atrace_update_tags(); 81} 82 83static void atrace_init_once() 84{ 85 atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC); 86 if (atrace_marker_fd < 0) { 87 // We're in container, ftrace may be disabled. In such case, we use the 88 // socket to write trace event. 89 90 // Protect the initialization of container socket from 91 // atrace_set_tracing_enabled. 92 pthread_mutex_lock(&atrace_enabling_mutex); 93 atrace_use_container_sock = true; 94 bool success = false; 95 if (atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) { 96 success = atrace_init_container_sock(); 97 } 98 pthread_mutex_unlock(&atrace_enabling_mutex); 99 100 if (!success) { 101 atrace_enabled_tags = 0; 102 goto done; 103 } 104 } 105 atrace_enabled_tags = atrace_get_property(); 106 107done: 108 atomic_store_explicit(&atrace_is_ready, true, memory_order_release); 109} 110 111void atrace_setup() 112{ 113 pthread_once(&atrace_once_control, atrace_init_once); 114} 115 116static inline uint64_t gettime(clockid_t clk_id) 117{ 118 struct timespec ts; 119 clock_gettime(clk_id, &ts); 120 return ts.tv_sec * 1000000 + ts.tv_nsec / 1000; 121} 122 123// Write trace events to container trace file. Note that we need to amend tid and time information 124// here comparing to normal ftrace, where those informations are added by kernel. 125#define WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value) { \ 126 char buf[CONTAINER_ATRACE_MESSAGE_LENGTH]; \ 127 int pid = getpid(); \ 128 int tid = gettid(); \ 129 uint64_t ts = gettime(CLOCK_MONOTONIC); \ 130 uint64_t tts = gettime(CLOCK_THREAD_CPUTIME_ID); \ 131 int len = snprintf( \ 132 buf, sizeof(buf), \ 133 ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%s" value_format, \ 134 pid, tid, ts, tts, name, value); \ 135 if (len >= (int) sizeof(buf)) { \ 136 int name_len = strlen(name) - (len - sizeof(buf)) - 1; \ 137 /* Truncate the name to make the message fit. */ \ 138 if (name_len > 0) { \ 139 ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \ 140 len = snprintf( \ 141 buf, sizeof(buf), \ 142 ph "|%d|%d|%" PRIu64 "|%" PRIu64 sep_before_name "%.*s" value_format, \ 143 pid, tid, ts, tts, name_len, name, value); \ 144 } else { \ 145 /* Data is still too long. Drop it. */ \ 146 ALOGW("Data is too long in %s: %s\n", __FUNCTION__, name); \ 147 len = 0; \ 148 } \ 149 } \ 150 if (len > 0) { \ 151 write(atrace_container_sock_fd, buf, len); \ 152 } \ 153} 154 155#define WRITE_MSG_IN_CONTAINER(ph, sep_before_name, value_format, name, value) { \ 156 pthread_rwlock_rdlock(&atrace_container_sock_rwlock); \ 157 if (atrace_container_sock_fd != -1) { \ 158 WRITE_MSG_IN_CONTAINER_LOCKED(ph, sep_before_name, value_format, name, value); \ 159 } \ 160 pthread_rwlock_unlock(&atrace_container_sock_rwlock); \ 161} 162 163void atrace_begin_body(const char* name) 164{ 165 if (CC_LIKELY(atrace_use_container_sock)) { 166 WRITE_MSG_IN_CONTAINER("B", "|", "%s", name, ""); 167 return; 168 } 169 170 if (atrace_marker_fd < 0) return; 171 172 WRITE_MSG("B|%d|", "%s", name, ""); 173} 174 175void atrace_end_body() 176{ 177 if (CC_LIKELY(atrace_use_container_sock)) { 178 WRITE_MSG_IN_CONTAINER("E", "", "%s", "", ""); 179 return; 180 } 181 182 if (atrace_marker_fd < 0) return; 183 184 WRITE_MSG("E|%d", "%s", "", ""); 185} 186 187void atrace_async_begin_body(const char* name, int32_t cookie) 188{ 189 if (CC_LIKELY(atrace_use_container_sock)) { 190 WRITE_MSG_IN_CONTAINER("S", "|", "|%d", name, cookie); 191 return; 192 } 193 194 if (atrace_marker_fd < 0) return; 195 196 WRITE_MSG("S|%d|", "|%" PRId32, name, cookie); 197} 198 199void atrace_async_end_body(const char* name, int32_t cookie) 200{ 201 if (CC_LIKELY(atrace_use_container_sock)) { 202 WRITE_MSG_IN_CONTAINER("F", "|", "|%d", name, cookie); 203 return; 204 } 205 206 if (atrace_marker_fd < 0) return; 207 208 WRITE_MSG("F|%d|", "|%" PRId32, name, cookie); 209} 210 211void atrace_int_body(const char* name, int32_t value) 212{ 213 if (CC_LIKELY(atrace_use_container_sock)) { 214 WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId32, name, value); 215 return; 216 } 217 218 if (atrace_marker_fd < 0) return; 219 220 WRITE_MSG("C|%d|", "|%" PRId32, name, value); 221} 222 223void atrace_int64_body(const char* name, int64_t value) 224{ 225 if (CC_LIKELY(atrace_use_container_sock)) { 226 WRITE_MSG_IN_CONTAINER("C", "|", "|%" PRId64, name, value); 227 return; 228 } 229 230 if (atrace_marker_fd < 0) return; 231 232 WRITE_MSG("C|%d|", "|%" PRId64, name, value); 233} 234