From 5a972a671cf946a492f0e477eb5d87c8fd259250 Mon Sep 17 00:00:00 2001 From: Bryan Biedenkapp Date: Sat, 17 Aug 2024 09:02:05 -0400 Subject: [PATCH] add some more verbose logging for overflow conditions; correct issue with DMR Tx timer expiring before the call actually ended; --- configs/config.example.yml | 2 +- src/host/Host.DMR.cpp | 2 ++ src/host/Host.cpp | 26 ++++++++++++++------------ src/host/dmr/Control.cpp | 2 ++ src/host/dmr/Slot.cpp | 17 +++++++++++++---- src/host/modem/Modem.cpp | 8 +------- src/host/modem/Modem.h | 25 ++++++++++++++++++++++--- src/host/nxdn/Control.cpp | 12 ++++++++---- src/host/p25/Control.cpp | 12 ++++++++---- 9 files changed, 71 insertions(+), 35 deletions(-) diff --git a/configs/config.example.yml b/configs/config.example.yml index 3185ad52..f9b040dc 100644 --- a/configs/config.example.yml +++ b/configs/config.example.yml @@ -488,7 +488,7 @@ system: # (Note: Changing this value will impact P25 protocol stability, and should not be altered.) p25CorrCount: 8 # Size (in bytes) of the DMR transmit FIFO buffer. - dmrFifoLength: 505 + dmrFifoLength: 560 # Size (in bytes) of the P25 transmit FIFO buffer. p25FifoLength: 522 # Size (in bytes) of the NXDN transmit FIFO buffer. diff --git a/src/host/Host.DMR.cpp b/src/host/Host.DMR.cpp index e05406ed..f2106790 100644 --- a/src/host/Host.DMR.cpp +++ b/src/host/Host.DMR.cpp @@ -259,6 +259,7 @@ void* Host::threadDMRWriter1(void* arg) // if the state is DMR; start DMR idle frames and write DMR slot 1 data if (host->m_state == STATE_DMR) { START_DMR_DUPLEX_IDLE(true); + host->m_dmrTXTimer.start(); host->m_modem->writeDMRFrame1(data, len); @@ -519,6 +520,7 @@ void* Host::threadDMRWriter2(void* arg) // if the state is DMR; start DMR idle frames and write DMR slot 2 data if (host->m_state == STATE_DMR) { START_DMR_DUPLEX_IDLE(true); + host->m_dmrTXTimer.start(); host->m_modem->writeDMRFrame2(data, len); diff --git a/src/host/Host.cpp b/src/host/Host.cpp index 2c74eefb..c102a7ef 100644 --- a/src/host/Host.cpp +++ b/src/host/Host.cpp @@ -1071,6 +1071,8 @@ int Host::run() m_dmrTXTimer.clock(ms); if (m_dmrTXTimer.isRunning() && m_dmrTXTimer.hasExpired()) { m_modem->writeDMRStart(false); + m_modem->clearDMRFrame1(); + m_modem->clearDMRFrame2(); m_dmrTXTimer.stop(); } } else { @@ -1711,11 +1713,10 @@ void* Host::threadWatchdog(void* arg) LogError(LOG_HOST, "PANIC; DMR, slot 1 Tx frame processor hung >%us, ms = %u", host->m_dmrTx1WatchdogTimer.getTimeout(), host->m_dmrTx1LoopMS); } - if (host->m_dmr->getTSCCSlotNo() != 1U) { - if (host->m_modem->gotModemStatus() && !host->m_modem->hasDMRSpace1() && host->m_dmr->isQueueFull(1U) && - !host->m_dmrBeaconDurationTimer.isRunning()) { - LogError(LOG_HOST, "PANIC; DMR, has no DMR slot 1 buffer space, and DMR slot 1 queue is full!"); - } + if (host->m_modem->gotModemStatus() && !host->m_modem->hasDMRSpace1() && host->m_dmr->isQueueFull(1U) && + !host->m_dmrBeaconDurationTimer.isRunning()) { + LogError(LOG_HOST, "PANIC; DMR, has no DMR slot 1 FIFO space, and DMR slot 1 queue is full!"); + host->m_modem->clearDMRFrame1(); } if (host->m_dmrTx2WatchdogTimer.isRunning()) @@ -1725,11 +1726,10 @@ void* Host::threadWatchdog(void* arg) LogError(LOG_HOST, "PANIC; DMR, slot 2 Tx frame processor hung >%us, ms = %u", host->m_dmrTx2WatchdogTimer.getTimeout(), host->m_dmrTx2LoopMS); } - if (host->m_dmr->getTSCCSlotNo() != 2U) { - if (host->m_modem->gotModemStatus() && !host->m_modem->hasDMRSpace2() && host->m_dmr->isQueueFull(2U) && - !host->m_dmrBeaconDurationTimer.isRunning()) { - LogError(LOG_HOST, "PANIC; DMR, has no DMR slot 2 buffer space, and DMR slot 2 queue is full!"); - } + if (host->m_modem->gotModemStatus() && !host->m_modem->hasDMRSpace2() && host->m_dmr->isQueueFull(2U) && + !host->m_dmrBeaconDurationTimer.isRunning()) { + LogError(LOG_HOST, "PANIC; DMR, has no DMR slot 2 FIFO space, and DMR slot 2 queue is full!"); + host->m_modem->clearDMRFrame2(); } } @@ -1744,7 +1744,8 @@ void* Host::threadWatchdog(void* arg) if (host->m_modem->gotModemStatus() && !host->m_modem->hasP25Space(P25DEF::P25_LDU_FRAME_LENGTH_BYTES) && host->m_p25->isQueueFull() && !host->m_p25CtrlChannel && !host->m_p25BcastDurationTimer.isRunning()) { - LogError(LOG_HOST, "PANIC; P25, modem has no P25 buffer space, and internal P25 queue is full!"); + LogError(LOG_HOST, "PANIC; P25, modem has no P25 FIFO space, and internal P25 queue is full!"); + host->m_modem->clearP25Frame(); } } @@ -1759,7 +1760,8 @@ void* Host::threadWatchdog(void* arg) if (host->m_modem->gotModemStatus() && !host->m_modem->hasNXDNSpace() && host->m_nxdn->isQueueFull() && !host->m_nxdnCtrlChannel && !host->m_nxdnBcastDurationTimer.isRunning()) { - LogError(LOG_HOST, "PANIC; NXDN, modem has no NXDN buffer space, and NXDN queue is full!"); + LogError(LOG_HOST, "PANIC; NXDN, modem has no NXDN FIFO space, and NXDN queue is full!"); + host->m_modem->clearNXDNFrame(); } } } diff --git a/src/host/dmr/Control.cpp b/src/host/dmr/Control.cpp index 8e1f77d5..05030690 100644 --- a/src/host/dmr/Control.cpp +++ b/src/host/dmr/Control.cpp @@ -517,9 +517,11 @@ void Control::tsccClearActivatedSlot(uint32_t slotNo) switch (slotNo) { case 1U: + m_modem->clearDMRFrame1(); m_slot1->clearTSCCActivated(); break; case 2U: + m_modem->clearDMRFrame2(); m_slot2->clearTSCCActivated(); break; default: diff --git a/src/host/dmr/Slot.cpp b/src/host/dmr/Slot.cpp index 69df19f4..57a88236 100644 --- a/src/host/dmr/Slot.cpp +++ b/src/host/dmr/Slot.cpp @@ -1026,6 +1026,15 @@ void Slot::addFrame(const uint8_t *data, bool net, bool imm) Utils::symbols("!!! *Tx DMR", data + 2U, len - 2U); } + uint32_t fifoSpace = 0U; + if (m_slotNo == 1U) { + fifoSpace = m_modem->getDMRSpace1(); + } else { + fifoSpace = m_modem->getDMRSpace2(); + } + + //LogDebug(LOG_DMR, "Slot %u, addFrame() fifoSpace = %u", m_slotNo, fifoSpace); + // is this immediate data? if (imm) { // resize immediate queue if necessary (this shouldn't really ever happen) @@ -1034,11 +1043,11 @@ void Slot::addFrame(const uint8_t *data, bool net, bool imm) if (!net) { uint32_t queueLen = m_txImmQueue.length(); m_txImmQueue.resize(queueLen + len); - LogError(LOG_DMR, "Slot %u, overflow in the imm DMR slot queue; queue free is %u, needed %u; resized was %u is %u", m_slotNo, space, len, queueLen, m_txQueue.length()); + LogError(LOG_DMR, "Slot %u, overflow in the imm DMR slot queue; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", m_slotNo, space, len, queueLen, m_txQueue.length(), fifoSpace); return; } else { - LogError(LOG_DMR, "Slot %u, overflow in the imm DMR slot queue while writing network data; queue free is %u, needed %u", m_slotNo, space, len); + LogError(LOG_DMR, "Slot %u, overflow in the imm DMR slot queue while writing network data; queue free is %u, needed %u, fifoSpace = %u", m_slotNo, space, len, fifoSpace); return; } } @@ -1053,11 +1062,11 @@ void Slot::addFrame(const uint8_t *data, bool net, bool imm) if (!net) { uint32_t queueLen = m_txQueue.length(); m_txQueue.resize(queueLen + (DMR_FRAME_LENGTH_BYTES + 2U)); - LogError(LOG_DMR, "Slot %u, overflow in the DMR slot queue; queue free is %u, needed %u; resized was %u is %u", m_slotNo, space, len, queueLen, m_txQueue.length()); + LogError(LOG_DMR, "Slot %u, overflow in the DMR slot queue; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", m_slotNo, space, len, queueLen, m_txQueue.length(), fifoSpace); return; } else { - LogError(LOG_DMR, "Slot %u, overflow in the DMR slot queue while writing network data; queue free is %u, needed %u", m_slotNo, space, len); + LogError(LOG_DMR, "Slot %u, overflow in the DMR slot queue while writing network data; queue free is %u, needed %u, fifoSpace = %u", m_slotNo, space, len, fifoSpace); return; } } diff --git a/src/host/modem/Modem.cpp b/src/host/modem/Modem.cpp index d72b3b36..69756a5b 100644 --- a/src/host/modem/Modem.cpp +++ b/src/host/modem/Modem.cpp @@ -139,7 +139,7 @@ Modem::Modem(port::IModemPort* port, bool duplex, bool rxInvert, bool txInvert, m_rxDMRQueue2(dmrQueueSize, "Modem RX DMR2"), m_rxP25Queue(p25QueueSize, "Modem RX P25"), m_rxNXDNQueue(nxdnQueueSize, "Modem RX NXDN"), - m_statusTimer(1000U, 0U, MODEM_POLL_TIME_IDLE), + m_statusTimer(1000U, 0U, MODEM_POLL_TIME), m_inactivityTimer(1000U, 8U), m_dmrSpace1(0U), m_dmrSpace2(0U), @@ -1699,12 +1699,6 @@ DVM_STATE Modem::getState() const bool Modem::setState(DVM_STATE state) { - if (state != STATE_IDLE) { - m_statusTimer.setTimeout(0U, MODEM_POLL_TIME_ACTIVE); - } else { - m_statusTimer.setTimeout(0U, MODEM_POLL_TIME_IDLE); - } - uint8_t buffer[4U]; buffer[0U] = DVM_SHORT_FRAME_START; diff --git a/src/host/modem/Modem.h b/src/host/modem/Modem.h index 4bd97bcc..7764703a 100644 --- a/src/host/modem/Modem.h +++ b/src/host/modem/Modem.h @@ -272,9 +272,8 @@ namespace modem const uint32_t MAX_ADC_OVERFLOW = 128U; const uint32_t MAX_DAC_OVERFLOW = 128U; - const uint32_t MODEM_POLL_TIME_IDLE = 125U; - const uint32_t MODEM_POLL_TIME_ACTIVE = 75U; - + const uint32_t MODEM_POLL_TIME = 250U; + /** @} */ // --------------------------------------------------------------------------- @@ -484,21 +483,41 @@ namespace modem * @returns bool True, if the DMR Slot 1 ring buffer has free space, otherwise false. */ bool hasDMRSpace1() const; + /** + * @brief Helper to return the currently reported available DMR Slot 1 ring buffer free space. + * @return uint32_t Size in bytes available for the DMR Slot 1 ring buffer. + */ + uint32_t getDMRSpace1() const { return m_dmrSpace1; } /** * @brief Helper to test if the DMR Slot 2 ring buffer has free space. * @returns bool True, if the DMR Slot 2 ring buffer has free space, otherwise false. */ bool hasDMRSpace2() const; + /** + * @brief Helper to return the currently reported available DMR Slot 2 ring buffer free space. + * @return uint32_t Size in bytes available for the DMR Slot 2 ring buffer. + */ + uint32_t getDMRSpace2() const { return m_dmrSpace2; } /** * @brief Helper to test if the P25 ring buffer has free space. * @returns bool True, if the P25 ring buffer has free space, otherwise false. */ virtual bool hasP25Space(uint32_t length) const; + /** + * @brief Helper to return the currently reported available P25 ring buffer free space. + * @return uint32_t Size in bytes available for the P25 ring buffer. + */ + uint32_t getP25Space() const { return m_p25Space; } /** * @brief Helper to test if the NXDN ring buffer has free space. * @returns bool True, if the NXDN ring buffer has free space, otherwise false. */ bool hasNXDNSpace() const; + /** + * @brief Helper to return the currently reported available NXDN ring buffer free space. + * @return uint32_t Size in bytes available for the NXDN ring buffer. + */ + uint32_t getNXDNSpace() const { return m_nxdnSpace; } /** * @brief Helper to test if the modem is a hotspot. diff --git a/src/host/nxdn/Control.cpp b/src/host/nxdn/Control.cpp index 844923ce..fde3464c 100644 --- a/src/host/nxdn/Control.cpp +++ b/src/host/nxdn/Control.cpp @@ -871,6 +871,10 @@ void Control::addFrame(const uint8_t *data, bool net, bool imm) Utils::symbols("!!! *Tx NXDN", data + 2U, len - 2U); } + uint32_t fifoSpace = m_modem->getNXDNSpace(); + + //LogDebug(LOG_NXDN, "addFrame() fifoSpace = %u", fifoSpace); + // is this immediate data? if (imm) { // resize immediate queue if necessary (this shouldn't really ever happen) @@ -879,11 +883,11 @@ void Control::addFrame(const uint8_t *data, bool net, bool imm) if (!net) { uint32_t queueLen = m_txImmQueue.length(); m_txImmQueue.resize(queueLen + len); - LogError(LOG_P25, "overflow in the NXDN queue while writing imm data; queue free is %u, needed %u; resized was %u is %u", space, len, queueLen, m_txImmQueue.length()); + LogError(LOG_NXDN, "overflow in the NXDN queue while writing imm data; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", space, len, queueLen, m_txImmQueue.length(), fifoSpace); return; } else { - LogError(LOG_P25, "overflow in the NXDN queue while writing imm network data; queue free is %u, needed %u", space, len); + LogError(LOG_NXDN, "overflow in the NXDN queue while writing imm network data; queue free is %u, needed %u, fifoSpace = %u", space, len, fifoSpace); return; } } @@ -898,11 +902,11 @@ void Control::addFrame(const uint8_t *data, bool net, bool imm) if (!net) { uint32_t queueLen = m_txQueue.length(); m_txQueue.resize(queueLen + len); - LogError(LOG_NXDN, "overflow in the NXDN queue while writing data; queue free is %u, needed %u; resized was %u is %u", space, len, queueLen, m_txQueue.length()); + LogError(LOG_NXDN, "overflow in the NXDN queue while writing data; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", space, len, queueLen, m_txQueue.length(), fifoSpace); return; } else { - LogError(LOG_NXDN, "overflow in the NXDN queue while writing network data; queue free is %u, needed %u", space, len); + LogError(LOG_NXDN, "overflow in the NXDN queue while writing network data; queue free is %u, needed %u, fifoSpace = %u", space, len, fifoSpace); return; } } diff --git a/src/host/p25/Control.cpp b/src/host/p25/Control.cpp index 80e036ae..502fc3b8 100644 --- a/src/host/p25/Control.cpp +++ b/src/host/p25/Control.cpp @@ -1179,6 +1179,10 @@ void Control::addFrame(const uint8_t* data, uint32_t length, bool net, bool imm) Utils::symbols("!!! *Tx P25", data + 2U, length - 2U); } + uint32_t fifoSpace = m_modem->getP25Space(); + + //LogDebug(LOG_P25, "addFrame() fifoSpace = %u", fifoSpace); + // is this immediate data? if (imm) { // resize immediate queue if necessary (this shouldn't really ever happen) @@ -1187,11 +1191,11 @@ void Control::addFrame(const uint8_t* data, uint32_t length, bool net, bool imm) if (!net) { uint32_t queueLen = m_txImmQueue.length(); m_txImmQueue.resize(queueLen + P25_LDU_FRAME_LENGTH_BYTES); - LogError(LOG_P25, "overflow in the P25 queue while writing imm data; queue free is %u, needed %u; resized was %u is %u", space, length, queueLen, m_txImmQueue.length()); + LogError(LOG_P25, "overflow in the P25 queue while writing imm data; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", space, length, queueLen, m_txImmQueue.length(), fifoSpace); return; } else { - LogError(LOG_P25, "overflow in the P25 queue while writing imm network data; queue free is %u, needed %u", space, length); + LogError(LOG_P25, "overflow in the P25 queue while writing imm network data; queue free is %u, needed %u, fifoSpace = %u", space, length, fifoSpace); return; } } @@ -1214,11 +1218,11 @@ void Control::addFrame(const uint8_t* data, uint32_t length, bool net, bool imm) if (!net) { uint32_t queueLen = m_txQueue.length(); m_txQueue.resize(queueLen + P25_LDU_FRAME_LENGTH_BYTES); - LogError(LOG_P25, "overflow in the P25 queue while writing data; queue free is %u, needed %u; resized was %u is %u", space, length, queueLen, m_txQueue.length()); + LogError(LOG_P25, "overflow in the P25 queue while writing data; queue free is %u, needed %u; resized was %u is %u, fifoSpace = %u", space, length, queueLen, m_txQueue.length(), fifoSpace); return; } else { - LogError(LOG_P25, "overflow in the P25 queue while writing network data; queue free is %u, needed %u", space, length); + LogError(LOG_P25, "overflow in the P25 queue while writing network data; queue free is %u, needed %u, fifoSpace = %u", space, length, fifoSpace); return; } }