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 31 static 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. 37 static bool atrace_use_container_sock = false; 38 static int atrace_container_sock_fd = -1; 39 static pthread_mutex_t atrace_enabling_mutex = PTHREAD_MUTEX_INITIALIZER; 40 static pthread_rwlock_t atrace_container_sock_rwlock = PTHREAD_RWLOCK_INITIALIZER; 41 42 static 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 54 static 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. 65 void 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 83 static 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 107 done: 108 atomic_store_explicit(&atrace_is_ready, true, memory_order_release); 109 } 110 111 void atrace_setup() 112 { 113 pthread_once(&atrace_once_control, atrace_init_once); 114 } 115 116 static 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 163 void 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 175 void 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 187 void 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 199 void 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 211 void 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 223 void 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
