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
18namespace {
19
20/**
21 * All events have a fixed block of information (TraceEvent), plus variable length payload:
22 * {TraceEvent} {TraceEventArgs} {Inline Payload}
23 */
24struct 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.
32struct 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
44    TraceEvent* next() {
45        return reinterpret_cast<TraceEvent*>(reinterpret_cast<char*>(this) + fSize);
46    }
47    TraceEventArg* args() { return reinterpret_cast<TraceEventArg*>(this + 1); }
48    char*          stringTable() { return reinterpret_cast<char*>(this->args() + fNumArgs); }
49};
50
51}  // namespace
52
53ChromeTracingTracer::ChromeTracingTracer(const char* filename) : fFilename(filename) {
54    this->createBlock();
55}
56
57ChromeTracingTracer::~ChromeTracingTracer() { this->flush(); }
58
59void ChromeTracingTracer::createBlock() {
60    fCurBlock.fBlock         = BlockPtr(new uint8_t[kBlockSize]);
61    fCurBlock.fEventsInBlock = 0;
62    fCurBlockUsed            = 0;
63}
64
65SkEventTracer::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
80SkEventTracer::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
142void 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
151static 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
172namespace {
173
174struct TraceEventSerializationState {
175    TraceEventSerializationState(uint64_t clockOffset)
176            : fClockOffset(clockOffset), fNextThreadID(0) {}
177
178    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
195static 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
272void 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