ewsdr/test/hpsdr/txtrace_scan.py

#!/usr/bin/env python3
"""Разбор кольцевой трассировки TX-тракта (файлы txtrace-*.txt).

Дамп пишет сама программа, запущенная с EWSDR_TXTRACE=1: кольцо сбрасывается
на диск в конце каждой передачи в каталог настроек (~/.config/ewsdr/).

Зачем: pcap показывает ПАУЗУ в потоке DUC, но не показывает, кто её сделал.
Здесь видно, кто именно не наполнил очередь: продюсер звука (TCI/звуковая
карта), TX-поток DSP или сетевой поток приёма.

Запуск: txtrace_scan.py <файл> [--context N]
"""

import sys
import statistics
from collections import defaultdict

# Подушка отправителя DUC: 2000 отсчётов @192 кГц (HPSDRNetwork.pas).
CUSHION_MS = 2000 / 192.0


def parse(path):
    rows = []
    for line in open(path, encoding='utf-8', errors='replace'):
        if line.startswith('#') or not line.strip():
            continue
        f = line.split()
        if len(f) != 5:
            continue
        try:
            rows.append((float(f[0]), f[1], int(f[2]), int(f[3]), int(f[4])))
        except ValueError:
            continue
    return rows


def segments(rows):
    """Кольцо накапливается через всю сессию: файл второй передачи содержит и
    первую. Режем по фронтам PTT — сравнивать можно только передачу с
    передачей."""
    segs, cur = [], None
    for r in rows:
        if r[1] == 'PTT' and r[2] == 1:
            cur = [r]
            segs.append(cur)
            continue
        if cur is not None:
            cur.append(r)
            if r[1] == 'PTT' and r[2] == 0:
                cur = None
    return segs if segs else [rows]


def inflight_tail(rows, seg):
    """Маркеры, оставшиеся в полёте на снятии PTT: планировщик пишет это
    (NOTE A=-3) на СЛЕДУЮЩЕМ тике, уже за границей передачи. Без учёта этой
    метки разбор считает их потерянными клиентом."""
    end = seg[-1][0]
    for r in rows:
        if r[0] < end or r[1] != 'NOTE' or r[2] != -3:
            continue
        if r[0] - end > 200:
            break
        return r[3]
    return 0


def stats(name, vals, unit='мкс'):
    if not vals:
        return f'  {name:<22} —'
    vals = sorted(vals)
    p99 = vals[min(len(vals) - 1, int(len(vals) * 0.99))]
    return (f'  {name:<22} n={len(vals):<6} медиана={statistics.median(vals):>9.1f} '
            f'p99={p99:>9.1f} макс={vals[-1]:>9.1f} {unit}')


def main():
    if len(sys.argv) < 2:
        print(__doc__)
        return 1
    path = sys.argv[1]
    ctx = 8
    if '--context' in sys.argv:
        ctx = int(sys.argv[sys.argv.index('--context') + 1])

    all_rows = parse(path)
    if not all_rows:
        print('пусто: в файле нет записей')
        return 1

    segs = segments(all_rows)
    print(f'=== {path}')
    print(f'записей {len(all_rows)}, передач в кольце {len(segs)}')
    for seg_no, seg in enumerate(segs, 1):
        report(seg, seg_no, ctx, inflight_tail(all_rows, seg))
    return 0


def report(rows, seg_no, ctx, tail_frames=0):
    by_kind = defaultdict(list)
    for r in rows:
        by_kind[r[1]].append(r)

    span = rows[-1][0] - rows[0][0]
    # Источник берём с ЗАКРЫВАЮЩЕГО фронта PTT: на открывающем он ещё старый
    # (SetMOX ставит метку до того, как ApplyMOX выберет источник).
    src_code = rows[0][3]
    for r in reversed(rows):
        if r[1] == 'PTT' and r[2] == 0:
            src_code = r[3]
            break
    src = {0: 'микрофон радио', 1: 'звуковая карта',
           2: 'внешняя подача (web/TCI)'}.get(src_code, '?')
    print(f'\n===== ПЕРЕДАЧА {seg_no}: {span/1000.0:.2f} с, источник — {src}, '
          f'подушка отправителя {CUSHION_MS:.2f} мс\n')

    print('РАСПРЕДЕЛЕНИЯ')
    print(stats('Synchronize (HP)', [r[2] for r in by_kind['HP-SYNC']]))
    print(stats('обработчик приёма', [r[2] for r in by_kind['HANDLER']]))
    print(stats('пауза в приёме', [r[2] for r in by_kind['RECV-GAP']]))
    print(stats('зазор тика TX', [r[2] for r in by_kind['TX-TICK']]))
    print(stats('fexchange0', [r[2] for r in by_kind['TX-PHASE']]))
    print(stats('TX-анализатор', [r[3] for r in by_kind['TX-PHASE']]))
    print(stats('отдача IQ', [r[4] for r in by_kind['TX-PHASE']]))
    print(stats('период TX_CHRONO', [r[4] for r in by_kind['CHRONO']]))
    print(stats('период TX-аудио', [r[2] for r in by_kind['TX-AUDIO']]))
    print(stats('простой очереди DUC', [r[2] for r in by_kind['DUC-RUN']]))

    # Продюсер: сколько блоков TX-поток делает за тик и как часто ринг пуст.
    ticks = by_kind['TX-TICK']
    if ticks:
        dry = sum(1 for t in ticks if t[4] == 0)
        burst = [t[4] for t in ticks if t[4] > 1]
        print(f'\n  тиков TX всего {len(ticks)}, из них вхолостую (ринг пуст) '
              f'{dry} ({100.0*dry/len(ticks):.1f}%), '
              f'пачками >1 блока {len(burst)}')

    # Учёт каналов: length в шапке против моно-отсчётов после интерполяции.
    audio = by_kind['TX-AUDIO']
    if audio:
        pairs = {(a[3], a[4]) for a in audio}
        print(f'  TX-аудио: пары (length, отсчётов после интерполяции) = '
              f'{sorted(pairs)[:6]}')

    # ★Баланс подачи. Просим по часам, а списываем долг при ОТПРАВКЕ маркера:
    # каждый маркер без ответа = безвозвратно потерянный кусок звука, наверстать
    # его нечем. Дефицит съедает единственный запас (аванс + pre-roll), и когда
    # запас кончился — очередь пустеет на каждой порции.
    chrono = by_kind['CHRONO']
    # Предварительный маркер (NOTE A=-4) уходит до фронта PTT, вне бухгалтерии
    # и вне статистики периода — но в баланс он входит наравне с прочими.
    prewarm = [n for n in by_kind['NOTE'] if n[2] == -4]
    if chrono and audio:
        asked = sum(c[2] for c in chrono) + sum(p[3] for p in prewarm)
        got = sum(a[4] for a in audio)
        secs = span / 1000.0
        print(f'\n  БАЛАНС ПОДАЧИ: маркеров {len(chrono) + len(prewarm)} '
              f'(из них предварительных {len(prewarm)}), порций {len(audio)}, '
              f'проглочено {len(chrono) + len(prewarm) - len(audio)}')
        print(f'    запрошено {asked} отсч., получено {got} '
              f'({got/secs:.0f} отсч/с при номинале 48000)')
        print(f'    дефицит {asked-got} отсч. = {(asked-got)/48.0:.1f} мс звука, '
              f'которого в эфире не будет')
        # NOTE несёт три разных записи: A>=0 — счётчик выброшенного очередью,
        # A=-1 — прощение зависшего кредита, A=-2 — выдача аванса,
        # A=-3 — сколько маркеров осталось В ПОЛЁТЕ на снятии PTT.
        notes = by_kind['NOTE']
        drops = [n for n in notes if n[2] >= 0]
        if drops:
            lost = drops[-1][2] - drops[0][2]
            print(f'    из них выброшено НАШЕЙ очередью к клиенту: {lost} блок(ов)')
        if tail_frames > 0:
            q = chrono[-1][2] if chrono else 0
            n_tail = tail_frames // q if q else 0
            print(f'    ★из «проглоченных» {n_tail} — это маркеры в полёте на '
                  f'снятии PTT, а не потеря')
        lead = [n for n in notes if n[2] == -2]
        if lead:
            print(f'    аванс под зернистость клиента: {lead[-1][3]} кадров '
                  f'({lead[-1][3] / 48.0:.1f} мс), выдан {len(lead)} раз(а)')
        forg = [n for n in notes if n[2] == -1]
        if forg:
            print(f'    прощений зависшего кредита: {len(forg)}')

    # Главное: каждый простой очереди — с историей перед ним.
    print('\nПРОСТОИ ОЧЕРЕДИ DUC (кто молчал перед пустой очередью)')
    n_over = 0
    for i, r in enumerate(rows):
        if r[1] != 'DUC-DRY':
            continue
        dur = None
        for q in rows[i + 1:]:
            if q[1] == 'DUC-RUN':
                dur = q[2] / 1000.0
                break
            if q[1] == 'DUC-DRY':
                break
        # Простой короче одного пакета (240 отсчётов @192 кГц = 1.25 мс) —
        # не голодание: быстрее отправитель всё равно не умеет. Такие точки
        # ловятся на самом фронте PTT, когда очередь ещё пуста, а pre-roll в
        # неё только заливается.
        over = (dur is not None and dur > CUSHION_MS
                and dur > 1.25)
        if over:
            n_over += 1
        mark = '★ДЛИННЕЕ ПОДУШКИ' if over else ''
        print(f'\n  t={r[0]:.3f} мс  простой {dur if dur is None else round(dur,2)} мс '
              f'(FIFO={r[2]} отсч., в очереди {r[3]} пак.) {mark}')
        for q in rows[max(0, i - ctx):i]:
            print(f'      −{r[0]-q[0]:8.3f} мс  {q[1]:<9} {q[2]:>9} {q[3]:>9} {q[4]:>9}')

    tx_s = span / 1000.0
    if tx_s > 0:
        print(f'\n★ПРОСТОЕВ ДЛИННЕЕ ПОДУШКИ: {n_over} '
              f'({n_over/tx_s:.2f} на секунду передачи)')


if __name__ == '__main__':
    sys.exit(main())