fix(tci): всплески на передаче — TX-аудио просилось общим тиком 20 мс

Посреди передачи из MSHV на водопаде появлялись всплески своего сигнала.
Цепочка: очередь DUC пустеет дольше подушки отправителя (DUC_FIFO_THROTTLE
= 2000 отсчётов = 10.4 мс) → FIFO радио сохнет → модуляция обрывается → в
эфире остаётся голая несущая на частоте гетеродина DUC, в стороне от тона
ровно на звуковой сдвиг. Доказано pcap-съёмом: шесть всплесков в дампе —
ровно столько, сколько видел оператор, и каждый стоит за паузой 10.3-23.5 мс,
а паузы 8 мс и короче не дали ни одного.

Виноват не клиент и не блокировка UI, а зернистость НАШЕГО запроса. Слой
первый: PushTxChrono жил на общем тике сервера 20 мс, а просил блок клиента
целиком (2048 отсчётов = 42.7 мс) — маркер выходил через два или три тика,
то есть через 40 или 60 мс. Слой второй: MSHV отвечает пачками по 4-5 блоков
раз в ~44 мс (STREAM_C = 4096 при 96 кГц), и мелкий квант этого не лечит —
нужен запас не меньше пачки.

Сделано:
* квант запроса = один блок TXA (512 отсчётов движка), а не блок клиента;
* свой поток-планировщик TxTickLoop с АБСОЛЮТНЫМИ дедлайнами (опоздание
  одного пробуждения не сдвигает сетку); общий тик маркеров больше не шлёт;
* бухгалтерия Owed/InFlight в кадрах на канал, гасится по k до интерполятора;
  потолок долга обязан быть выше окна в полёте (TCI_TX_OWED_HEADROOM_Q),
  иначе связывающим становится он и подача падает до 58% реального времени
  при полностью исправном клиенте;
* SendBinNow: маркеры пишутся в сокет напрямую под FWriteLock, минуя очередь
  (та выпускается лишь на пробуждении потока клиента, TCI_POLL_MS = 20 мс —
  вдвое больше кванта, и подача снова рвалась);
* FReapLock: планировщик TX — новый поток, а правило «клиента освобождает
  только тик-поток» держалось на том, что им же он и пользуется;
* аванс под зернистость клиента: измеряется по ПЕРИОДУ между пачками (размер
  пачки зависит от того, сколько мы запросили ⇒ положительная обратная связь),
  переживает конец передачи, умеет уменьшаться по выдержке TCI_TX_LEAD_DOWN_MS,
  потолок TCI_TX_LEAD_MAX_MS;
* старт передачи: KickTxTick будит планировщика на фронте PTT, TxPreWarm шлёт
  один маркер ДО SetMOX (41 мс раздумий клиента накладываются на нашу же
  подготовку тракта) под гейтом «передатчик свободен и чужого источника нет»,
  PrimeDUCIQ для источника TCI растянут до Max(6096, аванс×4) — путь микрофона
  радио, CW и web не затронут;
* посев аванса TCI_TX_LEAD_DEF_MS = 50 мс, пока про клиента ничего не известно:
  обучение к первому осушению физически не успевает.

Монотонные часы одного источника для всех потоков — PlatformUtils.MonotonicUs
(абсолютные дедлайны не терпят часов, способных прыгнуть от NTP).

На железе: опасных осушений посреди передачи НОЛЬ (было 12 за 11 с), четыре
передачи из пяти вообще без единого, включая старт; прогон 15:21 чист везде,
в том числе на первой передаче после подключения. Всплесков оператор больше
не видит.

Приборы: TxTrace.pas (EWSDR_TXTRACE=1) и стенд test/hpsdr — кольцевой tcpdump
capture.sh, разбор дампа pcap_tx_scan.py, разбор трассы txtrace_scan.py.
Стенд test/tci: часть F «Пейсинг TX», 260 проверок, провалов нет; живой клиент
с рампой, RTT и потерями — test/tci/tx_chrono_bench.py.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014gmVQnna1i4EbSZ2VGm6KD
This commit is contained in:
2026-08-23 22:06:10 +03:00
co-authored by Claude Opus 5
parent ced8581ada
commit d2096976df
15 changed files with 2796 additions and 39 deletions
+145
View File
@@ -0,0 +1,145 @@
# Разбор всплесков на передаче по трафику радио (openHPSDR, протокол 2)
Всплеск на передаче в этом тракте может родиться в трёх разных местах, и
глазами их не отличить. Дамп трафика отличает, потому что в проводе лежит
ровно то, что мы отдали радио, и ровно то, что радио вернуло:
| где родился | что видно в дампе |
|---|---|
| наш DSP / очередь TX | разрыв **внутри** DUC I&Q: скачок на стыке пакетов, клиппинг, дыра по времени |
| сеть / провод | потеря `seq` DUC I&Q (наружу) или DDC I&Q (внутрь), дубли, переупорядочение |
| радио / прошивка | DUC I&Q ушёл ровным, а радио жалуется: FIFO overflow, пустой DUC FIFO |
| приёмный тракт ПК | на проводе всё цело, но растут `RcvbufErrors`/`drops` — мусор на водопаде, а не в эфире |
Последняя строка важнее, чем кажется: **всплеск, увиденный на своём водопаде,
может вообще не уйти в эфир** — это может быть дыра в приёмном потоке DDC.
Инструмент это разделяет.
## 1. Съём
```
sudo test/hpsdr/capture.sh # bridge0, радио 172.16.2.200
sudo test/hpsdr/capture.sh -i eth0 -h 172.16.2.99 -d /var/tmp/cap
```
Пишется кольцо `-W 24 -C 150` (24 файла по 150 МБ ≈ 10-15 мин полного дуплекса)
плюс `*.drops` — счётчики потерь ядра раз в секунду.
Явление редкое, поэтому работаем так: запустили съём, работаем в эфире как
обычно. **Увидели всплеск — засекли время по часам и дали ещё секунд десять,
потом Ctrl-C.** Кольцо гарантирует, что последние минуты на диске, а засечённое
время сразу показывает, в какую строку отчёта смотреть.
Место: полный дуплекс на 192 кГц TX + пара DDC ≈ 3-6 МБ/с. Кольцо не растёт.
## 2. Разбор
```
test/hpsdr/pcap_tx_scan.py /tmp/hpsdrcap/hpsdr-*.pcap \
--watch-ddc 3 --drops /tmp/hpsdrcap/hpsdr-*.drops
```
**`--watch-ddc N` — главный ключ, если вы смотрите свой сигнал на конкретном
приёмнике** (DDC3 = UDP-порт 1038). Тогда скан ищет всплески прямо в приёмном
потоке и сопоставляет каждый с тем, что в этот момент ушло в эфир. Без ключа
всплески ищутся на всех DDC.
Прочие ключи: `--tx-only` (события только внутри передачи), `--radio IP` (если
автоопределение промахнулось), `--corr СЕК` (окно сопоставления, по умолчанию
0.05), `--max N`, `--env env.csv` (профиль огибающей по пакетам — можно
построить график и увидеть форму всплеска).
## 3. Как читать отчёт
**`=== передачи ===`** — по каждому нажатию PTT: сколько DUC-пакетов реально
ушло против расчётных `длительность / 1.25 мс`. Минус десятки пакетов = очередь
TX голодала, в эфире дыры. Тут же диапазон глубины DUC FIFO радио: здоровая
передача держит его далеко от нуля.
**`=== сопоставление ===`** — ради этого всё и делалось. По каждому всплеску,
найденному в приёмном потоке, печатается всё, что случилось в окне ±50 мс, со
смещением в миллисекундах, и вердикт. Смещение важно: свой сигнал возвращается
в приёмник с задержкой тракта (ЦАП, эфир, конвейер DDC), поэтому причина обязана
стоять с **минусом** — раньше всплеска. Вердикты: `НАШ ТРАКТ` (в DUC I&Q рядом
`BREAK`/`CLIP` — сигнал ушёл в провод уже испорченным), `АРТЕФАКТ ПРИЁМА` (дыра
в самом приёмном потоке или `SOCK-DROP` — в эфир всплеск не уходил), `РАДИО`,
`ПРОВОД`, `КОМАНДА НА ХОДУ`, `ЖЕЛЕЗО` (рядом чисто в обе стороны).
**`=== конфигурация DDC ===`** — из перехваченного DDC Specific: источник
каждого включённого DDC (`ADC0` = эфир, `DAC` = петля PureSignal) и его частота
дискретизации. Источник решает, что вообще означает увиденный всплеск: с ADC —
это сигнал в антенне, с DAC — только то, что ушло в модулятор.
**События, по убыванию доказательности:**
* `RX-SPIKE` — выброс над фоном в приёмном потоке. Ищется **только на передаче**:
там свой сигнал держит ровный уровень, и всё, что торчит над ним, — событие.
На приёме эфир скачет сам, детектор был бы бессмысленным. Первые 250 мс после
фронта PTT пропускаются: уровень там меняется законно.
* `BREAK` — последний отсчёт пакета N и первый отсчёт N+1 разошлись больше чем
на 45% огибающей. На 192 ksps соседние отсчёты речевого сигнала так не прыгают:
это разрыв фазы/амплитуды, то есть щелчок или всплеск шириной во весь фильтр.
Родился до провода, значит у нас — в WDSP, в сборке пакетов или в очереди.
(Ровно эта подпись однажды уже ловилась: `bfo=0` в `OpenChannel(TXA)`.)
Ищется только в исходящем DUC: на приёме шум эфира прыгает от отсчёта к
отсчёту сам по себе, а разрыв от потерянного пакета и так виден по `seq`.
* `CLIP` — упор в полную шкалу DAC, печатается по фронту с длительностью.
* `TX-STARVE` / `FIFO-OVF` — жалоба самого радио: DUC FIFO пуст на передаче
либо переполнение. При пустом FIFO радио передаёт что попало.
* `SOCK-DROP` — на проводе пакеты были, ядро их выбросило. Тогда всплеск на
экране — артефакт приёма, в эфир он не уходил.
* `HOLE` — пауза между пакетами больше 2.5 периодов потока. Для DUC норма
1.25 мс, для DDC период выучивается по медиане первых 200 интервалов.
* `SEQ-LOSS` / `SEQ-DUP` — потери и дубли в проводе, отдельно наружу и внутрь.
* `HP-CHG` — High Priority сменился ПОСРЕДИ передачи, с расшифровкой поля
(частота DDC/DUC, drive, Alex, атт., OC). Смена частоты или drive на ходу —
это клик по построению.
* `DUCSPEC` / `DDCSPEC` — Specific-пакеты, ушедшие на передаче.
**Пусто во всех разделах при засечённом всплеске** — значит трактовка меняется:
цифровой поток чист от нас до радио и обратно, ищем дальше по железу (PA, ALC,
питание, реле), а не в софте.
## Файлы
* `capture.sh` — кольцевой съём tcpdump + лог потерь ядра.
* `pcap_tx_scan.py` — разбор pcap, чистый Python без зависимостей (~40 МБ/с).
## Приборы внутри процесса: кольцевая трассировка TX-тракта
Дамп на проводе видит ПАУЗУ в потоке DUC, но не видит, кто её сделал. Для этого
в код вписано кольцо трассировки (`TxTrace.pas`), выключенное по умолчанию.
Включение — переменной окружения, кольцо сбрасывается на диск в конце КАЖДОЙ
передачи (после снятия PTT, чтобы файл не задержал выход из эфира):
EWSDR_TXTRACE=1 ./bin/x86_64-linux/ewsdr
# файлы: ~/.config/ewsdr/txtrace-<дата>-tx.txt
Разбор: `./txtrace_scan.py ~/.config/ewsdr/txtrace-*-tx.txt`
Что пишется (только выбросы там, где событий тысячи в секунду):
| событие | A | B | C |
|---|---|---|---|
| `PTT` | 1 старт / 0 конец | источник модуляции: 0 радио, 1 звуковая карта, 2 внешняя подача (web/TCI) | |
| `RECV-GAP` | пауза между возвратами `recvfrom` >2 мс | порт | |
| `HANDLER` | длительность обработчика >2 мс | порт | длина пакета |
| `HP-SYNC` | длительность `Invoke(ApplyHPStatus)` = `TThread.Synchronize` >2 мс | | |
| `TX-TICK` | зазор между тиками TX-потока | уровень mic-ринга НА ВХОДЕ тика | блоков сделано |
| `TX-PHASE` | `fexchange0` | кормление TX-анализатора (стоит ПЕРЕД отдачей IQ) | отдача IQ в очередь DUC |
| `CHRONO` | сколько отсчётов просим у клиента TCI | остаток долга | пауза от прошлого маркера |
| `TX-AUDIO` | пауза от прошлого блока от клиента | `length` из шапки клиента | отсчётов после интерполяции |
| `PULL-MIC` | запрошено у звуковой карты | реально получено | пауза от прошлой тяги |
| `DUC-DRY` | виртуальный уровень FIFO радио | глубина очереди | |
| `DUC-RUN` | длительность простоя очереди | уровень FIFO на выходе | глубина очереди |
Ключевые чтения:
* `DUC-RUN` длиннее 10.42 мс (подушка `DUC_FIFO_THROTTLE`) = кандидат на всплеск;
скрипт печатает историю событий перед каждым таким простоем;
* `TX-TICK` с `B` меньше 512 = продюсер не успел, тракт тут ни при чём;
* `TX-AUDIO` с периодом около 40-60 мс = зернистость запроса TCI (тик 20 мс
против блока 2048 отсчётов = 42.7 мс), а не сбой сети;
* пара (`B`, `C`) у `TX-AUDIO` проверяет учёт каналов: при стерео `length`
обязан быть вдвое больше моно-отсчётов до интерполяции.
+66
View File
@@ -0,0 +1,66 @@
#!/usr/bin/env bash
# Съём трафика радио openHPSDR для разбора всплесков на передаче.
#
# sudo test/hpsdr/capture.sh [-i bridge0] [-h 172.16.2.200] [-d /tmp/hpsdrcap]
#
# Пишет кольцевой буфер pcap (по умолчанию 24 x 150 МБ ~= 3.6 ГБ, это ~10-15 мин
# полного дуплекса) плюс лог счётчиков UDP-потерь ядра раз в секунду.
# Услышал/увидел всплеск — ЗАСЕКИ ВРЕМЯ и жми Ctrl-C: последние файлы кольца
# и есть нужный кусок.
set -euo pipefail
IFACE=bridge0
RADIO=172.16.2.200
OUTDIR=/tmp/hpsdrcap
FILES=24
SIZE=150
while getopts "i:h:d:n:s:" opt; do
case "$opt" in
i) IFACE=$OPTARG ;;
h) RADIO=$OPTARG ;;
d) OUTDIR=$OPTARG ;;
n) FILES=$OPTARG ;;
s) SIZE=$OPTARG ;;
*) echo "usage: $0 [-i iface] [-h radio_ip] [-d outdir] [-n ring_files] [-s mb_per_file]" >&2; exit 2 ;;
esac
done
if [ "$(id -u)" != 0 ]; then
echo "нужен root (tcpdump): sudo $0 ..." >&2
exit 1
fi
mkdir -p "$OUTDIR"
STAMP=$(date +%Y%m%d-%H%M%S)
echo "iface=$IFACE radio=$RADIO out=$OUTDIR/hpsdr-$STAMP-NNN.pcap ring=${FILES}x${SIZE}MB"
echo "старт: $(date -Ins)"
# Счётчики потерь ядра. Если растут — пакеты терялись НЕ на проводе, а в сокете
# приложения (мал rcvbuf / поток приёма не успевает), и в pcap всё будет чисто.
# drops=N в skmem — счётчик отброшенных ядром датаграмм этого сокета.
(
while :; do
printf '%s' "$(date +%s.%N)"
awk '/^Udp:/{getline; printf " InErrors=%s RcvbufErrors=%s", $4, $6; exit}' /proc/net/snmp
ss -uanm 2>/dev/null | awk '
/^(UNCONN|ESTAB)/ { port=$4; rq=$2; next }
/skmem:/ {
rb=0; d=0;
if (match($0, /rb[0-9]+/)) rb = substr($0, RSTART+2, RLENGTH-2);
if (match($0, /,d[0-9]+\)/)) d = substr($0, RSTART+2, RLENGTH-3);
if (rb+0 > 1000000) printf " sock=%s rq=%s drops=%s", port, rq, d;
}'
echo
sleep 1
done
) > "$OUTDIR/hpsdr-$STAMP.drops" &
DROPPID=$!
trap 'kill $DROPPID 2>/dev/null || true' EXIT
# Без exec: exec заменил бы процесс оболочки и trap EXIT не сработал бы,
# оставив сборщик .drops сиротой навсегда.
tcpdump -i "$IFACE" -s 0 -B 65536 -n --time-stamp-precision=nano \
-W "$FILES" -C "$SIZE" -w "$OUTDIR/hpsdr-$STAMP.pcap" \
"udp and host $RADIO"
+843
View File
@@ -0,0 +1,843 @@
#!/usr/bin/env python3
"""
Разбор pcap с трафиком радио openHPSDR (Ethernet Protocol 2) — поиск причины
всплесков на передаче.
test/hpsdr/pcap_tx_scan.py /tmp/hpsdrcap/hpsdr-*.pcap [--radio 172.16.2.200]
Что смотрим (по порядку доказательности):
* DUC I&Q (PC->1029, 240 пар 24 бит, 1.25 мс на пакет) — наш передаваемый
сигнал ровно в том виде, в каком он ушёл в провод:
- разрывы/дубли/сбросы seq;
- дыры по времени отправки (очередь опустела => FIFO радио голодает);
- СКАЧОК НА СТЫКЕ ПАКЕТОВ (последний отсчёт N против первого N+1) —
подпись разрыва фазы/амплитуды, того самого щелчка в эфире;
- упор в полную шкалу (клиппинг DAC).
* High Priority (PC->1027) — фронты PTT и ЛЮБОЕ изменение содержимого
(частота, drive, Alex, атт., OC) посреди передачи: это клик.
* DUC/DDC Specific (PC->1026 / PC->1025) — отправка посреди передачи.
* HP Status (радио->1025) — что говорит само радио: overflow-биты, глубина
DUC FIFO (0 = голод => разрыв в эфире), перегруз ADC, PWR fwd/rev.
* Mic (радио->1026) — дыры во входном потоке микрофона (голод продюсера).
* DDC I&Q (радио->1035+) — приёмный тракт: потери seq на приёме дают
мусор на водопаде, который легко принять за всплеск своего сигнала.
"""
import argparse
import cmath
import datetime
import math
import os
import re
import struct
import sys
from array import array
from collections import defaultdict
# --- порты openHPSDR P2 -----------------------------------------------------
P_COMMAND, P_DDC_SPEC, P_DUC_SPEC, P_HP_FROM_PC = 1024, 1025, 1026, 1027
P_HP_TO_PC, P_MIC, P_WIDEBAND = 1025, 1026, 1027
P_DDC_AUDIO, P_DUC_IQ, P_DDC0_IQ = 1028, 1029, 1035
DUC_PAIRS = 240
DUC_RATE = 192000.0
DUC_DT = DUC_PAIRS / DUC_RATE # 1.25 мс
# Подушка отправителя: DUC_FIFO_THROTTLE = 2000 отсчётов в HPSDRNetwork.pas,
# то есть поток отправки уходит вперёд реального времени не больше чем на
# 2000/192000 с. Пауза длиннее этого гарантированно осушает FIFO радио:
# ЦАП остаётся без данных, в эфире разрыв несущей.
DUC_CUSHION = 2000 / DUC_RATE # 10.4 мс
# Частоты в High Priority — ФАЗОВЫЕ СЛОВА, а не герцы: ewsdr шлёт их через
# FreqToPhaseWord (HPSDRNetwork.pas). Читать поле как Гц — получить сотни МГц.
DSP_CLOCK = 122880000.0
def phase_khz(b, o):
return struct.unpack('>I', b[o:o + 4])[0] * DSP_CLOCK / 4294967296.0 / 1000.0
FFT_N = 1024
_FFT_WIN = [0.5 - 0.5 * math.cos(2 * math.pi * i / FFT_N) for i in range(FFT_N)]
_FFT_REF = 8388608.0 * FFT_N / 2
def fft_inplace(a):
"""Радикс-2 по месту. Нужен свой: numpy в системе может не быть."""
n = len(a)
j = 0
for i in range(1, n):
b = n >> 1
while j & b:
j ^= b
b >>= 1
j |= b
if i < j:
a[i], a[j] = a[j], a[i]
ln = 2
while ln <= n:
w = cmath.exp(-2j * math.pi / ln)
h = ln >> 1
for i in range(0, n, ln):
wl = 1 + 0j
for k in range(h):
u = a[i + k]
v = a[i + k + h] * wl
a[i + k] = u + v
a[i + k + h] = u - v
wl *= w
ln <<= 1
return a
def spectrum_db(chunk):
"""Спектр кадра в dBFS, бин за бином.
Водопад показывает СПЕКТР, а не пик огибающей, и смотреть надо КАЖДЫЙ БИН
против его собственного фона. Медиана всех бинов (как считалось раньше)
ловит только широкополосную засветку во всю строку и слепа к главному
случаю: когда поток отсчётов прерывается, модуляция пропадает и в эфире
остаётся голая несущая на частоте гетеродина DUC — это один-два бина в
стороне от полезного тона, медиана их не замечает вовсе.
"""
a = [chunk[i] * _FFT_WIN[i] for i in range(FFT_N)]
return [20 * math.log10(max(abs(x), 1e-9) / _FFT_REF) for x in fft_inplace(a)]
def peak16(pl, o, end, n):
"""Пик |отсчёта| по старшим ДВУМ байтам 24-битных отсчётов, 0..32768.
По одному старшему байту считать нельзя: приёмные потоки живут на -40 dBFS,
там весь пакет квантуется в единицу и всплеск неотличим от фона. Собираем
16-битные слова через срезы bytearray и struct — всё на скорости C.
"""
buf = bytearray(n * 2)
buf[0::2] = pl[o:end:6]
buf[1::2] = pl[o + 1:end:6]
v = struct.unpack('>%dh' % n, buf)
return max(max(v), -min(v))
FS16 = 32768.0 # полная шкала в единицах peak16
def s24(b, o):
v = (b[o] << 16) | (b[o + 1] << 8) | b[o + 2]
return v - 0x1000000 if v & 0x800000 else v
def ip4(b):
return '%d.%d.%d.%d' % (b[0], b[1], b[2], b[3])
# --- чтение pcap ------------------------------------------------------------
def iter_pcap(path):
with open(path, 'rb') as f:
magic = f.read(4)
if magic == b'\x0a\x0d\x0d\x0a':
raise SystemExit('%s: это pcapng; снимайте tcpdump -w (классический pcap)' % path)
if magic == b'\xd4\xc3\xb2\xa1':
en, nano = '<', False
elif magic == b'\xa1\xb2\xc3\xd4':
en, nano = '>', False
elif magic == b'\x4d\x3c\xb2\xa1':
en, nano = '<', True
elif magic == b'\xa1\xb2\x3c\x4d':
en, nano = '>', True
else:
raise SystemExit('%s: не pcap (magic %s)' % (path, magic.hex()))
_, _, _, _, _, link = struct.unpack(en + 'HHiIII', f.read(20))
div = 1e9 if nano else 1e6
ph = struct.Struct(en + 'IIII')
while True:
h = f.read(16)
if len(h) < 16:
return
sec, frac, incl, _orig = ph.unpack(h)
data = f.read(incl)
if len(data) < incl:
return
rec = decode_link(link, data)
if rec:
yield (sec + frac / div,) + rec
def decode_link(link, d):
if link == 1: # Ethernet
if len(d) < 14:
return None
et = (d[12] << 8) | d[13]
off = 14
while et in (0x8100, 0x88A8) and len(d) >= off + 4:
et = (d[off + 2] << 8) | d[off + 3]
off += 4
elif link == 113: # LINUX_SLL
if len(d) < 16:
return None
et, off = (d[14] << 8) | d[15], 16
elif link == 276: # LINUX_SLL2
if len(d) < 20:
return None
et, off = (d[0] << 8) | d[1], 20
else:
return None
if et != 0x0800 or len(d) < off + 20:
return None
ihl = (d[off] & 0x0F) * 4
if d[off + 9] != 17: # не UDP
return None
if ((d[off + 6] << 8) | d[off + 7]) & 0x1FFF: # не первый фрагмент
return None
src, dst = ip4(d[off + 12:off + 16]), ip4(d[off + 16:off + 20])
u = off + ihl
if len(d) < u + 8:
return None
sport, dport, ulen = struct.unpack('>HHH', d[u:u + 6])
return (src, sport, dst, dport, d[u + 8:u + max(8, ulen)])
# --- потоки -----------------------------------------------------------------
class IQStream:
"""Общая часть для DUC (наш TX) и DDC (приём): seq, тайминг, огибающая."""
def __init__(self, name, hdr, pairs, dt=0.0):
self.name, self.hdr, self.pairs = name, hdr, pairs
self.dt = dt # 0 = период потока выучим по факту
self.gaps = []
self.n = self.lost = self.dup = 0
self.seq = None
self.ts = None
self.last = None # (I, Q) последнего отсчёта пакета
self.peak = 0 # оценка пика предыдущего пакета (0..128)
self.first_ts = self.last_ts = None
self.env = [] # (ts, peak) — профиль огибающей
self.clip = False # состояние «упёрлись в шкалу»
self.clip_from = None
self.clip_n = 0
self.brk = False # искать ли разрыв на стыке пакетов
self.watch = False # искать ли всплески в огибающей
self.ema = None # фон уровня, скользящее среднее
self.spike = False
self.quiet_until = 0.0 # после фронта PTT уровень скачет законно
self.pkmax = 0
self.holes = [] # (ts, длительность паузы)
def feed(self, ts, pl, ev, tx_on):
need = self.hdr + self.pairs * 6
if len(pl) < need:
return
seq = struct.unpack('>I', pl[0:4])[0]
self.n += 1
if self.first_ts is None:
self.first_ts = ts
self.last_ts = ts
if self.seq is not None:
d = (seq - self.seq) & 0xFFFFFFFF
if d != 1:
if d == 0 or d > 0x80000000:
self.dup += 1
ev(ts, 'SEQ-DUP', self.name, 'seq %u повтор/назад (было %u)' % (seq, self.seq))
else:
self.lost += d - 1
ev(ts, 'SEQ-LOSS', self.name,
'потеряно %d пакет(ов) (%u -> %u)' % (d - 1, self.seq, seq))
self.seq = seq
# Между передачами DUC-поток молчит по определению — паузу в несколько
# секунд нельзя считать голоданием очереди.
if self.brk and not tx_on:
self.ts = None
if self.ts is not None:
gap = ts - self.ts
if self.dt <= 0:
# период потока в протоколе не объявлен (зависит от sample rate
# DDC) — учим по медиане первых двух сотен интервалов.
self.gaps.append(gap)
if len(self.gaps) >= 200:
self.gaps.sort()
self.dt = self.gaps[len(self.gaps) // 2]
elif gap > self.dt * 2.5:
self.holes.append((ts, gap))
# Датируем НАЧАЛОМ паузы: FIFO радио сохнет через DUC_CUSHION
# после её начала, и всплеск в эфире идёт оттуда, а не от конца.
t_gap = ts - gap
if self.brk and gap > DUC_CUSHION:
ev(t_gap, 'UNDERRUN', self.name,
'очередь TX пуста %.2f мс — дольше подушки отправителя '
'%.1f мс, значит FIFO радио сохнет ~%.1f мс: модуляция '
'обрывается, в эфире остаётся голая несущая'
% (gap * 1e3, DUC_CUSHION * 1e3, (gap - DUC_CUSHION) * 1e3))
else:
ev(t_gap, 'HOLE', self.name,
'пауза %.2f мс между пакетами (норма %.2f мс)'
% (gap * 1e3, self.dt * 1e3))
self.ts = ts
i0, q0 = self.hdr, self.hdr + 3
pk = max(peak16(pl, i0, need, self.pairs), peak16(pl, q0, need, self.pairs))
self.env.append((ts, pk))
if pk > self.pkmax:
self.pkmax = pk
# Всплеск в приёме ищем ТОЛЬКО на передаче: там наш сигнал держит
# ровный уровень, и любой выброс над фоном — событие. На приёме эфир
# сам по себе скачет, детектор был бы бессмысленным.
if self.watch and tx_on and ts >= self.quiet_until:
if self.ema is None:
self.ema = float(pk)
else:
hot = (pk > 3.5 * self.ema) and (pk >= 64)
if hot and not self.spike:
self.spike = True
ev(ts, 'RX-SPIKE', self.name,
'ВСПЛЕСК В ПРИЁМЕ: %+.1f dBFS при фоне %+.1f (x%.1f)'
% (20 * math.log10(max(pk, 1) / FS16),
20 * math.log10(max(self.ema, 1) / FS16),
pk / max(self.ema, 0.5)))
elif not hot:
self.spike = False
self.ema += 0.02 * (pk - self.ema)
else:
self.ema, self.spike = None, False
cur_first = (s24(pl, i0), s24(pl, q0))
cur_last = (s24(pl, need - 6), s24(pl, need - 3))
# Разрыв на стыке ищем ТОЛЬКО в исходящем DUC. На приёме шум эфира сам
# по себе прыгает от отсчёта к отсчёту, а разрыв от потерянного пакета
# и так виден по seq — детектор там дал бы только ложные срабатывания.
if self.brk and tx_on and self.last is not None:
ref = max(self.peak, pk) * 256.0
if ref > 60000: # не тишина
jump = max(abs(cur_first[0] - self.last[0]), abs(cur_first[1] - self.last[1]))
if jump > 0.45 * ref:
ev(ts, 'BREAK', self.name,
'разрыв на стыке пакетов: скачок %.0f%% от огибающей '
'(|d|=%d, уровень=%.0f)' % (100.0 * jump / ref, jump, ref))
self.last, self.peak = cur_last, pk
if pk >= 32200:
if not self.clip:
self.clip, self.clip_from, self.clip_n = True, ts, 0
self.clip_n += 1
elif self.clip:
self.clip = False
ev(self.clip_from, 'CLIP', self.name,
'упор в полную шкалу: %d пакет(ов), %.2f мс'
% (self.clip_n, self.clip_n * (self.dt or DUC_DT) * 1e3))
def fmt_bytes_diff(a, b, skip=4):
out = []
for i in range(skip, min(len(a), len(b))):
if a[i] != b[i]:
out.append('%d:%02X->%02X' % (i, a[i], b[i]))
if len(out) >= 12:
out.append('...')
break
return ' '.join(out)
def hp_freqs(pl):
"""Частоты из HP-пакета: {'DUC': кГц, n: кГц по каждому ненулевому DDC}."""
out = {'DUC': phase_khz(pl, 329)}
for n in range(16):
f = phase_khz(pl, 9 + n * 4)
if f > 0:
out[n] = f
return out
HP_FIELD = {329: 'DUC0 freq', 330: 'DUC0 freq', 331: 'DUC0 freq', 332: 'DUC0 freq',
345: 'DUC0 drive', 1400: 'xvtr/audio', 1401: 'OC out', 1443: 'atten ADC0'}
def hp_note(a, b):
names = set()
for i in range(4, min(len(a), len(b))):
if a[i] != b[i]:
if 9 <= i <= 12:
names.add('DDC0 freq')
elif 13 <= i <= 328:
names.add('DDC%d freq' % ((i - 9) // 4))
elif 1432 <= i <= 1435:
names.add('Alex0')
else:
names.add(HP_FIELD.get(i, 'byte %d' % i))
return ', '.join(sorted(names))
def main():
ap = argparse.ArgumentParser(description=__doc__,
formatter_class=argparse.RawDescriptionHelpFormatter)
ap.add_argument('pcap', nargs='+')
ap.add_argument('--radio', help='IP радио (иначе определяется по потоку на 1029)')
ap.add_argument('--tx-only', action='store_true', help='события только внутри передачи')
ap.add_argument('--max', type=int, default=400, help='сколько событий печатать')
ap.add_argument('--env', help='выгрузить профиль огибающей в CSV')
ap.add_argument('--watch-ddc', type=int, default=None, metavar='N',
help='на каком DDC вы смотрите свой сигнал (по умолчанию все)')
ap.add_argument('--spectrum', action='store_true',
help='спектральный поиск всплесков на watch-DDC (как их видит '
'водопад). Медленно: ~3 с на секунду передачи')
ap.add_argument('--corr', type=float, default=0.05, metavar='СЕК',
help='окно сопоставления всплеска приёма с событиями TX (по умолч. 0.05)')
ap.add_argument('--drops', help='лог .drops от capture.sh — потери в сокете, а не на проводе')
args = ap.parse_args()
files = sorted(args.pcap, key=lambda p: (os.path.getmtime(p), p))
# Кольцо одного съёма — это hpsdr-СТАМП.pcapNN. Файлы от РАЗНЫХ съёмов
# склеивать нельзя: счётчики seq в каждом свои, разбор насчитает потери,
# которых не было.
runs = sorted(set(re.sub(r'\.pcap\d*$', '', os.path.basename(p)) for p in files))
if len(runs) > 1:
raise SystemExit('в списке файлы от разных съёмов (%s) — разбирайте по одному:\n'
' %s' % (', '.join(runs),
'\n '.join(os.path.join(os.path.dirname(files[0]),
r + '.pcap*') for r in runs)))
radio = args.radio
if not radio:
# PC всегда шлёт НА фиксированные порты 1024..1029; свой локальный порт
# у нас эфемерный, так что голосуем по адресату этих портов.
vote = defaultdict(int)
left = 20000
for p in files:
for _ts, _src, _sp, dst, dp, _pl in iter_pcap(p):
if P_COMMAND <= dp <= P_DUC_IQ:
vote[dst] += 1
left -= 1
if left <= 0:
break
if vote and left <= 0:
break
if vote:
radio = max(vote.items(), key=lambda kv: kv[1])[0]
if not radio:
raise SystemExit('не нашёл радио в дампе: укажите --radio')
events = []
tx_on = False
tx_sessions = [] # [ts_on, ts_off, duc_pkts, duc_lost]
cur_sess = None
def ev(ts, kind, stream, msg):
if args.tx_only and not tx_on:
return
events.append((ts, kind, stream, msg, tx_on))
duc = IQStream('DUC-IQ(TX)', 4, DUC_PAIRS, DUC_DT)
duc.brk = True
ddc = {}
audio = IQStream('DDC-AUDIO', 4, 0, 64 / 48000.0) # только счётчик seq
mic_seq = [None, 0, 0]
hp_prev = None
ducspec_prev = None
ddcspec_prev = None
st_prev = None
ddc_cfg = None
counts = defaultdict(int)
t0 = None
tlast = None
fifo_lo, fifo_hi = 1 << 30, 0
spec_buf, spec_t0 = [], None
spec_store = defaultdict(lambda: (array('f'), []))
onset = None
_edges = {}
def edge(key, cond):
"""True только на фронте: события радио иначе печатаются пачками."""
was = _edges.get(key, False)
_edges[key] = cond
return cond and not was
for path in files:
for ts, src, sp, dst, dp, pl in iter_pcap(path):
if t0 is None:
t0 = ts
tlast = ts
if len(pl) < 4:
continue
to_radio = (dst == radio)
key = (dp if to_radio else sp)
counts[('->' if to_radio else '<-', key)] += 1
if to_radio and dp == P_DUC_IQ:
duc.feed(ts, pl, ev, tx_on)
if cur_sess:
cur_sess[2] += 1
if onset is not None and len(pl) >= 1444:
if duc.env and duc.env[-1][1] == 0:
onset += 1 # ведущая цифровая тишина
else:
pk = max(max(abs(s24(pl, 4 + k * 6)),
abs(s24(pl, 7 + k * 6))) for k in range(240))
ramp = next((k for k in range(240)
if max(abs(s24(pl, 4 + k * 6)),
abs(s24(pl, 7 + k * 6))) > pk / 2), 0)
first = max(abs(s24(pl, 4)), abs(s24(pl, 7)))
if first > 0.05 * 8388608:
ev(ts, 'HARD-START', duc.name,
'передача начата СКАЧКОМ: после %.1f мс тишины первый '
'же отсчёт %+.1f dBFS, нарастание %d отсчёт(ов) — '
'мгновенное включение несущей, щелчок во всю полосу'
% (onset * DUC_DT * 1e3,
20 * math.log10(first / 8388608.0), ramp))
else:
ev(ts, 'SOFT-START', duc.name,
'старт плавный: %.1f мс тишины, нарастание %d отсчётов '
'(%.2f мс)' % (onset * DUC_DT * 1e3, ramp, ramp / 192.0))
onset = None
elif to_radio and dp == P_HP_FROM_PC and len(pl) >= 60:
ptt = bool(pl[4] & 0x1E)
if hp_prev is not None:
was = bool(hp_prev[4] & 0x1E)
if ptt != was:
tx_on = ptt
onset = 0 # считаем ведущую тишину передачи
duc.ts = None # первый пакет передачи паузой не считаем
duc.last = None
for _s in ddc.values():
_s.quiet_until = ts + 0.25 # уровень законно скачет
_s.ema = None
if ptt:
cur_sess = [ts, None, 0, duc.lost, hp_freqs(pl)]
events.append((ts, 'PTT', 'HP', 'ПЕРЕДАЧА (byte4=%02X)' % pl[4], True))
else:
if cur_sess:
cur_sess[1] = ts
cur_sess[3] = duc.lost - cur_sess[3]
tx_sessions.append(cur_sess)
cur_sess = None
events.append((ts, 'PTT', 'HP', 'приём (byte4=%02X)' % pl[4], False))
else:
f0, f1 = hp_freqs(hp_prev), hp_freqs(pl)
if f0 != f1:
ch = ['%s %.3f->%.3f' % ('DUC' if k == 'DUC' else 'DDC%d' % k,
f0.get(k, 0), f1[k])
for k in f1 if abs(f1[k] - f0.get(k, 0)) > 0.0005]
if ch:
events.append((ts, 'QSY', 'HP',
'смена частоты (кГц): %s' % ', '.join(ch),
tx_on))
if ptt and (ptt == was) and pl[4:] != hp_prev[4:]:
ev(ts, 'HP-CHG', 'HP',
'HP изменился ПОСРЕДИ ПЕРЕДАЧИ: %s | %s'
% (hp_note(hp_prev, pl), fmt_bytes_diff(hp_prev, pl)))
hp_prev = pl
elif to_radio and dp == P_DUC_SPEC and len(pl) >= 60:
if ducspec_prev is not None and pl[4:] != ducspec_prev[4:] and tx_on:
ev(ts, 'DUCSPEC', 'DUC-Spec',
'DUC Specific изменился на передаче: %s' % fmt_bytes_diff(ducspec_prev, pl))
elif tx_on:
ev(ts, 'DUCSPEC', 'DUC-Spec', 'повтор DUC Specific на передаче')
ducspec_prev = pl
elif to_radio and dp == P_DDC_SPEC and len(pl) > 60:
if ddc_cfg is None and len(pl) >= 497:
n_adc = pl[4]
ddc_cfg = {'nadc': n_adc, 'ddc': {}}
for n in range(80):
if not (pl[7 + n // 8] >> (n % 8)) & 1:
continue
o = 17 + n * 6
src_adc = pl[o]
ddc_cfg['ddc'][n] = (
'DAC (петля PureSignal)' if src_adc >= n_adc else 'ADC%d' % src_adc,
(pl[o + 1] << 8) | pl[o + 2], pl[o + 5])
if tx_on:
d = fmt_bytes_diff(ddcspec_prev, pl) if ddcspec_prev else '(первый)'
ev(ts, 'DDCSPEC', 'DDC-Spec',
'DDC Specific ушёл на передаче%s' % ((': ' + d) if d else ' (без изменений)'))
ddcspec_prev = pl
elif to_radio and dp == P_DDC_AUDIO:
seq = struct.unpack('>I', pl[0:4])[0]
if audio.seq is not None:
d = (seq - audio.seq) & 0xFFFFFFFF
if d != 1 and d < 0x80000000:
ev(ts, 'SEQ-LOSS', 'DDC-AUDIO', 'потеряно %d' % (d - 1))
audio.seq = seq
elif (not to_radio) and sp == P_HP_TO_PC and len(pl) >= 60:
duc_fifo = (pl[35] << 8) | pl[36]
if edge('ovf', pl[30] != 0):
ev(ts, 'FIFO-OVF', 'radio', 'радио: FIFO overflow биты=%02X' % pl[30])
if edge('adc', pl[5] != 0):
ev(ts, 'ADC-OVL', 'radio', 'радио: перегруз ADC биты=%02X' % pl[5])
if edge('starve', tx_on and duc_fifo == 0):
ev(ts, 'TX-STARVE', 'radio',
'радио: DUC FIFO пуст на передаче (голод => разрыв в эфире)')
fifo_lo = min(fifo_lo, duc_fifo) if tx_on else fifo_lo
fifo_hi = max(fifo_hi, duc_fifo) if tx_on else fifo_hi
if st_prev is not None:
if (pl[4] & 1) != (st_prev[4] & 1):
events.append((ts, 'PTT-HW', 'radio',
'радио сообщает PTT=%d' % (pl[4] & 1), tx_on))
if tx_on:
pf = (st_prev[35] << 8) | st_prev[36]
if pf and duc_fifo and abs(duc_fifo - pf) > 2000:
ev(ts, 'FIFO-JUMP', 'radio',
'DUC FIFO прыгнул %d -> %d' % (pf, duc_fifo))
st_prev = pl
elif (not to_radio) and sp == P_MIC and len(pl) >= 8:
seq = struct.unpack('>I', pl[0:4])[0]
if mic_seq[0] is not None:
d = (seq - mic_seq[0]) & 0xFFFFFFFF
if d != 1 and d < 0x80000000:
mic_seq[1] += d - 1
ev(ts, 'SEQ-LOSS', 'MIC', 'потеряно %d пакет(ов) микрофона' % (d - 1))
mic_seq[0] = seq
elif (not to_radio) and sp >= P_DDC0_IQ and sp < P_DDC0_IQ + 16 and len(pl) >= 16:
n = sp - P_DDC0_IQ
if args.spectrum and tx_on and (args.watch_ddc in (None, n)):
if spec_t0 is None:
spec_t0 = ts
npairs = (len(pl) - 16) // 6
for k in range(npairs):
o = 16 + k * 6
spec_buf.append(complex(s24(pl, o), s24(pl, o + 3)))
while len(spec_buf) >= FFT_N:
st = spec_store[n]
st[0].extend(spectrum_db(spec_buf[:FFT_N]))
st[1].append(spec_t0)
del spec_buf[:FFT_N]
spec_t0 = ts
s = ddc.get(n)
if s is None:
pairs = (len(pl) - 16) // 6
bits = (pl[12] << 8) | pl[13]
s = ddc[n] = IQStream('DDC%d-IQ(RX)' % n, 16, pairs)
s.bits = bits
s.watch = (args.watch_ddc is None or args.watch_ddc == n)
s.feed(ts, pl, ev, tx_on)
for n, (sp, tsl) in sorted(spec_store.items()):
nf = len(tsl)
if nf < 20:
continue
# Фон каждого бина — медиана по времени: устойчива к редким выбросам,
# то есть к тому самому, что мы ищем.
base = [0.0] * FFT_N
for i in range(FFT_N):
col = sorted(sp[k * FFT_N + i] for k in range(nf))
base[i] = col[nf // 2]
carr = max(range(FFT_N), key=lambda i: base[i])
st = ddc.get(n)
rate = (st.pairs / st.dt) if (st and st.dt > 0) else 0.0
hz = lambda i: (i if i < FFT_N // 2 else i - FFT_N) * rate / FFT_N
print('спектр DDC%d: кадров %d, несущая %+.0f Гц на %.1f dBFS'
% (n, nf, hz(carr), base[carr]))
hits = []
for k in range(nf):
o = k * FFT_N
for i in range(FFT_N):
if sp[o + i] - base[i] > 25:
hits.append((tsl[k], sp[o + i] - base[i], i, sp[o + i]))
break
grp = []
for h in hits:
if grp and h[0] - grp[-1][-1][0] < 0.08:
grp[-1].append(h)
else:
grp.append([h])
for g in grp:
t, d, bi, v = max(g, key=lambda x: x[1])
events.append((t, 'RX-SPLASH', 'DDC%d-IQ(RX)' % n,
'ВСПЛЕСК на водопаде: %+.0f Гц от центра, %.1f dBFS — '
'на %.0f dB выше фона этого бина%s'
% (hz(bi), v, d,
'' if abs(hz(bi) - hz(carr)) < rate / FFT_N * 1.5
else ' (несущая стоит на %+.0f Гц)' % hz(carr)), True))
if args.drops:
prev = {}
for line in open(args.drops):
f = line.split()
if not f:
continue
try:
ts = float(f[0])
except ValueError:
continue
cur = {}
for kv in f[1:]:
if '=' in kv:
k, v = kv.split('=', 1)
cur[k] = v
for k in ('InErrors', 'RcvbufErrors', 'drops'):
a, b = prev.get(k), cur.get(k)
if a is not None and b is not None and b.isdigit() and a.isdigit() and int(b) > int(a):
events.append((ts, 'SOCK-DROP', 'kernel',
'ядро отбросило датаграммы: %s %s -> %s '
'(на проводе они БЫЛИ, потерялись в сокете)' % (k, a, b), False))
prev = cur
if cur_sess:
cur_sess[1] = None
tx_sessions.append(cur_sess)
for st in [duc] + list(ddc.values()):
if st.clip:
events.append((st.clip_from, 'CLIP', st.name,
'упор в полную шкалу: %d пакет(ов) (до конца дампа)' % st.clip_n, True))
events.sort(key=lambda e: e[0])
# ---------------- отчёт ----------------
def clock(ts):
return datetime.datetime.fromtimestamp(ts).strftime('%H:%M:%S.%f')
print('радио: %s файлов: %d окно: %s .. %s'
% (radio, len(files), clock(t0) if t0 else '-',
clock(tlast) if tlast else '-'))
if ddc_cfg:
print('=== конфигурация DDC (из DDC Specific) ===')
for n, (srcname, rate, bits) in sorted(ddc_cfg['ddc'].items()):
mark = ' <-- смотрим тут' if (args.watch_ddc == n) else ''
print(' DDC%-2d источник %-22s %d ksps, %d бит%s' % (n, srcname, rate, bits, mark))
if args.watch_ddc is not None and args.watch_ddc not in ddc_cfg['ddc']:
print(' ВНИМАНИЕ: DDC%d в дампе не включён' % args.watch_ddc)
print()
print('=== потоки ===')
for (d, port), c in sorted(counts.items(), key=lambda kv: -kv[1]):
print(' %s :%-5d %9d пакетов' % (d, port, c))
print()
print('=== передачи ===')
if not tx_sessions:
print(' PTT в дампе не поднимался')
for i, (a, b, npk, lost, fr) in enumerate(tx_sessions, 1):
dur = (b - a) if b else float('nan')
exp = dur / DUC_DT if b else float('nan')
print(' #%d %s длит %.3f с DUC-пакетов %d из ~%.0f (%+.0f, потеряно на проводе %d)'
% (i, clock(a), dur, npk, exp, npk - exp, lost))
# Частоты берём НА ФРОНТЕ PTT: перед передачей бывает QSY, и снимок из
# начала дампа соврёт (DUP уводит приёмник на частоту передачи).
tx_khz = fr.get('DUC', 0)
ddcs = sorted(k for k in fr if k != 'DUC')
near = ['DDC%d %.3f (%+.0f Гц от TX)' % (k, fr[k], (fr[k] - tx_khz) * 1e3)
for k in ddcs if abs(fr[k] - tx_khz) < 96.0]
far = ['DDC%d %.3f' % (k, fr[k]) for k in ddcs
if abs(fr[k] - tx_khz) >= 96.0]
print(' TX %.3f кГц' % tx_khz)
print(' в полосе передачи: %s' % (', '.join(near) if near
else 'НИ ОДНОГО — всплеск в эфире увидеть нечем'))
if far:
print(' вне полосы (свидетелями быть не могут): %s' % ', '.join(far))
if duc.holes:
dry = [(t, g) for t, g in duc.holes if g > DUC_CUSHION]
txsec = sum((b - a) for a, b, _n, _l, _f in tx_sessions if b) or 1.0
print(' голодание очереди TX: пауз %d, из них осушающих FIFO %d, '
'суммарно сухо %.0f мс'
% (len(duc.holes), len(dry), sum(g - DUC_CUSHION for _t, g in dry) * 1e3))
# Главная цифра для сравнения прогонов: всплеск в эфире рождается ровно
# тогда, когда пауза длиннее подушки. Гнать её надо к нулю.
print(' ★ПАУЗ ДЛИННЕЕ ПОДУШКИ: %.3f на секунду передачи (%d за %.1f с)'
% (len(dry) / txsec, len(dry), txsec))
bins = [(2.5, 5), (5, 10), (10, 15), (15, 25), (25, 1e9)]
hist = []
for lo, hi in bins:
c = sum(1 for _t, g in duc.holes if lo <= g * 1e3 < hi)
if c:
hist.append('%g-%s мс: %d' % (lo, ('%g' % hi) if hi < 1e9 else '', c))
print(' длительности пауз — %s' % ', '.join(hist))
per = [duc.holes[i][0] - duc.holes[i - 1][0] for i in range(1, len(duc.holes))]
cl = sorted(x for x in per if x < 0.25)
if len(cl) >= 5:
med = cl[len(cl) // 2]
print(' пауз в пачках: %d, период внутри пачки %.1f мс (%.2f Гц) — '
'ищите в процессе периодику этой частоты'
% (len(cl), med * 1e3, 1.0 / med))
if fifo_hi:
if fifo_lo == fifo_hi:
print(' глубина DUC FIFO радио: всегда %d — поле статично, прошивка его '
'не заполняет, доверять нельзя' % fifo_hi)
else:
print(' глубина DUC FIFO радио на передаче: %d .. %d отсчётов' % (fifo_lo, fifo_hi))
print()
print('=== события (%d) ===' % len(events))
if not events:
print(' чисто: ни разрывов seq, ни дыр, ни скачков на стыках, ни жалоб радио')
order = {'HARD-START': 0, 'RX-SPLASH': 1, 'RX-SPIKE': 1, 'QSY': 12, 'SOFT-START': 13, 'BREAK': 1, 'UNDERRUN': 2, 'CLIP': 3, 'TX-STARVE': 4,
'FIFO-OVF': 5, 'SOCK-DROP': 6, 'HOLE': 7, 'SEQ-LOSS': 8, 'SEQ-DUP': 9,
'HP-CHG': 10}
for ts, kind, stream, msg, was_tx in events[:args.max]:
print(' %s %+8.3f %-10s %-12s %s%s'
% (clock(ts), ts - t0, kind, stream, msg, ' [TX]' if was_tx else ''))
if len(events) > args.max:
print(' ... ещё %d (см. --max)' % (len(events) - args.max))
spikes = [e for e in events if e[1] in ('RX-SPIKE', 'RX-SPLASH')]
if spikes:
print()
print('=== сопоставление: что происходило рядом с каждым всплеском ===')
print('(смещение в мс: минус = событие РАНЬШЕ всплеска. Наш сигнал возвращается')
print(' в приёмник с задержкой тракта, так что причина обязана быть раньше.)')
for sp_ts, _k, sp_stream, sp_msg, _t in spikes:
near = [e for e in events
if e[1] not in ('RX-SPIKE', 'RX-SPLASH') and abs(e[0] - sp_ts) <= args.corr]
print()
print(' %s (+%.3f) %s%s' % (clock(sp_ts), sp_ts - t0, sp_stream, sp_msg))
if not near:
print(' рядом (+-%.0f мс) в цифровом тракте ЧИСТО' % (args.corr * 1e3))
for ts, kind, stream, msg, _w in near:
print(' %+7.1f мс %-10s %-12s %s' % ((ts - sp_ts) * 1e3, kind, stream, msg))
kinds = set(k for _t2, k, _s, _m, _w in near)
own = set(k for _t2, k, st, _m, _w in near if st == sp_stream)
tx = set(k for _t2, k, st, _m, _w in near if st == duc.name)
if 'HARD-START' in tx:
v = ('НАШ ТРАКТ: передача начата скачком несущей без нарастания — '
'щелчок по построению')
elif {'BREAK', 'CLIP', 'UNDERRUN'} & tx:
v = ('НАШ ТРАКТ: сигнал ушёл в провод уже с разрывом — WDSP, сборка '
'пакетов или очередь TX')
elif own & {'SEQ-LOSS', 'SEQ-DUP', 'HOLE'} or 'SOCK-DROP' in kinds:
v = ('АРТЕФАКТ ПРИЁМА: дыра в самом потоке %s. В эфир этот всплеск '
'НЕ уходил, его видит только водопад' % sp_stream)
elif {'TX-STARVE', 'FIFO-OVF'} & kinds:
v = 'РАДИО: FIFO передатчика голодал или переполнился'
elif 'HOLE' in tx:
v = ('НАШ ТРАКТ: очередь TX голодала — пауза короче подушки, но рядом '
'со всплеском; смотрите её длительность')
elif {'SEQ-LOSS'} & kinds:
v = 'ПРОВОД: потери в сети на пути к радио'
elif 'HOLE' in kinds:
v = 'ПРОВОД: дыра во входящем потоке'
elif 'HP-CHG' in kinds:
v = 'КОМАНДА НА ХОДУ: High Priority сменился посреди передачи'
elif not near:
v = ('ЖЕЛЕЗО: цифровой поток рядом чист в обе стороны — искать в PA, '
'ALC, питании, реле, а не в софте')
else:
v = 'причина не классифицирована, смотреть список выше'
print(' => %s' % v)
print()
print('=== итог по типам ===')
tally = defaultdict(int)
for _ts, kind, stream, _m, _t in events:
tally[(kind, stream)] += 1
for (kind, stream), c in sorted(tally.items(), key=lambda kv: (order.get(kv[0][0], 9), -kv[1])):
print(' %-10s %-12s %d' % (kind, stream, c))
if args.env:
with open(args.env, 'w') as f:
f.write('t,stream,peak16\n')
for ts, pk in duc.env:
f.write('%.6f,DUC,%d\n' % (ts - t0, pk))
for n, s in sorted(ddc.items()):
for ts, pk in s.env:
f.write('%.6f,DDC%d,%d\n' % (ts - t0, n, pk))
print('\nпрофиль огибающей: %s' % args.env)
if __name__ == '__main__':
main()
+219
View File
@@ -0,0 +1,219 @@
#!/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())
+268
View File
@@ -1263,6 +1263,11 @@ type
слот в обоих. }
procedure SendClose;
procedure Pump(Ms: Integer);
{ ★То же, но с шагом сна в 1 мс. Обычный Pump спит по 10 мс, и для проверок
ПЕЙСИНГА он не годится вовсе: квант запроса — 10.7 мс, то есть клиент
отвечал бы раз в 10 мс и сам создавал бы те самые «длинные интервалы»,
которые тест ищет. }
procedure PumpFine(Ms: Integer);
function NextFrame(out Opcode: Byte; out Payload: TBytes): Boolean;
{ Ждать строку с подстрокой Needle не дольше Ms. }
function WaitText(const Needle: string; Ms: Integer): string;
@@ -1379,6 +1384,19 @@ begin
fpSend(FSock, @Frame[0], Length(Frame), 0);
end;
procedure TRawClient.PumpFine(Ms: Integer);
var
R: Integer;
Deadline: QWord;
begin
Deadline := GetTickCount64 + QWord(Ms);
repeat
R := fpRecv(FSock, @FIn[FLen], SizeOf(FIn) - FLen, MSG_DONTWAIT);
if R > 0 then Inc(FLen, R)
else Sleep(1);
until GetTickCount64 >= Deadline;
end;
procedure TRawClient.Pump(Ms: Integer);
var
R, Waited: Integer;
@@ -1889,6 +1907,255 @@ end;
RX-аудио и IQ с верными заголовками.
═══════════════════════════════════════════════════════════════════════════ }
{ ═══════════════════════════════════════════════════════════════════════════
F. Пейсинг TX: квант запроса, окно в полёте, потери ответов
═══════════════════════════════════════════════════════════════════════════ }
{ Обслуживает маркеры TX_CHRONO Ms миллисекунд, отвечая на каждый блоком
нужного размера. Skip первых N маркеров остаются БЕЗ ответа — это и есть
«замороженный кредит», ради которого всё затевалось: конвейер продолжает
отдавать звук, но медленнее реального времени, и сторож по одному лишь
молчанию клиента такого не видит. Возвращает число маркеров и раскладку
интервалов между ними. }
procedure ServeChrono(C: TRawClient; Ms, Skip: Integer;
out Markers, Answered, Quantum, LongGaps, MaxGapMs: Integer;
out MinReserve: Integer);
var
Deadline, Now_, Prev, Start: QWord;
Delivered, Reserve: Int64;
Op: Byte;
Pay: TBytes;
H, HA: TTCIStreamHeader;
Frames, i, Gap: Integer;
Blk: array[0..40000] of Byte;
Skipped: Integer;
begin
Markers := 0;
Answered := 0;
Quantum := 0;
LongGaps := 0;
MaxGapMs := 0;
Skipped := 0;
Prev := 0;
Delivered := 0;
MinReserve := 0;
Start := GetTickCount64;
Deadline := Start + QWord(Ms);
while GetTickCount64 < Deadline do
begin
C.PumpFine(1);
while C.NextFrame(Op, Pay) do
begin
if (Op <> $02) or (Length(Pay) < SizeOf(H)) then Continue;
Move(Pay[0], H, SizeOf(H));
if H.StreamType <> LongWord(Ord(tstTXChrono)) then Continue;
Now_ := GetTickCount64;
Inc(Markers);
if H.Channels = 0 then H.Channels := 1;
Frames := Integer(H.DataLength) div Integer(H.Channels);
Quantum := Frames;
if Prev > 0 then
begin
Gap := Integer(Now_ - Prev);
if Gap > MaxGapMs then MaxGapMs := Gap;
// Порог — полтора номинальных периода кванта (10.667 мс при 512/48к).
if Gap > 16 then Inc(LongGaps);
end;
Prev := Now_;
if Skipped < Skip then
begin
Inc(Skipped);
Continue; // кредит завис навсегда
end;
TCIFillHeader(HA, tstTXAudio, H.Receiver, H.SampleRate, tsyFloat32,
Frames, H.Channels);
Move(HA, Blk[0], SizeOf(HA));
for i := 0 to Frames * Integer(H.Channels) - 1 do
PSingle(@Blk[SizeOf(HA) + i * 4])^ := 0.1;
C.SendBinary(Blk[0], SizeOf(HA) + Frames * Integer(H.Channels) * 4);
Inc(Answered);
// ★Мера годности — не ровность интервалов, а НАКОПЛЕННЫЙ РЕЗЕРВ: подушка
// отправителя интегрирующая, и два подряд «почти в допуске» интервала
// сушат очередь не хуже одного грубого. Пачка маркеров сама по себе
// безвредна — она приносит звук ВПЕРЁД реального времени, и следующая за
// ней пауза оплачена этим запасом. Считаем в кадрах 48 кГц от начала
// фазы: сколько отдано минус сколько утекло по часам.
Inc(Delivered, Frames);
Reserve := Delivered -
Int64(GetTickCount64 - Start) * Int64(H.SampleRate) div 1000;
if Reserve < MinReserve then MinReserve := Reserve;
end;
end;
end;
procedure TestTxPacing;
const
PORT = 40099;
RATE = 48000;
TCI_TX_LEAD_MAX_MS_CHK = 120; // потолок аванса, копия TCI_TX_LEAD_MAX_MS
var
Ctrl: TRadioController;
Ad: TTCIAdapter;
Host: THost;
Cfg: TTCISettings;
C: TRawClient;
Markers, Answered, Quantum, LongGaps, MaxGapMs, MinReserve: Integer;
DbgOwed, DbgFlight: Double;
DbgWin, DbgQ, DbgLead, SeedLead: Integer;
begin
WriteLn('F. Пейсинг TX: квант запроса и потери ответов');
Host := THost.Create;
Ctrl := TRadioController.Create;
Ctrl.LocalAudioEnabled := False;
Ctrl.OnInvoke := Host.DoInvoke;
Ctrl.FSampleRate := RATE;
Ctrl.CreateEngines(RATE);
Ctrl.FWDSPReady := True; // движок не открываем: тракт тут не проверяется
C := nil;
Ad := nil;
try
Ad := TTCIAdapter.Create(Ctrl, nil);
Cfg.Enabled := True;
Cfg.Port := PORT;
Cfg.BindAddr := '127.0.0.1';
if not Ad.ApplySettings(Cfg) then
begin
Check('пейсинг: сервер поднялся', False);
Exit;
end;
C := TRawClient.Create;
if not C.Connect(PORT) then
begin
Check('пейсинг: клиент подключился', False);
Exit;
end;
C.WaitText('ready;', 2000);
// Клиент назвался ровно как MSHV: 48 кГц, два канала, блок 2048.
C.SendText('audio_samplerate:48000;');
C.SendText('audio_stream_channels:2;');
C.SendText('audio_stream_samples:2048;');
C.SendText('tx_stream_audio_buffering:50;');
// ★Без поднятого аудиопотока просьба «модулируй из TCI» отклоняется
// (§4.2, HasAudioStream): модулировать было бы нечем.
C.SendText('audio_start:0;');
C.Pump(200);
C.SendText('trx:0,true,tci;');
C.WaitText('trx:', 1500);
Check('пейсинг: модуляция из TCI взята', Ctrl.TCIMicActive);
// ── Здоровый клиент ──
// Прогрев: пока шёл разбор команды и проверки выше, клиент не отвечал, и
// окно в полёте успело набиться маркерами. Плюс за это время адаптер выдаёт
// разовый аванс под зернистость клиента — он тоже приходит пачкой. Меряем
// установившийся режим, а не этот стартовый ком, иначе в замер попадёт
// чужой долг: аванс отдан ДО окна замера, а расходуется уже внутри него.
ServeChrono(C, 1000, 0, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
ServeChrono(C, 900, 0, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
WriteLn(Format(' .. фаза 1: маркеров %d, квант %d ⇒ %d кадров/с, ' +
'просадка резерва %d кадров (%.1f мс), длинных интервалов %d, макс %d мс',
[Markers, Quantum, Round(Answered * Quantum / 0.9),
MinReserve, MinReserve / 48.0, LongGaps, MaxGapMs]));
Check('пейсинг: маркеры идут', Markers > 20, IntToStr(Markers));
// ★Главное число всей правки. Просить блок клиента целиком (2048 отсчётов =
// 42.7 мс) нельзя: подушка отправителя DUC — 10.42 мс, и на каждом запросе
// длиннее её очередь пересыхает. Квант обязан быть одним блоком TXA.
Check('пейсинг: квант = один блок TXA, а не блок клиента',
Quantum = 512, IntToStr(Quantum));
// ★Зернистость: раньше маркеры выходили через 40 или 60 мс (тик 20 мс не
// делится на 42.7), и каждый трёхтактный интервал давал осушение.
// Порог: подушка отправителя DUC (2000 отсчётов @192 кГц = 500 кадров
// @48 кГц) ПЛЮС аванс, который клиент попросил сам через
// TX_STREAM_AUDIO_BUFFERING (здесь 50 мс = 2400 кадров). Считать от нуля
// нельзя: этот аванс реально лежит в очереди и на то и дан. ★В эфире к нему
// добавляется ещё и нулевой pre-roll под зернистость клиента, но стенд
// работает без радио, и в нём этого слагаемого нет.
// Систематическую просадку порог не пропустит: она накапливается линейно и
// за 900 мс уходит далеко за любую константу.
Check('пейсинг: резерв не проседает ниже подушки DUC плюс аванс клиента',
MinReserve > -2900, Format('%d кадров (%.1f мс)',
[MinReserve, MinReserve / 48.0]));
// ── Посев аванса и его сползание ──
// ★Посев нужен потому, что первая передача после подключения физически не
// может знать зернистость клиента: аванс появляется только после первого
// ответа, а осушение случается раньше. Но посев обязан уметь сползать —
// иначе клиент с мелкой гранулой (как здесь: отвечает сразу) навсегда
// получит чужие 50 мс задержки.
Ad.TxDbgState(DbgOwed, DbgFlight, DbgWin, DbgQ, SeedLead);
Check('пейсинг: аванс посеян до первого ответа',
SeedLead >= 2000, IntToStr(SeedLead));
ServeChrono(C, 5200, 0, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
Ad.TxDbgState(DbgOwed, DbgFlight, DbgWin, DbgQ, DbgLead);
WriteLn(Format(' .. аванс: посев %d кадров (%.1f мс) → %d (%.1f мс), ' +
'худшая пауза клиента %d мс',
[SeedLead, SeedLead / 48.0, DbgLead, DbgLead / 48.0,
MaxGapMs]));
// ★Проверяем не «аванс уменьшился», а то, чем он обязан быть: запасом под
// САМУЮ ХУДШУЮ наблюдённую паузу клиента. Оценка нарочно несимметрична
// (вверх сразу, вниз по выдержке), поэтому редкий выброс её и держит — и
// это правильно: запас на то и нужен, чтобы такой выброс пережить. Стенд
// сам даёт выбросы под 60 мс (его клиент живёт в одном потоке с проверками),
// так что «сползание» здесь не наблюдаемо в принципе — оно проверяется
// конструкцией: путь снижения общий с путём роста, см. TCI_TX_LEAD_DOWN_MS.
Check('пейсинг: аванс покрывает худшую паузу клиента',
(DbgLead >= MaxGapMs * 48) and
(DbgLead <= (TCI_TX_LEAD_MAX_MS_CHK * 48)),
Format('%d кадров при худшей паузе %d мс', [DbgLead, MaxGapMs]));
// ── Замороженные кредиты: два ответа не приходят никогда ──
// Конвейер сужается, но продолжает работать — молчания клиента нет, и
// поймать это можно только по одновременному насыщению долга и окна.
ServeChrono(C, 1500, 2, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
Check('пейсинг: замороженные кредиты не остановили выдачу',
Markers > 40, IntToStr(Markers));
Check('пейсинг: после прощения кредита выдача вернулась к темпу',
MaxGapMs < 400, IntToStr(MaxGapMs));
// ── Полная защёлка: четыре ответа подряд пропали ──
ServeChrono(C, 800, 4, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
Ad.TxDbgState(DbgOwed, DbgFlight, DbgWin, DbgQ, DbgLead);
WriteLn(Format(' .. после потерь: долг %.0f, в полёте %.0f, окно %d кв., квант %d',
[DbgOwed, DbgFlight, DbgWin, DbgQ]));
// Потери позади. Даём сторожу время простить зависшие кредиты (по одному
// за выдержку), и лишь потом меряем: вернулась ли выдача к реальному темпу.
ServeChrono(C, 1500, 0, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
ServeChrono(C, 1000, 0, Markers, Answered, Quantum, LongGaps, MaxGapMs,
MinReserve);
WriteLn(Format(' .. фаза 3: после четырёх потерь маркеров %d, ' +
'просадка резерва %d кадров (%.1f мс)',
[Markers, MinReserve, MinReserve / 48.0]));
// Четыре потерянных ответа — это 43 мс звука, которых уже не будет: долг
// ограничен потолком, и «догонять» его пачкой мы намеренно не даём.
// Требование здесь одно: полной защёлки быть не должно — маркеры обязаны
// идти дальше, а не прекратиться до конца передачи.
// ★ОТКРЫТО: возврат к полному темпу после нескольких подряд потерянных
// ответов идёт медленно (прощение по одному кредиту за выдержку). В эфире
// это редкость (на живом MSHV — два неотвеченных маркера за 12 с), но
// строка ниже печатает просадку, чтобы регресс был виден.
WriteLn(Format(' .. фаза 3: возврат к темпу пока неполный — %d маркеров ' +
'из ~94/с, просадка %d кадров', [Markers, MinReserve]));
Check('пейсинг: защёлки нет, маркеры идут дальше',
Markers > 40, IntToStr(Markers));
C.SendText('trx:0,false;');
C.Pump(300);
finally
if C <> nil then C.Free;
if Ad <> nil then Ad.Free;
Ctrl.Free;
Host.Free;
end;
end;
procedure TestEndToEnd;
const
PORT = 40098;
@@ -2338,6 +2605,7 @@ begin
TestTextSender;
TestServer;
TestEndToEnd;
TestTxPacing;
WriteLn;
WriteLn(Format('Итого: %d проверок, провалено %d', [Passed + Failed, Failed]));
if Failed > 0 then Halt(1);
+329
View File
@@ -0,0 +1,329 @@
#!/usr/bin/env python3
"""Стенд подачи TX-аудио: проверяет планировщик TX_CHRONO под потерями и задержкой.
Зачем: всплески своего сигнала на передаче оказались не сбоем клиента и не
блокировкой UI, а зернистостью НАШЕГО запроса маркеры уходили через 40 или
60 мс при звуке на 42.7 мс в каждом, и на трёхтактном интервале очередь DUC
пересыхала. Здесь проверяется новый планировщик: квант в один блок TXA,
абсолютные дедлайны, бухгалтерия Owed/InFlight с прощением зависших кредитов.
Клиент отвечает на маркеры НУМЕРОВАННОЙ РАМПОЙ, а не тишиной: осушение очереди
не единственный способ испортить звук. Чтение неготовых данных, потерянный
или задвоенный кусок уходят в эфир молча, и видно их только сверкой с эталоном.
Период рампы простой и не связан с квантом (1021): будь он равен 512 или
кратен ему, потеря ровно одного кванта дала бы последовательность, неотличимую
от правильной тест прошёл бы при том самом дефекте, который ищет.
Сверка содержимого по сырому отводу приложения (моно-кадры ДО интерполятора):
EWSDR_TXAUDIO_DUMP=/tmp/txaudio.f32 ./bin/x86_64-linux/ewsdr
Сценарии (--scenario):
clean здоровый клиент, ответ сразу
rtt ответ с задержкой (--rtt-ms), окно обязано вырасти без прощений
drop потерять N ответов вразнобой (--drops), система обязана нагнать
freeze заморозить N слотов навсегда, остальные обслуживать: конвейер
продолжает отдавать звук медленнее реального времени ровно тот
случай, который сторож по одному лишь молчанию не ловит
latch потерять четыре ответа подряд: выход из полной защёлки
Запуск (приложение работает, TCI-сервер поднят, передатчик не в эфире):
test/tci/tx_chrono_bench.py --scenario freeze --freeze 2 --rtt-ms 30
"""
import argparse
import math
import os
import struct
import sys
import time
sys.path.insert(0, os.path.dirname(os.path.abspath(__file__)))
from live_rx_test import WS, split_commands, parse_command # noqa: E402
HDR = struct.Struct("<16I")
ST_TX_AUDIO = 3
ST_TX_CHRONO = 4
RAMP_PERIOD = 1021 # простое, взаимно простое с квантом 512
RAMP_AMPL = 0.25 # ★внутри ±1: дальше по тракту ScaleIQ24 зажимает
SYNC = [0.9, -0.9, 0.8, -0.8, 0.7, -0.7] # уникальная синхропоследовательность
def ramp_value(index):
return RAMP_AMPL * ((index % RAMP_PERIOD) / RAMP_PERIOD * 2.0 - 1.0)
class Bench:
def __init__(self, ws, rx, args):
self.ws = ws
self.rx = str(rx)
self.args = args
self.vfo_hz = None
self.markers = [] # (время, запрошено кадров)
self.answers = [] # (время, отдано кадров)
self.sent_index = 0 # позиция в эталонном сигнале
self.sync_done = False
self.pending = [] # отложенные ответы: (когда_слать, кадров)
self.dropped = 0
self.frozen = 0
self.chan = 2
self.rate = 48000
self.fmt = 3
self.failures = []
self.notes = []
# ── транспорт ────────────────────────────────────────────────────────
def pump(self, seconds):
deadline = time.monotonic() + seconds
while True:
now = time.monotonic()
self.flush_pending(now)
if now >= deadline:
return
frame = self.ws.recv_frame(min(0.005, max(0.0, deadline - now)))
if frame is None:
continue
opcode, payload = frame
if opcode == 1:
for command in split_commands(payload.decode("utf-8", "replace")):
self.on_text(command)
elif opcode == 2:
self.on_binary(payload)
def on_text(self, command):
name, args = parse_command(command)
if name == "vfo" and len(args) >= 3 and args[0] == self.rx and args[1] == "0":
try:
self.vfo_hz = int(args[2])
except ValueError:
pass
# ── ядро: ответ на маркер ────────────────────────────────────────────
def on_binary(self, payload):
if len(payload) < HDR.size:
return
head = HDR.unpack(payload[:HDR.size])
receiver, rate, fmt, _codec, _crc, length, stype, chan = head[:8]
if stype != ST_TX_CHRONO or receiver != int(self.rx):
return
self.rate, self.fmt, self.chan = rate, fmt, max(1, chan)
frames = length // self.chan # length — значения всего блока
self.markers.append((time.monotonic(), frames))
n = len(self.markers)
if self.args.scenario == "drop" and n in self.args.drop_set:
self.dropped += 1
return
if self.args.scenario == "latch" and self.args.latch_at <= n < self.args.latch_at + 4:
self.dropped += 1
return
if self.args.scenario == "freeze" and self.frozen < self.args.freeze:
self.frozen += 1
return # слот зависает навсегда
due = time.monotonic() + self.args.rtt_ms / 1000.0
self.pending.append((due, frames))
def flush_pending(self, now):
while self.pending and self.pending[0][0] <= now:
_due, frames = self.pending.pop(0)
self.send_audio(frames)
def send_audio(self, frames):
values = []
for _ in range(frames):
if not self.sync_done and self.sent_index < len(SYNC):
v = SYNC[self.sent_index]
else:
v = ramp_value(self.sent_index - len(SYNC))
self.sent_index += 1
if self.sent_index >= len(SYNC):
self.sync_done = True
# ★При двух каналах MSHV шлёт СОСЕДНИЕ отсчёты своего буфера 96 кГц,
# а приёмная сторона усредняет пару — это децимация, не стерео.
# Повторяем это же: два одинаковых значения на кадр дают после
# усреднения ровно его.
values.extend([v] * self.chan)
body = struct.pack(f"<{len(values)}f", *values)
head = [0] * 16
head[0] = int(self.rx)
head[1] = self.rate
head[2] = self.fmt
head[5] = len(values)
head[6] = ST_TX_AUDIO
head[7] = self.chan
self.ws.send_frame(2, HDR.pack(*head) + body)
self.answers.append((time.monotonic(), frames))
# ── сценарий ─────────────────────────────────────────────────────────
def run(self):
for _ in range(5):
self.ws.send_text(f"vfo:{self.rx},0;")
self.pump(0.4)
if self.vfo_hz is not None:
break
if self.vfo_hz is None:
self.failures.append("сервер не ответил vfo — приёмника нет")
return
self.ws.send_text("audio_samplerate:48000;")
self.ws.send_text("audio_stream_sample_type:float32;")
self.ws.send_text(f"audio_stream_channels:{self.args.channels};")
self.ws.send_text(f"audio_stream_samples:{self.args.block};")
self.ws.send_text("tx_stream_audio_buffering:50;")
self.pump(0.3)
self.ws.send_text(f"trx:{self.rx},true,tci;")
self.pump(self.args.seconds)
self.ws.send_text(f"trx:{self.rx},false;")
self.pump(0.5)
# ── разбор ───────────────────────────────────────────────────────────
def report(self):
print(f"\n=== сценарий {self.args.scenario}, RTT {self.args.rtt_ms} мс, "
f"каналов {self.args.channels}, блок клиента {self.args.block}")
if not self.markers:
self.failures.append("маркеров TX_CHRONO не пришло вовсе")
return
quanta = sorted({m[1] for m in self.markers})
periods = [1000.0 * (b[0] - a[0])
for a, b in zip(self.markers, self.markers[1:])]
periods.sort()
q = self.markers[0][1]
nominal = 1000.0 * q / self.rate
span = self.markers[-1][0] - self.markers[0][0]
asked = sum(m[1] for m in self.markers)
given = sum(a[1] for a in self.answers)
print(f" квант: {quanta} кадров (номинальный период {nominal:.2f} мс)")
print(f" маркеров {len(self.markers)} за {span:.2f} с, "
f"ответов {len(self.answers)}, потеряно намеренно "
f"{self.dropped + self.frozen}")
if periods:
print(f" период маркеров: медиана {periods[len(periods)//2]:.2f} "
f"макс {periods[-1]:.2f} мс")
print(f" запрошено {asked} кадров, отдано {given} "
f"({given / max(span, 1e-9):.0f} кадров/с при номинале {self.rate})")
# 1. Зернистость: систематических 2P/3P быть не должно.
if periods:
long_share = sum(1 for p in periods if p > 1.6 * nominal) / len(periods)
if long_share > 0.10:
self.failures.append(
f"{100*long_share:.0f}% интервалов маркеров длиннее 1.6 периода "
f"— зернистость запроса осталась")
else:
print(f" ok доля длинных интервалов {100*long_share:.1f}%")
# 2. Темп подачи: после любых потерь система обязана нагнать.
if span > 2.0:
rate_got = given / span
if rate_got < 0.97 * self.rate:
self.failures.append(
f"подача {rate_got:.0f} кадров/с ниже номинала {self.rate} "
f"— планировщик не нагнал потери")
else:
print(f" ok темп подачи {rate_got:.0f} кадров/с")
# 3. Защёлка: маркеры не должны прекратиться до конца сценария.
gap = self.markers[-1][0]
last_gap = 1000.0 * (self.answers[-1][0] - self.markers[-1][0]) if self.answers else 0
tail = span - (self.markers[-1][0] - self.markers[0][0])
if periods and periods[-1] > 20 * nominal:
self.failures.append(
f"пауза в выдаче маркеров {periods[-1]:.0f} мс "
f"— похоже на защёлку по InFlight")
_ = gap, last_gap, tail
def verify_audio(self, path):
if not path or not os.path.exists(path):
self.notes.append(f"отвод содержимого не включён (нет {path}) — "
f"проверены только темп и зернистость")
return
import array
data = array.array("f")
with open(path, "rb") as fh:
raw = fh.read()
data.frombytes(raw[:len(raw) - len(raw) % 4])
got = list(data)
if len(got) < len(SYNC) + 100:
self.failures.append(f"в отводе всего {len(got)} отсчётов")
return
# ★Выравнивание — по ВСЕЙ синхропоследовательности и ОДИН раз.
# По первому ненулевому отсчёту нельзя: так замаскируется ровно то,
# что ищем — потерянный или лишний начальный участок.
offset = -1
for i in range(0, len(got) - len(SYNC)):
if all(abs(got[i + j] - SYNC[j]) < 0.02 for j in range(len(SYNC))):
offset = i + len(SYNC)
break
if offset < 0:
self.failures.append("синхропоследовательность в отводе не найдена")
return
zeros = sum(1 for v in got[:offset - len(SYNC)] if abs(v) < 1e-6)
print(f" синхронизация на позиции {offset - len(SYNC)}, "
f"перед ней {zeros} нулевых отсчётов")
bad = 0
first_bad = None
n = min(len(got) - offset, self.sent_index - len(SYNC))
for i in range(n):
if abs(got[offset + i] - ramp_value(i)) > 0.02:
bad += 1
if first_bad is None:
first_bad = i
if bad:
self.failures.append(
f"содержимое разошлось с эталоном на {bad} из {n} отсчётов, "
f"первое расхождение на {first_bad} — вставка, пропуск или "
f"чтение неготовых данных")
else:
print(f" ok содержимое совпало с эталоном на {n} отсчётах")
def main():
ap = argparse.ArgumentParser(description=__doc__,
formatter_class=argparse.RawDescriptionHelpFormatter)
ap.add_argument("--host", default="127.0.0.1")
ap.add_argument("--port", type=int, default=40001)
ap.add_argument("--rx", type=int, default=0)
ap.add_argument("--seconds", type=float, default=10.0)
ap.add_argument("--scenario", default="clean",
choices=["clean", "rtt", "drop", "freeze", "latch"])
ap.add_argument("--rtt-ms", type=float, default=0.0)
ap.add_argument("--drops", default="20,55,90")
ap.add_argument("--freeze", type=int, default=2)
ap.add_argument("--latch-at", type=int, default=40)
ap.add_argument("--channels", type=int, default=2, choices=[1, 2])
ap.add_argument("--block", type=int, default=2048)
ap.add_argument("--audio-dump", default="",
help="файл EWSDR_TXAUDIO_DUMP для сверки содержимого")
args = ap.parse_args()
args.drop_set = {int(x) for x in args.drops.split(",") if x.strip()}
if args.scenario == "rtt" and args.rtt_ms == 0:
args.rtt_ms = 30.0
ws = WS(args.host, args.port)
ws.connect()
bench = Bench(ws, args.rx, args)
try:
bench.run()
finally:
ws.close()
bench.report()
bench.verify_audio(args.audio_dump)
for note in bench.notes:
print(f" .. {note}")
if bench.failures:
print("\nПРОВАЛЕНО:")
for f in bench.failures:
print(f" FAIL {f}")
return 1
print("\nвсё сошлось")
return 0
if __name__ == "__main__":
sys.exit(main())