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/base/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 using namespace skia_private;
19
20 namespace {
21
22 /**
23 * All events have a fixed block of information (TraceEvent), plus variable length payload:
24 * {TraceEvent} {TraceEventArgs} {Inline Payload}
25 */
26 struct TraceEventArg {
27 uint8_t fArgType;
28 const char* fArgName;
29 uint64_t fArgValue;
30 };
31
32 // These fields are ordered to minimize size due to alignment. Argument types could be packed
33 // better, but very few events have many arguments, so the net loss is pretty small.
34 struct TraceEvent {
35 char fPhase;
36 uint8_t fNumArgs;
37 uint32_t fSize;
38
39 const char* fName;
40 // TODO: Merge fID and fClockEnd (never used together)
41 uint64_t fID;
42 uint64_t fClockBegin;
43 uint64_t fClockEnd;
44 SkThreadID fThreadID;
45
next__anon75d6dbb40111::TraceEvent46 TraceEvent* next() {
47 return reinterpret_cast<TraceEvent*>(reinterpret_cast<char*>(this) + fSize);
48 }
args__anon75d6dbb40111::TraceEvent49 TraceEventArg* args() { return reinterpret_cast<TraceEventArg*>(this + 1); }
stringTable__anon75d6dbb40111::TraceEvent50 char* stringTable() { return reinterpret_cast<char*>(this->args() + fNumArgs); }
51 };
52
53 } // namespace
54
ChromeTracingTracer(const char * filename)55 ChromeTracingTracer::ChromeTracingTracer(const char* filename) : fFilename(filename) {
56 this->createBlock();
57 }
58
~ChromeTracingTracer()59 ChromeTracingTracer::~ChromeTracingTracer() { this->flush(); }
60
createBlock()61 void ChromeTracingTracer::createBlock() {
62 fCurBlock.fBlock = BlockPtr(new uint8_t[kBlockSize]);
63 fCurBlock.fEventsInBlock = 0;
64 fCurBlockUsed = 0;
65 }
66
appendEvent(const void * data,size_t size)67 SkEventTracer::Handle ChromeTracingTracer::appendEvent(const void* data, size_t size) {
68 SkASSERT(size > 0 && size <= kBlockSize);
69
70 SkAutoSpinlock lock(fMutex);
71 if (fCurBlockUsed + size > kBlockSize) {
72 fBlocks.push_back(std::move(fCurBlock));
73 this->createBlock();
74 }
75 memcpy(fCurBlock.fBlock.get() + fCurBlockUsed, data, size);
76 Handle handle = reinterpret_cast<Handle>(fCurBlock.fBlock.get() + fCurBlockUsed);
77 fCurBlockUsed += size;
78 fCurBlock.fEventsInBlock++;
79 return handle;
80 }
81
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)82 SkEventTracer::Handle ChromeTracingTracer::addTraceEvent(char phase,
83 const uint8_t* categoryEnabledFlag,
84 const char* name,
85 uint64_t id,
86 int numArgs,
87 const char** argNames,
88 const uint8_t* argTypes,
89 const uint64_t* argValues,
90 uint8_t flags) {
91 // TODO: Respect flags (or assert). INSTANT events encode scope in flags, should be stored
92 // using "s" key in JSON. COPY flag should be supported or rejected.
93
94 // Figure out how much extra storage we need for copied strings
95 int size = static_cast<int>(sizeof(TraceEvent) + numArgs * sizeof(TraceEventArg));
96 for (int i = 0; i < numArgs; ++i) {
97 if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
98 size += strlen(skia_private::TraceValueAsString(argValues[i])) + 1;
99 }
100 }
101
102 size = SkAlign8(size);
103
104 STArray<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 const char* valueStr = skia_private::TraceValueAsString(argValues[i]);
129 while (*valueStr) {
130 *stringTable++ = *valueStr++;
131 }
132 *stringTable++ = 0;
133 } else {
134 traceEventArgs[i].fArgValue = argValues[i];
135 }
136 }
137
138 return this->appendEvent(storagePtr, size);
139 }
140
updateTraceEventDuration(const uint8_t * categoryEnabledFlag,const char * name,SkEventTracer::Handle handle)141 void ChromeTracingTracer::updateTraceEventDuration(const uint8_t* categoryEnabledFlag,
142 const char* name,
143 SkEventTracer::Handle handle) {
144 // We could probably get away with not locking here, but let's be totally safe.
145 SkAutoSpinlock lock(fMutex);
146 TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(handle);
147 traceEvent->fClockEnd = std::chrono::steady_clock::now().time_since_epoch().count();
148 }
149
trace_value_to_json(SkJSONWriter * writer,uint64_t argValue,uint8_t argType,const char * stringTableBase)150 static void trace_value_to_json(SkJSONWriter* writer,
151 uint64_t argValue,
152 uint8_t argType,
153 const char* stringTableBase) {
154 switch (argType) {
155 case TRACE_VALUE_TYPE_BOOL: writer->appendBool(argValue); break;
156 case TRACE_VALUE_TYPE_UINT: writer->appendU64(argValue); break;
157 case TRACE_VALUE_TYPE_INT: writer->appendS64(static_cast<int64_t>(argValue)); break;
158 case TRACE_VALUE_TYPE_DOUBLE: writer->appendDouble(sk_bit_cast<double>(argValue)); break;
159 case TRACE_VALUE_TYPE_POINTER:
160 writer->appendPointer(skia_private::TraceValueAsPointer(argValue));
161 break;
162 case TRACE_VALUE_TYPE_STRING:
163 writer->appendCString(skia_private::TraceValueAsString(argValue));
164 break;
165 case TRACE_VALUE_TYPE_COPY_STRING:
166 // See addTraceEvent(), the value in _COPY_STRING events is replaced with an offset
167 writer->appendCString(stringTableBase + argValue);
168 break;
169 default: writer->appendNString("<unknown type>"); break;
170 }
171 }
172
173 namespace {
174
175 struct TraceEventSerializationState {
TraceEventSerializationState__anon75d6dbb40211::TraceEventSerializationState176 TraceEventSerializationState(uint64_t clockOffset)
177 : fClockOffset(clockOffset), fNextThreadID(0) {}
178
getShortThreadID__anon75d6dbb40211::TraceEventSerializationState179 int getShortThreadID(SkThreadID id) {
180 if (int* shortIDPtr = fShortThreadIDMap.find(id)) {
181 return *shortIDPtr;
182 }
183 int shortID = fNextThreadID++;
184 fShortThreadIDMap.set(id, shortID);
185 return shortID;
186 }
187
188 uint64_t fClockOffset;
189 THashMap<uint64_t, const char*> fBaseTypeResolver;
190 int fNextThreadID;
191 THashMap<SkThreadID, int> fShortThreadIDMap;
192 };
193
194 } // namespace
195
trace_event_to_json(SkJSONWriter * writer,TraceEvent * traceEvent,TraceEventSerializationState * serializationState)196 static void trace_event_to_json(SkJSONWriter* writer,
197 TraceEvent* traceEvent,
198 TraceEventSerializationState* serializationState) {
199 // We track the original (creation time) "name" of each currently live object, so we can
200 // automatically insert "base_name" fields in object snapshot events.
201 auto baseTypeResolver = &(serializationState->fBaseTypeResolver);
202 if (TRACE_EVENT_PHASE_CREATE_OBJECT == traceEvent->fPhase) {
203 SkASSERT(nullptr == baseTypeResolver->find(traceEvent->fID));
204 baseTypeResolver->set(traceEvent->fID, traceEvent->fName);
205 } else if (TRACE_EVENT_PHASE_DELETE_OBJECT == traceEvent->fPhase) {
206 SkASSERT(nullptr != baseTypeResolver->find(traceEvent->fID));
207 baseTypeResolver->remove(traceEvent->fID);
208 }
209
210 writer->beginObject();
211
212 writer->appendString("ph", &traceEvent->fPhase, 1);
213 writer->appendCString("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->appendCString("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.size() > 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.size(); ++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