Improve tracing a bit

AnKi/Core/CoreTracer.cpp

@@ -11,6 +11,10 @@
 
 namespace anki {
 
+BoolCVar g_tracingEnabledCVar(CVarSubsystem::kCore, "Tracing", false, "Enable or disable tracing");
+
+#if ANKI_TRACING_ENABLED
+
 static void getSpreadsheetColumnName(U32 column, Array<char, 3>& arr)
 {
 	U32 major = column / 26;
@@ -68,7 +72,7 @@ CoreTracer::~CoreTracer()
 	}
 
 	// Write counter file
-	err = writeCountersForReal();
+	err = writeCountersOnShutdown();
 
 	// Cleanup
 	while(!m_frameCounters.isEmpty())
@@ -90,7 +94,7 @@ CoreTracer::~CoreTracer()
 Error CoreTracer::init(CString directory)
 {
 	Tracer::allocateSingleton();
-	const Bool enableTracer = getenv("ANKI_CORE_TRACER_ENABLED") && getenv("ANKI_CORE_TRACER_ENABLED")[0] == '1';
+	const Bool enableTracer = g_tracingEnabledCVar.get();
 	Tracer::getSingleton().setEnabled(enableTracer);
 	ANKI_CORE_LOGI("Tracing is %s from the beginning", (enableTracer) ? "enabled" : "disabled");
 
@@ -102,10 +106,8 @@ Error CoreTracer::init(CString directory)
 	CoreString fname;
 	fname.sprintf("%s/%d%02d%02d-%02d%02d_", directory.cstr(), tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min);
 
-	ANKI_CHECK(m_traceJsonFile.open(CoreString().sprintf("%strace.json", fname.cstr()), FileOpenFlag::kWrite));
-	ANKI_CHECK(m_traceJsonFile.writeText("[\n"));
-
-	ANKI_CHECK(m_countersCsvFile.open(CoreString().sprintf("%scounters.csv", fname.cstr()), FileOpenFlag::kWrite));
+	m_traceJsonFilename.sprintf("%strace.json", fname.cstr());
+	m_countersCsvFilename.sprintf("%scounters.csv", fname.cstr());
 
 	return Error::kNone;
 }
@@ -158,6 +160,18 @@ Error CoreTracer::threadWorker()
 
 Error CoreTracer::writeEvents(ThreadWorkItem& item)
 {
+	if(item.m_events.getSize() == 0)
+	{
+		return Error::kNone;
+	}
+
+	if(!m_traceJsonFile.isOpen())
+	{
+		ANKI_CHECK(m_traceJsonFile.open(m_traceJsonFilename, FileOpenFlag::kWrite));
+		ANKI_CHECK(m_traceJsonFile.writeText("[\n"));
+		ANKI_CORE_LOGI("Trace file created: %s", m_traceJsonFilename.cstr());
+	}
+
 	// First sort them to fix overlaping in chrome
 	std::sort(item.m_events.getBegin(), item.m_events.getEnd(), [](const TracerEvent& a, TracerEvent& b) {
 		return (a.m_start != b.m_start) ? a.m_start < b.m_start : a.m_duration > b.m_duration;
@@ -170,7 +184,7 @@ Error CoreTracer::writeEvents(ThreadWorkItem& item)
 		const I64 durMicroSec = I64(event.m_duration * 1000000.0);
 
 		// Do a hack
-		const ThreadId tid = (event.m_name == "GPU_TIME") ? 1 : item.m_tid;
+		const ThreadId tid = (event.m_name == "tGpuFrameTime") ? 1 : item.m_tid;
 
 		ANKI_CHECK(m_traceJsonFile.writeTextf("{\"name\": \"%s\", \"cat\": \"PERF\", \"ph\": \"X\", "
 											  "\"pid\": 1, \"tid\": %" PRIu64 ", \"ts\": %" PRIi64 ", \"dur\": %" PRIi64 "},\n",
@@ -308,27 +322,37 @@ void CoreTracer::flushFrame(U64 frame)
 			self.m_cvar.notifyOne();
 		},
 		&ctx);
+
+	if(Tracer::getSingleton().getEnabled() != g_tracingEnabledCVar.get())
+	{
+		Tracer::getSingleton().setEnabled(g_tracingEnabledCVar.get());
+		ANKI_CORE_LOGI("%s tracing", (g_tracingEnabledCVar.get()) ? "Enabling" : "Disabling");
+	}
 }
 
-Error CoreTracer::writeCountersForReal()
+Error CoreTracer::writeCountersOnShutdown()
 {
-	if(!m_countersCsvFile.isOpen() || m_frameCounters.getSize() == 0)
+	if(m_frameCounters.getSize() == 0)
 	{
 		return Error::kNone;
 	}
 
+	File countersCsvFile;
+	ANKI_CHECK(countersCsvFile.open(m_countersCsvFilename, FileOpenFlag::kWrite));
+	ANKI_CORE_LOGI("Counter file created: %s", m_countersCsvFilename.cstr());
+
 	// Write the header
-	ANKI_CHECK(m_countersCsvFile.writeText("Frame"));
+	ANKI_CHECK(countersCsvFile.writeText("Frame"));
 	for(U32 i = 0; i < m_counterNames.getSize(); ++i)
 	{
-		ANKI_CHECK(m_countersCsvFile.writeTextf(",%s", m_counterNames[i].cstr()));
+		ANKI_CHECK(countersCsvFile.writeTextf(",%s", m_counterNames[i].cstr()));
 	}
-	ANKI_CHECK(m_countersCsvFile.writeText("\n"));
+	ANKI_CHECK(countersCsvFile.writeText("\n"));
 
 	// Write each frame
 	for(const PerFrameCounters& frame : m_frameCounters)
 	{
-		ANKI_CHECK(m_countersCsvFile.writeTextf("%" PRIu64, frame.m_frame));
+		ANKI_CHECK(countersCsvFile.writeTextf("%" PRIu64, frame.m_frame));
 
 		for(U32 j = 0; j < m_counterNames.getSize(); ++j)
 		{
@@ -343,28 +367,30 @@ Error CoreTracer::writeCountersForReal()
 				}
 			}
 
-			ANKI_CHECK(m_countersCsvFile.writeTextf(",%" PRIu64, value));
+			ANKI_CHECK(countersCsvFile.writeTextf(",%" PRIu64, value));
 		}
 
-		ANKI_CHECK(m_countersCsvFile.writeText("\n"));
+		ANKI_CHECK(countersCsvFile.writeText("\n"));
 	}
 
 	// Write some statistics
 	Array<const char*, 2> funcs = {"SUM", "AVERAGE"};
 	for(const char* func : funcs)
 	{
-		ANKI_CHECK(m_countersCsvFile.writeText(func));
+		ANKI_CHECK(countersCsvFile.writeText(func));
 		for(U32 i = 0; i < m_frameCounters.getSize(); ++i)
 		{
 			Array<char, 3> columnName;
 			getSpreadsheetColumnName(i + 1, columnName);
-			ANKI_CHECK(m_countersCsvFile.writeTextf(",=%s(%s2:%s%zu)", func, &columnName[0], &columnName[0], m_frameCounters.getSize() + 1));
+			ANKI_CHECK(countersCsvFile.writeTextf(",=%s(%s2:%s%zu)", func, &columnName[0], &columnName[0], m_frameCounters.getSize() + 1));
 		}
 
-		ANKI_CHECK(m_countersCsvFile.writeText("\n"));
+		ANKI_CHECK(countersCsvFile.writeText("\n"));
 	}
 
 	return Error::kNone;
 }
 
+#endif
+
 } // end namespace anki

AnKi/Core/CoreTracer.h

@@ -9,12 +9,17 @@
 #include <AnKi/Util/Thread.h>
 #include <AnKi/Util/List.h>
 #include <AnKi/Util/File.h>
+#include <AnKi/Core/CVarSet.h>
 
 namespace anki {
 
 /// @addtogroup core
 /// @{
 
+extern BoolCVar g_tracingEnabledCVar;
+
+#if ANKI_TRACING_ENABLED
+
 /// A system that sits on top of the tracer and processes the counters and events.
 class CoreTracer : public MakeSingleton<CoreTracer>
 {
@@ -40,8 +45,9 @@ private:
 	IntrusiveList<PerFrameCounters> m_frameCounters;
 
 	IntrusiveList<ThreadWorkItem> m_workItems; ///< Items for the thread to process.
+	CoreString m_traceJsonFilename;
+	CoreString m_countersCsvFilename;
 	File m_traceJsonFile;
-	File m_countersCsvFile;
 	Bool m_quit = false;
 
 	CoreTracer();
@@ -52,8 +58,10 @@ private:
 
 	Error writeEvents(ThreadWorkItem& item);
 	void gatherCounters(ThreadWorkItem& item);
-	Error writeCountersForReal();
+	Error writeCountersOnShutdown();
 };
+
+#endif
 /// @}
 
 } // end namespace anki

AnKi/Renderer/MainRenderer.cpp

@@ -170,7 +170,8 @@ Error MainRenderer::render(Texture* presentTex)
 
 		if(rgraphStats.m_gpuTime > 0.0)
 		{
-			ANKI_TRACE_CUSTOM_EVENT(Gpu, rgraphStats.m_cpuStartTime, rgraphStats.m_gpuTime);
+			// WARNING: The name of the event is somewhat special. Search it to see why
+			ANKI_TRACE_CUSTOM_EVENT(GpuFrameTime, rgraphStats.m_cpuStartTime, rgraphStats.m_gpuTime);
 		}
 	}
 

AnKi/Util/Tracer.cpp

@@ -10,6 +10,8 @@
 
 namespace anki {
 
+#if ANKI_TRACING_ENABLED
+
 class Tracer::Chunk : public IntrusiveListEnabled<Chunk>
 {
 public:
@@ -190,4 +192,6 @@ void Tracer::flush(TracerFlushCallback callback, void* callbackUserData)
 	}
 }
 
+#endif
+
 } // end namespace anki

AnKi/Util/Tracer.h

@@ -17,6 +17,8 @@ namespace anki {
 /// @addtogroup util_other
 /// @{
 
+#if ANKI_TRACING_ENABLED
+
 /// @memberof Tracer
 class TracerEventHandle
 {
@@ -149,7 +151,6 @@ private:
 	Tracer* m_tracer;
 };
 
-#if ANKI_TRACING_ENABLED
 #	define ANKI_TRACE_SCOPED_EVENT(name_) TracerScopedEvent _tse##name_(ANKI_STRINGIZE(ANKI_CONCATENATE(t, name_)))
 #	define ANKI_TRACE_CUSTOM_EVENT(name_, start_, duration_) \
 		Tracer::getSingleton().addCustomEvent(ANKI_STRINGIZE(ANKI_CONCATENATE(t, name_)), start_, duration_)

Samples/Common/SampleApp.cpp

@@ -169,9 +169,9 @@ Error SampleApp::userMainLoop(Bool& quit, Second elapsedTime)
 		}
 	}
 
-	if(in.getKey(KeyCode::kF12) == 1 && ANKI_TRACING_ENABLED)
+	if(in.getKey(KeyCode::kF11) == 1 && ANKI_TRACING_ENABLED)
 	{
-		Tracer::getSingleton().setEnabled(!Tracer::getSingleton().getEnabled());
+		g_tracingEnabledCVar.set(!g_tracingEnabledCVar.get());
 	}
 
 	if(in.getMouseButton(MouseButton::kRight) || in.hasTouchDevice())

Sandbox/Main.cpp

@@ -51,7 +51,7 @@ Error MyApp::init(int argc, char* argv[])
 	{
 		m_profile = true;
 		g_targetFpsCVar.set(240);
-		Tracer::getSingleton().setEnabled(true);
+		g_tracingEnabledCVar.set(true);
 	}
 
 	// Load scene
@@ -156,7 +156,7 @@ Error MyApp::userMainLoop(Bool& quit, Second elapsedTime)
 
 	if(in.getKey(KeyCode::kF11) == 1)
 	{
-		Tracer::getSingleton().setEnabled(!Tracer::getSingleton().getEnabled());
+		g_tracingEnabledCVar.set(!g_tracingEnabledCVar.get());
 	}
 
 #if !PLAYER
@@ -167,11 +167,6 @@ Error MyApp::userMainLoop(Bool& quit, Second elapsedTime)
 		mousePosOn1stClick = in.getMousePosition();
 	}
 
-	if(in.getKey(KeyCode::kF12) == 1 && ANKI_TRACING_ENABLED)
-	{
-		Tracer::getSingleton().setEnabled(!Tracer::getSingleton().getEnabled());
-	}
-
 	if(in.getMouseButton(MouseButton::kRight) || in.hasTouchDevice())
 	{
 		constexpr F32 ROTATE_ANGLE = toRad(2.5f);