Profilowanie kodu PHP

OxPHP dostarcza wbudowany profiler działający dla każdego żądania. W odróżnieniu od xdebug czy samodzielnych rozszerzeń, działa on wewnątrz samego serwera, nie wymaga restartu PHP i nie wprowadza znaczącego narzutu, gdy jest wyłączony (gałąź mode=Off kończy działanie, zanim w ogóle dotknie cache'u filtrów).

To praktyczny przewodnik: od zerowej konfiguracji po tropienie wolnych endpointów produkcyjnych, czytanie flamegraphów i porównywanie przebiegów przed optymalizacją i po niej.

Szybki start: pierwszy profil w 60 sekund

compose.yml
services: app: image: ghcr.io/oxphp/oxphp:0.10.0 environment: INTERNAL_ADDR: 0.0.0.0:9090 PROFILER_ENABLED: "true" PROFILER_AUTH_TOKEN: "dev-secret" PROFILER_OUTPUT_FORMATS: "xhprof,speedscope,collapsed" volumes: - ./www:/var/www/html - profiles:/tmp/oxphp-profiles ports: - "80:80" - "9090:9090" volumes: profiles:
bash
# 1. Request a page with the profiling trigger. curl -H "X-OxPHP-Profile: dev-secret" http://localhost/slow-endpoint # 2. List captured runs. curl -H "Authorization: Bearer dev-secret" http://localhost:9090/__profiler/runs \ | jq '.runs[0]' # 3. Open the profile in speedscope (in-browser flamegraph). open "http://localhost:9090/__profiler/runs/<run_id>/speedscope"

To wszystko. Reszta przewodnika wyjaśnia, co dzieje się naprawdę i jak przekuć to w wiedzę przydatną na produkcji.

Co robi profiler

  • Przechwytuje każde wywołanie funkcji PHP przez Zend Observer API — bez łatania bytecode'u, bez zmian w kodzie aplikacji.
  • Buduje drzewo spanów z czasem zegarowym, czasem CPU, pamięcią przy wejściu/wyjściu, atrybutami i zdarzeniami.
  • Eksportuje cztery formaty jednocześnie: xhprof.json, speedscope.json, pprof (protobuf + gzip), collapsed (dla flamegraph.pl).
  • Utrwala przebiegi: cache LRU w pamięci + pliki na dysku + opcjonalny push HTTP (xhgui lub dowolny własny kolektor).
  • Udostępnia 8 wewnętrznych tras HTTP pod INTERNAL_ADDR do przeglądania i pobierania profili.
  • Emituje metryki Prometheusa — przebiegi wg źródła, zebrane spany, zapisane bajty, odrzucenia, nieudane pushe.
  • Bez restartu — aktywowany dla pojedynczego żądania przez wyzwalacz.

Jak to działa

graph TD
  R["Request"]
  R --> S1["Tokio thread: ProfilerRequestHandler inspects the trigger<br/>(header / cookie / query / sample_rate), constant-time compare"]
  S1 --> S2["Decision written into PluginRequestActions,<br/>forwarded to the worker via the SAPI channel"]
  S2 --> S3["Before RINIT the worker sets ProfilingMode = ProfileAll<br/>and registers Observer handlers on begin/end of every function"]
  S3 --> S4["Each PHP function call → C hook → bridge buffer → Rust SpanTree<br/>(span_id = monotonic BE counter; names interned in a<br/>thread-local interner, no extra allocations)"]
  S4 --> S5["After the response: ProfilerCompleteHandler receives Arc&lt;SpanTree&gt;,<br/>runs 4 exporters, puts it in the LRU cache, spawns disk-write<br/>and HTTP-push tasks (semaphores bound the fan-out)"]

Trzy tryby na poziomie żądania

Tryb Kiedy Co jest przechwytywane
Off Domyślnie. Żaden plugin nie zażądał profilowania. Nic. Zerowy narzut.
ApmOnly plugin-apm jest włączony, ale żaden wyzwalacz profilera nie zadziałał. Tylko jawne haki APM: #[Trace], emitery PDO/cURL, oxphp_trace_*().
ProfileAll Zadziałał wyzwalacz profilera (lub wywołano OxPHP\Profile\start()). Każde wywołanie funkcji PHP przez Observer API plus wszystko, co zbiera APM.

ProfileAll ma pierwszeństwo przed ApmOnly: gdy oba pluginy są włączone i wyzwalacz zadziała, używane jest jedno współdzielone Arc<SpanTree> — bez podwójnego zbierania.

Instalacja i budowanie

Plugin plugin-profiler jest częścią domyślnych funkcji cargo. Standardowe docker compose build już go zawiera.

Aby go wyłączyć:

Dockerfile
ARG OXPHP_WITH_PROFILER=0 # or ARG CARGO_FEATURES="plugin-apm,plugin-otel" # no plugin-profiler

Aby sprawdzić, że plugin został wkompilowany:

bash
docker compose exec app cat /proc/self/maps | grep -i profiler # or: oxphp --list-plugins (if the command is available)

Wyzwalacze aktywacji

Wyzwalacze są sprawdzane w następującej kolejności priorytetu: header → cookie → query → sample_rate. Każde dopasowanie aktywuje ProfileAll. Tokeny są porównywane w stałym czasie (subtle::ConstantTimeEq).

Do programowania i skryptów.

bash
curl -H "X-OxPHP-Profile: dev-secret" https://app.local/checkout

Idealny do benchmarków CI, kolekcji Postmana, skryptów curl.

Wykluczanie ścieżek z próbkowania

PROFILER_SAMPLE_RATE próbkuje losowy ułamek wszystkich żądań — w tym własny ruch frameworka, który zaśmieca dane. Pasek debugowania Symfony odpytuje /_wdt/{token} i linkuje do /_profiler/{token}; Laravel Debugbar i Telescope zachowują się podobnie. Trzymaj je poza próbkowaniem za pomocą PROFILER_EXCLUDE_PATHS:

bash
PROFILER_EXCLUDE_PATHS=/_profiler,/_profiler/**,/_wdt/**

Wzorce glob rozdzielone przecinkami, ta sama składnia co PHP_DENY_PATHS: * nie przechodzi przez /, ** przechodzi, a wiodący / jest opcjonalny. Wzorzec dopasowuje samą ścieżkę lub jej poddrzewo tylko wtedy, gdy wymienisz oba — /_profiler/** obejmuje /_profiler/x, ale nie samo /_profiler, stąd powyższy przepis z dwoma wzorcami. Wzorce są dopasowywane do ścieżki żądania w postaci, w jakiej dotarła — bez percent-dekodowania i bez normalizacji .. — więc wymieniaj dosłowną ścieżkę, jakiej używa twój framework.

Wykluczanie dotyczy tylko automatycznego próbkowania

Żądanie niosące jawny wyzwalacz — nagłówek x-oxphp-profile, cookie OXPROF lub parametr zapytania __oxprof — jest zawsze profilowane, nawet na wykluczonej ścieżce. Pozwala to celowo profilować samo /_profiler, trzymając je jednocześnie poza próbkowaniem w tle.

Dokumentacja konfiguracji

Zmienna Domyślnie Opis
PROFILER_ENABLED false Główny przełącznik. true → plugin jest ładowany.
PROFILER_AUTH_TOKEN (nieustawione) Sekret dla wyzwalaczy oraz token bearer dla tras /__profiler/*. Pusty ciąg = „token niewymagany" (przechodzi dowolna niepusta wartość wyzwalacza). Nigdy nie commituj tokena do repozytorium.
PROFILER_SAMPLE_RATE 0.0 [0.0; 1.0]. Częstotliwość losowego próbkowania.
PROFILER_EXCLUDE_PATHS (nieustawione) Wzorce glob CSV (składnia PHP_DENY_PATHS) wykluczone z PROFILER_SAMPLE_RATE. Jawne wyzwalacze i tak je profilują. Przykład: /_profiler,/_profiler/**,/_wdt/**.
PROFILER_INTERNAL false Obserwuj wewnętrzne funkcje C (strlen, json_encode, …). Pełne pokrycie, ale 2–5× narzutu. Używaj chirurgicznie.
PROFILER_MAX_SPANS 50000 Twardy limit rozmiaru drzewa na żądanie. Po przekroczeniu kolejne spany są oznaczane jako truncated i nie są zapisywane.
PROFILER_MAX_DEPTH 256 Twardy limit głębokości stosu.
PROFILER_OUTPUT_DIR /tmp/oxphp-profiles Ścieżka bezwzględna. Musi być zapisywalna przez www-data.
PROFILER_OUTPUT_FORMATS xhprof,speedscope Podzbiór CSV z xhprof, speedscope, pprof, collapsed.
PROFILER_RETENTION_COUNT 100 Ile przebiegów zachować (zarówno na dysku, jak i w LRU). Przycinanie w tle co 5 sekund.
PROFILER_DISK_MAX_PER_SEC 10 Token bucket chroniący dysk. Nadmiar jest odrzucany i zwiększa oxphp_profiler_disk_drops_total.
PROFILER_EXPORT_URL (nieustawione) URL do POST dla każdego przechwyconego przebiegu (xhgui, własny kolektor).
PROFILER_EXPORT_FORMAT xhprof Jeden z czterech formatów dla pusha HTTP.
PROFILER_EXPORT_AUTH_TOKEN (nieustawione) Token bearer dla celu pusha.
PROFILER_EXPORT_XHGUI auto Wymuś tryb koperty xhgui. Auto: ścieżka URL kończy się na /run/import (kanoniczny endpoint xhgui; wskazówki w hoście/query nie są dopasowywane — ustaw na true dla niestandardowej ścieżki).
PROFILER_EXPORT_BUGGREGATOR auto Wymuś kopertę Buggregatora. Auto: ścieżka URL kończy się na /api/profiler/store. Koperta zawsze emituje xhprof, więc PROFILER_EXPORT_FORMAT jest dla niej ignorowany (wartość inna niż xhprof powoduje ostrzeżenie, nie błąd krytyczny). Wzajemnie wykluczający się z PROFILER_EXPORT_XHGUI (włączenie obu to błąd przy starcie).
PROFILER_EXPORT_APP_NAME (nieustawione) app_name Buggregatora — projekt, pod którym grupowany jest profil.
PROFILER_EXPORT_TAGS (nieustawione) tags Buggregatora, lista key=value,key2=value2 do filtrowania. Źle sformułowany token (nie key=value), pusty klucz lub zduplikowany klucz to błąd przy starcie.

Przykładowa konfiguracja produkcyjna

yaml
environment: PROFILER_ENABLED: "true" PROFILER_AUTH_TOKEN: "${PROFILER_TOKEN_FROM_VAULT}" PROFILER_SAMPLE_RATE: "0.001" # ~0.1% of traffic PROFILER_INTERNAL: "false" PROFILER_OUTPUT_DIR: /var/lib/oxphp/profiles PROFILER_OUTPUT_FORMATS: "xhprof,collapsed" PROFILER_RETENTION_COUNT: "500" PROFILER_DISK_MAX_PER_SEC: "20" PROFILER_EXPORT_URL: "http://xhgui.monitoring.svc.cluster.local/run/import" PROFILER_EXPORT_FORMAT: "xhprof"

PHP SDK

Wszystkie funkcje należą do przestrzeni nazw OxPHP\Profile. Zawsze można je bezpiecznie wywołać: jeśli profilowanie nie jest aktywne dla bieżącego żądania, mutatory są bezpiecznymi no-opami, a is_active() zwraca false.

Jawne przechwytywanie wokół fragmentu

php
use function OxPHP\Profile\{start, stop, is_active}; function heavy_report(): array { start(); // activate ProfileAll inside the request $result = build_report(); // this lands in the tree stop(); // stop capture return $result; }

start() jest idempotentne, podobnie jak stop(): dwukrotne wywołanie z rzędu jest bezpieczne.

Warning

Wywołanie start() w trakcie żądania resetuje bieżące drzewo (zobacz PROFILING_CONTEXT.reset() w php_sdk.rs). Jest to zgodne z niezmiennikiem specyfikacji: tryb ustawiany jest raz na żądanie — albo przez wyzwalacz przy RINIT, albo przez pierwsze wywołanie start().

Wstrzymanie i wznowienie

php
use function OxPHP\Profile\{pause, resume}; pause(); noisy_helper_we_dont_care_about(); // will not land in the tree resume();

W odróżnieniu od stop(), pause/resume to sygnał dokumentujący „tymczasowość". Wewnętrznie to ta sama flaga; rozróżnienie pomaga jedynie temu, kto czyta kod.

Znaczniki punktowe: mark()

php
use function OxPHP\Profile\mark; mark('cache_miss'); mark('got_auth_token', ['user_id' => (string) $user->id]);

Dołącza zdarzenie SpanEventKind::Mark do najwyższego otwartego spanu. No-op, gdy żaden span nie jest otwarty. Przydatne do pośrednich znaczników czasu w długiej funkcji lub do oznaczania gałęzi if/else.

Metryki liczbowe: metric()

php
use function OxPHP\Profile\metric; $rows = $pdo->query('SELECT ...')->fetchAll(); metric('db.rows', (float) count($rows)); metric('payload.kb', strlen($body) / 1024.0);

Dołącza metric.<name>=<value> do atrybutów bieżącego spanu. W odróżnieniu od mark() to zwykła para klucz-wartość (bez znacznika czasu). Pojawia się w speedscope/xhgui jako właściwość spanu.

Sprawdzenie stanu: is_active()

php
if (OxPHP\Profile\is_active()) { // can afford an expensive debug dump — // this request is being profiled anyway error_log(json_encode($debug_state)); }

Dwa odczyty TLS, bez FFI. Bezpieczne do wywołania w gorącym kodzie.

Atrybuty (PHP 8)

Siedem atrybutów dzieli się na dwie kategorie: filtry observera działają przed utworzeniem spanu; dekoratory działają po zamknięciu spanu.

Atrybut Kategoria Efekt
#[Profile] filtr Wymuś włączenie funkcji do drzewa (nawet jeśli ogólne reguły by ją wykluczyły).
#[Exclude] filtr Pomiń funkcję; jej dzieci zostają podpięte do najbliższego włączonego przodka.
#[Sample(rate: 0.1)] filtr Zachowaj tylko ułamek wywołań (rate ∈ [0.0; 1.0]). Probabilistyczne — bez blokad.
#[Tag(key, value)] filtr Dołącz etykietę do spanu. Powtarzalne — wiele #[Tag] się kumuluje.
#[Mark(label?)] dekorator Emituj zdarzenie Mark przy wejściu do funkcji.
#[SlowThreshold(ms)] dekorator Emituj zdarzenie Slow + ustaw status, gdy czas zegarowy ≥ ms.
#[MemoryThreshold(kb)] dekorator Emituj MemorySpike + status, gdy alokacja netto ≥ kb.

Kompozycja: klasa a metoda

php
use OxPHP\Profile\{Tag, Profile, Exclude}; #[Tag(key: 'layer', value: 'domain')] #[Profile] // the whole class is always profiled class OrderService { #[Tag(key: 'op', value: 'create')] public function create(array $data): Order { /* ... */ } #[Exclude] // excluded, despite class-level #[Profile] public function debug_dump(): void { /* ... */ } public function find(int $id): ?Order { /* ... */ } // inherits #[Profile] and #[Tag(layer)] }
  • Atrybuty na poziomie klasy propagują się na każdą metodę.
  • Atrybuty na poziomie metody dodają się do tych z poziomu klasy (tagi się kumulują).
  • #[Exclude] na metodzie nadpisuje #[Profile] z poziomu klasy.

Próg wolnej funkcji

php
use OxPHP\Profile\SlowThreshold; #[SlowThreshold(ms: 250)] function render_dashboard(User $u): string { // if it runs ≥ 250 ms — a Slow event is appended to the span and // status_code=2 (error). Immediately visible in xhgui / speedscope. }

Próg pamięci

php
use OxPHP\Profile\MemoryThreshold; #[MemoryThreshold(kb: 512)] function import_csv(string $path): int { // if the function net-allocates ≥ 512 KB during execution — // MemorySpike event + status=error }

Próbkowanie pojedynczych funkcji

php
use OxPHP\Profile\Sample; #[Sample(rate: 0.01)] function log_event(string $evt, array $ctx): void { // ≈ 1% of calls land in the tree; the rest are skipped entirely — // neither the span nor its children are created. Useful for functions // called millions of times per request. }
Filtry a dekoratory?

Gdy funkcja jest wywoływana bardzo często, a chcesz obniżyć koszt przechwytywania, użyj #[Sample] lub #[Exclude] (działają przed utworzeniem spanu). Gdy chcesz oznaczyć zdarzenie powyżej progu, użyj #[SlowThreshold] / #[MemoryThreshold] (patrzą na już zebrany span).

Co zawiera przechwycony span

ruby
FinishedSpan { span_id # Arc<str>, W3C-compatible parent_span_id # Arc<str> trace_id # Arc<str>, shared with APM name # Fully-qualified PHP function/method name start_ns # wall-clock, ns since the profiler epoch end_ns cpu_ns # CLOCK_THREAD_CPUTIME_ID (0 when the platform doesn't provide it) memory_start # zend_memory_usage(0) on entry memory_end # zend_memory_usage(0) on exit attributes # Vec<(Arc<str>, Arc<str>)> — from #[Tag], metric(), APM SQL/HTTP events # Vec<SpanEvent { ts, kind, label, attrs }> status_code # 0 = unset, 1 = ok, 2 = error status_message leaked # true if the span was force-closed by finalize (PHP threw past the observer) }

Rodzaje zdarzeń (SpanEvent::kind):

Rodzaj Emitowane przez
Mark mark(), metric(), #[Mark]
Slow #[SlowThreshold]
MemorySpike #[MemoryThreshold]
Sql haki APM (PDO, mysqli)
Http haki APM (cURL, strumienie HTTP)
Exception obsługa wyjątków APM
Alloc (zarezerwowane dla próbkowania sterty)
Other fallback

Formaty eksportu

Pliki znajdują się w PROFILER_OUTPUT_DIR, nazwane <run_id>.<ext>, gdzie run_id = <ts_ms>-<req_id_prefix>-<rand4> (np. 1713600000000-a1b2c3d4-0f5e).

speedscope (domyślny do analizy interaktywnej)

Rozszerzenie: .speedscope.json

  • Flamegraph w przeglądarce z zoomem, wyszukiwaniem, przełącznikiem CPU / czas / pamięć.
  • Zero konfiguracji — otwórz bezpośrednio na speedscope.app.
  • OxPHP zwraca przekierowanie 302 pod /__profiler/runs/{id}/speedscope → speedscope.app z parametrem profileURL=…, który pobiera profil prosto z twojego serwera.
bash
# Ctrl-click in macOS Terminal / xdg-open on Linux open "http://localhost:9090/__profiler/runs/<run_id>/speedscope"

xhprof (dla xhgui: oś czasu i różnice historyczne)

Rozszerzenie: .xhprof.json

  • Kompatybilny z xhgui (wyszukiwanie po URL, trendy, różnice między dwoma przebiegami).
  • Idealny do gromadzenia na produkcji: uruchom kontener xhgui obok aplikacji, skieruj PROFILER_EXPORT_URL=http://xhgui/run/import, a historia gromadzi się w interfejsie.
  • Gotowy docker-compose: tests/compose.xhgui.yml.

pprof (narzędzia Google pprof, plugin pprof w Grafanie, Pyroscope)

Rozszerzenie: .pprof (protobuf + gzip, poziom fast, backend zlib)

bash
# save and open curl -H "Authorization: Bearer dev-secret" \ http://localhost:9090/__profiler/runs/<run_id>.pprof > profile.pprof go tool pprof -http=:8080 profile.pprof # or pyroscope-cli adhoc --input profile.pprof

collapsed (flamegraph.pl Brendana Gregga)

Rozszerzenie: .collapsed

  • Format tekstowy func;child;grandchild <count>.
  • De facto wejście dla flamegraphów SVG.
  • Trzy warianty metryki: czas zegarowy, CPU, pamięć. OxPHP zapisuje .collapsed (zegarowy); wewnętrzne ścieżki produkują też .collapsed.cpu i .collapsed.mem (zobacz tests/fixtures/profiler_exports/).
bash
curl -H "Authorization: Bearer dev-secret" \ http://localhost:9090/__profiler/runs/<run_id>.collapsed \ | flamegraph.pl --title "Checkout $run_id" > flame.svg

Buggregator (lokalny serwer debugowania)

Buggregator to jednoplikowy serwer debugowania, który m.in. renderuje profile xhprof jako flame graphy pogrupowane wg projektu. Push xhprof trafia bezpośrednio do jego endpointu POST /api/profiler/store: nie jest potrzebne rozszerzenie PHP xhprof ani biblioteka kliencka, ponieważ dane produkuje natywny profiler OxPHP.

yaml
services: buggregator: image: ghcr.io/buggregator/server:latest ports: ["8000:8000"] app: image: ghcr.io/oxphp/oxphp:latest environment: PROFILER_ENABLED: "true" PROFILER_SAMPLE_RATE: "0.01" PROFILER_EXPORT_URL: "http://buggregator:8000/api/profiler/store" PROFILER_EXPORT_FORMAT: "xhprof" PROFILER_EXPORT_APP_NAME: "checkout" # groups profiles by project PROFILER_EXPORT_TAGS: "env=staging,region=eu" # filterable in the UI

URL, którego ścieżka kończy się na /api/profiler/store, automatycznie wybiera kopertę Buggregatora (PROFILER_EXPORT_BUGGREGATOR: "true" wymusza ją dla niestandardowego URL; "false" wyłącza). Ta koperta zawsze emituje xhprof, więc PROFILER_EXPORT_FORMAT jest dla niej ignorowany (wartość inna niż xhprof powoduje ostrzeżenie przy starcie, nie błąd krytyczny — profiler nigdy nie wywala serwera z powodu opcji eksportu). app_name i tags sterują grupowaniem i filtrowaniem projektów w Buggregatorze; bez nich profil nadal się renderuje, ale trafia bez grupowania. hostname pochodzi z $HOSTNAME, a gdy ta zmienna nie jest ustawiona, następuje odwołanie do wywołania systemowego gethostname(2).

Przechowywanie i sprzątanie

text
/tmp/oxphp-profiles/ ├── index.json # NDJSON — one record per line ├── 1713600000000-a1b2c3d4-0f5e.xhprof.json ├── 1713600000000-a1b2c3d4-0f5e.speedscope.json └── 1713600001234-b2c3d4e5-4a2b.xhprof.json

Schemat wpisu index.json

json
{ "run_id": "1713600000000-a1b2c3d4-0f5e", "request_id": "a1b2c3d4e5f67890", "trace_id": "0af7651916cd43dd8448eb211c80319c", "timestamp_ms": 1713600000000, "duration_ms": 123, "method": "GET", "url": "/checkout", "status": 200, "user_agent": "Mozilla/5.0 …", "client_ip": "10.0.0.42", "source": "Header", // Header | Cookie | Query | SampleRate "span_count": 4821, "event_count": 7, "error_count": 0, "leaked_count": 0, "truncated": false, // true — exceeded PROFILER_MAX_SPANS "oxphp_version": "0.10.0", "formats": ["xhprof.json", "speedscope.json"] }

index.json jest parsowany przez /__profiler/runs, sortowany od najnowszych i stronicowany przez ?limit=N&offset=M.

Retencja

  • Zadanie w tle co 5 sekund usuwa wpisy przekraczające PROFILER_RETENTION_COUNT (atomowy renameindex.json).
  • Pliki bez wpisu w index.json (osierocone przez awarię) są usuwane.
  • Token bucket PROFILER_DISK_MAX_PER_SEC chroni dysk: jeśli tempo jest wyższe, przebiegi nie są zapisywane, a oxphp_profiler_disk_drops_total rośnie.

Wewnętrzne trasy HTTP

Przy INTERNAL_ADDR=0.0.0.0:9090 plugin rejestruje 8 endpointów pod prefiksem /__profiler/. Wszystkie wymagają Authorization: Bearer <PROFILER_AUTH_TOKEN>, gdy skonfigurowano token. Porównanie odbywa się w stałym czasie.

Trasa Metoda Przeznaczenie
/__profiler/ GET Strona główna HTML z indeksem endpointów.
/__profiler/runs GET Tablica JSON przebiegów. ?limit=N&offset=M.
/__profiler/runs/{id} GET Metadane JSON jednego przebiegu.
/__profiler/runs/{id}.{format} GET Surowe bajty profilu. formatxhprof.json, speedscope.json, pprof, collapsed.
/__profiler/runs/{id}/speedscope GET 302 → speedscope.app z profileURL=….
/__profiler/runs/{id} DELETE Usuwa wszystkie pliki formatów + wpis w indeksie (zwraca 204).
/__profiler/config GET Bieżąca konfiguracja pluginu (tokeny zredagowane).
/__profiler/stats GET Migawka JSON liczników.

Przykładowe skrypty

bash
# Top-5 slowest of the last 20 runs curl -s -H "Authorization: Bearer $TOK" \ "http://localhost:9090/__profiler/runs?limit=20" \ | jq '.runs | sort_by(.duration_ms) | reverse | .[:5]' # All profiles for a given URL curl -s -H "Authorization: Bearer $TOK" \ "http://localhost:9090/__profiler/runs?limit=500" \ | jq '.runs[] | select(.url == "/checkout")' # Delete all runs older than 1 hour (independent of the plugin's retention) NOW=$(date +%s%3N) CUTOFF=$((NOW - 3600000)) curl -s -H "Authorization: Bearer $TOK" \ "http://localhost:9090/__profiler/runs?limit=1000" \ | jq -r --arg c "$CUTOFF" '.runs[] | select(.timestamp_ms < ($c|tonumber)) | .run_id' \ | xargs -I{} curl -X DELETE -H "Authorization: Bearer $TOK" \ "http://localhost:9090/__profiler/runs/{}"

Push HTTP i xhgui

Wysyłaj każdy przebieg do zdalnego kolektora:

yaml
environment: PROFILER_EXPORT_URL: "http://xhgui/run/import" PROFILER_EXPORT_FORMAT: "xhprof" PROFILER_EXPORT_AUTH_TOKEN: "shared-secret" # optional
  • Autowykrywanie koperty xhgui: ścieżka URL kończy się na /run/import (kanoniczny endpoint xhgui). Rozmyty podłańcuch xhgui w hoście lub query nie jest dopasowywany — wymuś przez PROFILER_EXPORT_XHGUI=true|false dla takich URL-i.
  • Plan ponawiania: 3 próby z wykładniczym backoffem 100/200/400 ms, łączny budżet 5 s czasu zegarowego. Ciało żądania jest współdzielone między próbami jako bytes::Bytes (zero alokacji przy ponawianiu).
  • Błędy zwiększają oxphp_profiler_http_push_failures_total.

Pełny stos demonstracyjny

bash
docker compose -f tests/compose.xhgui.yml up -d # app: :80, xhgui: :8142 (UI), :27017 (mongo)

Test dymny E2E: tests/php/profiler/test_xhgui_import.php.

Metryki Prometheusa

Udostępniane pod /metrics:

text
oxphp_profiler_runs_total{source="header"|"cookie"|"query"|"sample"} oxphp_profiler_spans_collected_total oxphp_profiler_bytes_written_total{format="xhprof"|"speedscope"|"pprof"|"collapsed"} oxphp_profiler_disk_drops_total oxphp_profiler_http_push_failures_total oxphp_profiler_truncated_total oxphp_profiler_in_memory_runs

Startowe alerty Prometheusa:

yaml
- alert: ProfilerDiskDrops expr: rate(oxphp_profiler_disk_drops_total[5m]) > 0 annotations: summary: "Profiler is dropping runs on disk — check PROFILER_DISK_MAX_PER_SEC" - alert: ProfilerPushFailing expr: rate(oxphp_profiler_http_push_failures_total[5m]) > 0 annotations: summary: "xhgui / collector is unreachable" - alert: ProfilerTruncatingTrees expr: rate(oxphp_profiler_truncated_total[5m]) > 0 annotations: summary: "Requests exceed PROFILER_MAX_SPANS — raise the cap or investigate"

Przepływy pracy

Znajdź wolny endpoint

  1. Włącz PROFILER_SAMPLE_RATE=0.001 na produkcji. Pozwól, aby dane się nagromadziły.
  2. Posortuj przebiegi wg duration_ms:
    bash
    curl -s -H "Authorization: Bearer $TOK" \ "http://INT_ADDR/__profiler/runs?limit=500" \ | jq '.runs | sort_by(.duration_ms) | reverse | .[:10] | map({run_id, url, duration_ms, span_count})'
  3. Otwórz najwyższy w speedscope: .../__profiler/runs/<id>/speedscope.
  4. Włącz tryb Left Heavy w speedscope — zobaczysz funkcje o największym skumulowanym czasie.
  5. Kliknij najszerszy słupek — otrzymasz plik:linię oraz listę dzieci.

Zweryfikuj hipotezę „przed i po"

  1. Uruchom benchmark PRZED zmianami:
    bash
    for i in $(seq 1 20); do curl -s -H "X-OxPHP-Profile: dev-secret" http://localhost/api/report > /dev/null done curl -s -H "Authorization: Bearer dev-secret" \ "http://localhost:9090/__profiler/runs?limit=20" \ | jq '.runs | map(.duration_ms) | add / length' > /tmp/p50_before.txt
  2. Wprowadź zmiany, przebuduj, powtórz. Porównaj mediany.
  3. Dla szczegółowej różnicy pobierz dwa profile xhprof i wgraj do xhgui — ma wbudowany widok różnic.

Tropienie wycieku pamięci

  1. Wyślij żądanie, które „rośnie":
    bash
    curl -H "X-OxPHP-Profile: dev-secret" http://localhost/import?file=big.csv
  2. Otwórz je w speedscope, przełącz na metrykę pamięci (przez .collapsed.mem lub widok pamięci w speedscope).
  3. Dodaj #[MemoryThreshold(kb: 1024)] na podejrzanych funkcjach — przy kolejnym przebiegu otrzymasz jawne zdarzenia MemorySpike.
  4. Użyj metric('mem.after', memory_get_usage()) do chirurgicznej instrumentacji.

Ciągłe monitorowanie krytycznej ścieżki

php
#[Profile] #[SlowThreshold(ms: 500)] public function chargeCard(PaymentRequest $r): PaymentResult { // always captured + an explicit Slow mark when it lags }

W Grafanie dodaj panel dla oxphp_profiler_runs_total{source="sample"} oraz alert na odstających duration_ms z index.json (przez metrykę opartą na logach lub eksporter sidecar).

Współpracownik mówi „u mnie /admin/report zwraca 500". Odpowiadasz:

text
https://app.local/admin/report?__oxprof=<one-time-token>

Gdy odwiedzi — /__profiler/runs?limit=5, otwórz profil i zobacz dokładnie, gdzie wylądował wyjątek (status_code=2 + zdarzenie Exception).

Współdziałanie z APM

  • Oba pluginy współdzielą jedno Arc<SpanTree>. Bez podwójnego zbierania.
  • Brak wyzwalacza profilera + APM włączony → mode=ApmOnly. Drzewo zawiera tylko jawnie otagowane spany (#[Trace], haki SQL/HTTP APM).
  • Trafienie wyzwalacza profilera → mode=ProfileAll. Drzewo zawiera wszystko plus adnotacje APM.
  • APM nadal wysyła do OTLP tylko swoje jawne spany (Jaeger/Tempo mają limit ~10k spanów na ślad). Po pełny obraz — /__profiler/runs/<id>.

Dobre praktyki

  1. Nigdy nie commituj PROFILER_AUTH_TOKEN. Odczytuj z Vault / Docker secrets / Kubernetes secrets.
  2. Na produkcji — tylko SAMPLE_RATE. Header/cookie/query to narzędzia deweloperskie. Jeśli potrzebujesz profilowania na produkcji na żądanie — użyj dedykowanego, codziennie rotowanego tokena.
  3. Nie włączaj PROFILER_INTERNAL=true globalnie. Narzut 2–5× zamienia produkcję w laboratorium. Używaj chirurgicznie, w izolacji.
  4. Utrzymuj PROFILER_RETENTION_COUNT realistycznie — przebieg może ważyć od setek KB (małe żądanie) do megabajtów (duże drzewo). 500 przebiegów × 2 MB = 1 GB. Dobierz rozmiar dysku odpowiednio.
  5. Oznacz #[Exclude] hałaśliwe funkcje pomocnicze (logowanie, i18n, autoloader) — drzewo staje się czytelne bez utraty znaczenia.
  6. Łącz profile ze śladami: trace_id jest współdzielony. W Grafanie / Kibanie linkuj /__profiler/runs/<id> z widoku śladu.
  7. Identyfikatory przyjazne dla Gita. W tym buildzie span_id to deterministyczny, monotoniczny licznik big-endian. Porównywanie dwóch zapisanych profili jest czyste.
  8. APM + profiler jest darmowe. Trzymaj oba włączone; drzewo jest współdzielone, narzut bierze się jedynie ze skumulowanego pokrycia APM.

Rozwiązywanie problemów

Nie pojawiają się żadne profile
  1. Czy plugin jest wkompilowany? docker compose build domyślnie go zawiera. Sprawdź, czy nie przekazano --build-arg OXPHP_WITH_PROFILER=0 ani własnego CARGO_FEATURES bez plugin-profiler.
  2. PROFILER_ENABLED=true?
  3. Czy wyzwalacz rzeczywiście pasuje do PROFILER_AUTH_TOKEN?
    • Poszukaj zabłąkanego \n w zmiennej środowiskowej.
    • Dla query — czy jest poprawnie zakodowany w URL?
  4. Czy serwer w ogóle widzi twoje żądanie? Sprawdź log dostępu.
401 z /__profiler/runs

Token bearer w nagłówku nie pasuje do PROFILER_AUTH_TOKEN. Częsta pułapka: echo "secret" > secret.txt dopisuje \n. Użyj printf lub przekaż przez zmienną środowiskową.

xhgui nie pokazuje nowych przebiegów
  1. Sprawdź osiągalność:
    bash
    docker compose exec app curl -v $PROFILER_EXPORT_URL
  2. Spójrz na oxphp_profiler_http_push_failures_total.
  3. Sprawdź logi: przy każdej awarii emitowany jest tracing::warn! z run_id i statusem HTTP.
Brak plików na dysku
  • Czy PROFILER_OUTPUT_DIR jest bezwzględny? Ścieżki względne są ignorowane.
  • Zapisywalny przez www-data?
    bash
    docker compose exec app ls -la /tmp/oxphp-profiles
  • Czy PROFILER_DISK_MAX_PER_SEC nie jest zbyt niski? Spójrz na oxphp_profiler_disk_drops_total.
Zbyt duży narzut na produkcji
  • PROFILER_INTERNAL=false (to wartość domyślna).
  • PROFILER_SAMPLE_RATE w rozsądnym przedziale (0.0005..0.002).
  • Rozsądny PROFILER_MAX_SPANS — po przekroczeniu drzewo jest obcinane, ale przechwytywanie nadal działa. Dla bardzo dużych żądań lepszy jest chirurgiczny start()/stop() wokół interesującego fragmentu.
truncated=true w index.json

Żądanie przekroczyło PROFILER_MAX_SPANS (domyślnie 50 000). Opcje:

  1. Podnieś limit (kosztem pamięci za szczegółowość).
  2. Dodaj #[Exclude] / #[Sample(rate: 0.01)] na funkcjach wywoływanych dziesiątki tysięcy razy.
  3. Owiń w start()/stop() tylko podejrzany fragment.

Ściągawka poleceń

bash
# Activate for one request curl -H "X-OxPHP-Profile: $TOK" http://localhost/endpoint # List runs, top-10 by duration curl -sH "Authorization: Bearer $TOK" http://localhost:9090/__profiler/runs \ | jq '.runs | sort_by(.duration_ms) | reverse | .[:10]' # Open in speedscope open "http://localhost:9090/__profiler/runs/$RUN_ID/speedscope" # Download as xhprof for xhgui import curl -sH "Authorization: Bearer $TOK" \ http://localhost:9090/__profiler/runs/$RUN_ID.xhprof.json > run.xhprof.json # Download as pprof and open curl -sH "Authorization: Bearer $TOK" \ http://localhost:9090/__profiler/runs/$RUN_ID.pprof > run.pprof go tool pprof -http=:8080 run.pprof # flamegraph.pl curl -sH "Authorization: Bearer $TOK" \ http://localhost:9090/__profiler/runs/$RUN_ID.collapsed \ | flamegraph.pl > flame.svg # Delete a run curl -X DELETE -H "Authorization: Bearer $TOK" \ http://localhost:9090/__profiler/runs/$RUN_ID # Metrics curl -s http://localhost:9090/metrics | grep oxphp_profiler_ # Current plugin config (safe — tokens are redacted) curl -sH "Authorization: Bearer $TOK" http://localhost:9090/__profiler/config | jq

Praktyczne przykłady

Poniżej gotowe do uruchomienia scenariusze PHP, które możesz wrzucić do www/public/ i wywołać curl-em.

Prosty kontroler z ręcznym sterowaniem

www/public/report.php
<?php declare(strict_types=1); use function OxPHP\Profile\{start, stop, mark, metric, is_active}; function fetch_rows(PDO $db, int $user_id): array { $stmt = $db->prepare('SELECT * FROM orders WHERE user_id = ? LIMIT 1000'); $stmt->execute([$user_id]); return $stmt->fetchAll(PDO::FETCH_ASSOC); } function render_report(array $rows): string { $sum = array_sum(array_column($rows, 'amount')); return json_encode(['count' => count($rows), 'total' => $sum]); } $db = new PDO('mysql:host=db;dbname=app', 'app', 'secret'); $user_id = (int) ($_GET['user_id'] ?? 1); // Explicitly profile only the heavy block — even if the trigger wasn't set. start(); mark('report.begin', ['user_id' => (string) $user_id]); $rows = fetch_rows($db, $user_id); metric('db.rows', (float) count($rows)); $body = render_report($rows); metric('response.bytes', (float) strlen($body)); mark('report.done'); stop(); header('Content-Type: application/json'); echo $body; // Optional — tell the frontend that this request was profiled: if (is_active()) { header('X-Profiled: 1'); }

Wywołanie:

bash
curl -H "X-OxPHP-Profile: dev-secret" 'http://localhost/report.php?user_id=42'

Klasa serwisu z atrybutami

www/lib/OrderService.php
<?php declare(strict_types=1); use OxPHP\Profile\{Profile, Tag, Exclude, Sample, SlowThreshold, MemoryThreshold}; #[Profile] #[Tag(key: 'layer', value: 'domain')] #[Tag(key: 'svc', value: 'orders')] final class OrderService { public function __construct( private readonly PDO $db, private readonly Mailer $mailer, ) {} #[SlowThreshold(ms: 250)] #[Tag(key: 'op', value: 'create')] public function create(array $payload): int { $this->db->beginTransaction(); try { $id = $this->insertOrder($payload); $this->insertLines($id, $payload['items']); $this->db->commit(); $this->mailer->sendReceipt($id); return $id; } catch (\Throwable $e) { $this->db->rollBack(); throw $e; } } #[MemoryThreshold(kb: 2048)] #[Tag(key: 'op', value: 'export')] public function exportCsv(int $user_id): string { $stmt = $this->db->prepare('SELECT * FROM orders WHERE user_id = ?'); $stmt->execute([$user_id]); $buf = fopen('php://temp', 'r+'); fputcsv($buf, ['id', 'created_at', 'total']); while ($row = $stmt->fetch(PDO::FETCH_ASSOC)) { fputcsv($buf, [$row['id'], $row['created_at'], $row['total']]); } rewind($buf); return stream_get_contents($buf); } // Trivial getter — don't clutter the tree. #[Exclude] public function find(int $id): ?array { $stmt = $this->db->prepare('SELECT * FROM orders WHERE id = ?'); $stmt->execute([$id]); return $stmt->fetch(PDO::FETCH_ASSOC) ?: null; } // Very frequent audit — sample to avoid inflating the tree. #[Sample(rate: 0.05)] private function audit(string $event, array $ctx): void { $this->db->prepare('INSERT INTO audit (event, ctx) VALUES (?, ?)') ->execute([$event, json_encode($ctx)]); } private function insertOrder(array $p): int { /* ... */ return 0; } private function insertLines(int $id, array $items): void { /* ... */ } }

Zadanie wsadowe: profiluj tylko pierwszą z N iteracji

www/bin/import.php
<?php declare(strict_types=1); use function OxPHP\Profile\{start, stop, pause, resume, mark}; $files = glob('/data/incoming/*.csv'); $i = 0; foreach ($files as $path) { if ($i === 0) { start(); // profile only the first file in full mark('batch.begin', ['path' => $path]); } else { pause(); // the rest — no-op for capture } import_one($path); if ($i === 0) { mark('batch.first_done'); stop(); } $i++; } function import_one(string $path): void { /* ... */ }

Porównanie dwóch implementacji (mikrobenchmark z profilami)

www/public/bench.php
<?php // naive vs streaming comparison declare(strict_types=1); use function OxPHP\Profile\{start, stop, mark, metric}; function naive_sum(string $path): int { $rows = array_map('str_getcsv', file($path)); // whole file into memory return array_sum(array_column($rows, 1)); } function streaming_sum(string $path): int { $h = fopen($path, 'r'); $total = 0; while (($row = fgetcsv($h)) !== false) { $total += (int) ($row[1] ?? 0); } fclose($h); return $total; } $path = '/data/big.csv'; $which = $_GET['impl'] ?? 'naive'; start(); mark('bench.begin', ['impl' => $which]); $t0 = hrtime(true); $result = $which === 'naive' ? naive_sum($path) : streaming_sum($path); $elapsed_ms = (hrtime(true) - $t0) / 1e6; metric('bench.elapsed_ms', $elapsed_ms); metric('bench.result', (float) $result); mark('bench.done'); stop(); echo json_encode(['impl' => $which, 'elapsed_ms' => $elapsed_ms, 'result' => $result]);

Procedura:

bash
# Naive curl -H "X-OxPHP-Profile: dev-secret" "http://localhost/bench.php?impl=naive" # Streaming curl -H "X-OxPHP-Profile: dev-secret" "http://localhost/bench.php?impl=streaming" # Diff in xhgui (two latest xhprof runs) curl -sH "Authorization: Bearer dev-secret" \ "http://localhost:9090/__profiler/runs?limit=2" | jq '.runs[] | .run_id'

Warunkowe profilowanie w kodzie produkcyjnym

php
<?php // Classic case: a suspected function is slow for certain users only. declare(strict_types=1); use function OxPHP\Profile\{start, stop, is_active}; function charge(User $user, Money $amount): PaymentResult { // Audit: if this request is being profiled, // enable extra logging inside the third-party call. $verbose = is_active(); $gateway = new StripeClient(verbose: $verbose); return $gateway->charge($user->id, $amount); } function oncall_path(Order $order): void { // Profile only VIP users — no external trigger needed. if ($order->user->tier === 'vip') { start(); } process($order); if ($order->user->tier === 'vip') { stop(); } }

Test integracyjny, który sam się profiluje

tests/php/profile_smoke.php
<?php declare(strict_types=1); require __DIR__ . '/test_helper.php'; use function OxPHP\Profile\{start, stop, mark, is_active}; $t = new TestCase('profile_smoke', 'my-app'); // Enable the profiler manually (no trigger needed to test the SDK). $t->assertFalse('initially not active', is_active()); start(); $t->assertTrue('active after start', is_active()); mark('test.midpoint'); // some work $sum = 0; for ($i = 0; $i < 100_000; $i++) { $sum += $i; } stop(); $t->assertFalse('inactive after stop', is_active()); $t->assertSame('computation OK', $sum, 4999950000); $t->done();

Znajdowanie hotspotu z serii żądań Postmana

Scenariusz: „/api/search bywa wolny, ale nie zawsze."

javascript
// Postman Pre-request Script pm.request.headers.add({ key: 'X-OxPHP-Profile', value: pm.environment.get('PROFILE_TOKEN') });

Po 100 przebiegach jednolinijkowiec jq dla największych anomalii:

bash
curl -sH "Authorization: Bearer $TOK" \ "http://int.app.local:9090/__profiler/runs?limit=200" \ | jq -r '.runs | map(select(.url | startswith("/api/search"))) | sort_by(-.duration_ms) | .[:5] | map("\(.duration_ms)ms \(.run_id) \(.url)") | .[]'

Własny dekorator zasilający profiler

Twój własny #[ProfileDb] — loguje liczbę wierszy i automatycznie wywołuje metric('db.rows', …):

php
<?php use OxPHP\Decorator\{AttributeInterface, Context}; use function OxPHP\Profile\metric; #[Attribute(Attribute::TARGET_METHOD)] class ProfileDb implements AttributeInterface { public function before(Context $ctx): void {} public function after(Context $ctx): void { $result = $ctx->returnValue; if (is_array($result)) { metric('db.rows', (float) count($result)); } elseif ($result instanceof PDOStatement) { metric('db.rows', (float) $result->rowCount()); } } } oxphp_register_decorator(ProfileDb::class); class UserRepository { #[ProfileDb] public function findAll(): array { /* ... */ return []; } }

Połączenie dekorator + profiler działa od ręki: metric() automatycznie dołącza się do spanu funkcji, którą aktualnie obserwuje Observer API.

Źródła