[rio] telemetry FIX: printing from the serial poll path deadlocks against the PCSPAK RX thread (0-CPU park ~10s after every live-RIO boot, A/B-convicted on ALPHA-MR) -- GetNextEvent now only COUNTS; the printer (BTRioHealthReport) rides the glass tick beside [glassperf]

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Joe DiPrima
2026-08-10 13:06:06 -05:00
co-authored by Claude Fable 5
parent 7cd58d3000
commit ab1b3439f4
2 changed files with 120 additions and 61 deletions
+7
View File
@@ -2121,12 +2121,19 @@ static unsigned long
return token;
}
// [rio] health printer (L4RIO.cpp): the serial path may only COUNT --
// printing from it deadlocks against the PCSPAK RX thread -- so the report
// rides this tick, which already streams [glassperf] safely every second.
extern "C" void BTRioHealthReport();
void
BTGlassPanels_Tick()
{
if (gWinCount == 0)
return;
BTRioHealthReport();
static unsigned long sLastPaint = 0;
unsigned long now = GetTickCount();
if (now - sLastPaint < (unsigned long)RepaintMilliseconds)
+113 -61
View File
@@ -1241,21 +1241,100 @@ RIO::~RIO()
}
//
// [rio] telemetry state (see the block in GetNextEvent). File-scope statics
// on purpose: one hardware RIO per process, and no header/layout churn.
// [rio] telemetry state (see the tracking block in GetNextEvent). File-scope
// statics on purpose: one hardware RIO per process, no header/layout churn --
// and the PRINTER (BTRioHealthReport, called from the glass tick) reads ONLY
// these statics, never RIO members, so it needs no instance and touches
// nothing the serial layer locks.
//
static int sRioLog = -1;
static int gRioPresent = 0;
static unsigned gRioReqCount = 0;
static unsigned gRioRepCount = 0;
static unsigned gRioBtnCount = 0;
static int gRioReqPending = 0;
static DWORD gRioLastReqTick = 0;
static DWORD gRioLastReplyTick = 0;
static DWORD gRioLastReportTick = 0;
static int gRioStallActive = 0;
static DWORD gRioStallStart = 0;
static unsigned gRioStallBtnBase = 0;
static unsigned gRioStallErrBase = 0;
static unsigned gRioStallCount = 0;
static DWORD gRioLastStallMs = 0;
static unsigned gRioLastStallBtns = 0;
static unsigned gRioLineErrMirror = 0;
static unsigned gRioOverrunMirror = 0;
static unsigned gRioAbandonMirror = 0;
static unsigned gRioRRetryMirror = 0;
static unsigned gRioRAbandonMirror = 0;
static unsigned gRioRFullMirror = 0;
//
// The printer half -- called from BTGlassPanels_Tick beside the [glassperf]
// report (a stream site that prints every second without incident), NEVER
// from the serial path. Edge lines land at the tick's ~1 s granularity,
// ample for the multi-second field dropouts this exists to catch.
// BT_RIO_LOG=0 opts out; silent when no hardware RIO ever came up.
//
extern "C" void
BTRioHealthReport()
{
static int sLog = -1;
static DWORD sLastLine = 0;
static unsigned sSeenStalls = 0;
static int sSawActive = 0;
if (!gRioPresent)
{
return;
}
if (sLog < 0)
{
const char *e = getenv("BT_RIO_LOG");
sLog = (e != 0 && *e == '0') ? 0 : 1;
}
if (!sLog)
{
return;
}
DWORD now = GetTickCount();
if (gRioStallActive && !sSawActive)
{
sSawActive = 1;
DEBUG_STREAM << "[rio] STALL analog silent "
<< (now - gRioStallStart) << "ms and counting req="
<< gRioReqCount << " rep=" << gRioRepCount
<< "\n" << std::flush;
}
else if (!gRioStallActive && sSawActive)
{
sSawActive = 0;
}
if (sSeenStalls != gRioStallCount)
{
sSeenStalls = gRioStallCount;
DEBUG_STREAM << "[rio] RECOVER stall#" << gRioStallCount
<< " lasted " << gRioLastStallMs
<< "ms btnDuring=" << gRioLastStallBtns
<< "\n" << std::flush;
}
if (now - sLastLine >= 5000)
{
sLastLine = now;
DEBUG_STREAM << "[rio] req=" << gRioReqCount
<< " rep=" << gRioRepCount
<< " btn=" << gRioBtnCount
<< " age=" << (gRioLastReplyTick != 0
? (now - gRioLastReplyTick) : 0)
<< "ms stalls=" << gRioStallCount
<< " lineErr=" << gRioLineErrMirror
<< " overrun=" << gRioOverrunMirror
<< " abandon=" << gRioAbandonMirror
<< " rRetry=" << gRioRRetryMirror
<< " rAbandon=" << gRioRAbandonMirror
<< " rFull=" << gRioRFullMirror
<< "\n" << std::flush;
}
}
Logical
RIO::TestInstance() const
@@ -1282,54 +1361,31 @@ Logical
Word errors;
//
// [rio] link-health telemetry (encoder-dropout hunt, 2026-08-10). The
// protocol is polled (host requests analog, board replies) over an
// ACK-gated packet layer, so ONE lost byte can freeze every axis until
// unrelated board traffic resyncs the exchange -- which is exactly what
// a dropout-revived-by-a-button feels like from the seat. These lines
// discriminate wire noise (lineErr/overrun climbing) from protocol jams
// (abandon/rRetry/rFull climbing) from quiet stalls (age grows, counters
// still). STALL = a specific analog request unanswered for >500 ms;
// RECOVER records whether a BUTTON arrived during the stall (the field
// theory). Default ON on real-RIO rigs only; BT_RIO_LOG=0 opts out.
// [rio] link-health TRACKING -- pure arithmetic, no I/O. ⚠ NEVER PRINT
// FROM THIS PATH: the first version DEBUG_STREAMed here and deadlocked
// the process against the PCSPAK RX thread within ~10 s of every
// live-RIO boot (2026-08-10 ALPHA-MR: 0-CPU park after "RIO successfully
// initialized", A/B-convicted by BT_RIO_LOG=0 booting clean). The
// printer half is BTRioHealthReport() below, called from the glass tick
// beside [glassperf] -- a proven-safe stream site.
//
if (operational)
{
if (sRioLog < 0)
DWORD now = GetTickCount();
if (!gRioStallActive && gRioReqPending
&& now - gRioLastReqTick > 500)
{
const char *e = getenv("BT_RIO_LOG");
sRioLog = (e != 0 && *e == '0') ? 0 : 1;
}
if (sRioLog && operational)
{
DWORD now = GetTickCount();
if (!gRioStallActive && gRioReqPending
&& now - gRioLastReqTick > 500)
{
gRioStallActive = 1;
gRioStallStart = now;
gRioStallBtnBase = gRioBtnCount;
gRioStallErrBase = (unsigned)(lineErrorCount + abandonCount);
DEBUG_STREAM << "[rio] STALL analog request unanswered "
<< (now - gRioLastReqTick) << "ms req=" << gRioReqCount
<< " rep=" << gRioRepCount << "\n" << std::flush;
}
if (now - gRioLastReportTick >= 5000)
{
gRioLastReportTick = now;
DEBUG_STREAM << "[rio] req=" << gRioReqCount
<< " rep=" << gRioRepCount
<< " btn=" << gRioBtnCount
<< " age=" << (gRioLastReplyTick != 0
? (now - gRioLastReplyTick) : 0)
<< "ms lineErr=" << lineErrorCount
<< " overrun=" << overrunCount
<< " abandon=" << abandonCount
<< " rRetry=" << remoteRetryCount
<< " rAbandon=" << remoteAbandonCount
<< " rFull=" << remoteFullBufferCount
<< "\n" << std::flush;
}
gRioStallActive = 1;
gRioStallStart = gRioLastReqTick;
gRioStallBtnBase = gRioBtnCount;
}
gRioPresent = 1;
gRioLineErrMirror = (unsigned) lineErrorCount;
gRioOverrunMirror = (unsigned) overrunCount;
gRioAbandonMirror = (unsigned) abandonCount;
gRioRRetryMirror = (unsigned) remoteRetryCount;
gRioRAbandonMirror = (unsigned) remoteAbandonCount;
gRioRFullMirror = (unsigned) remoteFullBufferCount;
}
//PCSPAKState(this);
@@ -1450,18 +1506,14 @@ Logical
gRioLastReplyTick = GetTickCount();
if (gRioStallActive)
{
// The reply that ended the drought. btnDuring is the
// field theory's verdict: >0 on every RECOVER = button
// traffic is what resyncs the link; 0 = it self-heals.
DEBUG_STREAM << "[rio] RECOVER after "
<< (gRioLastReplyTick - gRioStallStart)
<< "ms btnDuring="
<< (gRioBtnCount - gRioStallBtnBase)
<< " errsDuring="
<< ((unsigned)(lineErrorCount + abandonCount)
- gRioStallErrBase)
<< "\n" << std::flush;
gRioStallActive = 0;
// The reply that ended the drought -- record only; the
// glass-tick printer emits the RECOVER line. btnDuring
// is the field theory's verdict: >0 on every recover =
// button traffic resyncs the link; 0 = it self-heals.
gRioStallActive = 0;
++gRioStallCount;
gRioLastStallMs = gRioLastReplyTick - gRioStallStart;
gRioLastStallBtns = gRioBtnCount - gRioStallBtnBase;
}
destination->Type = RIO::AnalogEvent;
//