tools/trace/SkChromeTracingTracer.cpp - platform/external/skia - Gitiles

 /*
  * Copyright 2017 Google Inc.
  *
  * Use of this source code is governed by a BSD-style license that can be
  * found in the LICENSE file.
  */

 #include "SkChromeTracingTracer.h"
 #include "SkJSONWriter.h"
 #include "SkThreadID.h"
 #include "SkTraceEvent.h"
 #include "SkOSFile.h"
 #include "SkOSPath.h"
 #include "SkStream.h"

 #include <chrono>

 namespace {

 /**
  * All events have a fixed block of information (TraceEvent), plus variable length payload:
  * {TraceEvent} {TraceEventArgs} {Inline Payload}
  */
 struct TraceEventArg {
     uint8_t fArgType;
     const char* fArgName;
     uint64_t fArgValue;
 };

 // These fields are ordered to minimize size due to alignment. Argument types could be packed
 // better, but very few events have many arguments, so the net loss is pretty small.
 struct TraceEvent {
     char fPhase;
     uint8_t fNumArgs;
     uint32_t fSize;

     const char* fName;
     // TODO: Merge fID and fClockEnd (never used together)
     uint64_t fID;
     uint64_t fClockBegin;
     uint64_t fClockEnd;
     SkThreadID fThreadID;

     TraceEvent* next() {
         return reinterpret_cast<TraceEvent*>(reinterpret_cast<char*>(this) + fSize);
     }
     TraceEventArg* args() {
         return reinterpret_cast<TraceEventArg*>(this + 1);
     }
     char* stringTable() {
         return reinterpret_cast<char*>(this->args() + fNumArgs);
     }
 };

 }

 SkChromeTracingTracer::SkChromeTracingTracer(const char* filename) : fFilename(filename) {
     this->createBlock();
 }

 SkChromeTracingTracer::~SkChromeTracingTracer() {
     this->flush();
 }

 void SkChromeTracingTracer::createBlock() {
     fCurBlock.fBlock = BlockPtr(new uint8_t[kBlockSize]);
     fCurBlock.fEventsInBlock = 0;
     fCurBlockUsed = 0;
 }

 SkEventTracer::Handle SkChromeTracingTracer::appendEvent(const void* data, size_t size) {
     SkASSERT(size > 0 && size <= kBlockSize);

     SkAutoMutexAcquire lock(fMutex);
     if (fCurBlockUsed + size > kBlockSize) {
         fBlocks.push_back(std::move(fCurBlock));
         this->createBlock();
     }
     memcpy(fCurBlock.fBlock.get() + fCurBlockUsed, data, size);
     Handle handle = reinterpret_cast<Handle>(fCurBlock.fBlock.get() + fCurBlockUsed);
     fCurBlockUsed += size;
     fCurBlock.fEventsInBlock++;
     return handle;
 }

 SkEventTracer::Handle SkChromeTracingTracer::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) {
     // TODO: Respect flags (or assert). INSTANT events encode scope in flags, should be stored
     // using "s" key in JSON. COPY flag should be supported or rejected.

     // Figure out how much extra storage we need for copied strings
     int size = static_cast<int>(sizeof(TraceEvent) + numArgs * sizeof(TraceEventArg));
     for (int i = 0; i < numArgs; ++i) {
         if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
             skia::tracing_internals::TraceValueUnion value;
             value.as_uint = argValues[i];
             size += strlen(value.as_string) + 1;
         }
     }

     SkSTArray<128, uint8_t, true> storage;
     uint8_t* storagePtr = storage.push_back_n(size);

     TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(storagePtr);
     traceEvent->fPhase = phase;
     traceEvent->fNumArgs = numArgs;
     traceEvent->fSize = size;
     traceEvent->fName = name;
     traceEvent->fID = id;
     traceEvent->fClockBegin = std::chrono::steady_clock::now().time_since_epoch().count();
     traceEvent->fClockEnd = 0;
     traceEvent->fThreadID = SkGetThreadID();

     TraceEventArg* traceEventArgs = traceEvent->args();
     char* stringTableBase = traceEvent->stringTable();
     char* stringTable = stringTableBase;
     for (int i = 0; i < numArgs; ++i) {
         traceEventArgs[i].fArgName = argNames[i];
         traceEventArgs[i].fArgType = argTypes[i];
         if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
             // Just write an offset into the arguments array
             traceEventArgs[i].fArgValue = stringTable  - stringTableBase;

             // Copy string into our buffer (and advance)
             skia::tracing_internals::TraceValueUnion value;
             value.as_uint = argValues[i];
             while (*value.as_string) {
                 *stringTable++ = *value.as_string++;
             }
             *stringTable++ = 0;
         } else {
             traceEventArgs[i].fArgValue = argValues[i];
         }
     }

     return this->appendEvent(storagePtr, size);
 }

 void SkChromeTracingTracer::updateTraceEventDuration(const uint8_t* categoryEnabledFlag,
                                                      const char* name,
                                                      SkEventTracer::Handle handle) {
     // We could probably get away with not locking here, but let's be totally safe.
     SkAutoMutexAcquire lock(fMutex);
     TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(handle);
     traceEvent->fClockEnd = std::chrono::steady_clock::now().time_since_epoch().count();
 }

 static void trace_value_to_json(SkJSONWriter* writer, uint64_t argValue, uint8_t argType,
                                 const char* stringTableBase) {
     skia::tracing_internals::TraceValueUnion value;
     value.as_uint = argValue;

     switch (argType) {
         case TRACE_VALUE_TYPE_BOOL:
             writer->appendBool(value.as_bool);
             break;
         case TRACE_VALUE_TYPE_UINT:
             writer->appendU64(value.as_uint);
             break;
         case TRACE_VALUE_TYPE_INT:
             writer->appendS64(value.as_int);
             break;
         case TRACE_VALUE_TYPE_DOUBLE:
             writer->appendDouble(value.as_double);
             break;
         case TRACE_VALUE_TYPE_POINTER:
             writer->appendPointer(value.as_pointer);
             break;
         case TRACE_VALUE_TYPE_STRING:
             writer->appendString(value.as_string);
             break;
         case TRACE_VALUE_TYPE_COPY_STRING:
             writer->appendString(stringTableBase + value.as_uint);
             break;
         default:
             writer->appendString("<unknown type>");
             break;
     }
 }

 namespace {

 struct TraceEventSerializationState {
     TraceEventSerializationState(uint64_t clockOffset)
             : fClockOffset(clockOffset), fNextThreadID(0) {}

     int getShortThreadID(SkThreadID id) {
         if (int* shortIDPtr = fShortThreadIDMap.find(id)) {
             return *shortIDPtr;
         }
         int shortID = fNextThreadID++;
         fShortThreadIDMap.set(id, shortID);
         return shortID;
     }

     uint64_t fClockOffset;
     SkTHashMap<uint64_t, const char*> fBaseTypeResolver;
     int fNextThreadID;
     SkTHashMap<SkThreadID, int> fShortThreadIDMap;
 };

 }

 static void trace_event_to_json(SkJSONWriter* writer, TraceEvent* traceEvent,
                                 TraceEventSerializationState* serializationState) {
     // We track the original (creation time) "name" of each currently live object, so we can
     // automatically insert "base_name" fields in object snapshot events.
     auto baseTypeResolver = &(serializationState->fBaseTypeResolver);
     if (TRACE_EVENT_PHASE_CREATE_OBJECT == traceEvent->fPhase) {
         SkASSERT(nullptr == baseTypeResolver->find(traceEvent->fID));
         baseTypeResolver->set(traceEvent->fID, traceEvent->fName);
     } else if (TRACE_EVENT_PHASE_DELETE_OBJECT == traceEvent->fPhase) {
         SkASSERT(nullptr != baseTypeResolver->find(traceEvent->fID));
         baseTypeResolver->remove(traceEvent->fID);
     }

     writer->beginObject();

     char phaseString[2] = { traceEvent->fPhase, 0 };
     writer->appendString("ph", phaseString);
     writer->appendString("name", traceEvent->fName);
     if (0 != traceEvent->fID) {
         // IDs are (almost) always pointers
         writer->appendPointer("id", reinterpret_cast<void*>(traceEvent->fID));
     }

     // Offset timestamps to reduce JSON length, then convert nanoseconds to microseconds
     // (standard time unit for tracing JSON files).
     uint64_t relativeTimestamp = static_cast<int64_t>(traceEvent->fClockBegin -
                                                       serializationState->fClockOffset);
     writer->appendDoubleDigits("ts", static_cast<double>(relativeTimestamp) * 1E-3, 3);
     if (0 != traceEvent->fClockEnd) {
         double dur = static_cast<double>(traceEvent->fClockEnd - traceEvent->fClockBegin) * 1E-3;
         writer->appendDoubleDigits("dur", dur, 3);
     }

     writer->appendS64("tid", serializationState->getShortThreadID(traceEvent->fThreadID));
     // Trace events *must* include a process ID, but for internal tools this isn't particularly
     // important (and certainly not worth adding a cross-platform API to get it).
     writer->appendS32("pid", 0);

     if (traceEvent->fNumArgs) {
         writer->beginObject("args");
         const char* stringTable = traceEvent->stringTable();
         bool addedSnapshot = false;
         if (TRACE_EVENT_PHASE_SNAPSHOT_OBJECT == traceEvent->fPhase &&
                 baseTypeResolver->find(traceEvent->fID) &&
                 0 != strcmp(*baseTypeResolver->find(traceEvent->fID), traceEvent->fName)) {
             // Special handling for snapshots where the name differs from creation.
             writer->beginObject("snapshot");
             writer->appendString("base_type", *baseTypeResolver->find(traceEvent->fID));
             addedSnapshot = true;
         }

         for (int i = 0; i < traceEvent->fNumArgs; ++i) {
             const TraceEventArg* arg = traceEvent->args() + i;
             // TODO: Skip '#'
             writer->appendName(arg->fArgName);

             if (arg->fArgName && '#' == arg->fArgName[0]) {
                 writer->beginObject();
                 writer->appendName("id_ref");
                 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
                 writer->endObject();
             } else {
                 trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
             }
         }

         if (addedSnapshot) {
             writer->endObject();
         }

         writer->endObject();
     }

     writer->endObject();
 }

 void SkChromeTracingTracer::flush() {
     SkAutoMutexAcquire lock(fMutex);

     SkString dirname = SkOSPath::Dirname(fFilename.c_str());
     if (!dirname.isEmpty() && !sk_exists(dirname.c_str(), kWrite_SkFILE_Flag)) {
         if (!sk_mkdir(dirname.c_str())) {
             SkDebugf("Failed to create directory.");
         }
     }

     SkFILEWStream fileStream(fFilename.c_str());
     SkJSONWriter writer(&fileStream, SkJSONWriter::Mode::kFast);
     writer.beginArray();

     uint64_t clockOffset = 0;
     if (fBlocks.count() > 0) {
         clockOffset = reinterpret_cast<TraceEvent*>(fBlocks[0].fBlock.get())->fClockBegin;
     } else if (fCurBlock.fEventsInBlock > 0) {
         clockOffset = reinterpret_cast<TraceEvent*>(fCurBlock.fBlock.get())->fClockBegin;
     }

     TraceEventSerializationState serializationState(clockOffset);

     auto event_block_to_json = [](SkJSONWriter* writer, const TraceEventBlock& block,
                                   TraceEventSerializationState* serializationState) {
         TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(block.fBlock.get());
         for (int i = 0; i < block.fEventsInBlock; ++i) {
             trace_event_to_json(writer, traceEvent, serializationState);
             traceEvent = traceEvent->next();
         }
     };

     for (int i = 0; i < fBlocks.count(); ++i) {
         event_block_to_json(&writer, fBlocks[i], &serializationState);
     }
     event_block_to_json(&writer, fCurBlock, &serializationState);

     writer.endArray();
     writer.flush();
     fileStream.flush();
 }
	/*
	* Copyright 2017 Google Inc.
	*
	* Use of this source code is governed by a BSD-style license that can be
	* found in the LICENSE file.
	*/

	#include "SkChromeTracingTracer.h"
	#include "SkJSONWriter.h"
	#include "SkThreadID.h"
	#include "SkTraceEvent.h"
	#include "SkOSFile.h"
	#include "SkOSPath.h"
	#include "SkStream.h"

	#include <chrono>

	namespace {

	/**
	* All events have a fixed block of information (TraceEvent), plus variable length payload:
	* {TraceEvent} {TraceEventArgs} {Inline Payload}
	*/
	struct TraceEventArg {
	uint8_t fArgType;
	const char* fArgName;
	uint64_t fArgValue;
	};

	// These fields are ordered to minimize size due to alignment. Argument types could be packed
	// better, but very few events have many arguments, so the net loss is pretty small.
	struct TraceEvent {
	char fPhase;
	uint8_t fNumArgs;
	uint32_t fSize;

	const char* fName;
	// TODO: Merge fID and fClockEnd (never used together)
	uint64_t fID;
	uint64_t fClockBegin;
	uint64_t fClockEnd;
	SkThreadID fThreadID;

	TraceEvent* next() {
	return reinterpret_cast<TraceEvent>(reinterpret_cast<char>(this) + fSize);
	}
	TraceEventArg* args() {
	return reinterpret_cast<TraceEventArg*>(this + 1);
	}
	char* stringTable() {
	return reinterpret_cast<char*>(this->args() + fNumArgs);
	}
	};

	}

	SkChromeTracingTracer::SkChromeTracingTracer(const char* filename) : fFilename(filename) {
	this->createBlock();
	}

	SkChromeTracingTracer::~SkChromeTracingTracer() {
	this->flush();
	}

	void SkChromeTracingTracer::createBlock() {
	fCurBlock.fBlock = BlockPtr(new uint8_t[kBlockSize]);
	fCurBlock.fEventsInBlock = 0;
	fCurBlockUsed = 0;
	}

	SkEventTracer::Handle SkChromeTracingTracer::appendEvent(const void* data, size_t size) {
	SkASSERT(size > 0 && size <= kBlockSize);

	SkAutoMutexAcquire lock(fMutex);
	if (fCurBlockUsed + size > kBlockSize) {
	fBlocks.push_back(std::move(fCurBlock));
	this->createBlock();
	}
	memcpy(fCurBlock.fBlock.get() + fCurBlockUsed, data, size);
	Handle handle = reinterpret_cast<Handle>(fCurBlock.fBlock.get() + fCurBlockUsed);
	fCurBlockUsed += size;
	fCurBlock.fEventsInBlock++;
	return handle;
	}

	SkEventTracer::Handle SkChromeTracingTracer::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) {
	// TODO: Respect flags (or assert). INSTANT events encode scope in flags, should be stored
	// using "s" key in JSON. COPY flag should be supported or rejected.

	// Figure out how much extra storage we need for copied strings
	int size = static_cast<int>(sizeof(TraceEvent) + numArgs * sizeof(TraceEventArg));
	for (int i = 0; i < numArgs; ++i) {
	if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
	skia::tracing_internals::TraceValueUnion value;
	value.as_uint = argValues[i];
	size += strlen(value.as_string) + 1;
	}
	}

	SkSTArray<128, uint8_t, true> storage;
	uint8_t* storagePtr = storage.push_back_n(size);

	TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(storagePtr);
	traceEvent->fPhase = phase;
	traceEvent->fNumArgs = numArgs;
	traceEvent->fSize = size;
	traceEvent->fName = name;
	traceEvent->fID = id;
	traceEvent->fClockBegin = std::chrono::steady_clock::now().time_since_epoch().count();
	traceEvent->fClockEnd = 0;
	traceEvent->fThreadID = SkGetThreadID();

	TraceEventArg* traceEventArgs = traceEvent->args();
	char* stringTableBase = traceEvent->stringTable();
	char* stringTable = stringTableBase;
	for (int i = 0; i < numArgs; ++i) {
	traceEventArgs[i].fArgName = argNames[i];
	traceEventArgs[i].fArgType = argTypes[i];
	if (TRACE_VALUE_TYPE_COPY_STRING == argTypes[i]) {
	// Just write an offset into the arguments array
	traceEventArgs[i].fArgValue = stringTable - stringTableBase;

	// Copy string into our buffer (and advance)
	skia::tracing_internals::TraceValueUnion value;
	value.as_uint = argValues[i];
	while (*value.as_string) {
	stringTable++ = value.as_string++;
	}
	*stringTable++ = 0;
	} else {
	traceEventArgs[i].fArgValue = argValues[i];
	}
	}

	return this->appendEvent(storagePtr, size);
	}

	void SkChromeTracingTracer::updateTraceEventDuration(const uint8_t* categoryEnabledFlag,
	const char* name,
	SkEventTracer::Handle handle) {
	// We could probably get away with not locking here, but let's be totally safe.
	SkAutoMutexAcquire lock(fMutex);
	TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(handle);
	traceEvent->fClockEnd = std::chrono::steady_clock::now().time_since_epoch().count();
	}

	static void trace_value_to_json(SkJSONWriter* writer, uint64_t argValue, uint8_t argType,
	const char* stringTableBase) {
	skia::tracing_internals::TraceValueUnion value;
	value.as_uint = argValue;

	switch (argType) {
	case TRACE_VALUE_TYPE_BOOL:
	writer->appendBool(value.as_bool);
	break;
	case TRACE_VALUE_TYPE_UINT:
	writer->appendU64(value.as_uint);
	break;
	case TRACE_VALUE_TYPE_INT:
	writer->appendS64(value.as_int);
	break;
	case TRACE_VALUE_TYPE_DOUBLE:
	writer->appendDouble(value.as_double);
	break;
	case TRACE_VALUE_TYPE_POINTER:
	writer->appendPointer(value.as_pointer);
	break;
	case TRACE_VALUE_TYPE_STRING:
	writer->appendString(value.as_string);
	break;
	case TRACE_VALUE_TYPE_COPY_STRING:
	writer->appendString(stringTableBase + value.as_uint);
	break;
	default:
	writer->appendString("<unknown type>");
	break;
	}
	}

	namespace {

	struct TraceEventSerializationState {
	TraceEventSerializationState(uint64_t clockOffset)
	: fClockOffset(clockOffset), fNextThreadID(0) {}

	int getShortThreadID(SkThreadID id) {
	if (int* shortIDPtr = fShortThreadIDMap.find(id)) {
	return *shortIDPtr;
	}
	int shortID = fNextThreadID++;
	fShortThreadIDMap.set(id, shortID);
	return shortID;
	}

	uint64_t fClockOffset;
	SkTHashMap<uint64_t, const char*> fBaseTypeResolver;
	int fNextThreadID;
	SkTHashMap<SkThreadID, int> fShortThreadIDMap;
	};

	}

	static void trace_event_to_json(SkJSONWriter* writer, TraceEvent* traceEvent,
	TraceEventSerializationState* serializationState) {
	// We track the original (creation time) "name" of each currently live object, so we can
	// automatically insert "base_name" fields in object snapshot events.
	auto baseTypeResolver = &(serializationState->fBaseTypeResolver);
	if (TRACE_EVENT_PHASE_CREATE_OBJECT == traceEvent->fPhase) {
	SkASSERT(nullptr == baseTypeResolver->find(traceEvent->fID));
	baseTypeResolver->set(traceEvent->fID, traceEvent->fName);
	} else if (TRACE_EVENT_PHASE_DELETE_OBJECT == traceEvent->fPhase) {
	SkASSERT(nullptr != baseTypeResolver->find(traceEvent->fID));
	baseTypeResolver->remove(traceEvent->fID);
	}

	writer->beginObject();

	char phaseString[2] = { traceEvent->fPhase, 0 };
	writer->appendString("ph", phaseString);
	writer->appendString("name", traceEvent->fName);
	if (0 != traceEvent->fID) {
	// IDs are (almost) always pointers
	writer->appendPointer("id", reinterpret_cast<void*>(traceEvent->fID));
	}

	// Offset timestamps to reduce JSON length, then convert nanoseconds to microseconds
	// (standard time unit for tracing JSON files).
	uint64_t relativeTimestamp = static_cast<int64_t>(traceEvent->fClockBegin -
	serializationState->fClockOffset);
	writer->appendDoubleDigits("ts", static_cast<double>(relativeTimestamp) * 1E-3, 3);
	if (0 != traceEvent->fClockEnd) {
	double dur = static_cast<double>(traceEvent->fClockEnd - traceEvent->fClockBegin) * 1E-3;
	writer->appendDoubleDigits("dur", dur, 3);
	}

	writer->appendS64("tid", serializationState->getShortThreadID(traceEvent->fThreadID));
	// Trace events must include a process ID, but for internal tools this isn't particularly
	// important (and certainly not worth adding a cross-platform API to get it).
	writer->appendS32("pid", 0);

	if (traceEvent->fNumArgs) {
	writer->beginObject("args");
	const char* stringTable = traceEvent->stringTable();
	bool addedSnapshot = false;
	if (TRACE_EVENT_PHASE_SNAPSHOT_OBJECT == traceEvent->fPhase &&
	baseTypeResolver->find(traceEvent->fID) &&
	0 != strcmp(*baseTypeResolver->find(traceEvent->fID), traceEvent->fName)) {
	// Special handling for snapshots where the name differs from creation.
	writer->beginObject("snapshot");
	writer->appendString("base_type", *baseTypeResolver->find(traceEvent->fID));
	addedSnapshot = true;
	}

	for (int i = 0; i < traceEvent->fNumArgs; ++i) {
	const TraceEventArg* arg = traceEvent->args() + i;
	// TODO: Skip '#'
	writer->appendName(arg->fArgName);

	if (arg->fArgName && '#' == arg->fArgName[0]) {
	writer->beginObject();
	writer->appendName("id_ref");
	trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
	writer->endObject();
	} else {
	trace_value_to_json(writer, arg->fArgValue, arg->fArgType, stringTable);
	}
	}

	if (addedSnapshot) {
	writer->endObject();
	}

	writer->endObject();
	}

	writer->endObject();
	}

	void SkChromeTracingTracer::flush() {
	SkAutoMutexAcquire lock(fMutex);

	SkString dirname = SkOSPath::Dirname(fFilename.c_str());
	if (!dirname.isEmpty() && !sk_exists(dirname.c_str(), kWrite_SkFILE_Flag)) {
	if (!sk_mkdir(dirname.c_str())) {
	SkDebugf("Failed to create directory.");
	}
	}

	SkFILEWStream fileStream(fFilename.c_str());
	SkJSONWriter writer(&fileStream, SkJSONWriter::Mode::kFast);
	writer.beginArray();

	uint64_t clockOffset = 0;
	if (fBlocks.count() > 0) {
	clockOffset = reinterpret_cast<TraceEvent*>(fBlocks[0].fBlock.get())->fClockBegin;
	} else if (fCurBlock.fEventsInBlock > 0) {
	clockOffset = reinterpret_cast<TraceEvent*>(fCurBlock.fBlock.get())->fClockBegin;
	}

	TraceEventSerializationState serializationState(clockOffset);

	auto event_block_to_json = [](SkJSONWriter* writer, const TraceEventBlock& block,
	TraceEventSerializationState* serializationState) {
	TraceEvent* traceEvent = reinterpret_cast<TraceEvent*>(block.fBlock.get());
	for (int i = 0; i < block.fEventsInBlock; ++i) {
	trace_event_to_json(writer, traceEvent, serializationState);
	traceEvent = traceEvent->next();
	}
	};

	for (int i = 0; i < fBlocks.count(); ++i) {
	event_block_to_json(&writer, fBlocks[i], &serializationState);
	}
	event_block_to_json(&writer, fCurBlock, &serializationState);

	writer.endArray();
	writer.flush();
	fileStream.flush();
	}