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