From 0e6208cc6770f0aeaa00b298b3df13e21c04bab2 Mon Sep 17 00:00:00 2001 From: Tim Stewart Date: Fri, 1 Jan 2021 15:46:05 -0500 Subject: [PATCH] Add frame content details to D-Star debug logging Commit bf5651b deleted all log entries related to D-Star frame contents. This change adds some detail to the existing D-Star frame debugging log entries. Rather than always printing "audio", frames may be logged as one of "audio", "nullaudio", or "fastdata". A minimum width has been set for some fields so that the log messages form columns while watching a data stream. By virtue of centralizing the frame log messages, this commit also adds debugging entries for frames originating from the network. Example log entries that contain all three types as generated by a Kenwood TH-D74 using fast data: M: 2021-01-01 19:52:44.255 D-Star, received RF header from KG4BXH /D74 to CQCQCQ D: 2021-01-01 19:52:44.282 D-Star, RF nullaudio sequence no. 0 D: 2021-01-01 19:52:44.282 D-Star, RF nullaudio sequence no. 1 D: 2021-01-01 19:52:44.309 D-Star, RF nullaudio sequence no. 2 D: 2021-01-01 19:52:44.332 D-Star, RF nullaudio sequence no. 3 D: 2021-01-01 19:52:44.354 D-Star, RF nullaudio sequence no. 4 D: 2021-01-01 19:52:44.365 D-Star, RF nullaudio sequence no. 5 D: 2021-01-01 19:52:44.388 D-Star, RF nullaudio sequence no. 6 D: 2021-01-01 19:52:44.404 D-Star, RF nullaudio sequence no. 7 D: 2021-01-01 19:52:44.426 D-Star, RF nullaudio sequence no. 8 D: 2021-01-01 19:52:44.443 D-Star, RF nullaudio sequence no. 9 D: 2021-01-01 19:52:44.465 D-Star, RF nullaudio sequence no. 10 D: 2021-01-01 19:52:44.488 D-Star, RF nullaudio sequence no. 11 D: 2021-01-01 19:52:44.510 D-Star, RF nullaudio sequence no. 12 D: 2021-01-01 19:52:44.526 D-Star, RF nullaudio sequence no. 13 D: 2021-01-01 19:52:44.543 D-Star, RF nullaudio sequence no. 14 D: 2021-01-01 19:52:44.565 D-Star, RF nullaudio sequence no. 15 D: 2021-01-01 19:52:44.588 D-Star, RF nullaudio sequence no. 16 D: 2021-01-01 19:52:44.604 D-Star, RF nullaudio sequence no. 17 D: 2021-01-01 19:52:44.627 D-Star, RF nullaudio sequence no. 18 D: 2021-01-01 19:52:44.649 D-Star, RF nullaudio sequence no. 19 D: 2021-01-01 19:52:44.665 D-Star, RF nullaudio sequence no. 20 D: 2021-01-01 19:52:44.704 D-Star, RF fastdata sequence no. 0 D: 2021-01-01 19:52:44.704 D-Star, RF fastdata sequence no. 1 D: 2021-01-01 19:52:44.726 D-Star, RF fastdata sequence no. 2 D: 2021-01-01 19:52:44.748 D-Star, RF fastdata sequence no. 3 D: 2021-01-01 19:52:44.765 D-Star, RF fastdata sequence no. 4 ... many fastdata frames elided ... D: 2021-01-01 19:52:45.486 D-Star, RF fastdata sequence no. 19 D: 2021-01-01 19:52:45.508 D-Star, RF fastdata sequence no. 20 D: 2021-01-01 19:52:45.548 D-Star, RF fastdata sequence no. 0 D: 2021-01-01 19:52:45.548 D-Star, RF fastdata sequence no. 1 D: 2021-01-01 19:52:45.565 D-Star, RF fastdata sequence no. 2 D: 2021-01-01 19:52:45.587 D-Star, RF audio sequence no. 3, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.609 D-Star, RF audio sequence no. 4, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.631 D-Star, RF audio sequence no. 5, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.648 D-Star, RF audio sequence no. 6, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.670 D-Star, RF audio sequence no. 7, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.687 D-Star, RF audio sequence no. 8, errs: 0/48 ( 0.0%) D: 2021-01-01 19:52:45.709 D-Star, RF fastdata sequence no. 9 D: 2021-01-01 19:52:45.731 D-Star, RF fastdata sequence no. 10 D: 2021-01-01 19:52:45.753 D-Star, RF fastdata sequence no. 11 D: 2021-01-01 19:52:45.775 D-Star, RF fastdata sequence no. 12 D: 2021-01-01 19:52:45.786 D-Star, RF fastdata sequence no. 13 ... many more fastdata frames with periodic audio as above ... --- DStarControl.cpp | 26 +++++++++++++++++++++----- 1 file changed, 21 insertions(+), 5 deletions(-) diff --git a/DStarControl.cpp b/DStarControl.cpp index 794b748be..7a436e5a2 100644 --- a/DStarControl.cpp +++ b/DStarControl.cpp @@ -145,6 +145,7 @@ unsigned int CDStarControl::maybeFixupVoiceFrame( ) { unsigned int errors = 0U; + unsigned int voice_sync_errors = 0U; unsigned char mini_header = data[offset + 9U] ^ DSTAR_SCRAMBLER_BYTES[0U]; unsigned char mini_header_type = mini_header & DSTAR_SLOW_DATA_TYPE_MASK; @@ -157,10 +158,14 @@ unsigned int CDStarControl::maybeFixupVoiceFrame( *next_frame_is_fast_data = true; if (blank_dtmf) *skip_dtmf_blanking_frames = FAST_DATA_BEEP_GRACE_FRAMES; + if (n == 1U) + LogDebug("D-Star, %s fastdata sequence no. 0", log_prefix); + LogDebug("D-Star, %s fastdata sequence no. %2u", log_prefix, n); } else if (*next_frame_is_fast_data == true) { *next_frame_is_fast_data = false; if (blank_dtmf) *skip_dtmf_blanking_frames = FAST_DATA_BEEP_GRACE_FRAMES; + LogDebug("D-Star, %s fastdata sequence no. %2u", log_prefix, n); } else { bool voice_sync_data_is_null_ambe_data = false; bool data_is_null_ambe_data = false; @@ -170,7 +175,7 @@ unsigned int CDStarControl::maybeFixupVoiceFrame( data_is_null_ambe_data = true; if ((n == 1U) && !voice_sync_data_is_null_ambe_data) - errors += m_fec.regenerateDStar(voice_sync_data + offset); + voice_sync_errors += m_fec.regenerateDStar(voice_sync_data + offset); if (!data_is_null_ambe_data) errors += m_fec.regenerateDStar(data + offset); @@ -182,9 +187,22 @@ unsigned int CDStarControl::maybeFixupVoiceFrame( if (!data_is_null_ambe_data) blankDTMF(data + offset); } - } - return errors; + if (n == 1U) { + if (voice_sync_data_is_null_ambe_data) + LogDebug("D-Star, %s nullaudio sequence no. 0", log_prefix); + else + LogDebug("D-Star, %s audio sequence no. 0, errs: %2u/48 (%5.1f%%)", log_prefix, voice_sync_errors, + float(voice_sync_errors) / 0.48F); + } + if (data_is_null_ambe_data) + LogDebug("D-Star, %s nullaudio sequence no. %2u", log_prefix, n); + else + LogDebug("D-Star, %s audio sequence no. %2u, errs: %2u/48 (%5.1f%%)", log_prefix, n, errors, + float(errors) / 0.48F); + } + + return voice_sync_errors + errors; } bool CDStarControl::writeModem(unsigned char *data, unsigned int len) @@ -440,7 +458,6 @@ bool CDStarControl::writeModem(unsigned char *data, unsigned int len) errors = maybeFixupVoiceFrame(data, len, 1U, "RF", m_rfN, m_duplex, m_rfVoiceSyncData, &m_rfVoiceSyncDataLen, &m_rfNextFrameIsFastData, &m_rfSkipDTMFBlankingFrames); m_display->writeDStarBER(float(errors) / 0.48F); - LogDebug("D-Star, audio sequence no. %u, errs: %u/48 (%.1f%%)", m_rfN, errors, float(errors) / 0.48F); m_rfErrs += errors; } @@ -573,7 +590,6 @@ bool CDStarControl::writeModem(unsigned char *data, unsigned int len) if (!m_rfHeader.isDataPacket()) { errors = maybeFixupVoiceFrame(data, len, 1U, "RF", m_rfN, m_duplex, m_rfVoiceSyncData, &m_rfVoiceSyncDataLen, &m_rfNextFrameIsFastData, &m_rfSkipDTMFBlankingFrames); - LogDebug("D-Star, audio sequence no. %u, errs: %u/48 (%.1f%%)", m_rfN, errors, float(errors) / 0.48F); m_rfErrs += errors; }