From d2ed457109d5c3d4069c258b5892bd943b03b979 Mon Sep 17 00:00:00 2001 From: Bryan Biedenkapp Date: Fri, 10 Dec 2021 17:54:36 -0500 Subject: [PATCH] make clearer log messages in the case of coding errors such as TSBK Trellis or CRC errors; allow CRC TSDU errors to be warnings in calibration mode; --- dmr/lc/CSBK.cpp | 7 +++-- host/calibrate/HostCal.cpp | 1 + p25/Control.cpp | 2 +- p25/TrunkPacket.cpp | 2 +- p25/lc/LC.cpp | 22 +++++++++------ p25/lc/TDULC.cpp | 14 ++++++---- p25/lc/TSBK.cpp | 57 +++++++++++++++++++++++++------------- p25/lc/TSBK.h | 4 +++ 8 files changed, 72 insertions(+), 37 deletions(-) diff --git a/dmr/lc/CSBK.cpp b/dmr/lc/CSBK.cpp index f678247d..a63f8bb2 100644 --- a/dmr/lc/CSBK.cpp +++ b/dmr/lc/CSBK.cpp @@ -92,8 +92,10 @@ bool CSBK::decode(const uint8_t* bytes) m_data[11U] ^= CSBK_CRC_MASK[1U]; bool valid = edac::CRC::checkCCITT162(m_data, DMR_LC_HEADER_LENGTH_BYTES); - if (!valid) + if (!valid) { + LogError(LOG_DMR, "CSBK::decode(), failed CRC CCITT-162 check"); return false; + } // restore the checksum m_data[10U] ^= CSBK_CRC_MASK[0U]; @@ -191,7 +193,7 @@ bool CSBK::decode(const uint8_t* bytes) m_dstId = 0U; m_dataContent = false; m_CBF = 0U; - LogError(LOG_DMR, "unknown CSBK type, csbko = $%02X", m_CSBKO); + LogError(LOG_DMR, "CSBK::decode(), unknown CSBK type, csbko = $%02X", m_CSBKO); return true; } @@ -457,6 +459,7 @@ void CSBK::encode(uint8_t* bytes) m_data[7U] = (m_srcId >> 16) & 0xFFU; // Source ID m_data[8U] = (m_srcId >> 8) & 0xFFU; m_data[9U] = (m_srcId >> 0) & 0xFFU; + LogError(LOG_DMR, "CSBK::encode(), unknown CSBK type, csbko = $%02X", m_CSBKO); break; } diff --git a/host/calibrate/HostCal.cpp b/host/calibrate/HostCal.cpp index 2f74c541..fc59628a 100644 --- a/host/calibrate/HostCal.cpp +++ b/host/calibrate/HostCal.cpp @@ -1730,6 +1730,7 @@ void HostCal::processP25BER(const uint8_t* buffer) lc::TSBK tsbk = lc::TSBK(SiteData(), lookups::IdenTable()); tsbk.setVerbose(true); // always verbose in CAL + tsbk.setWarnCRC(true); Utils::dump(1U, "Raw TSBK Dump", buffer + 1U, P25_TSDU_FRAME_LENGTH_BYTES); diff --git a/p25/Control.cpp b/p25/Control.cpp index 721b3ac5..d4c47e5c 100644 --- a/p25/Control.cpp +++ b/p25/Control.cpp @@ -75,7 +75,7 @@ const uint32_t MAX_PREAMBLE_TDU_CNT = 64U; /// Instance of the RSSIInterpolator class. /// /// -/// +/// Flag indicating whether TSBK data is dumped to the log. /// Flag indicating whether P25 debug is enabled. /// Flag indicating whether P25 verbose logging is enabled. Control::Control(uint32_t nac, uint32_t callHang, uint32_t queueSize, modem::Modem* modem, network::BaseNetwork* network, diff --git a/p25/TrunkPacket.cpp b/p25/TrunkPacket.cpp index d3eaf08f..ed0fcaa5 100644 --- a/p25/TrunkPacket.cpp +++ b/p25/TrunkPacket.cpp @@ -1148,7 +1148,7 @@ void TrunkPacket::setTSBKVerbose(bool verbose) /// /// Instance of the Control class. /// Instance of the BaseNetwork class. -/// +/// Flag indicating whether TSBK data is dumped to the log. /// Flag indicating whether P25 debug is enabled. /// Flag indicating whether P25 verbose logging is enabled. TrunkPacket::TrunkPacket(Control* p25, network::BaseNetwork* network, bool dumpTSBKData, bool debug, bool verbose) : diff --git a/p25/lc/LC.cpp b/p25/lc/LC.cpp index 624b4bfe..6a1906c4 100644 --- a/p25/lc/LC.cpp +++ b/p25/lc/LC.cpp @@ -176,11 +176,13 @@ bool LC::decodeHDU(const uint8_t* data) // decode RS (36,20,17) FEC try { bool ret = m_rs.decode362017(rs); - if (!ret) + if (!ret) { + LogError(LOG_P25, "LC::decodeHDU(), failed to decode RS (36,20,17) FEC"); return false; + } } catch (...) { - Utils::dump(2U, "P25, RS crashed with input data", rs, P25_HDU_LENGTH_BYTES); + Utils::dump(2U, "P25, RS excepted with input data", rs, P25_HDU_LENGTH_BYTES); return false; } @@ -299,11 +301,13 @@ bool LC::decodeLDU1(const uint8_t * data) // decode RS (24,12,13) FEC try { bool ret = m_rs.decode241213(rs); - if (!ret) + if (!ret) { + LogError(LOG_P25, "LC::decodeLDU1(), failed to decode RS (24,12,13) FEC"); return false; + } } catch (...) { - Utils::dump(2U, "P25, RS crashed with input data", rs, P25_LDU_LC_LENGTH_BYTES); + Utils::dump(2U, "P25, RS excepted with input data", rs, P25_LDU_LC_LENGTH_BYTES); return false; } @@ -391,11 +395,13 @@ bool LC::decodeLDU2(const uint8_t * data) // decode RS (24,16,9) FEC try { bool ret = m_rs.decode24169(rs); - if (!ret) + if (!ret) { + LogError(LOG_P25, "LC::decodeLDU2(), failed to decode RS (24,16,9) FEC"); return false; + } } catch (...) { - Utils::dump(2U, "P25, RS crashed with input data", rs, P25_LDU_LC_LENGTH_BYTES); + Utils::dump(2U, "P25, RS excepted with input data", rs, P25_LDU_LC_LENGTH_BYTES); return false; } @@ -556,7 +562,7 @@ bool LC::decodeLC(const uint8_t * rs) } break; default: - LogError(LOG_P25, "unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "LC::decodeLC(), unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); return false; } @@ -626,7 +632,7 @@ void LC::encodeLC(uint8_t * rs) rsValue = (rsValue << 8) + m_siteData.serviceClass(); // System Service Class break; default: - LogError(LOG_P25, "unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "LC::encodeLC(), unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } diff --git a/p25/lc/TDULC.cpp b/p25/lc/TDULC.cpp index ab236e47..358b52ab 100644 --- a/p25/lc/TDULC.cpp +++ b/p25/lc/TDULC.cpp @@ -164,11 +164,13 @@ bool TDULC::decode(const uint8_t* data) // decode RS (24,12,13) FEC try { bool ret = m_rs.decode241213(rs); - if (!ret) + if (!ret) { + LogError(LOG_P25, "TDULC::decode(), failed to decode RS (24,12,13) FEC"); return false; + } } catch (...) { - Utils::dump(2U, "P25, RS crashed with input data", rs, P25_TDULC_LENGTH_BYTES); + Utils::dump(2U, "P25, RS excepted with input data", rs, P25_TDULC_LENGTH_BYTES); return false; } @@ -299,7 +301,7 @@ bool TDULC::decodeLC(const uint8_t* rs) } break; default: - LogError(LOG_P25, "unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TDULC::decodeLC(), unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); return false; } @@ -385,7 +387,7 @@ void TDULC::encodeLC(uint8_t* rs) rsValue = (rsValue << 32) + calcBaseFreq; // Base Frequency } else { - LogError(LOG_P25, "invalid values for LC_IDEN_UP, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", + LogError(LOG_P25, "TDULC::encodeLC(), invalid values for LC_IDEN_UP, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", m_siteIdenEntry.baseFrequency(), m_siteIdenEntry.txOffsetMhz(), m_siteIdenEntry.chBandwidthKhz(), m_siteIdenEntry.chSpaceKhz()); return; // blatently ignore creating this TSBK @@ -415,7 +417,7 @@ void TDULC::encodeLC(uint8_t* rs) rsValue = (rsValue << 8) + m_adjServiceClass; // System Service Class } else { - LogError(LOG_P25, "invalid values for LC_ADJ_STS_BCAST, tsbkAdjSiteRFSSId = $%02X, tsbkAdjSiteId = $%02X, tsbkAdjSiteChannel = $%02X", + LogError(LOG_P25, "TDULC::encodeLC(), invalid values for LC_ADJ_STS_BCAST, tsbkAdjSiteRFSSId = $%02X, tsbkAdjSiteId = $%02X, tsbkAdjSiteChannel = $%02X", m_adjRfssId, m_adjSiteId, m_adjChannelNo); return; // blatently ignore creating this TSBK } @@ -441,7 +443,7 @@ void TDULC::encodeLC(uint8_t* rs) rsValue = (rsValue << 8) + m_siteData.serviceClass(); // System Service Class break; default: - LogError(LOG_P25, "unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TDULC::encodeLC(), unknown LC value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } diff --git a/p25/lc/TSBK.cpp b/p25/lc/TSBK.cpp index 66af680f..619e9863 100644 --- a/p25/lc/TSBK.cpp +++ b/p25/lc/TSBK.cpp @@ -61,9 +61,20 @@ TSBK::TSBK(SiteData siteData, lookups::IdenTable entry) : TSBK(siteData) /// /// /// -TSBK::TSBK(SiteData siteData, lookups::IdenTable entry, bool verbose) : TSBK(siteData) +TSBK::TSBK(SiteData siteData, lookups::IdenTable entry, bool verbose) : TSBK(siteData, entry, verbose, false) { m_verbose = verbose; +} + +/// +/// Initializes a new instance of the TSBK class. +/// +/// +/// +/// +TSBK::TSBK(SiteData siteData, lookups::IdenTable entry, bool verbose, bool warnCRC) : TSBK(siteData) +{ + m_warnCRC = warnCRC; m_siteIdenEntry = entry; } @@ -106,6 +117,7 @@ TSBK& TSBK::operator=(const TSBK& data) { if (this != &data) { m_verbose = data.m_verbose; + m_warnCRC = data.m_warnCRC; m_protect = data.m_protect; m_lco = data.m_lco; m_mfId = data.m_mfId; @@ -185,21 +197,27 @@ bool TSBK::decode(const uint8_t* data) // decode 1/2 rate Trellis & check CRC-CCITT 16 try { bool ret = m_trellis.decode12(raw, tsbk); - if (m_verbose && !ret) { - LogDebug(LOG_P25, "TSBK::decode(): failed to decode Trellis 1/2 rate"); + if (!ret) { + LogError(LOG_P25, "TSBK::decode(), failed to decode Trellis 1/2 rate coding"); } if (ret) { ret = edac::CRC::checkCCITT162(tsbk, P25_TSBK_LENGTH_BYTES); - if (m_verbose && !ret) { - LogDebug(LOG_P25, "TSBK::decode(): CRC CCITT-162 failed to match"); + if (!ret) { + if (m_warnCRC) { + LogWarning(LOG_P25, "TSBK::decode(), failed CRC CCITT-162 check"); + ret = true; // ignore CRC error + } + else { + LogError(LOG_P25, "TSBK::decode(), failed CRC CCITT-162 check"); + } } } if (!ret) return false; } catch (...) { - Utils::dump(2U, "P25, CRC failed with input data", tsbk, P25_TSBK_LENGTH_BYTES); + Utils::dump(2U, "P25, decoding excepted with input data", tsbk, P25_TSBK_LENGTH_BYTES); return false; } @@ -247,7 +265,7 @@ bool TSBK::decode(const uint8_t* data) m_mfId = P25_MFG_STANDARD; break; default: - LogError(LOG_P25, "unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TSBK::decode(), unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } @@ -391,7 +409,7 @@ bool TSBK::decode(const uint8_t* data) m_adjServiceClass = (uint8_t)(tsbkValue & 0xFFU); // Site Service Class break; default: - LogError(LOG_P25, "unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TSBK::decode(), unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } @@ -522,10 +540,10 @@ void TSBK::encode(uint8_t * data, bool singleBlock) { if (m_response == 0U) { if (m_lco == TSBK_OSP_QUE_RSP) { - LogError(LOG_P25, "invalid values for TSBK_OSP_QUE_RSP, reason = %u", m_response); + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_QUE_RSP, reason = %u", m_response); } else { - LogError(LOG_P25, "invalid values for TSBK_OSP_DENY_RSP, reason = %u", m_response); + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_DENY_RSP, reason = %u", m_response); } return; // blatently ignore creating this TSBK } @@ -606,7 +624,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) tsbkValue = (tsbkValue << 32) + calcBaseFreq; // Base Frequency } else { - LogError(LOG_P25, "invalid values for TSBK_OSP_IDEN_UP_VU, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_IDEN_UP_VU, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", m_siteIdenEntry.baseFrequency(), m_siteIdenEntry.txOffsetMhz(), m_siteIdenEntry.chBandwidthKhz(), m_siteIdenEntry.chSpaceKhz()); return; // blatently ignore creating this TSBK @@ -672,7 +690,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) tsbkValue = (tsbkValue << 8) + m_adjServiceClass; // System Service Class } else { - LogError(LOG_P25, "invalid values for OSP_ADJ_STS_BCAST, adjRfssId = $%02X, adjSiteId = $%02X, adjChannelId = %u, adjChannelNo = $%02X, adjSvcClass = $%02X", + LogError(LOG_P25, "TSBK::encode(), invalid values for OSP_ADJ_STS_BCAST, adjRfssId = $%02X, adjSiteId = $%02X, adjChannelId = %u, adjChannelNo = $%02X, adjSvcClass = $%02X", m_adjRfssId, m_adjSiteId, m_adjChannelId, m_adjChannelNo, m_adjServiceClass); return; // blatently ignore creating this TSBK } @@ -683,7 +701,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) if ((m_siteIdenEntry.chBandwidthKhz() != 0.0F) && (m_siteIdenEntry.chSpaceKhz() != 0.0F) && (m_siteIdenEntry.txOffsetMhz() != 0.0F) && (m_siteIdenEntry.baseFrequency() != 0U)) { if (m_siteIdenEntry.baseFrequency() < 762000000U) { - LogError(LOG_P25, "invalid values for TSBK_OSP_IDEN_UP, baseFrequency = %uHz", + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_IDEN_UP, baseFrequency = %uHz", m_siteIdenEntry.baseFrequency()); return; // blatently ignore creating this TSBK } @@ -703,7 +721,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) tsbkValue = (tsbkValue << 32) + calcBaseFreq; // Base Frequency } else { - LogError(LOG_P25, "invalid values for TSBK_OSP_IDEN_UP, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_IDEN_UP, baseFrequency = %uHz, txOffsetMhz = %uMHz, chBandwidthKhz = %fKHz, chSpaceKhz = %fKHz", m_siteIdenEntry.baseFrequency(), m_siteIdenEntry.txOffsetMhz(), m_siteIdenEntry.chBandwidthKhz(), m_siteIdenEntry.chSpaceKhz()); return; // blatently ignore creating this TSBK @@ -712,7 +730,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) break; default: if (m_mfId == P25_MFG_STANDARD) { - LogError(LOG_P25, "unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TSBK::encode(), unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); } break; } @@ -767,7 +785,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) } } else { - LogError(LOG_P25, "invalid values for TSBK_OSP_MOT_GRG_DEL, patchSuperGroupId = $%02X, patchGroup1Id = $%02X", + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_MOT_GRG_DEL, patchSuperGroupId = $%02X, patchGroup1Id = $%02X", m_patchSuperGroupId, m_patchGroup1Id); return; // blatently ignore creating this TSBK } @@ -783,7 +801,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) tsbkValue = (tsbkValue << 24) + m_srcId; // Source Radio Address } else { - LogError(LOG_P25, "invalid values for TSBK_OSP_MOT_GRG_VCH_GRANT, patchSuperGroupId = $%02X", m_patchSuperGroupId); + LogError(LOG_P25, "TSBK::encode(), invalid values for TSBK_OSP_MOT_GRG_VCH_GRANT, patchSuperGroupId = $%02X", m_patchSuperGroupId); return; // blatently ignore creating this TSBK } } @@ -824,7 +842,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) case TSBK_OSP_U_DEREG_ACK: break; default: - LogError(LOG_P25, "unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TSBK::encode(), unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } } @@ -839,7 +857,7 @@ void TSBK::encode(uint8_t * data, bool singleBlock) tsbkValue = (tsbkValue << 24) + m_srcId; // Source Radio Address break; default: - LogError(LOG_P25, "unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); + LogError(LOG_P25, "TSBK::encode(), unknown TSBK LCO value, mfId = $%02X, lco = $%02X", m_mfId, m_lco); break; } } @@ -915,6 +933,7 @@ void TSBK::setCallsign(std::string callsign) /// TSBK::TSBK(SiteData siteData) : m_verbose(false), + m_warnCRC(false), m_protect(false), m_lco(LC_GROUP), m_mfId(P25_MFG_STANDARD), diff --git a/p25/lc/TSBK.h b/p25/lc/TSBK.h index bce7fce5..2ea47769 100644 --- a/p25/lc/TSBK.h +++ b/p25/lc/TSBK.h @@ -63,6 +63,8 @@ namespace p25 /// Initializes a new instance of the TSBK class. TSBK(SiteData siteData, lookups::IdenTable entry, bool verbose); /// Initializes a new instance of the TSBK class. + TSBK(SiteData siteData, lookups::IdenTable entry, bool verbose, bool warnCRC); + /// Initializes a new instance of the TSBK class. TSBK(LC* lc); /// Finalizes a instance of the TSBK class. ~TSBK(); @@ -84,6 +86,8 @@ namespace p25 public: /// Flag indicating verbose log output. __PROPERTY(bool, verbose, Verbose); + /// Flag indicating CRC-errors should be warnings and not errors. + __PROPERTY(bool, warnCRC, WarnCRC); /** Common Data */ /// Flag indicating the link control data is protected.