trace all the things

firmware/controllers/scheduling/pwm_generator_logic.cpp

@@ -152,6 +152,8 @@ void PwmConfig::handleCycleStart() {
  * @return Next time for signal toggle
  */
 efitimeus_t PwmConfig::togglePwmState() {
+	ScopePerf perf(PE::PwmConfigTogglePwmState);
+
 #if DEBUG_PWM
 	scheduleMsg(&logger, "togglePwmState phaseIndex=%d iteration=%d", safe.phaseIndex, safe.iteration);
 	scheduleMsg(&logger, "period=%.2f safe.period=%.2f", period, safe.periodNt);
@@ -186,7 +188,10 @@ efitimeus_t PwmConfig::togglePwmState() {
 		cbStateIndex = 1;
 	}
 
+	{
+		ScopePerf perf(PE::PwmConfigStateChangeCallback);
 		stateChangeCallback(cbStateIndex, arg);
+	}
 
 	efitimeus_t nextSwitchTimeUs = getNextSwitchTimeUs(this);
 #if DEBUG_PWM

firmware/controllers/trigger/rpm_calculator.cpp

@@ -18,6 +18,7 @@
 #include "trigger_central.h"
 #include "engine_configuration.h"
 #include "engine_math.h"
+#include "perf_trace.h"
 
 #if EFI_PROD_CODE
 #include "os_util.h"
@@ -370,6 +371,9 @@ void initRpmCalculator(Logging *sharedLogger DECLARE_ENGINE_PARAMETER_SUFFIX) {
 void scheduleByAngle(int rpm, scheduling_s *timer, angle_t angle,
 		schfunc_t callback, void *param, RpmCalculator *calc DECLARE_ENGINE_PARAMETER_SUFFIX) {
 	UNUSED(rpm);
+
+	ScopePerf perf(PE::ScheduleByAngle);
+
 	efiAssertVoid(CUSTOM_ANGLE_NAN, !cisnan(angle), "NaN angle?");
 	efiAssertVoid(CUSTOM_ERR_6634, isValidRpm(rpm), "RPM check expected");
 	float delayUs = calc->oneDegreeUs * angle;

firmware/development/perf_trace.cpp

@@ -1,24 +1,23 @@
 
+#include "efifeatures.h"
 #include "perf_trace.h"
 #include "efitime.h"
-#include "efifeatures.h"
 #include "os_util.h"
 
-#define TRACE_BUFFER_LENGTH 4096
+#define TRACE_BUFFER_LENGTH 2048
 
-enum class Phase : char
+enum class EPhase : char
 {
 	Start,
 	End,
 	InstantThread,
 	InstantGlobal,
-
 };
 
 struct TraceEntry
 {
 	PE Event;
-	Phase Type;
+	EPhase Phase;
 	uint8_t Data;
 	uint8_t ThreadId;
 	uint32_t Timestamp;
@@ -29,10 +28,15 @@ static_assert(sizeof(TraceEntry) == 8);
 static TraceEntry s_traceBuffer[TRACE_BUFFER_LENGTH];
 static size_t s_nextIdx = 0;
 
-void perfEventImpl(PE event, Phase type, uint8_t data)
+static bool s_isTracing = true;
-{
+
-	if constexpr (!ENABLE_PERF_TRACE)
+void perfEventImpl(PE event, EPhase phase, uint8_t data)
 {
+	if constexpr (!ENABLE_PERF_TRACE) {
+		return;
+	}
+	
+	if (!s_isTracing) {
 		return;
 	}
 
@@ -45,9 +49,9 @@ void perfEventImpl(PE event, Phase type, uint8_t data)
 		bool wasLocked = lockAnyContext();
 
 		idx = s_nextIdx++;
-		if (s_nextIdx >= TRACE_BUFFER_LENGTH)
+		if (s_nextIdx >= TRACE_BUFFER_LENGTH) {
-		{
 			s_nextIdx = 0;
+			s_isTracing = false;
 		}
 
 		if (!wasLocked) {
@@ -56,31 +60,33 @@ void perfEventImpl(PE event, Phase type, uint8_t data)
 	}
 
 	// We can safely write data out of the lock, our spot is reserved
-	TraceEntry& entry = s_traceBuffer[idx];
+	volatile TraceEntry& entry = s_traceBuffer[idx];
 
 	entry.Event = event;
-	entry.Type = type;
+	entry.Phase = phase;
-	entry.ThreadId = 0; // TODO
+	entry.ThreadId = static_cast<uint8_t>(SCB->ICSR & SCB_ICSR_VECTACTIVE_Msk);
 	entry.Timestamp = timestamp;
 	entry.Data = data;
 }
 
-void perfEventBegin(PE event, uint8_t data)
+void perfEventBegin(PE event, uint8_t data) {
-{
+	perfEventImpl(event, EPhase::Start, data);
-	perfEventImpl(event, Phase::Start, data);
 }
 
-void perfEventEnd(PE event, uint8_t data)
+void perfEventEnd(PE event, uint8_t data) {
-{
+	perfEventImpl(event, EPhase::End, data);
-	perfEventImpl(event, Phase::End, data);
 }
 
-void perfEventInstantThread(PE event, uint8_t data)
+void perfEventInstantGlobal(PE event, uint8_t data) {
-{
+	perfEventImpl(event, EPhase::InstantGlobal, data);
-	perfEventImpl(event, Phase::InstantThread, data);
 }
 
-void perfEventInstantGlobal(PE event, uint8_t data)
+size_t perfTraceEnable() {
-{
+	s_isTracing = true;
-	perfEventImpl(event, Phase::InstantGlobal, data);
+
+	return sizeof(s_traceBuffer);
+}
+
+const uint8_t* getTraceBuffer() {
+	return reinterpret_cast<const uint8_t*>(s_traceBuffer);
 }

firmware/development/perf_trace.h

@@ -2,6 +2,7 @@
 #pragma once
 
 #include <cstdint>
+#include <cstddef>
 
 // Defines different events we want to trace.  These can be an interval (begin -> end), or an
 // instant.  Instants can be global, or specific to one thread.  You probably don't want to use
@@ -44,12 +45,13 @@ enum class PE : uint8_t {
 	ScheduleByAngle,
 	EventQueueExecuteCallback,
 	PwmGeneratorCallback,
-	TunerStudioHandleCrcCommand
+	TunerStudioHandleCrcCommand,
+	PwmConfigTogglePwmState,
+	PwmConfigStateChangeCallback,
 };
 
 void perfEventBegin(PE event, uint8_t data);
 void perfEventEnd(PE event, uint8_t data);
-void perfEventInstantThread(PE event, uint8_t data);
 void perfEventInstantGlobal(PE event, uint8_t data);
 
 inline void perfEventBegin(PE event) {
@@ -60,14 +62,14 @@ inline void perfEventEnd(PE event) {
 	perfEventEnd(event, 0);
 }
 
-inline void perfEventInstantThread(PE event) {
-	perfEventInstantThread(event, 0);
-}
-
 inline void perfEventInstantGlobal(PE event) {
 	perfEventInstantGlobal(event, 0);
 }
 
+// Enable one buffer's worth of perf tracing, and retrieve the buffer size in bytes
+size_t perfTraceEnable();
+// Retrieve the trace buffer
+const uint8_t* getTraceBuffer();
 
 class ScopePerf
 {

firmware/hw_layer/hardware.cpp

@@ -206,7 +206,7 @@ void adc_callback_fast(ADCDriver *adcp, adcsample_t *buffer, size_t n) {
 	 * intermediate callback when the buffer is half full.
 	 * */
 	if (adcp->state == ADC_COMPLETE) {
-		perfEventEnd(PE::AdcConversionFast, 0);
+		ScopePerf perf(PE::AdcCallbackFastComplete);
 
 		fastAdc.invalidateSamplesCache();