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 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__anon0cc5b6e30111::TraceEvent44 TraceEvent* next() {
45 return reinterpret_cast<TraceEvent*>(reinterpret_cast<char*>(this) + fSize);
46 }
args__anon0cc5b6e30111::TraceEvent47 TraceEventArg* args() { return reinterpret_cast<TraceEventArg*>(this + 1); }
stringTable__anon0cc5b6e30111::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_private::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_private::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_private::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->appendCString(value.as_string); break;
165 case TRACE_VALUE_TYPE_COPY_STRING:
166 writer->appendCString(stringTableBase + value.as_uint);
167 break;
168 default: writer->appendNString("<unknown type>"); break;
169 }
170 }
171
172 namespace {
173
174 struct TraceEventSerializationState {
TraceEventSerializationState__anon0cc5b6e30211::TraceEventSerializationState175 TraceEventSerializationState(uint64_t clockOffset)
176 : fClockOffset(clockOffset), fNextThreadID(0) {}
177
getShortThreadID__anon0cc5b6e30211::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 writer->appendString("ph", &traceEvent->fPhase, 1);
212 writer->appendCString("name", traceEvent->fName);
213 if (0 != traceEvent->fID) {
214 // IDs are (almost) always pointers
215 writer->appendPointer("id", reinterpret_cast<void*>(traceEvent->fID));
216 }
217
218 // Offset timestamps to reduce JSON length, then convert nanoseconds to microseconds
219 // (standard time unit for tracing JSON files).
220 uint64_t relativeTimestamp =
221 static_cast<int64_t>(traceEvent->fClockBegin - serializationState->fClockOffset);
222 writer->appendDouble("ts", static_cast<double>(relativeTimestamp) * 1E-3);
223 if (0 != traceEvent->fClockEnd) {
224 double dur = static_cast<double>(traceEvent->fClockEnd - traceEvent->fClockBegin) * 1E-3;
225 writer->appendDouble("dur", dur);
226 }
227
228 writer->appendS64("tid", serializationState->getShortThreadID(traceEvent->fThreadID));
229 // Trace events *must* include a process ID, but for internal tools this isn't particularly
230 // important (and certainly not worth adding a cross-platform API to get it).
231 writer->appendS32("pid", 0);
232
233 if (traceEvent->fNumArgs) {
234 writer->beginObject("args");
235 const char* stringTable = traceEvent->stringTable();
236 bool addedSnapshot = false;
237 if (TRACE_EVENT_PHASE_SNAPSHOT_OBJECT == traceEvent->fPhase &&
238 baseTypeResolver->find(traceEvent->fID) &&
239 0 != strcmp(*baseTypeResolver->find(traceEvent->fID), traceEvent->fName)) {
240 // Special handling for snapshots where the name differs from creation.
241 writer->beginObject("snapshot");
242 writer->appendCString("base_type", *baseTypeResolver->find(traceEvent->fID));
243 addedSnapshot = true;
244 }
245
246 for (int i = 0; i < traceEvent->fNumArgs; ++i) {
247 const TraceEventArg* arg = traceEvent->args() + i;
248 // TODO: Skip '#'
249 writer->appendName(arg->fArgName);
250
251 if (arg->fArgName && '#' == arg->fArgName[0]) {
252 writer->beginObject();
253 writer->appendName("id_ref");
254 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
255 writer->endObject();
256 } else {
257 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
258 }
259 }
260
261 if (addedSnapshot) {
262 writer->endObject();
263 }
264
265 writer->endObject();
266 }
267
268 writer->endObject();
269 }
270
flush()271 void ChromeTracingTracer::flush() {
272 SkAutoSpinlock lock(fMutex);
273
274 SkString dirname = SkOSPath::Dirname(fFilename.c_str());
275 if (!dirname.isEmpty() && !sk_exists(dirname.c_str(), kWrite_SkFILE_Flag)) {
276 if (!sk_mkdir(dirname.c_str())) {
277 SkDebugf("Failed to create directory.");
278 }
279 }
280
281 SkFILEWStream fileStream(fFilename.c_str());
282 SkJSONWriter writer(&fileStream, SkJSONWriter::Mode::kFast);
283 writer.beginArray();
284
285 uint64_t clockOffset = 0;
286 if (fBlocks.size() > 0) {
287 clockOffset = reinterpret_cast<TraceEvent*>(fBlocks[0].fBlock.get())->fClockBegin;
288 } else if (fCurBlock.fEventsInBlock > 0) {
289 clockOffset = reinterpret_cast<TraceEvent*>(fCurBlock.fBlock.get())->fClockBegin;
290 }
291
292 TraceEventSerializationState serializationState(clockOffset);
293
294 auto event_block_to_json = [](SkJSONWriter* writer,
295 const TraceEventBlock& block,
296 TraceEventSerializationState* serializationState) {
297 TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(block.fBlock.get());
298 for (int i = 0; i < block.fEventsInBlock; ++i) {
299 trace_event_to_json(writer, traceEvent, serializationState);
300 traceEvent = traceEvent->next();
301 }
302 };
303
304 for (int i = 0; i < fBlocks.size(); ++i) {
305 event_block_to_json(&writer, fBlocks[i], &serializationState);
306 }
307 event_block_to_json(&writer, fCurBlock, &serializationState);
308
309 writer.endArray();
310 writer.flush();
311 fileStream.flush();
312 }
313