From dc8e3eeaaf094a3d16991289934093d5e7127680 Mon Sep 17 00:00:00 2001 From: Naveen Albert Date: Fri, 15 Aug 2025 08:32:00 -0400 Subject: [PATCH] dsp.c: Improve debug logging in tone_detect(). The debug logging during DSP processing has always been kind of overwhelming and annoying to troubleshoot. Simplify and improve the logging in a few ways to aid DSP debugging: * If we had a DSP hit, don't also emit the previous debug message that was always logged. It is duplicated by the hit message, so this can reduce the number of debug messages during detection by 50%. * Include the hit count and required number of hits in the message so on partial detections can be more easily troubleshot. * Use debug level 9 for hits instead of 10, so we can focus on hits without all the noise from the per-frame debug message. * 1-index the hit count in the debug messages. On the first hit, it currently logs '0', just as when we are not detecting anything, which can be confusing. Resolves: #1375 --- main/dsp.c | 10 ++++++---- 1 file changed, 6 insertions(+), 4 deletions(-) diff --git a/main/dsp.c b/main/dsp.c index 0955f66677..0bcce132c1 100644 --- a/main/dsp.c +++ b/main/dsp.c @@ -618,12 +618,14 @@ static int tone_detect(struct ast_dsp *dsp, tone_detect_state_t *s, int16_t *amp tone_energy *= 2.0; s->energy *= s->block_size; - ast_debug(10, "%d Hz tone %2d Ew=%.4E, Et=%.4E, s/n=%10.2f\n", s->freq, s->hit_count, tone_energy, s->energy, tone_energy / (s->energy - tone_energy)); - hit = 0; + /* Add 1 to hit_count when logging, since it doesn't get incremented until later in the loop. */ if (TONE_THRESHOLD <= tone_energy && tone_energy > s->energy * s->threshold) { - ast_debug(10, "%d Hz tone Hit! %2d Ew=%.4E, Et=%.4E, s/n=%10.2f\n", s->freq, s->hit_count, tone_energy, s->energy, tone_energy / (s->energy - tone_energy)); + ast_debug(9, "%d Hz tone Hit! [%d/%d] Ew=%.4E, Et=%.4E, s/n=%10.2f\n", s->freq, s->hit_count + 1, s->hits_required, tone_energy, s->energy, tone_energy / (s->energy - tone_energy)); hit = 1; + } else { + ast_debug(10, "%d Hz tone [%d/%d] Ew=%.4E, Et=%.4E, s/n=%10.2f\n", s->freq, s->hit_count + 1, s->hits_required, tone_energy, s->energy, tone_energy / (s->energy - tone_energy)); + hit = 0; } if (s->hit_count) { @@ -633,11 +635,11 @@ static int tone_detect(struct ast_dsp *dsp, tone_detect_state_t *s, int16_t *amp if (hit == s->last_hit) { if (!hit) { /* Two successive misses. Tone ended */ + ast_debug(9, "Partial detect expired after %d/%d hits\n", s->hit_count, s->hits_required); s->hit_count = 0; } else if (!s->hit_count) { s->hit_count++; } - } if (s->hit_count == s->hits_required) {