diff --git a/src/helpers/radiolib/ProfileSwitchTiming.h b/src/helpers/radiolib/ProfileSwitchTiming.h index 989000c0a..a53870e1b 100644 --- a/src/helpers/radiolib/ProfileSwitchTiming.h +++ b/src/helpers/radiolib/ProfileSwitchTiming.h @@ -13,12 +13,12 @@ namespace mesh { namespace profiletiming { enum Stage : uint32_t { - BeginReconfigure = 0, Frequency, Modulation, Preamble, GuardMath, + Admission = 0, Standby, PostStandby, Frequency, Modulation, Preamble, GuardMath, ProtocolAndCache, RxResume, Tail, Whole, StageCount }; enum Result : uint32_t { Success = 0, Busy = 1, Failure = 2 }; static constexpr uint32_t Magic = 0x4d435054; // MCPT -static constexpr uint32_t Version = 2; +static constexpr uint32_t Version = 3; static constexpr uint32_t HistogramCount = 16; static constexpr uint32_t HistogramWidthUs = 64; #if defined(NRF52_PLATFORM) @@ -109,6 +109,32 @@ inline void mark(Stage stage, uint32_t now_ticks) { work.mask |= uint32_t(1) << stage; } +// Instrument beginReconfigure's existing operations without adding radio I/O. +// Every exit records the admission and post-standby bookkeeping. If admission +// defers or the receiver was idle, Standby is present with duration zero. +class ReconfigureScope { + bool admission_marked_ = false; + bool standby_marked_ = false; + public: + void admissionComplete() { + mark(Admission, readClock()); + admission_marked_ = true; + } + int16_t standbyResult(int16_t result) { + mark(Standby, readClock()); + standby_marked_ = true; + return result; + } + ~ReconfigureScope() { + auto& work = mesh_hil_profile_timing_work; + if (!work.active) return; + const uint32_t now_ticks = readClock(); + if (!admission_marked_) mark(Admission, now_ticks); + if (!standby_marked_) mark(Standby, work.previous_ticks); + mark(PostStandby, now_ticks); + } +}; + inline void finish(Result result, uint32_t now_ticks) { auto& work = mesh_hil_profile_timing_work; if (!work.active) return; @@ -149,6 +175,8 @@ inline void finish(Result result, uint32_t now_ticks) { static_assert(sizeof(Capture) == 40 + 2 * (20 + StageCount * (8 + 88)), "Unexpected profile timing ABI"); +static_assert(StageCount == 11 && sizeof(Capture) == 2192, + "Profile timing version 3 requires eleven stages and 2192 bytes"); } // namespace profiletiming } // namespace mesh diff --git a/src/helpers/radiolib/RadioLibWrappers.cpp b/src/helpers/radiolib/RadioLibWrappers.cpp index 917195a78..dc256a7c4 100644 --- a/src/helpers/radiolib/RadioLibWrappers.cpp +++ b/src/helpers/radiolib/RadioLibWrappers.cpp @@ -368,6 +368,9 @@ bool RadioLibWrapper::setTxPower(int8_t dbm) { } uint8_t RadioLibWrapper::beginReconfigure() { +#if MESH_HIL_PROFILE_TIMING + mesh::profiletiming::ReconfigureScope profile_timing; +#endif #if MESH_RADIO_TRACE_ENABLED mesh::radiotrace::trace().context(_radio, _active_profile, _profile_generation); #endif @@ -382,7 +385,16 @@ uint8_t RadioLibWrapper::beginReconfigure() { if (base_state == STATE_TX_WAIT || isChipBusy()) return 2; claimRadioInterrupt(); _rx_hold_continuous = false; - if (_radio->standby() != RADIOLIB_ERR_NONE) { +#if MESH_HIL_PROFILE_TIMING + profile_timing.admissionComplete(); +#endif + if ( +#if MESH_HIL_PROFILE_TIMING + profile_timing.standbyResult(_radio->standby()) +#else + _radio->standby() +#endif + != RADIOLIB_ERR_NONE) { state = STATE_IDLE; return 3; } @@ -399,9 +411,18 @@ uint8_t RadioLibWrapper::beginReconfigure() { return 2; } +#if MESH_HIL_PROFILE_TIMING + profile_timing.admissionComplete(); +#endif const bool resume_rx = base_state == STATE_RX; if (_rx_ps_armed || resume_rx) { - if (_radio->standby() != RADIOLIB_ERR_NONE) { + if ( +#if MESH_HIL_PROFILE_TIMING + profile_timing.standbyResult(_radio->standby()) +#else + _radio->standby() +#endif + != RADIOLIB_ERR_NONE) { state = STATE_IDLE; _profile_refresh_required = _profile_repair_required = true; return 3; @@ -617,9 +638,6 @@ mesh::RadioParamApplyResult RadioLibWrapper::tuneProfile(uint8_t profile) { #endif beginProfileRetune(isInRecvMode() && !_rx_ps_armed && !_rx_ps_enabled); const uint8_t resume = beginReconfigure(); -#if MESH_HIL_PROFILE_TIMING - mesh::profiletiming::mark(mesh::profiletiming::BeginReconfigure, mesh::profiletiming::readClock()); -#endif if (resume > 1) { endProfileRetune(resume == 2); // Only a BUSY guard deferred before changing hardware. #if MESH_HIL_PROFILE_TIMING diff --git a/test/test_profile_switch_timing.py b/test/test_profile_switch_timing.py index 577400adf..b3a430ec6 100644 --- a/test/test_profile_switch_timing.py +++ b/test/test_profile_switch_timing.py @@ -48,7 +48,7 @@ void dwt_enable() { clockEnabled=true; ++enableCalls; } int main() { using namespace mesh::profiletiming; auto& capture=mesh_hil_profile_timing; - assert(capture.magic==Magic && capture.version==2 && capture.size_bytes==1808); + assert(capture.magic==Magic && capture.version==3 && capture.size_bytes==2192); assert(capture.clock_hz==64000000 && capture.sequence==0); initializeClock(); assert(enableCalls==1 && capture.clock_state==2); @@ -67,16 +67,16 @@ int main() { assert(capture.sequence==2 && !(capture.sequence&1)); const auto& forward=capture.direction[0]; assert(forward.successes==1 && forward.busy==0 && forward.failures==0); - assert(forward.last_mask==511 && forward.last_us[Whole]==600); - assert(forward.worst_us[Whole]==600 && forward.worst_us[Frequency]==50); - assert(forward.stage[Whole].sum_low_us==600 && forward.stage[Whole].sum_high_us==0); - assert(forward.stage[Whole].min_us==600 && forward.stage[Whole].max_us==600); - assert(forward.stage[Whole].histogram[9]==1); + assert(forward.last_mask==2047 && forward.last_us[Whole]==850); + assert(forward.worst_us[Whole]==850 && forward.worst_us[Frequency]==70); + assert(forward.stage[Whole].sum_low_us==850 && forward.stage[Whole].sum_high_us==0); + assert(forward.stage[Whole].min_us==850 && forward.stage[Whole].max_us==850); + assert(forward.stage[Whole].histogram[13]==1); for(uint32_t stage=0;stage +#include +#define MESH_HIL_PROFILE_TIMING 1 +#define MESH_ENABLE_TX_BEACONS 1 +#define RADIOLIB_ERR_NONE 0 +#define STATE_IDLE 0 +#define STATE_RX 1 +#define STATE_TX_WAIT 3 +static uint32_t now_us=0; +uint32_t micros() { return now_us; } +#include +@GLOBALS@ +struct RadioLibWrapper { + bool _beacon_owned=false,_beacon_restoring=false,_cw_active=false; + bool _profile_repair_required=false,_rx_hold_continuous=true; + bool _rx_ps_armed=false,_profile_refresh_required=false; + bool pending=false,busy=false,receiving=false,post_irq=false; + uint8_t state=STATE_RX; + unsigned standby_calls=0; + int16_t standby_result=0; + struct Chip { + RadioLibWrapper* owner; + int16_t standby() { + ++owner->standby_calls;now_us+=20; + if(owner->post_irq) owner->pending=true; + return owner->standby_result; + } + } chip{this}; + Chip* _radio=&chip; + bool hasPendingRadioInterrupt() { now_us+=2;return pending; } + bool isChipBusy() { now_us+=3;return busy; } + bool isReceivingPacket() { now_us+=5;return receiving; } + void claimRadioInterrupt() { now_us+=4;pending=false; } + uint8_t beginReconfigure(); +}; +@METHOD@ +int main() { + using namespace mesh::profiletiming; + auto& direction=mesh_hil_profile_timing.direction[0]; + // Success, already idle, each admission guard, both standby failures, + // an IRQ arriving in standby, and the physical-repair branch. + for(unsigned scenario=0;scenario<13;++scenario) { + RadioLibWrapper radio; + uint8_t expected_result=2; + unsigned admission=0,standby=0,post=0,calls=0; + switch(scenario) { + case 0: expected_result=1;admission=10;standby=20;post=2;calls=1;break; + case 1: radio.state=STATE_IDLE;expected_result=0;admission=10;post=2;break; + case 2: radio.pending=true;admission=2;break; + case 3: radio.state=STATE_TX_WAIT;admission=2;break; + case 4: radio.busy=true;admission=5;break; + case 5: radio.receiving=true;admission=10;break; + case 6: radio._cw_active=true;break; + case 7: radio.standby_result=-1;expected_result=3;admission=10;standby=20;calls=1;break; + case 8: radio.post_irq=true;admission=10;standby=20;post=2;calls=1;break; + case 9: radio._profile_repair_required=true;expected_result=1;admission=7;standby=20;post=4;calls=1;break; + case 10: radio._profile_repair_required=true;radio.busy=true;admission=3;break; + case 11: radio._profile_repair_required=true;radio.standby_result=-1; + expected_result=3;admission=7;standby=20;calls=1;break; + case 12: radio._beacon_owned=true;break; + } + now_us=0;begin(0,1,now_us); + const uint32_t samples=direction.stage[Admission].count; + assert(radio.beginReconfigure()==expected_result); + assert(radio.standby_calls==calls); + const Result result=expected_result<2 ? Success : expected_result==2 ? Busy : Failure; + finish(result,now_us); + assert(direction.last_mask==((1U<