Skip to content

Instantly share code, notes, and snippets.

@maronsson
Forked from TheCherno/Instrumentor.h
Last active June 8, 2024 04:27
Show Gist options
  • Save maronsson/073840bf94e4d6df94c5f294a6e96e03 to your computer and use it in GitHub Desktop.
Save maronsson/073840bf94e4d6df94c5f294a6e96e03 to your computer and use it in GitHub Desktop.
Basic Instrumentation Profiler
//
// Basic instrumentation profiler by Cherno
// Usage: include this header file somewhere in your code (eg. precompiled header), and then use like:
//
// Instrumentor::Get().BeginSession("Session Name"); // Begin session
// {
// InstrumentationTimer timer("Profiled Scope Name"); // Place code like this in scopes you'd like to include in profiling
// // Code
// }
// Instrumentor::Get().EndSession(); // End Session
//
// You will probably want to macro-fy this, to switch on/off easily and use things like __FUNCSIG__ for the profile name.
//
#pragma once
#include <string>
#include <chrono>
#include <algorithm>
#include <fstream>
#include <mutex>
#include <thread>
struct ProfileResult
{
std::string Name;
long long Start, End;
uint32_t ThreadID;
};
struct InstrumentationSession
{
std::string Name;
};
class Instrumentor
{
private:
InstrumentationSession* m_CurrentSession;
std::ofstream m_OutputStream;
int m_ProfileCount;
std::mutex m_lock;
public:
Instrumentor()
: m_CurrentSession(nullptr), m_ProfileCount(0)
{
}
void BeginSession(const std::string& name, const std::string& filepath = "results.json")
{
m_OutputStream.open(filepath);
WriteHeader();
m_CurrentSession = new InstrumentationSession{ name };
}
void EndSession()
{
WriteFooter();
m_OutputStream.close();
delete m_CurrentSession;
m_CurrentSession = nullptr;
m_ProfileCount = 0;
}
void WriteProfile(const ProfileResult& result)
{
std::lock_guard<std::mutex> lock(m_lock);
if (m_ProfileCount++ > 0)
m_OutputStream << ",";
std::string name = result.Name;
std::replace(name.begin(), name.end(), '"', '\'');
m_OutputStream << "{";
m_OutputStream << "\"cat\":\"function\",";
m_OutputStream << "\"dur\":" << (result.End - result.Start) << ',';
m_OutputStream << "\"name\":\"" << name << "\",";
m_OutputStream << "\"ph\":\"X\",";
m_OutputStream << "\"pid\":0,";
m_OutputStream << "\"tid\":" << result.ThreadID << ",";
m_OutputStream << "\"ts\":" << result.Start;
m_OutputStream << "}";
m_OutputStream.flush();
}
void WriteHeader()
{
m_OutputStream << "{\"otherData\": {},\"traceEvents\":[";
m_OutputStream.flush();
}
void WriteFooter()
{
m_OutputStream << "]}";
m_OutputStream.flush();
}
static Instrumentor& Get()
{
static Instrumentor instance;
return instance;
}
};
class InstrumentationTimer
{
public:
InstrumentationTimer(const char* name)
: m_Name(name), m_Stopped(false)
{
m_StartTimepoint = std::chrono::high_resolution_clock::now();
}
~InstrumentationTimer()
{
if (!m_Stopped)
Stop();
}
void Stop()
{
auto endTimepoint = std::chrono::high_resolution_clock::now();
long long start = std::chrono::time_point_cast<std::chrono::microseconds>(m_StartTimepoint).time_since_epoch().count();
long long end = std::chrono::time_point_cast<std::chrono::microseconds>(endTimepoint).time_since_epoch().count();
uint32_t threadID = std::hash<std::thread::id>{}(std::this_thread::get_id());
Instrumentor::Get().WriteProfile({ m_Name, start, end, threadID });
m_Stopped = true;
}
private:
const char* m_Name;
std::chrono::time_point<std::chrono::high_resolution_clock> m_StartTimepoint;
bool m_Stopped;
};
#include <iostream>
#include <unistd.h>
#include "Instrumentor.h"
#define USE_TIMEIT 1
#if USE_TIMEIT
# define TIMEIT() InstrumentationTimer timer(__FUNCTION__);
#else
# define TIMEIT()
#endif
void a()
{
TIMEIT()
usleep(50000);
}
void b()
{
TIMEIT()
usleep(50000);
}
void f1() {
TIMEIT()
usleep(200000);
a();
}
void f2() {
TIMEIT()
usleep(200000);
b();
}
void f3() {
TIMEIT()
usleep(200000);
a();
b();
}
int main()
{
Instrumentor::Get().BeginSession("test-main");
std::vector<std::thread> workers;
workers.push_back(std::thread(f1));
workers.push_back(std::thread(f2));
workers.push_back(std::thread(f3));
for (auto& w : workers)
{
w.join();
}
Instrumentor::Get().EndSession();
return 0;
}
vpc: main.cpp Instrumentor.h
g++ -std=c++17 main.cpp -o vpc -lpthread
clean:
rm -f vpc
@thedpaul
Copy link

thedpaul commented May 4, 2020

@maronsson I liked the program you wrote with thread lock and so on. But I found an issue with the visual display of the results in chrom://tracing. I added another void function c which is also being timed with the TIMEIT() macro and it runs functions a and b sequentially.
Then, I added another void function f4 which is also being timed with the TIMEIT() macro and it runs function c. For some reason ... the display is not working properly in tracing. Do you know the reason? With this comment, I bind the function texts and a screenshot of the tracing view.

void c()
{
TIMEIT()
a();
b();
}

void f4()
{
TIMEIT()
usleep(200000);
c();
}

int main()
{
Profiler::get().beginSession("test-main");

std::vector<std::thread> workers;

workers.push_back(std::thread(f1));
workers.push_back(std::thread(f2));
workers.push_back(std::thread(f3));
workers.push_back(std::thread(f4));

for (auto& w : workers)
{
    w.join();
}

Profiler::get().endSession();

return 0;

}

Screenshot_20200504_120521

@kafeg
Copy link

kafeg commented Aug 3, 2020

@DPaulModz hey! As i understand it's because 'a' and 'c' started at the same time. If you will change 'c' like this then it will show everything correctly:
void c()
{
TIMEIT()
usleep(1);
a();
b();
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment