From 7b4101b9755081d574158434c79471a59b4b27a0 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Tue, 3 Mar 2026 17:08:40 -0800 Subject: [PATCH 01/10] Port V24 pre-#7 startup baseline onto master --- .gitignore | 3 +++ src/host/Host.P25.cpp | 7 ++++++- src/host/modem/Modem.cpp | 9 +++++++-- src/host/modem/ModemV24.cpp | 11 ++++------- 4 files changed, 20 insertions(+), 10 deletions(-) diff --git a/.gitignore b/.gitignore index 247a1564..531f09d4 100644 --- a/.gitignore +++ b/.gitignore @@ -23,6 +23,9 @@ _deps # Ignore thumbnails created by windows Thumbs.db +# Ignore macOS Finder metadata files +.DS_Store + # Ignore files created by clang-check *.plist diff --git a/src/host/Host.P25.cpp b/src/host/Host.P25.cpp index 1db6a6ba..9c5f3e71 100644 --- a/src/host/Host.P25.cpp +++ b/src/host/Host.P25.cpp @@ -255,6 +255,11 @@ void* Host::threadP25Writer(void* arg) if (nextLen > 0U) { bool ret = host->m_modem->hasP25Space(nextLen); + // V.24 modem status space can lag at call start; do not block + // initial Net->RF voice frames on stale p25Space accounting. + if (!ret && host->m_modem->isV24Connected()) { + ret = true; + } if (ret) { bool imm = false; uint32_t len = host->m_p25->getFrame(data, &imm); @@ -267,7 +272,7 @@ void* Host::threadP25Writer(void* arg) // if the state is P25; write P25 frame data if (host->m_state == STATE_P25) { - host->m_modem->writeP25Frame(data, len); + host->m_modem->writeP25Frame(data, len, imm); afterWriteCallback(); diff --git a/src/host/modem/Modem.cpp b/src/host/modem/Modem.cpp index 18a95e3f..3ff080d4 100644 --- a/src/host/modem/Modem.cpp +++ b/src/host/modem/Modem.cpp @@ -1517,7 +1517,10 @@ bool Modem::writeP25Frame(const uint8_t* data, uint32_t length, bool imm) uint32_t len = length + 2U; // write or buffer P25 data to air interface - if (m_p25Space >= length) { + // + // For V.24/DFSI, the modem status space value may lag call startup; do + // not block initial Net->RF frames solely on stale p25Space. + if (m_p25Space >= length || isV24Connected()) { if (m_debug) LogDebugEx(LOG_MODEM, "Modem::writeP25Frame()", "immediate write (len %u)", length); if (m_trace) @@ -1529,7 +1532,9 @@ bool Modem::writeP25Frame(const uint8_t* data, uint32_t length, bool imm) return false; } - m_p25Space -= length; + if (m_p25Space >= length) { + m_p25Space -= length; + } } else { return false; diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index eb2b9e2a..695464ef 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -394,10 +394,11 @@ void ModemV24::clock(uint32_t ms) int len = 0; // write anything waiting to the serial port - if (!m_txImmP25Queue.isEmpty()) + // + // Keep normal queue first for startup consistency with older behavior. + len = writeSerial(&m_txP25Queue); + if (len == 0 && !m_txImmP25Queue.isEmpty()) len = writeSerial(&m_txImmP25Queue); - else - len = writeSerial(&m_txP25Queue); if (m_debug && len > 0) { LogDebug(LOG_MODEM, "Wrote %u-byte message to the serial V24 device", len); } else if (len < 0) { @@ -496,10 +497,6 @@ int ModemV24::writeSerial(RingBuffer* queue) return 0U; } - // check available modem space - if (m_p25Space < len) - return 0U; - std::lock_guard lock(m_txP25QueueLock); // get current timestamp From d3b6e002eea8486c7ef90f20999d331bb6e37ee3 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 07:05:22 -0800 Subject: [PATCH 02/10] Update ModemV24.cpp prevent stray network/RF TDU/TDULC from tearing down V.24 at call start --- src/host/modem/ModemV24.cpp | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 695464ef..aa795124 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -2803,13 +2803,18 @@ void ModemV24::convertFromAirV24(uint8_t* data, uint32_t length, bool imm) break; case DUID::TDU: - endOfStreamV24(); // this may incorrectly sent STOP ICW's with the VOICE payload, but it's better than nothing for now + if (m_txCallInProgress) + endOfStreamV24(); + else if (m_debug) + ::LogDebugEx(LOG_MODEM, "ModemV24::convertFromAirV24()", "P25 TDU received with no active V.24 TX call; suppressing STOP ICW"); break; case DUID::TDULC: { if (m_txCallInProgress) endOfStreamV24(); + else if (m_debug) + ::LogDebugEx(LOG_MODEM, "ModemV24::convertFromAirV24()", "P25 TDULC received with no active V.24 TX call; suppressing STOP ICW"); lc::tdulc::LC_TDULC_RAW tdulc = lc::tdulc::LC_TDULC_RAW(); if (!tdulc.decode(data + 2U)) { From a08f0f5b7dca056ae8f0063cb8d11fc9e9dde1f8 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 07:36:16 -0800 Subject: [PATCH 03/10] Add V24 startup timing trace for clipped call onset --- src/host/modem/ModemV24.cpp | 49 +++++++++++++++++++++++++++++++++++-- src/host/modem/ModemV24.h | 3 +++ 2 files changed, 50 insertions(+), 2 deletions(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index aa795124..5618f2fe 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -58,6 +58,9 @@ ModemV24::ModemV24(port::IModemPort* port, bool duplex, uint32_t p25QueueSize, u m_callTimeout(200U), m_jitter(jitter), m_lastP25Tx(0U), + m_txStartupTraceActive(false), + m_txStartupTraceT0(0U), + m_txStartupTraceWritesLeft(0U), m_rs(), m_useTIAFormat(false), m_txP25QueueLock() @@ -501,6 +504,7 @@ int ModemV24::writeSerial(RingBuffer* queue) // get current timestamp int64_t now = std::chrono::duration_cast(std::chrono::system_clock::now().time_since_epoch()).count(); + int64_t ts = 0L; // peek the timestamp to see if we should wait if (queue->dataSize() >= 11U) { @@ -509,7 +513,6 @@ int ModemV24::writeSerial(RingBuffer* queue) queue->peek(lengthTagTs, 11U); // get the timestamp - int64_t ts; assert(sizeof ts == 8); ::memcpy(&ts, lengthTagTs + 3U, 8U); @@ -537,7 +540,27 @@ int ModemV24::writeSerial(RingBuffer* queue) } // we already checked the timestamp above, so we just get the data and write it - return m_port->write(buffer, len); + int ret = m_port->write(buffer, len); + if (ret > 0 && m_debug && m_txStartupTraceActive && m_txStartupTraceWritesLeft > 0U) { + uint8_t frameType = (len > 4U) ? buffer[4U] : 0xFFU; + const char* queueName = (queue == &m_txImmP25Queue) ? "imm" : "norm"; + + int64_t nowMs = std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + int64_t dtStart = (int64_t)(nowMs - (int64_t)m_txStartupTraceT0); + int64_t schedSkew = (int64_t)(nowMs - ts); + + LogDebugEx(LOG_MODEM, "ModemV24::writeSerial()", + "TX startup trace: q=%s, frameType=$%02X, dtStart=%lld ms, schedSkew=%lld ms, txQ=%u, immQ=%u, p25Space=%u", + queueName, frameType, dtStart, schedSkew, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); + + m_txStartupTraceWritesLeft--; + if (m_txStartupTraceWritesLeft == 0U) { + m_txStartupTraceActive = false; + } + } + + return ret; } return 0U; @@ -2425,6 +2448,15 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType void ModemV24::startOfStreamV24(const p25::lc::LC& control) { m_txCallInProgress = true; + if (m_debug) { + m_txStartupTraceActive = true; + m_txStartupTraceT0 = std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + m_txStartupTraceWritesLeft = 8U; + LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamV24()", + "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", + m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); + } MotStartOfStream start = MotStartOfStream(); start.setOpcode(m_rtrt ? MotStartStreamOpcode::TRANSMIT : MotStartStreamOpcode::RECEIVE); @@ -2520,6 +2552,8 @@ void ModemV24::endOfStreamV24() queueP25Frame(endBuf, DFSI_MOT_START_LEN, STT_START_STOP); m_txCallInProgress = false; + m_txStartupTraceActive = false; + m_txStartupTraceWritesLeft = 0U; } /* Helper to generate the NID value. */ @@ -2542,6 +2576,15 @@ void ModemV24::startOfStreamTIA(const p25::lc::LC& control) { m_txCallInProgress = true; m_superFrameCnt = 1U; + if (m_debug) { + m_txStartupTraceActive = true; + m_txStartupTraceT0 = std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + m_txStartupTraceWritesLeft = 8U; + LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamTIA()", + "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", + m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); + } p25::lc::LC lc = p25::lc::LC(control); @@ -2688,6 +2731,8 @@ void ModemV24::endOfStreamTIA() queueP25Frame(buffer, length, STT_START_STOP); m_txCallInProgress = false; + m_txStartupTraceActive = false; + m_txStartupTraceWritesLeft = 0U; } /* Send a start of stream ACK. */ diff --git a/src/host/modem/ModemV24.h b/src/host/modem/ModemV24.h index 8f33e926..c70b14c8 100644 --- a/src/host/modem/ModemV24.h +++ b/src/host/modem/ModemV24.h @@ -606,6 +606,9 @@ namespace modem uint16_t m_jitter; uint64_t m_lastP25Tx; + bool m_txStartupTraceActive; + uint64_t m_txStartupTraceT0; + uint8_t m_txStartupTraceWritesLeft; edac::RS634717 m_rs; From 8d97cbe2f413ac6affe3549cfe6b2ba24f98a683 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 08:14:05 -0800 Subject: [PATCH 04/10] Reset V24 TX scheduler epoch at stream start --- src/host/modem/ModemV24.cpp | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 5618f2fe..3ade3ba6 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -2448,6 +2448,9 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType void ModemV24::startOfStreamV24(const p25::lc::LC& control) { m_txCallInProgress = true; + // Start each Net->RF stream with a fresh scheduler epoch so a new call + // doesn't inherit a future-biased timestamp from the previous call. + m_lastP25Tx = 0U; if (m_debug) { m_txStartupTraceActive = true; m_txStartupTraceT0 = std::chrono::duration_cast( @@ -2576,6 +2579,9 @@ void ModemV24::startOfStreamTIA(const p25::lc::LC& control) { m_txCallInProgress = true; m_superFrameCnt = 1U; + // Start each Net->RF stream with a fresh scheduler epoch so a new call + // doesn't inherit a future-biased timestamp from the previous call. + m_lastP25Tx = 0U; if (m_debug) { m_txStartupTraceActive = true; m_txStartupTraceT0 = std::chrono::duration_cast( From c7a1c5a3b723aceeefe3064b69d3bf4c80dfd859 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 08:25:11 -0800 Subject: [PATCH 05/10] Add queue-side startup trace for V24 onset timing --- src/host/modem/ModemV24.cpp | 14 ++++++++++++++ src/host/modem/ModemV24.h | 1 + 2 files changed, 15 insertions(+) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 3ade3ba6..f54961d0 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -61,6 +61,7 @@ ModemV24::ModemV24(port::IModemPort* port, bool duplex, uint32_t p25QueueSize, u m_txStartupTraceActive(false), m_txStartupTraceT0(0U), m_txStartupTraceWritesLeft(0U), + m_txStartupTraceQueueLogsLeft(0U), m_rs(), m_useTIAFormat(false), m_txP25QueueLock() @@ -2378,6 +2379,15 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType } } + if (m_debug && m_txStartupTraceActive && m_txStartupTraceQueueLogsLeft > 0U) { + int64_t dtNow = (int64_t)now - (int64_t)m_txStartupTraceT0; + int64_t dtSched = (int64_t)msgTime - (int64_t)m_txStartupTraceT0; + LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", + "TX startup queue: frameType=$%02X, msgType=$%02X, dtNow=%lld ms, dtSched=%lld ms, lastP25Tx=%llu, txQ=%u, immQ=%u", + data[0U], msgType, dtNow, dtSched, m_lastP25Tx, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); + m_txStartupTraceQueueLogsLeft--; + } + len += 4U; std::lock_guard lock(m_txP25QueueLock); @@ -2456,6 +2466,7 @@ void ModemV24::startOfStreamV24(const p25::lc::LC& control) m_txStartupTraceT0 = std::chrono::duration_cast( std::chrono::system_clock::now().time_since_epoch()).count(); m_txStartupTraceWritesLeft = 8U; + m_txStartupTraceQueueLogsLeft = 12U; LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamV24()", "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); @@ -2557,6 +2568,7 @@ void ModemV24::endOfStreamV24() m_txCallInProgress = false; m_txStartupTraceActive = false; m_txStartupTraceWritesLeft = 0U; + m_txStartupTraceQueueLogsLeft = 0U; } /* Helper to generate the NID value. */ @@ -2587,6 +2599,7 @@ void ModemV24::startOfStreamTIA(const p25::lc::LC& control) m_txStartupTraceT0 = std::chrono::duration_cast( std::chrono::system_clock::now().time_since_epoch()).count(); m_txStartupTraceWritesLeft = 8U; + m_txStartupTraceQueueLogsLeft = 12U; LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamTIA()", "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); @@ -2739,6 +2752,7 @@ void ModemV24::endOfStreamTIA() m_txCallInProgress = false; m_txStartupTraceActive = false; m_txStartupTraceWritesLeft = 0U; + m_txStartupTraceQueueLogsLeft = 0U; } /* Send a start of stream ACK. */ diff --git a/src/host/modem/ModemV24.h b/src/host/modem/ModemV24.h index c70b14c8..818a87da 100644 --- a/src/host/modem/ModemV24.h +++ b/src/host/modem/ModemV24.h @@ -609,6 +609,7 @@ namespace modem bool m_txStartupTraceActive; uint64_t m_txStartupTraceT0; uint8_t m_txStartupTraceWritesLeft; + uint8_t m_txStartupTraceQueueLogsLeft; edac::RS634717 m_rs; From 148f884cfecc3b9ce9b20f3f51ff410d7fa2368f Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 10:14:01 -0800 Subject: [PATCH 06/10] Fix V24 startup queue race and preserve frames on write failure --- src/host/modem/ModemV24.cpp | 42 ++++++++++++++++++++++++++----------- 1 file changed, 30 insertions(+), 12 deletions(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index f54961d0..58f4da87 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -482,6 +482,8 @@ int ModemV24::writeSerial(RingBuffer* queue) * | Length | Tag | int64_t timestamp in ms | data | */ + std::lock_guard lock(m_txP25QueueLock); + // check empty if (queue->isEmpty()) return 0U; @@ -491,18 +493,16 @@ int ModemV24::writeSerial(RingBuffer* queue) ::memset(length, 0x00U, 2U); queue->peek(length, 2U); - // convert length byets to int + // convert length bytes to int uint16_t len = 0U; len = (length[0U] << 8) + length[1U]; - // this ensures we never get in a situation where we have length & type bytes stuck in the queue by themselves + // this ensures we never get in a situation where we have length bytes stuck in the queue by themselves if (queue->dataSize() == 2U && len > queue->dataSize()) { queue->get(length, 2U); // ensure we pop bytes off return 0U; } - std::lock_guard lock(m_txP25QueueLock); - // get current timestamp int64_t now = std::chrono::duration_cast(std::chrono::system_clock::now().time_since_epoch()).count(); int64_t ts = 0L; @@ -525,23 +525,32 @@ int ModemV24::writeSerial(RingBuffer* queue) // check if we have enough data to get everything - len + 2U (length bytes) + 1U (tag) + 8U (timestamp) if (queue->dataSize() >= len + 11U) { - // Get the length, tag and timestamp - uint8_t lengthTagTs[11U]; - queue->get(lengthTagTs, 11U); - - // Get the actual data - DECLARE_UINT8_ARRAY(buffer, len); - queue->get(buffer, len); + // Peek the full entry so we can keep it queued if a write fails. + DECLARE_UINT8_ARRAY(entry, len + 11U); + queue->peek(entry, len + 11U); + + // Get the length, tag, timestamp and payload pointers from peeked data. + uint8_t* lengthTagTs = entry; + uint8_t* buffer = entry + 11U; // Sanity check on data tag uint8_t tag = lengthTagTs[2U]; if (tag != TAG_DATA) { LogError(LOG_MODEM, "Got unexpected data tag from TX P25 ringbuffer! %02X", tag); + // Drop malformed entry so we can recover queue alignment. + DECLARE_UINT8_ARRAY(discard, len + 11U); + queue->get(discard, len + 11U); return 0U; } - // we already checked the timestamp above, so we just get the data and write it + // we already checked the timestamp above, so we just write it int ret = m_port->write(buffer, len); + if (ret > 0) { + // Only remove an entry once it was written successfully. + DECLARE_UINT8_ARRAY(discard, len + 11U); + queue->get(discard, len + 11U); + } + if (ret > 0 && m_debug && m_txStartupTraceActive && m_txStartupTraceWritesLeft > 0U) { uint8_t frameType = (len > 4U) ? buffer[4U] : 0xFFU; const char* queueName = (queue == &m_txImmP25Queue) ? "imm" : "norm"; @@ -559,6 +568,15 @@ int ModemV24::writeSerial(RingBuffer* queue) if (m_txStartupTraceWritesLeft == 0U) { m_txStartupTraceActive = false; } + } else if (ret <= 0 && m_debug && m_txStartupTraceActive) { + uint8_t frameType = (len > 4U) ? buffer[4U] : 0xFFU; + const char* queueName = (queue == &m_txImmP25Queue) ? "imm" : "norm"; + int64_t nowMs = std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + int64_t dtStart = (int64_t)(nowMs - (int64_t)m_txStartupTraceT0); + LogDebugEx(LOG_MODEM, "ModemV24::writeSerial()", + "TX startup write blocked/fail: q=%s, frameType=$%02X, dtStart=%lld ms, ret=%d, txQ=%u, immQ=%u, p25Space=%u", + queueName, frameType, dtStart, ret, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); } return ret; From bfa5ec9c62382cf48b795a2fce399485127bcc5b Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 10:27:14 -0800 Subject: [PATCH 07/10] Avoid exact-full V24 TX queue wraps at call startup --- src/host/modem/ModemV24.cpp | 24 +++++++++++++++++++++--- 1 file changed, 21 insertions(+), 3 deletions(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 58f4da87..4d3ebab6 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -2410,13 +2410,31 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType std::lock_guard lock(m_txP25QueueLock); - // check available ringbuffer space + // check available ringbuffer space. + // + // Keep one byte of headroom to avoid the ring buffer "full == empty" + // ambiguity (iPtr == oPtr) when a write would consume exactly all free space. + uint32_t needed = len + 11U; if (imm) { - if (m_txImmP25Queue.freeSpace() < (len + 11U)) + uint32_t free = m_txImmP25Queue.freeSpace(); + if (free <= needed) { + if (m_debug && m_txStartupTraceActive) { + LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", + "TX startup drop: q=imm, frameType=$%02X, msgType=$%02X, need=%u, free=%u, txQ=%u, immQ=%u", + data[0U], msgType, needed, free, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); + } return false; + } } else { - if (m_txP25Queue.freeSpace() < (len + 11U)) + uint32_t free = m_txP25Queue.freeSpace(); + if (free <= needed) { + if (m_debug && m_txStartupTraceActive) { + LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", + "TX startup drop: q=norm, frameType=$%02X, msgType=$%02X, need=%u, free=%u, txQ=%u, immQ=%u", + data[0U], msgType, needed, free, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); + } return false; + } } // convert 16-bit length to 2 bytes From bd6b279e14ba666533224afd23abbdc3dcb7653a Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 11:36:06 -0800 Subject: [PATCH 08/10] Increase DFSI P25 TX scheduler queue size at startup --- src/host/Host.Config.cpp | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/src/host/Host.Config.cpp b/src/host/Host.Config.cpp index 983328ef..a9ba8af1 100644 --- a/src/host/Host.Config.cpp +++ b/src/host/Host.Config.cpp @@ -511,6 +511,7 @@ bool Host::createModem() uint16_t dmrFifoLength = (uint16_t)modemConf["dmrFifoLength"].as(DMR_TX_BUFFER_LEN); uint16_t p25FifoLength = (uint16_t)modemConf["p25FifoLength"].as(P25_TX_BUFFER_LEN); uint16_t nxdnFifoLength = (uint16_t)modemConf["nxdnFifoLength"].as(NXDN_TX_BUFFER_LEN); + uint32_t v24P25TxQueueSize = p25FifoLength; yaml::Node dfsiParams = modemConf["dfsi"]; @@ -645,6 +646,14 @@ bool Host::createModem() LogInfo(" DFSI FSC Initiator: %s", fscInitiator ? "yes" : "no"); LogInfo(" DFSI TIA-102 Frames: %s", dfsiTIAMode ? "yes" : "no"); } + + // DFSI startup can enqueue a burst of timed frames before the modem + // thread starts draining; keep the TX scheduler queue larger than the + // raw modem FIFO to avoid clipping first-call onset. + uint32_t minV24TxQueueSize = m_p25QueueSizeBytes + p25FifoLength; + if (v24P25TxQueueSize < minV24TxQueueSize) { + v24P25TxQueueSize = minV24TxQueueSize; + } } if (g_remoteModemMode) { @@ -708,6 +717,8 @@ bool Host::createModem() LogInfo(" NXDN Queue Size: %u (%u bytes)", nxdnQueueSize, m_nxdnQueueSizeBytes); LogInfo(" DMR FIFO Size: %u bytes", dmrFifoLength); LogInfo(" P25 FIFO Size: %u bytes", p25FifoLength); + if (m_isModemDFSI) + LogInfo(" P25 DFSI TX Queue Size: %u bytes", v24P25TxQueueSize); LogInfo(" NXDN FIFO Size: %u bytes", nxdnFifoLength); if (ignoreModemConfigArea) { @@ -728,7 +739,7 @@ bool Host::createModem() } if (m_isModemDFSI) { - m_modem = new ModemV24(modemPort, m_duplex, m_p25QueueSizeBytes, p25FifoLength, rtrt, jitter, + m_modem = new ModemV24(modemPort, m_duplex, m_p25QueueSizeBytes, v24P25TxQueueSize, rtrt, jitter, dumpModemStatus, displayModemDebugMessages, trace, debug); ((ModemV24*)m_modem)->setCallTimeout(dfsiCallTimeout); ((ModemV24*)m_modem)->setTIAFormat(dfsiTIAMode); From 92cf581cff0a347129ccb4d636a47aab36837e60 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Wed, 4 Mar 2026 13:19:19 -0800 Subject: [PATCH 09/10] Remove temporary V24 startup debug instrumentation --- src/host/modem/ModemV24.cpp | 77 ------------------------------------- src/host/modem/ModemV24.h | 4 -- 2 files changed, 81 deletions(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 4d3ebab6..1114b37e 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -58,10 +58,6 @@ ModemV24::ModemV24(port::IModemPort* port, bool duplex, uint32_t p25QueueSize, u m_callTimeout(200U), m_jitter(jitter), m_lastP25Tx(0U), - m_txStartupTraceActive(false), - m_txStartupTraceT0(0U), - m_txStartupTraceWritesLeft(0U), - m_txStartupTraceQueueLogsLeft(0U), m_rs(), m_useTIAFormat(false), m_txP25QueueLock() @@ -551,34 +547,6 @@ int ModemV24::writeSerial(RingBuffer* queue) queue->get(discard, len + 11U); } - if (ret > 0 && m_debug && m_txStartupTraceActive && m_txStartupTraceWritesLeft > 0U) { - uint8_t frameType = (len > 4U) ? buffer[4U] : 0xFFU; - const char* queueName = (queue == &m_txImmP25Queue) ? "imm" : "norm"; - - int64_t nowMs = std::chrono::duration_cast( - std::chrono::system_clock::now().time_since_epoch()).count(); - int64_t dtStart = (int64_t)(nowMs - (int64_t)m_txStartupTraceT0); - int64_t schedSkew = (int64_t)(nowMs - ts); - - LogDebugEx(LOG_MODEM, "ModemV24::writeSerial()", - "TX startup trace: q=%s, frameType=$%02X, dtStart=%lld ms, schedSkew=%lld ms, txQ=%u, immQ=%u, p25Space=%u", - queueName, frameType, dtStart, schedSkew, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); - - m_txStartupTraceWritesLeft--; - if (m_txStartupTraceWritesLeft == 0U) { - m_txStartupTraceActive = false; - } - } else if (ret <= 0 && m_debug && m_txStartupTraceActive) { - uint8_t frameType = (len > 4U) ? buffer[4U] : 0xFFU; - const char* queueName = (queue == &m_txImmP25Queue) ? "imm" : "norm"; - int64_t nowMs = std::chrono::duration_cast( - std::chrono::system_clock::now().time_since_epoch()).count(); - int64_t dtStart = (int64_t)(nowMs - (int64_t)m_txStartupTraceT0); - LogDebugEx(LOG_MODEM, "ModemV24::writeSerial()", - "TX startup write blocked/fail: q=%s, frameType=$%02X, dtStart=%lld ms, ret=%d, txQ=%u, immQ=%u, p25Space=%u", - queueName, frameType, dtStart, ret, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); - } - return ret; } @@ -2397,15 +2365,6 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType } } - if (m_debug && m_txStartupTraceActive && m_txStartupTraceQueueLogsLeft > 0U) { - int64_t dtNow = (int64_t)now - (int64_t)m_txStartupTraceT0; - int64_t dtSched = (int64_t)msgTime - (int64_t)m_txStartupTraceT0; - LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", - "TX startup queue: frameType=$%02X, msgType=$%02X, dtNow=%lld ms, dtSched=%lld ms, lastP25Tx=%llu, txQ=%u, immQ=%u", - data[0U], msgType, dtNow, dtSched, m_lastP25Tx, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); - m_txStartupTraceQueueLogsLeft--; - } - len += 4U; std::lock_guard lock(m_txP25QueueLock); @@ -2418,21 +2377,11 @@ bool ModemV24::queueP25Frame(uint8_t* data, uint16_t len, SERIAL_TX_TYPE msgType if (imm) { uint32_t free = m_txImmP25Queue.freeSpace(); if (free <= needed) { - if (m_debug && m_txStartupTraceActive) { - LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", - "TX startup drop: q=imm, frameType=$%02X, msgType=$%02X, need=%u, free=%u, txQ=%u, immQ=%u", - data[0U], msgType, needed, free, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); - } return false; } } else { uint32_t free = m_txP25Queue.freeSpace(); if (free <= needed) { - if (m_debug && m_txStartupTraceActive) { - LogDebugEx(LOG_MODEM, "ModemV24::queueP25Frame()", - "TX startup drop: q=norm, frameType=$%02X, msgType=$%02X, need=%u, free=%u, txQ=%u, immQ=%u", - data[0U], msgType, needed, free, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize()); - } return false; } } @@ -2497,16 +2446,6 @@ void ModemV24::startOfStreamV24(const p25::lc::LC& control) // Start each Net->RF stream with a fresh scheduler epoch so a new call // doesn't inherit a future-biased timestamp from the previous call. m_lastP25Tx = 0U; - if (m_debug) { - m_txStartupTraceActive = true; - m_txStartupTraceT0 = std::chrono::duration_cast( - std::chrono::system_clock::now().time_since_epoch()).count(); - m_txStartupTraceWritesLeft = 8U; - m_txStartupTraceQueueLogsLeft = 12U; - LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamV24()", - "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", - m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); - } MotStartOfStream start = MotStartOfStream(); start.setOpcode(m_rtrt ? MotStartStreamOpcode::TRANSMIT : MotStartStreamOpcode::RECEIVE); @@ -2602,9 +2541,6 @@ void ModemV24::endOfStreamV24() queueP25Frame(endBuf, DFSI_MOT_START_LEN, STT_START_STOP); m_txCallInProgress = false; - m_txStartupTraceActive = false; - m_txStartupTraceWritesLeft = 0U; - m_txStartupTraceQueueLogsLeft = 0U; } /* Helper to generate the NID value. */ @@ -2630,16 +2566,6 @@ void ModemV24::startOfStreamTIA(const p25::lc::LC& control) // Start each Net->RF stream with a fresh scheduler epoch so a new call // doesn't inherit a future-biased timestamp from the previous call. m_lastP25Tx = 0U; - if (m_debug) { - m_txStartupTraceActive = true; - m_txStartupTraceT0 = std::chrono::duration_cast( - std::chrono::system_clock::now().time_since_epoch()).count(); - m_txStartupTraceWritesLeft = 8U; - m_txStartupTraceQueueLogsLeft = 12U; - LogDebugEx(LOG_MODEM, "ModemV24::startOfStreamTIA()", - "TX startup trace begin, jitter=%u, txQ=%u, immQ=%u, p25Space=%u", - m_jitter, m_txP25Queue.dataSize(), m_txImmP25Queue.dataSize(), m_p25Space); - } p25::lc::LC lc = p25::lc::LC(control); @@ -2786,9 +2712,6 @@ void ModemV24::endOfStreamTIA() queueP25Frame(buffer, length, STT_START_STOP); m_txCallInProgress = false; - m_txStartupTraceActive = false; - m_txStartupTraceWritesLeft = 0U; - m_txStartupTraceQueueLogsLeft = 0U; } /* Send a start of stream ACK. */ diff --git a/src/host/modem/ModemV24.h b/src/host/modem/ModemV24.h index 818a87da..8f33e926 100644 --- a/src/host/modem/ModemV24.h +++ b/src/host/modem/ModemV24.h @@ -606,10 +606,6 @@ namespace modem uint16_t m_jitter; uint64_t m_lastP25Tx; - bool m_txStartupTraceActive; - uint64_t m_txStartupTraceT0; - uint8_t m_txStartupTraceWritesLeft; - uint8_t m_txStartupTraceQueueLogsLeft; edac::RS634717 m_rs; From 62c43504ce807aee7649fd54b703c7a9a3732135 Mon Sep 17 00:00:00 2001 From: Tim Sawyer Date: Thu, 5 Mar 2026 10:15:52 -0800 Subject: [PATCH 10/10] Remove V24 STOP suppression debug logging --- src/host/modem/ModemV24.cpp | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/host/modem/ModemV24.cpp b/src/host/modem/ModemV24.cpp index 1114b37e..ac22283a 100644 --- a/src/host/modem/ModemV24.cpp +++ b/src/host/modem/ModemV24.cpp @@ -2829,16 +2829,12 @@ void ModemV24::convertFromAirV24(uint8_t* data, uint32_t length, bool imm) case DUID::TDU: if (m_txCallInProgress) endOfStreamV24(); - else if (m_debug) - ::LogDebugEx(LOG_MODEM, "ModemV24::convertFromAirV24()", "P25 TDU received with no active V.24 TX call; suppressing STOP ICW"); break; case DUID::TDULC: { if (m_txCallInProgress) endOfStreamV24(); - else if (m_debug) - ::LogDebugEx(LOG_MODEM, "ModemV24::convertFromAirV24()", "P25 TDULC received with no active V.24 TX call; suppressing STOP ICW"); lc::tdulc::LC_TDULC_RAW tdulc = lc::tdulc::LC_TDULC_RAW(); if (!tdulc.decode(data + 2U)) {