1 /*
2 * Copyright 2017 Google Inc.
3 *
4 * Use of this source code is governed by a BSD-style license that can be
5 * found in the LICENSE file.
6 */
7
8 #include "include/core/SkStream.h"
9 #include "include/private/SkThreadID.h"
10 #include "src/core/SkOSFile.h"
11 #include "src/core/SkTraceEvent.h"
12 #include "src/utils/SkJSONWriter.h"
13 #include "src/utils/SkOSPath.h"
14 #include "tools/trace/ChromeTracingTracer.h"
15
16 #include <chrono>
17
18 namespace {
19
20 /**
21 * All events have a fixed block of information (TraceEvent), plus variable length payload:
22 * {TraceEvent} {TraceEventArgs} {Inline Payload}
23 */
24 struct TraceEventArg {
25 uint8_t fArgType;
26 const char* fArgName;
27 uint64_t fArgValue;
28 };
29
30 // These fields are ordered to minimize size due to alignment. Argument types could be packed
31 // better, but very few events have many arguments, so the net loss is pretty small.
32 struct TraceEvent {
33 char fPhase;
34 uint8_t fNumArgs;
35 uint32_t fSize;
36
37 const char* fName;
38 // TODO: Merge fID and fClockEnd (never used together)
39 uint64_t fID;
40 uint64_t fClockBegin;
41 uint64_t fClockEnd;
42 SkThreadID fThreadID;
43
next__anon4f0f108f0111::TraceEvent44 TraceEvent* next() {
45 return reinterpret_cast<TraceEvent*>(reinterpret_cast<char*>(this) + fSize);
46 }
args__anon4f0f108f0111::TraceEvent47 TraceEventArg* args() { return reinterpret_cast<TraceEventArg*>(this + 1); }
stringTable__anon4f0f108f0111::TraceEvent48 char* stringTable() { return reinterpret_cast<char*>(this->args() + fNumArgs); }
49 };
50
51 } // namespace
52
ChromeTracingTracer(const char * filename)53 ChromeTracingTracer::ChromeTracingTracer(const char* filename) : fFilename(filename) {
54 this->createBlock();
55 }
56
~ChromeTracingTracer()57 ChromeTracingTracer::~ChromeTracingTracer() { this->flush(); }
58
createBlock()59 void ChromeTracingTracer::createBlock() {
60 fCurBlock.fBlock = BlockPtr(new uint8_t[kBlockSize]);
61 fCurBlock.fEventsInBlock = 0;
62 fCurBlockUsed = 0;
63 }
64
appendEvent(const void * data,size_t size)65 SkEventTracer::Handle ChromeTracingTracer::appendEvent(const void* data, size_t size) {
66 SkASSERT(size > 0 && size <= kBlockSize);
67
68 SkAutoSpinlock lock(fMutex);
69 if (fCurBlockUsed + size > kBlockSize) {
70 fBlocks.push_back(std::move(fCurBlock));
71 this->createBlock();
72 }
73 memcpy(fCurBlock.fBlock.get() + fCurBlockUsed, data, size);
74 Handle handle = reinterpret_cast<Handle>(fCurBlock.fBlock.get() + fCurBlockUsed);
75 fCurBlockUsed += size;
76 fCurBlock.fEventsInBlock++;
77 return handle;
78 }
79
addTraceEvent(char phase,const uint8_t * categoryEnabledFlag,const char * name,uint64_t id,int numArgs,const char ** argNames,const uint8_t * argTypes,const uint64_t * argValues,uint8_t flags)80 SkEventTracer::Handle ChromeTracingTracer::addTraceEvent(char phase,
81 const uint8_t* categoryEnabledFlag,
82 const char* name,
83 uint64_t id,
84 int numArgs,
85 const char** argNames,
86 const uint8_t* argTypes,
87 const uint64_t* argValues,
88 uint8_t flags) {
89 // TODO: Respect flags (or assert). INSTANT events encode scope in flags, should be stored
90 // using "s" key in JSON. COPY flag should be supported or rejected.
91
92 // Figure out how much extra storage we need for copied strings
93 int size = static_cast<int>(sizeof(TraceEvent) + numArgs * sizeof(TraceEventArg));
94 for (int i = 0; i < numArgs; ++i) {
95 if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
96 skia::tracing_internals::TraceValueUnion value;
97 value.as_uint = argValues[i];
98 size += strlen(value.as_string) + 1;
99 }
100 }
101
102 size = SkAlign8(size);
103
104 SkSTArray<128, uint8_t, true> storage;
105 uint8_t* storagePtr = storage.push_back_n(size);
106
107 TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(storagePtr);
108 traceEvent->fPhase = phase;
109 traceEvent->fNumArgs = numArgs;
110 traceEvent->fSize = size;
111 traceEvent->fName = name;
112 traceEvent->fID = id;
113 traceEvent->fClockBegin = std::chrono::steady_clock::now().time_since_epoch().count();
114 traceEvent->fClockEnd = 0;
115 traceEvent->fThreadID = SkGetThreadID();
116
117 TraceEventArg* traceEventArgs = traceEvent->args();
118 char* stringTableBase = traceEvent->stringTable();
119 char* stringTable = stringTableBase;
120 for (int i = 0; i < numArgs; ++i) {
121 traceEventArgs[i].fArgName = argNames[i];
122 traceEventArgs[i].fArgType = argTypes[i];
123 if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
124 // Just write an offset into the arguments array
125 traceEventArgs[i].fArgValue = stringTable - stringTableBase;
126
127 // Copy string into our buffer (and advance)
128 skia::tracing_internals::TraceValueUnion value;
129 value.as_uint = argValues[i];
130 while (*value.as_string) {
131 *stringTable++ = *value.as_string++;
132 }
133 *stringTable++ = 0;
134 } else {
135 traceEventArgs[i].fArgValue = argValues[i];
136 }
137 }
138
139 return this->appendEvent(storagePtr, size);
140 }
141
updateTraceEventDuration(const uint8_t * categoryEnabledFlag,const char * name,SkEventTracer::Handle handle)142 void ChromeTracingTracer::updateTraceEventDuration(const uint8_t* categoryEnabledFlag,
143 const char* name,
144 SkEventTracer::Handle handle) {
145 // We could probably get away with not locking here, but let's be totally safe.
146 SkAutoSpinlock lock(fMutex);
147 TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(handle);
148 traceEvent->fClockEnd = std::chrono::steady_clock::now().time_since_epoch().count();
149 }
150
trace_value_to_json(SkJSONWriter * writer,uint64_t argValue,uint8_t argType,const char * stringTableBase)151 static void trace_value_to_json(SkJSONWriter* writer,
152 uint64_t argValue,
153 uint8_t argType,
154 const char* stringTableBase) {
155 skia::tracing_internals::TraceValueUnion value;
156 value.as_uint = argValue;
157
158 switch (argType) {
159 case TRACE_VALUE_TYPE_BOOL: writer->appendBool(value.as_bool); break;
160 case TRACE_VALUE_TYPE_UINT: writer->appendU64(value.as_uint); break;
161 case TRACE_VALUE_TYPE_INT: writer->appendS64(value.as_int); break;
162 case TRACE_VALUE_TYPE_DOUBLE: writer->appendDouble(value.as_double); break;
163 case TRACE_VALUE_TYPE_POINTER: writer->appendPointer(value.as_pointer); break;
164 case TRACE_VALUE_TYPE_STRING: writer->appendString(value.as_string); break;
165 case TRACE_VALUE_TYPE_COPY_STRING:
166 writer->appendString(stringTableBase + value.as_uint);
167 break;
168 default: writer->appendString("<unknown type>"); break;
169 }
170 }
171
172 namespace {
173
174 struct TraceEventSerializationState {
TraceEventSerializationState__anon4f0f108f0211::TraceEventSerializationState175 TraceEventSerializationState(uint64_t clockOffset)
176 : fClockOffset(clockOffset), fNextThreadID(0) {}
177
getShortThreadID__anon4f0f108f0211::TraceEventSerializationState178 int getShortThreadID(SkThreadID id) {
179 if (int* shortIDPtr = fShortThreadIDMap.find(id)) {
180 return *shortIDPtr;
181 }
182 int shortID = fNextThreadID++;
183 fShortThreadIDMap.set(id, shortID);
184 return shortID;
185 }
186
187 uint64_t fClockOffset;
188 SkTHashMap<uint64_t, const char*> fBaseTypeResolver;
189 int fNextThreadID;
190 SkTHashMap<SkThreadID, int> fShortThreadIDMap;
191 };
192
193 } // namespace
194
trace_event_to_json(SkJSONWriter * writer,TraceEvent * traceEvent,TraceEventSerializationState * serializationState)195 static void trace_event_to_json(SkJSONWriter* writer,
196 TraceEvent* traceEvent,
197 TraceEventSerializationState* serializationState) {
198 // We track the original (creation time) "name" of each currently live object, so we can
199 // automatically insert "base_name" fields in object snapshot events.
200 auto baseTypeResolver = &(serializationState->fBaseTypeResolver);
201 if (TRACE_EVENT_PHASE_CREATE_OBJECT == traceEvent->fPhase) {
202 SkASSERT(nullptr == baseTypeResolver->find(traceEvent->fID));
203 baseTypeResolver->set(traceEvent->fID, traceEvent->fName);
204 } else if (TRACE_EVENT_PHASE_DELETE_OBJECT == traceEvent->fPhase) {
205 SkASSERT(nullptr != baseTypeResolver->find(traceEvent->fID));
206 baseTypeResolver->remove(traceEvent->fID);
207 }
208
209 writer->beginObject();
210
211 char phaseString[2] = {traceEvent->fPhase, 0};
212 writer->appendString("ph", phaseString);
213 writer->appendString("name", traceEvent->fName);
214 if (0 != traceEvent->fID) {
215 // IDs are (almost) always pointers
216 writer->appendPointer("id", reinterpret_cast<void*>(traceEvent->fID));
217 }
218
219 // Offset timestamps to reduce JSON length, then convert nanoseconds to microseconds
220 // (standard time unit for tracing JSON files).
221 uint64_t relativeTimestamp =
222 static_cast<int64_t>(traceEvent->fClockBegin - serializationState->fClockOffset);
223 writer->appendDouble("ts", static_cast<double>(relativeTimestamp) * 1E-3);
224 if (0 != traceEvent->fClockEnd) {
225 double dur = static_cast<double>(traceEvent->fClockEnd - traceEvent->fClockBegin) * 1E-3;
226 writer->appendDouble("dur", dur);
227 }
228
229 writer->appendS64("tid", serializationState->getShortThreadID(traceEvent->fThreadID));
230 // Trace events *must* include a process ID, but for internal tools this isn't particularly
231 // important (and certainly not worth adding a cross-platform API to get it).
232 writer->appendS32("pid", 0);
233
234 if (traceEvent->fNumArgs) {
235 writer->beginObject("args");
236 const char* stringTable = traceEvent->stringTable();
237 bool addedSnapshot = false;
238 if (TRACE_EVENT_PHASE_SNAPSHOT_OBJECT == traceEvent->fPhase &&
239 baseTypeResolver->find(traceEvent->fID) &&
240 0 != strcmp(*baseTypeResolver->find(traceEvent->fID), traceEvent->fName)) {
241 // Special handling for snapshots where the name differs from creation.
242 writer->beginObject("snapshot");
243 writer->appendString("base_type", *baseTypeResolver->find(traceEvent->fID));
244 addedSnapshot = true;
245 }
246
247 for (int i = 0; i < traceEvent->fNumArgs; ++i) {
248 const TraceEventArg* arg = traceEvent->args() + i;
249 // TODO: Skip '#'
250 writer->appendName(arg->fArgName);
251
252 if (arg->fArgName && '#' == arg->fArgName[0]) {
253 writer->beginObject();
254 writer->appendName("id_ref");
255 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
256 writer->endObject();
257 } else {
258 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
259 }
260 }
261
262 if (addedSnapshot) {
263 writer->endObject();
264 }
265
266 writer->endObject();
267 }
268
269 writer->endObject();
270 }
271
flush()272 void ChromeTracingTracer::flush() {
273 SkAutoSpinlock lock(fMutex);
274
275 SkString dirname = SkOSPath::Dirname(fFilename.c_str());
276 if (!dirname.isEmpty() && !sk_exists(dirname.c_str(), kWrite_SkFILE_Flag)) {
277 if (!sk_mkdir(dirname.c_str())) {
278 SkDebugf("Failed to create directory.");
279 }
280 }
281
282 SkFILEWStream fileStream(fFilename.c_str());
283 SkJSONWriter writer(&fileStream, SkJSONWriter::Mode::kFast);
284 writer.beginArray();
285
286 uint64_t clockOffset = 0;
287 if (fBlocks.count() > 0) {
288 clockOffset = reinterpret_cast<TraceEvent*>(fBlocks[0].fBlock.get())->fClockBegin;
289 } else if (fCurBlock.fEventsInBlock > 0) {
290 clockOffset = reinterpret_cast<TraceEvent*>(fCurBlock.fBlock.get())->fClockBegin;
291 }
292
293 TraceEventSerializationState serializationState(clockOffset);
294
295 auto event_block_to_json = [](SkJSONWriter* writer,
296 const TraceEventBlock& block,
297 TraceEventSerializationState* serializationState) {
298 TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(block.fBlock.get());
299 for (int i = 0; i < block.fEventsInBlock; ++i) {
300 trace_event_to_json(writer, traceEvent, serializationState);
301 traceEvent = traceEvent->next();
302 }
303 };
304
305 for (int i = 0; i < fBlocks.count(); ++i) {
306 event_block_to_json(&writer, fBlocks[i], &serializationState);
307 }
308 event_block_to_json(&writer, fCurBlock, &serializationState);
309
310 writer.endArray();
311 writer.flush();
312 fileStream.flush();
313 }
314