ewsdr/PerfLog.pas

unit PerfLog;

{ ===========================================================================
  PerfLog — лёгкий зонный CPU-профилировщик для поиска горячих точек.

  ВРЕМЕННЫЙ ОТЛАДОЧНЫЙ МОДУЛЬ (ветка perf/cpu-profiling) — не мержить в main.

  Использование в горячем коде:
      var t0: Int64;
      ...
      t0 := PerfNow;
      <работа>
      PerfAdd(pzDspFexMain, t0);

  Накладные расходы: два чтения монотонных часов + несколько сложений.
  Никаких строк/аллокаций/локов в горячем пути. Каждая зона пишется из
  одного потока (single-writer), поэтому обычные Int64-инкременты безопасны;
  репортер читает значения racy — для отладки это приемлемо.

  Отчёт раз в PERF_REPORT_SEC секунд в StdErr (и в файл, если задан
  EWSDR_PERF_FILE). Отключение: переменная окружения EWSDR_PERF=0.

  Колонки отчёта:
      calls  — вызовов за интервал
      c/s    — вызовов в секунду
      avg    — среднее время на вызов, мкс
      max    — максимум за интервал, мкс
      total  — суммарно за интервал, мс
      core%  — доля одного ядра CPU (total / интервал * 100)
  =========================================================================== }

{$mode objfpc}{$H+}

interface

type
  TPerfZone = (
    // Сетевой поток (приём UDP от радио)
    pzNetDDCIQ,        // HandleDDCIQ: разбор IQ-пакета + постановка в очередь
    pzNetWideband,     // HandleWidebandData: wideband-пакеты ADC

    // Pluto (libiio, свои RX/TX потоки — мимо HPSDRNetwork)
    pzPlutoRxConv,     // RX: конверсия iio-буфера int16→24bit BE + FOnDDCIQ
    pzPlutoTxResamp,   // TX: полифазный интерполятор 192k→device-rate + FIFO
    pzPlutoTxFill,     // TX: наполнение iio-буфера из FIFO (без блокирующего push)

    // DSP-поток (WDSPEngine)
    pzDspPushIQ,       // PushIQItemToDSP целиком (декод 24-бит + акк + всё ниже)
    pzDspSpectrum0,    // Spectrum0() — скармливание display-блока анализатору
    pzDspFexMain,      // fexchange0 главного RX-канала
    pzDspAudioCb,      // копирование аудио + FOnAudio (маршрут аудио)
    pzDspSlices,       // ProcessSlices целиком (все слайсы)
    pzDspSliceFex,     // fexchange0 одного слайс-канала
    pzDspTxBlock,      // ProcessTXBlock (TX-тракт)

    // Display-поток (WDSPEngine.UpdateSpectrum)
    pzDispGetPixels,   // GetPixels спектр+водопад из анализатора WDSP

    // Аудио-выход (PortAudio ring, из DSP-потока)
    pzAudioWrite,      // TAudioOutput.Write (все экземпляры: главный + слайсы)

    // UI-поток (главная форма, таймеры, отрисовка)
    pzUiSpectrumTick,  // SpectrumTimerTick целиком
    pzUiMeterTick,     // MeterTimerTick целиком
    pzUiDrawSpectrum,  // SpectrumView.DrawSpectrum (CPU или GL)
    pzUiDrawWaterfall, // SpectrumView.DrawWaterfall
    pzUiPaintSpectrum, // PaintSpectrum: блит битмапа на канву (Qt6!)
    pzUiPaintWaterfall,// PaintWaterfall: блит битмапа на канву (Qt6!)
    pzUiSliceFlags,    // обновление S-метров слайс-флагов (ре-рендер флага)
    pzUiVfoOverlay,    // обновление VFO-оверлея (S-метр/частота/позиция)
    pzUiWidebandPaint, // отрисовка wideband-панорамы
    pzUiWebPush,       // WebAdapter.PushState (зеркало состояния + кадры в web)

    // Разбивка CPU-рендера спектра (внутри ui.draw_spectrum)
    pzUiSpecGrid,      // ребилд кэша сетки + полный memcpy сетки в битмап
    pzUiSpecBands,     // полоса фильтра + слайс-маркеры + AGC-линии (BlendBand)
    pzUiSpecCurve,     // расчёт точек кривой + градиент под кривой + Polyline
    pzUiSpecOverlays,  // края/VFO/маркеры/бэндплан/флаги (DrawOverlay в битмап)
    pzUiSpecAlpha,     // финальный альфа-OR проход по всему битмапу
    pzUiGlSwap,        // SwapBuffers (GL) — включает ожидание vsync!
    pzUiComposites     // композиты бэндплан/панель/флаги (внутри raw-лока)
  );

const
  PERF_REPORT_SEC = 5;

  PerfZoneName: array[TPerfZone] of string = (
    'net.ddc_iq',
    'net.wideband',
    'pluto.rx_conv',
    'pluto.tx_resamp',
    'pluto.tx_fill',
    'dsp.push_iq',
    'dsp.spectrum0',
    'dsp.fex_main',
    'dsp.audio_cb',
    'dsp.slices',
    'dsp.slice_fex',
    'dsp.tx_block',
    'disp.get_pixels',
    'audio.write',
    'ui.spectrum_tick',
    'ui.meter_tick',
    'ui.draw_spectrum',
    'ui.draw_waterfall',
    'ui.paint_spectrum',
    'ui.paint_waterfall',
    'ui.slice_flags',
    'ui.vfo_overlay',
    'ui.wideband_paint',
    'ui.web_push',
    'ui.spec_grid',
    'ui.spec_bands',
    'ui.spec_curve',
    'ui.spec_overlays',
    'ui.spec_alpha',
    'ui.gl_swap',
    'ui.composites'
  );

var
  PerfEnabled: Boolean = True;

// Монотонные микросекунды.
function PerfNow: Int64;

// Прибавить (PerfNow - StartUs) к зоне. Вызывать в конце измеряемого участка.
procedure PerfAdd(Zone: TPerfZone; StartUs: Int64);

implementation

uses
  SysUtils, Classes
  {$IFDEF WINDOWS}, Windows{$ENDIF}
  {$IFDEF LINUX}, BaseUnix, Linux{$ENDIF}
  {$IF DEFINED(UNIX) AND NOT DEFINED(LINUX)}, BaseUnix, Unix{$ENDIF};

type
  TZoneAcc = record
    Count:   Int64;
    TotalUs: Int64;
    MaxUs:   Int64;
  end;

var
  Zones: array[TPerfZone] of TZoneAcc;

{$IFDEF WINDOWS}
var
  QPCFreq: Int64 = 0;

function PerfNow: Int64;
var C: Int64;
begin
  if QPCFreq = 0 then QueryPerformanceFrequency(QPCFreq);
  QueryPerformanceCounter(C);
  Result := (C * 1000000) div QPCFreq;
end;
{$ELSE}
{$IFDEF LINUX}
function PerfNow: Int64;
var ts: TTimeSpec;
begin
  clock_gettime(CLOCK_MONOTONIC, @ts);
  Result := Int64(ts.tv_sec) * 1000000 + ts.tv_nsec div 1000;
end;
{$ELSE}
function PerfNow: Int64;
var tv: TTimeVal;
begin
  fpGetTimeOfDay(@tv, nil);
  Result := Int64(tv.tv_sec) * 1000000 + tv.tv_usec;
end;
{$ENDIF}
{$ENDIF}

procedure PerfAdd(Zone: TPerfZone; StartUs: Int64);
var El: Int64;
begin
  if not PerfEnabled then Exit;
  El := PerfNow - StartUs;
  if El < 0 then El := 0;
  Inc(Zones[Zone].Count);
  Inc(Zones[Zone].TotalUs, El);
  if El > Zones[Zone].MaxUs then Zones[Zone].MaxUs := El;
end;

// ---------------------------------------------------------------------------
// Репортер
// ---------------------------------------------------------------------------

type
  TPerfReporter = class(TThread)
  private
    FFile:     TextFile;
    FFileOpen: Boolean;
    procedure Emit(const S: string);
    procedure Report(ElapsedUs: Int64);
  protected
    procedure Execute; override;
  public
    constructor Create;
  end;

var
  Reporter: TPerfReporter = nil;

constructor TPerfReporter.Create;
var FN: string;
begin
  FFileOpen := False;
  FN := GetEnvironmentVariable('EWSDR_PERF_FILE');
  if FN <> '' then
  begin
    AssignFile(FFile, FN);
    try
      Rewrite(FFile);
      FFileOpen := True;
    except
      FFileOpen := False;
    end;
  end;
  FreeOnTerminate := False;
  inherited Create(False);
end;

procedure TPerfReporter.Emit(const S: string);
begin
  try
    WriteLn(StdErr, S);
  except
  end;
  if FFileOpen then
  begin
    WriteLn(FFile, S);
    Flush(FFile);
  end;
end;

procedure TPerfReporter.Report(ElapsedUs: Int64);
var
  Z:    TPerfZone;
  Snap: array[TPerfZone] of TZoneAcc;
  Sec:  Double;
  Any:  Boolean;
begin
  // Снимок + сброс (racy, но для отладки достаточно).
  for Z := Low(TPerfZone) to High(TPerfZone) do
  begin
    Snap[Z] := Zones[Z];
    Zones[Z].Count   := 0;
    Zones[Z].TotalUs := 0;
    Zones[Z].MaxUs   := 0;
  end;

  Any := False;
  for Z := Low(TPerfZone) to High(TPerfZone) do
    if Snap[Z].Count > 0 then begin Any := True; Break; end;
  if not Any then Exit;

  Sec := ElapsedUs / 1000000.0;
  Emit(Format('[PERF] ===== interval %.2f s =====', [Sec]));
  Emit(Format('[PERF] %-18s %8s %8s %8s %8s %9s %6s',
       ['zone', 'calls', 'c/s', 'avg_us', 'max_us', 'total_ms', 'core%']));
  for Z := Low(TPerfZone) to High(TPerfZone) do
    if Snap[Z].Count > 0 then
      Emit(Format('[PERF] %-18s %8d %8.0f %8.1f %8d %9.1f %6.1f',
        [PerfZoneName[Z],
         Snap[Z].Count,
         Snap[Z].Count / Sec,
         Snap[Z].TotalUs / Snap[Z].Count,
         Snap[Z].MaxUs,
         Snap[Z].TotalUs / 1000.0,
         Snap[Z].TotalUs / ElapsedUs * 100.0]));
end;

procedure TPerfReporter.Execute;
var
  LastUs, NowUs: Int64;
  Waited: Integer;
begin
  LastUs := PerfNow;
  while not Terminated do
  begin
    // Спим мелкими шагами, чтобы быстро завершаться.
    Waited := 0;
    while (Waited < PERF_REPORT_SEC * 1000) and not Terminated do
    begin
      Sleep(100);
      Inc(Waited, 100);
    end;
    if Terminated then Break;
    NowUs := PerfNow;
    Report(NowUs - LastUs);
    LastUs := NowUs;
  end;
end;

initialization
  if GetEnvironmentVariable('EWSDR_PERF') = '0' then
    PerfEnabled := False;
  if PerfEnabled then
    Reporter := TPerfReporter.Create;

finalization
  if Reporter <> nil then
  begin
    Reporter.Terminate;
    Reporter.WaitFor;
    if Reporter.FFileOpen then
      CloseFile(Reporter.FFile);
    Reporter.Free;
  end;

end.