diff --git a/.env.example b/.env.example index fab5b21..d8fb581 100644 --- a/.env.example +++ b/.env.example @@ -39,6 +39,19 @@ APP_NAME=edu-framework APP_ENV=prod ## >> Config application +## << Config profiler de code (barre de debug, mode dev uniquement) +## Nécessite l'extension PHP Excimer (installée dans l'image Docker) +## off -> profiler désactivé +## trigger -> profilage à la demande : bouton "Code" de la barre de debug +## (cookie edu_profile=1) ou paramètre ?_profile=1 dans l'URL +## on -> chaque requête est profilée +EDU_PROFILER=trigger +## Nombre de profils conservés dans la base des logs +EDU_PROFILER_KEEP=50 +## Image Docker : 1 => avec Excimer (défaut), 0 => sans profiler +EDU_PROFILER_BUILD=1 +## >> Config profiler de code + ## << Config Mailer MAILER_DSN="smtp://localhost:1025" ## >> Config Mailer diff --git a/.github/workflows/testing.yml b/.github/workflows/testing.yml index c1a2e4b..2069d86 100644 --- a/.github/workflows/testing.yml +++ b/.github/workflows/testing.yml @@ -45,7 +45,7 @@ jobs: uses: shivammathur/setup-php@v2 with: php-version: ${{ matrix.php-versions }} - extensions: mbstring, xml, ctype, iconv, intl, pdo_sqlite, dom, filter, gd, iconv, json, mbstring, pdo, curl + extensions: mbstring, xml, ctype, iconv, intl, pdo_sqlite, dom, filter, gd, iconv, json, mbstring, pdo, curl, excimer env: update: true diff --git a/CHANGELOG.md b/CHANGELOG.md index 872d05d..4105781 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,16 @@ **Présentation des versions du framework Edu Framework** +## Prochaine version (non publiée) + +**new features** + +- Profiler de code dans la barre de debug : le temps passé dans chaque fonction PHP d'une requête HTTP est mesuré par l'extension [Excimer](https://www.mediawiki.org/wiki/Excimer) (profiler par échantillonnage toutes les 0,1 ms, compatible FrankenPHP en mode classique et worker). Le profilage est **à la demande** (`EDU_PROFILER=trigger` par défaut) : le nouveau bloc **Code** de la barre de debug pose le cookie `edu_profile=1` (ou paramètre `?_profile=1`) et reste actif jusqu'au clic sur **Désactiver** ; `EDU_PROFILER=on` profile chaque requête, `off` désactive le profiler. Le profil est rattaché au token de la requête et stocké compressé dans la table `serv_code_profiles` (`EDU_PROFILER_KEEP` profils conservés, 50 par défaut). Le bloc affiche le temps profilé et le top 3 des fonctions ; le nouvel onglet **Code** du profiler (`/_debug/profiler#code/{token}`) liste toutes les fonctions (temps propre / inclusif, filtre par origine `app` / `framework` / `vendor`), leurs appelants et appelés, et exporte le profil au format Speedscope pour un flamegraph. Nouvel endpoint interne `GET /edu-code-profile` (mode dev uniquement). L'image Docker installe Excimer (argument de build `EDU_PROFILER`, `EDU_PROFILER_BUILD=0` pour l'exclure) et `php bin/edu check:config` signale l'extension comme recommandée + +**documentation** + +- update [La barre de debug et le profiler](docs/boost/debug-bar.md) : nouvelle section « Le profiler de code » (installation, modes, lecture du profil, API) + ## v2.7.3 - 17/10/2026 **new features** diff --git a/Dockerfile b/Dockerfile index 7a7dc3f..bef466d 100644 --- a/Dockerfile +++ b/Dockerfile @@ -32,6 +32,13 @@ RUN install-php-extensions \ intl \ opcache +# Profiler de code de la barre de debug (Excimer, profiler par échantillonnage) +# Installé uniquement pour l'image de développement : +# docker compose build --build-arg EDU_PROFILER=0 => image sans profiler +# Doc : https://www.mediawiki.org/wiki/Excimer +ARG EDU_PROFILER=1 +RUN if [ "$EDU_PROFILER" = "1" ]; then install-php-extensions excimer; fi + # Composer (depuis l'image officielle) COPY --from=composer:2 /usr/bin/composer /usr/bin/composer diff --git a/compose.yaml b/compose.yaml index b714b4f..455e549 100644 --- a/compose.yaml +++ b/compose.yaml @@ -10,13 +10,21 @@ services: frankenphp: container_name: ${APP_NAME}-http-server - build: . + build: + context: . + args: + # Profiler de code de la barre de debug (extension Excimer) : + # 1 => installé (défaut, développement) | 0 => image sans profiler + EDU_PROFILER: ${EDU_PROFILER_BUILD:-1} # tty: true => logs lisibles en dev ; retirer pour des logs JSON (prod) tty: true environment: # Application (voir .env) APP_NAME: ${APP_NAME:-edu-framework} APP_ENV: ${APP_ENV:-dev} + # Profiler de code de la barre de debug : off | trigger | on (voir .env) + EDU_PROFILER: ${EDU_PROFILER:-trigger} + EDU_PROFILER_KEEP: ${EDU_PROFILER_KEEP:-50} TZ: ${TZ:-Europe/Paris} # Base de données : mêmes valeurs que le .env, sauf l'hôte et le port # qui, dans le réseau Docker, sont toujours ceux du service (database:3306) diff --git a/docs/boost/debug-bar.md b/docs/boost/debug-bar.md index a3aa500..226e8c5 100644 --- a/docs/boost/debug-bar.md +++ b/docs/boost/debug-bar.md @@ -208,6 +208,65 @@ Exemple de réponse : - `queries` : liste chronologique des exécutions (`rows_count` à `null` si le pilote ne fournit pas l'information, Exemple : `-1` pour un `SELECT` sous PostgreSQL) ; - `groups` : requêtes identiques regroupées avec leur nombre d'exécutions et leur temps cumulé. +## Le profiler de code + +Le profiler de code mesure **le temps passé dans chaque fonction PHP** pendant une requête HTTP, pour repérer ce qui ralentit une page. Il s'appuie sur l'extension [Excimer](https://www.mediawiki.org/wiki/Excimer){:target="_blank"} (Wikimedia), un profiler **par échantillonnage** : toutes les 0,1 ms, Excimer relève la pile d'appels en cours. Une fonction présente dans 30 % des relevés a consommé environ 30 % du temps de la requête. Le coût reste faible (quelques %) et fonctionne avec FrankenPHP, y compris en mode worker. + +!!! info "Un résultat statistique" + + Une fonction très courte (moins de 0,1 ms) peut ne jamais apparaître dans le profil. Les temps affichés sont des estimations : `nombre de relevés × 0,1 ms`. + +### Installer l'extension + +L'image Docker du framework installe Excimer par défaut (argument de build `EDU_PROFILER=1`). Pour construire une image sans profiler : + +```bash +EDU_PROFILER_BUILD=0 docker compose build +``` + +Hors Docker, installez l'extension avec PECL (`pecl install excimer`) puis activez-la dans le `php.ini` (`extension=excimer`). La commande `php bin/edu check:config` indique si l'extension est chargée. + +### Activer le profilage + +Le profilage se règle avec la variable `EDU_PROFILER` du `.env` : + +```bash +## << Config profiler de code +EDU_PROFILER=trigger +EDU_PROFILER_KEEP=50 +## >> Config profiler de code +``` + +| Valeur | Comportement | +|-----------|------------------------------------------------------------------------------| +| `off` | Profiler désactivé, le bloc **Code** est masqué | +| `trigger` | (défaut) Profilage à la demande : bouton **Code** de la barre de debug, ou paramètre `?_profile=1` dans l'URL | +| `on` | Chaque requête est profilée | + +`EDU_PROFILER_KEEP` fixe le nombre de profils conservés (les plus anciens sont supprimés, 50 par défaut). + +En mode `trigger`, un clic sur le bloc **Code** pose le cookie `edu_profile=1` et recharge la page : cette page **et les suivantes** sont profilées, jusqu'au clic sur **Désactiver** dans le panneau du bloc. + +### Lire le profil + +- Le bloc **Code** de la barre de debug affiche le temps profilé et la fonction la plus coûteuse ; son panneau liste le top 3 des fonctions. +- L'onglet **Code** du profiler (`/_debug/profiler#code/{token}`) affiche le tableau de toutes les fonctions, triable par **temps propre** (temps passé dans la fonction elle-même) ou **temps inclusif** (fonction et fonctions appelées), filtrable par origine (`app`, `framework`, `vendor`). Un clic sur une fonction affiche ses appelants et ses appelés. +- Le bouton **Télécharger (Speedscope)** exporte les piles d'appels, à ouvrir sur [speedscope.app](https://www.speedscope.app){:target="_blank"} pour obtenir un *flamegraph*. + +### L'API du profil de code + +``` +GET /edu-code-profile?token=42 +``` + +| Paramètre | Description | Défaut | +|-----------|---------------------------------------------------------------------|--------| +| `token` | Identifiant du log de la requête HTTP (`#42` accepté) | requis | +| `full` | `1` : ajoute toutes les fonctions (`functions`) et le graphe d'appels (`edges`) | — | +| `format` | `speedscope` : retourne le fichier Speedscope de la requête | — | + +La réponse contient `status` (`ready`, ou `pending` tant que le profil n'est pas enregistré), `summary` (`driver`, `period_ms`, `samples`, `wall_ms`, `peak_mb`, `functions_count`) et `top` (fonctions les plus coûteuses). Les profils sont stockés, compressés, dans la table `serv_code_profiles` de la base des logs. + ## Le stockage des logs Les requêtes HTTP traitées par le framework sont enregistrées dans une base **SQLite** dédiée : diff --git a/docs/changelog.md b/docs/changelog.md index a2041b4..066f6f1 100644 --- a/docs/changelog.md +++ b/docs/changelog.md @@ -2,6 +2,16 @@ **Présentation des versions du framework Edu Framework** +## Prochaine version (non publiée) + +**new features** + +- Profiler de code dans la barre de debug : le temps passé dans chaque fonction PHP d'une requête HTTP est mesuré par l'extension [Excimer](https://www.mediawiki.org/wiki/Excimer) (profiler par échantillonnage toutes les 0,1 ms, compatible FrankenPHP en mode classique et worker). Le profilage est **à la demande** (`EDU_PROFILER=trigger` par défaut) : le nouveau bloc **Code** de la barre de debug pose le cookie `edu_profile=1` (ou paramètre `?_profile=1`) et reste actif jusqu'au clic sur **Désactiver** ; `EDU_PROFILER=on` profile chaque requête, `off` désactive le profiler. Le profil est rattaché au token de la requête et stocké compressé dans la table `serv_code_profiles` (`EDU_PROFILER_KEEP` profils conservés, 50 par défaut). Le bloc affiche le temps profilé et le top 3 des fonctions ; le nouvel onglet **Code** du profiler (`/_debug/profiler#code/{token}`) liste toutes les fonctions (temps propre / inclusif, filtre par origine `app` / `framework` / `vendor`), leurs appelants et appelés, et exporte le profil au format Speedscope pour un flamegraph. Nouvel endpoint interne `GET /edu-code-profile` (mode dev uniquement). L'image Docker installe Excimer (argument de build `EDU_PROFILER`, `EDU_PROFILER_BUILD=0` pour l'exclure) et `php bin/edu check:config` signale l'extension comme recommandée + +**documentation** + +- update [La barre de debug et le profiler](boost/debug-bar.md) : nouvelle section « Le profiler de code » (installation, modes, lecture du profil, API) + ## v2.7.3 - 17/10/2026 **new features** diff --git a/docs/installation/docker.md b/docs/installation/docker.md index f964e7e..9a30abd 100644 --- a/docs/installation/docker.md +++ b/docs/installation/docker.md @@ -71,6 +71,9 @@ Docker Compose lit le fichier `.env` à la racine du projet et transmet ses vari | `DB_TYPE` | Type de base (`mysql`, `mariadb`, `sqlite`) | `mysql` | | `DB_USER`, `DB_PASSWORD`, `DB_NAME` | Identifiants de la base | `root` / `studoo` / `app_db` | | `MAILER_DSN` | Serveur SMTP pour l'envoi de mails | `smtp://localhost:1025` | +| `EDU_PROFILER` | Profiler de code : `off`, `trigger` (à la demande) ou `on` | `trigger` | +| `EDU_PROFILER_KEEP` | Nombre de profils de code conservés | `50` | +| `EDU_PROFILER_BUILD` | `0` construit l'image sans l'extension Excimer | `1` | !!! warning "Trois valeurs sont surchargées dans le conteneur" diff --git a/docs/installation/prerequis.md b/docs/installation/prerequis.md index c6d1905..8b818d0 100644 --- a/docs/installation/prerequis.md +++ b/docs/installation/prerequis.md @@ -251,6 +251,16 @@ Pour cela, vous devez ouvrir votre fichier php.ini et décommenter la ligne suiv ```` Enlever le point-virgule pour activer l'extension. +#### excimer extension (optionnelle) + +L'extension `excimer` active le [profiler de code](../boost/debug-bar.md#le-profiler-de-code) de la barre de debug. +Elle est déjà installée dans l'image Docker du framework. Hors Docker : + +````Bash +pecl install excimer +```` +Puis ajoutez la ligne `extension=excimer` dans votre fichier php.ini. + ___ ## :simple-composer: Gestionnaire de dépendance diff --git a/src/EduFramework/Commands/Extends/CkeckStack.php b/src/EduFramework/Commands/Extends/CkeckStack.php index 2085890..c70ea0b 100644 --- a/src/EduFramework/Commands/Extends/CkeckStack.php +++ b/src/EduFramework/Commands/Extends/CkeckStack.php @@ -75,6 +75,8 @@ public function render(): void $this->checkExtension('mbstring'); $this->checkExtension('openssl'); $this->checkExtension('json'); + // Extension optionnelle : profiler de code de la barre de debug + $this->checkExtension('excimer'); } /** diff --git a/src/EduFramework/Core/Controller/Debug/DebugCodeProfileController.php b/src/EduFramework/Core/Controller/Debug/DebugCodeProfileController.php new file mode 100644 index 0000000..d9d16ad --- /dev/null +++ b/src/EduFramework/Core/Controller/Debug/DebugCodeProfileController.php @@ -0,0 +1,135 @@ +get('format') === 'speedscope'); + + // L'en-tête n'est envoyé que si la sortie n'a pas déjà commencé + // (Exemple : exécution dans un contexte de test) + if (headers_sent() === false) { + header('Content-Type: application/json; charset=utf-8'); + } + + $token = ltrim((string) $request->get('token'), '#'); + if (preg_match('/^\d{1,18}$/', $token) !== 1) { + return json_encode(['token' => null, 'status' => 'pending', 'summary' => null, 'top' => []]); + } + + $tokenId = (int) $token; + $full = ((string) $request->get('full') === '1'); + $profile = LogsService::getCodeProfile($tokenId, ($full === true || $speedscope === true)); + + if ($profile === null) { + return json_encode(['token' => $tokenId, 'status' => 'pending', 'summary' => null, 'top' => []]); + } + + if ($speedscope === true) { + return $this->speedscope($tokenId, $profile); + } + + $response = [ + 'token' => $tokenId, + 'status' => 'ready', + 'summary' => [ + 'driver' => $profile['driver'], + 'period_ms' => $profile['period_ms'], + 'samples' => $profile['samples'], + 'wall_ms' => $profile['wall_ms'], + 'peak_mb' => $profile['peak_mb'], + 'functions_count' => $profile['functions_count'], + ], + 'top' => $profile['top'], + ]; + + if ($full === true) { + $response += $this->details($profile); + } + + return json_encode($response); + } + + /** + * Retourne les piles d'appels du profil au format Speedscope (fichier téléchargé) + * + * @param int $tokenId Identifiant du log de la requête HTTP + * @param array $profile Profil avec ses données (LogsService::getCodeProfile) + * @return string + */ + private function speedscope(int $tokenId, array $profile): string + { + if (headers_sent() === false) { + header('Content-Disposition: attachment; filename="edu-profile-' . $tokenId . '.speedscope.json"'); + } + $data = $profile['data']['speedscope'] ?? []; + if (is_array($data) === true && isset($data['profiles'][0]) === true) { + $data['name'] = 'Edu Framework #' . $tokenId; + $data['profiles'][0]['name'] = 'Requête #' . $tokenId; + } + + return (string) json_encode($data); + } + + /** + * Détail complet du profil : toutes les fonctions et le graphe d'appels + * + * @param array $profile Profil avec ses données (LogsService::getCodeProfile) + * @return array{functions: array>, edges: array>} + */ + private function details(array $profile): array + { + $data = $profile['data']; + $speedscope = (is_array($data['speedscope'] ?? null) === true ? $data['speedscope'] : []); + + return [ + 'functions' => CodeProfileAggregator::byFunction($data), + 'edges' => CodeProfileAggregator::callGraph($speedscope, (float) ($data['period_ms'] ?? $profile['period_ms'])), + ]; + } +} diff --git a/src/EduFramework/Core/Controller/Template/profiler.html.twig b/src/EduFramework/Core/Controller/Template/profiler.html.twig index 95c6375..c9ea010 100644 --- a/src/EduFramework/Core/Controller/Template/profiler.html.twig +++ b/src/EduFramework/Core/Controller/Template/profiler.html.twig @@ -247,6 +247,33 @@ .status-text { font-weight: bold; } .back-link { margin-bottom: 14px; } + /* Onglet Code : profiler du code PHP (Excimer) */ + .code-filters { display: flex; flex-wrap: wrap; gap: 14px; margin: 0 0 14px; font-size: 14px; } + .code-filters label { display: flex; align-items: center; gap: 6px; cursor: pointer; } + .code-note { margin: 0 0 16px; font-size: 13px; color: #777; } + .code-actions { margin: 0 0 16px; display: flex; gap: 10px; flex-wrap: wrap; } + .origin-badge { display: inline-block; padding: 2px 6px; border-radius: 2px; font-size: 12px; font-weight: bold; white-space: nowrap; background: #eee; color: #555; } + .origin-badge.app { background: #fff1c2; color: #7a5b00; } + .origin-badge.framework { background: #cfe2ff; color: #0b4f8a; } + .origin-badge.vendor { background: #e8e0f5; color: #5a3d8a; } + #codeBody tr.app td { background: #fffbea; } + #codeBody tr { cursor: pointer; } + #codeBody tr.selected td { background: #e8f0fe; } + .code-fn { font-family: monospace; font-size: 13px; word-break: break-all; } + .code-file { display: block; color: #888; font-size: 12px; font-family: monospace; word-break: break-all; } + .code-bar { display: inline-block; height: 6px; background: #4f805d; border-radius: 3px; vertical-align: middle; margin-right: 6px; } + .profiler-table th.sortable button { all: inherit; cursor: pointer; user-select: none; display: inline; padding: 0; border: 0; background: none; } + .profiler-table th.sortable button:focus-visible, .code-fn-btn:focus-visible { outline: 2px solid #4f805d; outline-offset: 2px; } + .profiler-table th.sortable.sorted button::after { content: ' \25BE'; } + .code-fn-btn { font-family: monospace; font-size: 13px; color: inherit; text-align: left; background: none; border: 0; padding: 0; cursor: pointer; } + #codeGraph .code-fn-btn { color: #0b62a3; text-decoration: underline; } + #codeGraph { margin-top: 24px; } + #codeGraph h2 { font-size: 16px; margin: 0 0 10px; } + .code-graph-cols { display: grid; grid-template-columns: 1fr 1fr; gap: 20px; } + .code-graph-cols h3 { font-size: 13px; text-transform: uppercase; color: #777; margin: 0 0 6px; } + .code-graph-cols a { cursor: pointer; } + .profiled-badge { display: inline-block; margin-left: 6px; padding: 1px 5px; border-radius: 2px; font-size: 11px; background: #fff1c2; color: #7a5b00; text-decoration: none; } + @media (max-width: 800px) { .code-graph-cols { grid-template-columns: 1fr; } } @@ -290,6 +317,7 @@ @@ -399,6 +427,40 @@ + + @@ -409,6 +471,10 @@ var token = ''; var requestToken = ''; var sqlToken = ''; + var codeToken = ''; + var codeData = null; + var codeSort = 'self'; + var codeSelected = null; var logsStatus = ''; var searchFilters = { limit: 20 }; @@ -468,6 +534,14 @@ return fetch('/edu-sql-logs?' + url.toString()).then(function(response) { return response.json(); }); } + function codeQuery(params) { + var url = new URLSearchParams(); + Object.keys(params).forEach(function(key) { + if (params[key] !== '' && params[key] !== undefined && params[key] !== null) { url.set(key, params[key]); } + }); + return fetch('/edu-code-profile?' + url.toString()).then(function(response) { return response.json(); }); + } + function fail(error) { console.error('[EduFramework Profiler]', error); } // ----- Contexte d'un log : tronqué si long, complet au clic ("Show full context") ----- @@ -635,6 +709,12 @@ tr.appendChild(tdMethod); var tdPath = el('td'); tdPath.appendChild(requestLink(log.id, log.event.path)); + if (log.profiled === true) { + var badge = el('a', 'profiled-badge', 'profil'); + badge.href = '#code/' + log.id; + badge.title = 'Profil du code de cette requ\u00eate'; + tdPath.appendChild(badge); + } tr.appendChild(tdPath); var tdSapi = el('td', 'nowrap'); tdSapi.appendChild(sapiBadge(log.event.sapi)); @@ -680,6 +760,18 @@ } } + function updateCodeNav(id) { + // L'entrée "Code" de la navigation suit le dernier profil consulté + var link = $('navCode'); + if (id) { + link.classList.remove('disabled'); + link.setAttribute('href', '#code/' + id); + } else { + link.classList.add('disabled'); + link.setAttribute('href', '#'); + } + } + function requestRow(label, valueNode) { var tr = el('tr'); tr.appendChild(el('td', 'req-label', label)); @@ -720,6 +812,11 @@ sqlLink.href = '#sql/' + log.id; sqlLink.id = 'requestSqlLink'; body.appendChild(requestRow('Requ\u00eates SQL', sqlLink)); + // Profil du code : présent seulement si la requête a été profilée + var codeLink = el('a', null, log.profiled === true ? 'Voir le profil du code' : 'Requ\u00eate non profil\u00e9e'); + codeLink.href = '#code/' + log.id; + codeLink.id = 'requestCodeLink'; + body.appendChild(requestRow('Profil du code', codeLink)); if (e.error_message !== undefined) { body.appendChild(requestRow('Erreur', el('pre', 'error-message', e.error_message))); } @@ -851,6 +948,177 @@ }).catch(fail); } + // ----- Vue "profil du code d'une requête HTTP" ----- + function originBadge(origin) { + var labels = { app: 'mon code', framework: 'framework', vendor: 'vendor', other: 'autre' }; + return el('span', 'origin-badge ' + origin, labels[origin] || origin); + } + + function codeFilters() { + var origins = []; + document.querySelectorAll('#codeFilters input:checked').forEach(function(node) { origins.push(node.value); }); + return origins; + } + + function timeCell(ms, pct, max) { + var td = el('td', 'nowrap'); + var bar = el('span', 'code-bar'); + bar.style.width = Math.max(2, Math.round(pct / Math.max(max, 1) * 80)) + 'px'; + td.appendChild(bar); + td.appendChild(el('b', null, prettyNumber(ms, 2) + ' ms')); + td.appendChild(document.createTextNode(' (' + prettyNumber(pct, 1) + ' %)')); + return td; + } + + function renderCodeEmpty(message) { + $('codeMeta').innerHTML = ''; + $('codeActions').classList.add('hidden'); + $('codeGraph').classList.add('hidden'); + var body = $('codeBody'); + body.innerHTML = ''; + var tr = el('tr'); + var td = el('td', 'empty-state'); + td.colSpan = 4; + td.appendChild(document.createTextNode(message + ' ')); + var activate = el('a', null, 'Activer le profilage et rouvrir la page'); + activate.href = '#'; + activate.addEventListener('click', function(event) { + event.preventDefault(); + document.cookie = 'edu_profile=1; path=/; SameSite=Lax'; + query({ token: codeToken, limit: 1 }).then(function(data) { + var path = (data.logs.length > 0 && data.logs[0].event) ? data.logs[0].event.path : '/'; + // Seule une URL du site est rouverte (le chemin journalisé vient de la requête HTTP) + var url = new URL(path || '/', window.location.origin); + if (url.origin !== window.location.origin) { url = new URL('/', window.location.origin); } + window.open(url.href, '_blank', 'noopener'); + }).catch(fail); + }); + td.appendChild(activate); + tr.appendChild(td); + body.appendChild(tr); + } + + function renderCodeTable() { + var body = $('codeBody'); + body.innerHTML = ''; + var origins = codeFilters(); + var functions = codeData.functions.filter(function(fn) { + return origins.indexOf(fn.origin) !== -1 && (fn.self > 0 || fn.inclusive > 0); + }); + functions.sort(function(a, b) { return b[codeSort] - a[codeSort]; }); + document.querySelectorAll('#codeTable th.sortable').forEach(function(node) { + node.classList.toggle('sorted', node.getAttribute('data-sort') === codeSort); + }); + + if (functions.length === 0) { + var trEmpty = el('tr'); + var tdEmpty = el('td', 'empty-state', 'Aucune fonction pour ce filtre : cochez Framework ou Autre pour voir le reste du code ex\u00e9cut\u00e9'); + tdEmpty.colSpan = 4; + trEmpty.appendChild(tdEmpty); + body.appendChild(trEmpty); + return; + } + + var maxSelf = Math.max.apply(null, functions.map(function(fn) { return fn.self_pct; })); + var maxInclusive = Math.max.apply(null, functions.map(function(fn) { return fn.inclusive_pct; })); + functions.forEach(function(fn) { + var tr = el('tr', fn.origin === 'app' ? 'app' : null); + if (fn.name === codeSelected) { tr.classList.add('selected'); } + var tdName = el('td'); + // Bouton : la sélection est aussi accessible au clavier + var nameButton = el('button', 'code-fn code-fn-btn', fn.name); + nameButton.type = 'button'; + nameButton.addEventListener('click', function(event) { event.stopPropagation(); selectFunction(fn.name); }); + tdName.appendChild(nameButton); + if (fn.file) { tdName.appendChild(el('span', 'code-file', fn.file + (fn.line ? ':' + fn.line : ''))); } + tr.appendChild(tdName); + var tdOrigin = el('td'); + tdOrigin.appendChild(originBadge(fn.origin)); + tr.appendChild(tdOrigin); + tr.appendChild(timeCell(fn.self_ms, fn.self_pct, maxSelf)); + tr.appendChild(timeCell(fn.inclusive_ms, fn.inclusive_pct, maxInclusive)); + tr.addEventListener('click', function() { selectFunction(fn.name); }); + body.appendChild(tr); + }); + } + + function graphRows(target, edges, key) { + target.innerHTML = ''; + if (edges.length === 0) { + var tr = el('tr'); + tr.appendChild(el('td', 'empty-state', '\u2014')); + target.appendChild(tr); + return; + } + edges.forEach(function(edge) { + var tr = el('tr'); + var td = el('td'); + var link = el('button', 'code-fn code-fn-btn', edge[key]); + link.type = 'button'; + link.addEventListener('click', function() { selectFunction(edge[key]); }); + td.appendChild(link); + tr.appendChild(td); + tr.appendChild(el('td', 'nowrap', prettyNumber(edge.ms, 2) + ' ms')); + target.appendChild(tr); + }); + } + + function selectFunction(name) { + codeSelected = name; + renderCodeTable(); + $('codeGraph').classList.remove('hidden'); + $('codeGraphTitle').textContent = name; + graphRows($('codeCallers'), codeData.edges.filter(function(edge) { return edge.callee === name; }), 'caller'); + graphRows($('codeCallees'), codeData.edges.filter(function(edge) { return edge.caller === name; }), 'callee'); + $('codeGraph').scrollIntoView({ behavior: 'smooth', block: 'nearest' }); + } + + function renderCode(data) { + codeSelected = null; + $('codeGraph').classList.add('hidden'); + $('codeTitle').textContent = 'Profil du code \u2014 requ\u00eate #' + codeToken; + if (data.status !== 'ready') { + codeData = null; + renderCodeEmpty('Cette requ\u00eate n\'a pas \u00e9t\u00e9 profil\u00e9e (ou le profil a \u00e9t\u00e9 supprim\u00e9 : seuls les derniers sont conserv\u00e9s).'); + return; + } + codeData = data; + var meta = $('codeMeta'); + meta.innerHTML = ''; + meta.appendChild(document.createTextNode('Temps profil\u00e9 : ')); + meta.appendChild(el('b', null, prettyNumber(data.summary.wall_ms, 1) + ' ms')); + meta.appendChild(document.createTextNode(' \u2014 ' + data.summary.samples + ' \u00e9chantillons (1 toutes les ' + + prettyNumber(data.summary.period_ms, 1) + ' ms) \u2014 ' + data.summary.functions_count + ' fonctions \u2014 m\u00e9moire ' + + prettyMemory(data.summary.peak_mb) + ' \u2014 driver ' + data.summary.driver)); + $('codeActions').classList.remove('hidden'); + $('codeSpeedscope').href = '/edu-code-profile?token=' + encodeURIComponent(codeToken) + '&format=speedscope'; + $('codeSpeedscope').setAttribute('download', 'edu-profile-' + codeToken + '.speedscope.json'); + renderCodeTable(); + } + + function loadCode() { + if (codeToken === '') { + $('summary').classList.add('hidden'); + renderCode({ status: 'pending' }); + return; + } + var requested = codeToken; + Promise.all([ + query({ token: requested, limit: 1 }), + codeQuery({ token: requested, full: 1 }) + ]).then(function(results) { + // Réponse d'un profil qui n'est plus affiché : ignorée + if (requested !== codeToken || window.location.hash.indexOf('#code/') !== 0) { return; } + var log = (results[0].logs.length > 0 ? results[0].logs[0] : null); + if (log !== null) { + renderSummary(log); + } else { + $('summary').classList.add('hidden'); + } + renderCode(results[1]); + }).catch(fail); + } + // ----- Navigation entre les vues ----- function show(name) { view = name; @@ -859,6 +1127,7 @@ $('viewLogs').classList.toggle('hidden', name !== 'logs'); $('viewRequest').classList.toggle('hidden', name !== 'request'); $('viewSql').classList.toggle('hidden', name !== 'sql'); + $('viewCode').classList.toggle('hidden', name !== 'code'); $('searchForm').classList.toggle('hidden', !isSearch); $('logsNav').classList.toggle('hidden', isSearch); $('searchTitle').classList.toggle('hidden', !isSearch); @@ -867,6 +1136,7 @@ document.querySelectorAll('#logsNav a').forEach(function(node) { node.classList.toggle('active', (name === 'request' && node.id === 'navRequest') || (name === 'sql' && node.id === 'navSql') + || (name === 'code' && node.id === 'navCode') || (name === 'logs' && node.getAttribute('href') === '#logs')); }); } @@ -890,6 +1160,12 @@ if (sqlToken !== '') { $('sqlBackLink').setAttribute('href', '#request/' + sqlToken); } show('sql'); loadSql(); + } else if (hash[0] === 'code') { + codeToken = hash[1] || ''; + updateCodeNav(codeToken); + if (codeToken !== '') { $('codeBackLink').setAttribute('href', '#request/' + codeToken); } + show('code'); + loadCode(); } else { show('search'); loadSearch(); @@ -955,6 +1231,15 @@ loadLogs(); }); + $('codeFilters').addEventListener('change', function() { if (codeData !== null) { renderCodeTable(); } }); + + $('codeTable').querySelector('thead').addEventListener('click', function(event) { + var th = event.target.closest('th.sortable'); + if (th === null || codeData === null) { return; } + codeSort = th.getAttribute('data-sort'); + renderCodeTable(); + }); + window.addEventListener('hashchange', route); route(); })(); diff --git a/src/EduFramework/Core/LoadCouchCore.php b/src/EduFramework/Core/LoadCouchCore.php index 02b1b52..5a94380 100644 --- a/src/EduFramework/Core/LoadCouchCore.php +++ b/src/EduFramework/Core/LoadCouchCore.php @@ -14,6 +14,7 @@ use Dotenv\Dotenv; use PDO; use Studoo\EduFramework\Core\ConfigCore; +use Studoo\EduFramework\Core\Controller\Debug\DebugCodeProfileController; use Studoo\EduFramework\Core\Controller\Debug\DebugLogsController; use Studoo\EduFramework\Core\Controller\Debug\DebugSqlLogsController; use Studoo\EduFramework\Core\Controller\Debug\ProfilerController; @@ -27,6 +28,7 @@ use Studoo\EduFramework\Core\Logs\HttpRequestLogger; use Studoo\EduFramework\Core\Logs\LogsService; use Studoo\EduFramework\Core\Logs\SqlQueryLogger; +use Studoo\EduFramework\Core\Profiler\CodeProfiler; use Studoo\EduFramework\Core\Service\DatabaseService; use Studoo\EduFramework\Core\View\TwigCore; @@ -65,6 +67,10 @@ public function run(): void // d'exécution et mémoire) dans le bloc finally HttpRequestLogger::start(); + // Profiler de code de la barre de debug : démarre le profilage de la requête + // si elle est journalisée et si le profilage est demandé (bouton Code de la barre) + CodeProfiler::start(); + // Gestion des routes $route = new FastRouteCore(); @@ -78,6 +84,7 @@ public function run(): void $route->addRoute('GET', '/_debug/profiler', ProfilerController::class); $route->addRoute('GET', '/edu-logs', DebugLogsController::class); $route->addRoute('GET', '/edu-sql-logs', DebugSqlLogsController::class); + $route->addRoute('GET', '/edu-code-profile', DebugCodeProfileController::class); } // Récupération de la route à appeler @@ -100,6 +107,9 @@ public function run(): void HttpRequestLogger::setError($exception); echo (new HttpErrorDefaultController($exception))->execute($this->getRequest()); } finally { + // Arrête le profilage avant d'écrire les logs, pour ne pas profiler la journalisation, + // puis enregistre le profil de code rattaché au token de la requête + CodeProfiler::stop(); // Écrit les requêtes SQL collectées pendant la requête (table serv_sql_logs), // rattachées par le token de la requête HTTP, puis complète la ligne de // log réservée en début de requête : statut final, temps d'exécution et mémoire diff --git a/src/EduFramework/Core/Logs/HttpRequestLogger.php b/src/EduFramework/Core/Logs/HttpRequestLogger.php index 91373d4..489a788 100644 --- a/src/EduFramework/Core/Logs/HttpRequestLogger.php +++ b/src/EduFramework/Core/Logs/HttpRequestLogger.php @@ -179,7 +179,8 @@ private static function shouldLog(): bool return str_starts_with($path, '/_debug/') === false && str_starts_with($path, '/edu-logs') === false - && str_starts_with($path, '/edu-sql-logs') === false; + && str_starts_with($path, '/edu-sql-logs') === false + && str_starts_with($path, '/edu-code-profile') === false; } /** diff --git a/src/EduFramework/Core/Logs/LogsInitialiser.php b/src/EduFramework/Core/Logs/LogsInitialiser.php index 2e5b5b7..50e444b 100644 --- a/src/EduFramework/Core/Logs/LogsInitialiser.php +++ b/src/EduFramework/Core/Logs/LogsInitialiser.php @@ -11,8 +11,20 @@ namespace Studoo\EduFramework\Core\Logs; +/** + * Class LogsInitialiser + * Crée la structure de la base SQLite des logs (var/logs/core_logs.sqlite) : + * tables des requêtes HTTP, des requêtes SQL et des profils de code + * + * @package Studoo\EduFramework\Core\Logs + */ class LogsInitialiser { + /** + * Crée les tables de la base des logs si elles n'existent pas encore + * + * @return void + */ public function exeStructure(): void { try { @@ -38,6 +50,22 @@ public function exeStructure(): void event_date TEXT DEFAULT (datetime('now')) )"); $pdo->exec("CREATE INDEX IF NOT EXISTS idx_serv_sql_logs_request_id ON serv_sql_logs (request_id)"); + + // Table des profils de code (profiler de la barre de debug), un profil + // par requête HTTP, rattaché par l'identifiant du log de la requête (request_id) + $pdo->exec("CREATE TABLE IF NOT EXISTS serv_code_profiles ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + request_id INTEGER NOT NULL UNIQUE, + driver TEXT NOT NULL, + period_ms REAL NOT NULL, + samples INTEGER NOT NULL, + wall_ms REAL NOT NULL, + peak_mb REAL, + functions_count INTEGER NOT NULL, + top_json TEXT NOT NULL, + data BLOB NOT NULL, + event_date TEXT DEFAULT (datetime('now')) + )"); } catch (\PDOException $e) { error_log('[EduFramework Logs] ' . $e->getMessage()); } diff --git a/src/EduFramework/Core/Logs/LogsService.php b/src/EduFramework/Core/Logs/LogsService.php index 71f4a8b..17e2376 100644 --- a/src/EduFramework/Core/Logs/LogsService.php +++ b/src/EduFramework/Core/Logs/LogsService.php @@ -15,6 +15,13 @@ use Studoo\EduFramework\Core\ConfigCore; use Studoo\EduFramework\Core\Service\DatabaseSqlite; +/** + * Class LogsService + * Accès à la base SQLite des logs (var/logs/core_logs.sqlite) : écriture et lecture + * des requêtes HTTP, des requêtes SQL et des profils de code du profiler + * + * @package Studoo\EduFramework\Core\Logs + */ class LogsService { private string $dbNameLogs = 'core_logs'; @@ -110,14 +117,17 @@ public static function updateLog(int $id, string $eventDesc): void * @param int $limit Nombre de logs à récupérer * @param int $offset Décalage pour la pagination * @param array $filters Filtres optionnels - * @return array> Liste des logs (id, event_date, event) + * @return array> Liste des logs (id, event_date, event, profiled : + * la requête a un profil de code) */ public static function getLogs(int $limit = 20, int $offset = 0, array $filters = []): array { [$where, $params] = self::buildFilters($filters); $stmt = self::getConnect()->prepare( - 'SELECT id, event_date, event_desc FROM serv_logs' . $where + 'SELECT id, event_date, event_desc, ' + . '(SELECT COUNT(*) FROM serv_code_profiles WHERE request_id = serv_logs.id) AS profiled ' + . 'FROM serv_logs' . $where . ' ORDER BY id DESC LIMIT :limit OFFSET :offset' ); foreach ($params as $key => $value) { @@ -134,6 +144,7 @@ public static function getLogs(int $limit = 20, int $offset = 0, array $filters 'id' => (int) $row['id'], 'event_date' => $row['event_date'], 'event' => (is_array($event) === true ? $event : ['raw' => (string) $row['event_desc']]), + 'profiled' => ((int) $row['profiled'] > 0), ]; } @@ -330,4 +341,73 @@ public static function getSqlGroups(int $tokenId): array return $groups; } + + /** + * Permets de récupérer le profil de code d'une requête HTTP (rattaché par + * le token du log de la requête), enregistré par CodeProfileLogger + * + * @param int $tokenId Identifiant du log de la requête HTTP + * @param bool $withData true pour décompresser aussi les données complètes (clé data) + * @return array|null Profil (driver, period_ms, samples, wall_ms, peak_mb, + * functions_count, top, event_date, data), null si la requête n'a pas de profil + */ + public static function getCodeProfile(int $tokenId, bool $withData = false): ?array + { + $stmt = self::getConnect()->prepare( + 'SELECT driver, period_ms, samples, wall_ms, peak_mb, functions_count, top_json, event_date' + . ($withData === true ? ', data' : '') + . ' FROM serv_code_profiles WHERE request_id = :request_id' + ); + $stmt->bindValue(':request_id', $tokenId, PDO::PARAM_INT); + $stmt->execute(); + $row = $stmt->fetch(PDO::FETCH_ASSOC); + if ($row === false) { + return null; + } + + $profile = [ + 'driver' => (string) $row['driver'], + 'period_ms' => (float) $row['period_ms'], + 'samples' => (int) $row['samples'], + 'wall_ms' => (float) $row['wall_ms'], + 'peak_mb' => ($row['peak_mb'] === null ? null : (float) $row['peak_mb']), + 'functions_count' => (int) $row['functions_count'], + 'top' => json_decode((string) $row['top_json'], true) ?: [], + 'event_date' => $row['event_date'], + ]; + + if ($withData === true) { + $raw = self::uncompress((string) $row['data']); + $data = ($raw === null ? null : json_decode($raw, true)); + $profile['data'] = (is_array($data) === true ? $data : []); + } + + return $profile; + } + + /** + * Décompresse les données d'un profil de code (gzcompress) + * Un profil corrompu ne doit pas faire échouer le profiler : l'erreur + * de gzuncompress() est convertie en exception puis envoyée dans les logs PHP + * + * @param string $payload Données compressées + * @return string|null Données décompressées, null si elles sont invalides + */ + private static function uncompress(string $payload): ?string + { + set_error_handler(static function (int $severity, string $message, string $file, int $line): bool { + throw new \ErrorException($message, 0, $severity, $file, $line); + }); + + try { + $raw = gzuncompress($payload); + } catch (\ErrorException $exception) { + error_log('[EduFramework Profiler] Profil illisible : ' . $exception->getMessage()); + $raw = false; + } finally { + restore_error_handler(); + } + + return ($raw === false ? null : $raw); + } } diff --git a/src/EduFramework/Core/Profiler/CodeProfileAggregator.php b/src/EduFramework/Core/Profiler/CodeProfileAggregator.php new file mode 100644 index 0000000..975d153 --- /dev/null +++ b/src/EduFramework/Core/Profiler/CodeProfileAggregator.php @@ -0,0 +1,210 @@ + appelé) reconstruit depuis les piles d'appels. + * + * Rappel : un profiler par échantillonnage relève la pile d'appels toutes les + * `period_ms` millisecondes. Une fonction présente dans 30 échantillons à 0,1 ms + * a donc tourné environ 3 ms. Une fonction plus courte que la période peut + * ne pas apparaître du tout. + * + * @package Studoo\EduFramework\Core\Profiler + */ +class CodeProfileAggregator +{ + /** + * Calcule le détail par fonction, trié par temps propre décroissant + * + * @param array $data Données du driver (period_ms, samples, functions) + * @return array> Fonctions (name, origin, file, line, self, inclusive, + * self_ms, inclusive_ms, self_pct, inclusive_pct) + */ + public static function byFunction(array $data): array + { + $periodMs = (float) ($data['period_ms'] ?? 0); + $total = max(1, (int) ($data['samples'] ?? 0)); + $functions = []; + + foreach (($data['functions'] ?? []) as $name => $info) { + $self = (float) ($info['self'] ?? 0); + $inclusive = (float) ($info['inclusive'] ?? 0); + $file = (isset($info['file']) === true ? (string) $info['file'] : null); + $functions[] = [ + 'name' => self::displayName((string) $name), + 'origin' => self::origin($file), + 'file' => ($file === null ? null : self::relativePath($file)), + 'line' => (isset($info['line']) === true ? (int) $info['line'] : null), + 'self' => $self, + 'inclusive' => $inclusive, + 'self_ms' => round($self * $periodMs, 2), + 'inclusive_ms' => round($inclusive * $periodMs, 2), + 'self_pct' => round($self * 100 / $total, 1), + 'inclusive_pct' => round($inclusive * 100 / $total, 1), + ]; + } + + usort( + $functions, + static fn (array $left, array $right): int + => [$right['self'], $right['inclusive']] <=> [$left['self'], $left['inclusive']] + ); + + return $functions; + } + + /** + * Retourne les fonctions qui consomment le plus de temps propre + * + * @param array> $functions Résultat de byFunction() + * @param int $limit Nombre de fonctions retournées + * @return array> + */ + public static function top(array $functions, int $limit = 20): array + { + $functions = array_values(array_filter($functions, static fn (array $function): bool => $function['self'] > 0)); + + return array_slice($functions, 0, $limit); + } + + /** + * Reconstruit le graphe d'appels depuis les piles d'appels au format Speedscope : + * pour chaque couple appelant => appelé, le nombre d'échantillons dans lesquels + * l'appelant était en train d'exécuter l'appelé + * + * @param array $speedscope Données Speedscope du driver + * @param float $periodMs Période d'échantillonnage en millisecondes + * @return array + */ + public static function callGraph(array $speedscope, float $periodMs): array + { + $frames = $speedscope['shared']['frames'] ?? []; + $profile = $speedscope['profiles'][0] ?? []; + $samples = $profile['samples'] ?? []; + $weights = $profile['weights'] ?? []; + $periodNs = $periodMs * 1000000; + $edges = []; + + foreach ($samples as $index => $stack) { + // Un échantillon peut représenter plusieurs périodes (dépassement du timer) + $count = ($periodNs > 0 ? max(1, (int) round(($weights[$index] ?? $periodNs) / $periodNs)) : 1); + $seen = []; + $stackSize = count($stack); + for ($i = 1; $i < $stackSize; $i++) { + $caller = self::displayName((string) ($frames[$stack[$i - 1]]['name'] ?? '?')); + $callee = self::displayName((string) ($frames[$stack[$i]]['name'] ?? '?')); + $key = $caller . "\0" . $callee; + // Une fonction récursive ne compte qu'une fois par échantillon + if (isset($seen[$key]) === true) { + continue; + } + $seen[$key] = true; + $edges[$key] ??= ['caller' => $caller, 'callee' => $callee, 'samples' => 0, 'ms' => 0.0]; + $edges[$key]['samples'] += $count; + } + } + + foreach ($edges as $key => $edge) { + $edges[$key]['ms'] = round($edge['samples'] * $periodMs, 2); + } + usort($edges, static fn (array $left, array $right): int => $right['samples'] <=> $left['samples']); + + return $edges; + } + + /** + * Détermine l'origine d'une fonction d'après le fichier où elle est définie + * + * @param string|null $file Chemin du fichier + * @return string app, framework, vendor ou other + */ + public static function origin(?string $file): string + { + if ($file === null || $file === '') { + return 'other'; + } + + $file = str_replace('\\', '/', $file); + $base = self::basePath(); + + if (str_contains($file, '/vendor/studoo/edu-framework/') === true) { + return 'framework'; + } + if (str_contains($file, '/vendor/') === true) { + return 'vendor'; + } + if ($base !== null && str_starts_with($file, $base) === true) { + $relative = substr($file, strlen($base)); + return match (true) { + str_starts_with($relative, 'app/') => 'app', + str_starts_with($relative, 'src/'), str_starts_with($relative, 'public/'), str_starts_with($relative, 'bin/') => 'framework', + default => 'other', + }; + } + + return 'other'; + } + + /** + * @param string $file Chemin absolu + * @return string Chemin relatif à la racine du projet (base_path), sinon le chemin d'origine + */ + private static function relativePath(string $file): string + { + $normalized = str_replace('\\', '/', $file); + $base = self::basePath(); + + return ($base !== null && str_starts_with($normalized, $base) === true) + ? substr($normalized, strlen($base)) + : $file; + } + + /** + * Nom affiché d'une fonction : le code exécuté hors fonction (fichier + * de la page) est affiché par son chemin relatif + * + * @param string $name Nom fourni par le driver + * @return string + */ + private static function displayName(string $name): string + { + if (str_contains($name, '/') === true && str_contains($name, '{closure') === false) { + return self::relativePath($name); + } + + return $name; + } + + /** + * @return string|null Racine du projet normalisée, terminée par un slash + */ + private static function basePath(): ?string + { + $base = ConfigCore::getConfig('base_path'); + if (is_string($base) === false || $base === '') { + return null; + } + $real = realpath($base); + + return rtrim(str_replace('\\', '/', ($real === false ? $base : $real)), '/') . '/'; + } +} diff --git a/src/EduFramework/Core/Profiler/CodeProfileLogger.php b/src/EduFramework/Core/Profiler/CodeProfileLogger.php new file mode 100644 index 0000000..4618523 --- /dev/null +++ b/src/EduFramework/Core/Profiler/CodeProfileLogger.php @@ -0,0 +1,99 @@ + $data Données brutes du driver + * @return void + */ + public static function save(int $requestId, string $driver, float $wallMs, float $peakMb, array $data): void + { + $functions = CodeProfileAggregator::byFunction($data); + $payload = gzcompress((string) json_encode($data)); + + $pdo = LogsService::getConnect(); + $stmt = $pdo->prepare( + 'INSERT OR REPLACE INTO serv_code_profiles ' + . '(request_id, driver, period_ms, samples, wall_ms, peak_mb, functions_count, top_json, data) ' + . 'VALUES (:request_id, :driver, :period_ms, :samples, :wall_ms, :peak_mb, :functions_count, :top_json, :data)' + ); + $stmt->bindValue(':request_id', $requestId, PDO::PARAM_INT); + $stmt->bindValue(':driver', $driver, PDO::PARAM_STR); + $stmt->bindValue(':period_ms', (float) ($data['period_ms'] ?? 0)); + $stmt->bindValue(':samples', (int) ($data['samples'] ?? 0), PDO::PARAM_INT); + $stmt->bindValue(':wall_ms', $wallMs); + $stmt->bindValue(':peak_mb', $peakMb); + $stmt->bindValue(':functions_count', count($functions), PDO::PARAM_INT); + $stmt->bindValue(':top_json', (string) json_encode(CodeProfileAggregator::top($functions, 10)), PDO::PARAM_STR); + $stmt->bindValue(':data', ($payload === false ? '' : $payload), PDO::PARAM_LOB); + $stmt->execute(); + + self::purge(self::keep()); + } + + /** + * Supprime les profils les plus anciens pour n'en garder que $keep + * + * @param int $keep Nombre de profils conservés + * @return void + */ + public static function purge(int $keep): void + { + $stmt = LogsService::getConnect()->prepare( + 'DELETE FROM serv_code_profiles WHERE id NOT IN ' + . '(SELECT id FROM serv_code_profiles ORDER BY id DESC LIMIT :keep)' + ); + $stmt->bindValue(':keep', max(1, $keep), PDO::PARAM_INT); + $stmt->execute(); + } + + /** + * @return int Nombre de profils conservés (variable EDU_PROFILER_KEEP) + */ + private static function keep(): int + { + if (ConfigCore::existEnv('EDU_PROFILER_KEEP') === true && ctype_digit((string) ConfigCore::getEnv('EDU_PROFILER_KEEP')) === true) { + return max(1, (int) ConfigCore::getEnv('EDU_PROFILER_KEEP')); + } + + return self::DEFAULT_KEEP; + } +} diff --git a/src/EduFramework/Core/Profiler/CodeProfiler.php b/src/EduFramework/Core/Profiler/CodeProfiler.php new file mode 100644 index 0000000..4407c87 --- /dev/null +++ b/src/EduFramework/Core/Profiler/CodeProfiler.php @@ -0,0 +1,191 @@ +start(); + self::$requestId = $requestId; + } catch (\Throwable $exception) { + error_log('[EduFramework Profiler] ' . $exception->getMessage()); + } + } + + /** + * Arrête le profilage de la requête HTTP en cours et enregistre le profil. + * Ne fait rien si la requête n'est pas profilée. + * + * @return void + */ + public static function stop(): void + { + $requestId = self::$requestId; + self::$requestId = null; + + if ($requestId === null) { + return; + } + + try { + // Temps mesuré avant stop() : le traitement du profil (agrégation) n'est pas compté + $wallMs = round((microtime(true) - self::$startedAt) * 1000, 1); + $data = self::driver()->stop(); + CodeProfileLogger::save( + $requestId, + self::driver()->name(), + $wallMs, + round(memory_get_peak_usage(true) / 1048576, 2), + $data + ); + } catch (\Throwable $exception) { + error_log('[EduFramework Profiler] ' . $exception->getMessage()); + } + } + + /** + * @return string Mode du profiler : off, trigger ou on (variable EDU_PROFILER, trigger par défaut) + */ + public static function mode(): string + { + $mode = (ConfigCore::existEnv('EDU_PROFILER') === true ? (string) ConfigCore::getEnv('EDU_PROFILER') : 'trigger'); + + return (in_array($mode, ['off', 'trigger', 'on'], true) === true ? $mode : 'trigger'); + } + + /** + * Indique si le profilage est demandé pour la requête en cours. + * Le déclencheur (cookie edu_profile, paramètre ?_profile=1) est lu dans les + * superglobales : le profilage démarre avant le routage, quand l'objet Request + * n'existe pas encore. + * + * @SuppressWarnings(PHPMD.Superglobals) + * @return bool + */ + public static function isRequested(): bool + { + return match (self::mode()) { + 'on' => true, + 'off' => false, + default => ($_COOKIE[self::COOKIE] ?? '') === '1' || ($_GET['_profile'] ?? '') === '1', + }; + } + + /** + * @return bool Indique si l'extension de profilage est installée + */ + public static function isAvailable(): bool + { + return self::driver()->isAvailable(); + } + + /** + * @return bool Indique si la requête en cours est en train d'être profilée + */ + public static function isActive(): bool + { + return self::$requestId !== null; + } + + /** + * Remplace le driver de profilage (tests, autre extension) + * + * @param ProfilerDriverInterface|null $driver Driver à utiliser, null pour la détection automatique + * @return void + */ + public static function setDriver(?ProfilerDriverInterface $driver): void + { + self::$driver = $driver; + } + + /** + * Réinitialise l'état du profiler (isolation des tests) + * + * @return void + */ + public static function reset(): void + { + self::$requestId = null; + self::$startedAt = 0.0; + } + + /** + * @return ProfilerDriverInterface Driver de profilage, détecté selon les extensions chargées + */ + private static function driver(): ProfilerDriverInterface + { + return self::$driver ??= (\extension_loaded('excimer') === true ? new ExcimerDriver() : new NullDriver()); + } +} diff --git a/src/EduFramework/Core/Profiler/ExcimerDriver.php b/src/EduFramework/Core/Profiler/ExcimerDriver.php new file mode 100644 index 0000000..c43cd48 --- /dev/null +++ b/src/EduFramework/Core/Profiler/ExcimerDriver.php @@ -0,0 +1,91 @@ +profiler ??= new \ExcimerProfiler(); + $this->profiler->setPeriod(self::PERIOD); + // Temps réel (et non CPU) : l'attente d'une base de données doit apparaître + $this->profiler->setEventType(EXCIMER_REAL); + $this->profiler->start(); + } + + /** + * Arrête l'échantillonnage et retourne le profil de la requête + * + * @return array period_ms, samples, functions (agrégées par fonction) et speedscope + */ + public function stop(): array + { + if ($this->profiler === null) { + return []; + } + + $this->profiler->stop(); + // flush() retourne le log de la requête et en ouvre un neuf pour la suivante + $log = $this->profiler->flush(); + + return [ + 'period_ms' => self::PERIOD * 1000, + 'samples' => $log->getEventCount(), + 'functions' => $log->aggregateByFunction(), + 'speedscope' => $log->getSpeedscopeData(), + ]; + } +} diff --git a/src/EduFramework/Core/Profiler/NullDriver.php b/src/EduFramework/Core/Profiler/NullDriver.php new file mode 100644 index 0000000..3513160 --- /dev/null +++ b/src/EduFramework/Core/Profiler/NullDriver.php @@ -0,0 +1,55 @@ + Profil vide + */ + public function stop(): array + { + return []; + } +} diff --git a/src/EduFramework/Core/Profiler/ProfilerDriverInterface.php b/src/EduFramework/Core/Profiler/ProfilerDriverInterface.php new file mode 100644 index 0000000..7b4efb2 --- /dev/null +++ b/src/EduFramework/Core/Profiler/ProfilerDriverInterface.php @@ -0,0 +1,53 @@ + + */ + public function stop(): array; +} diff --git a/src/EduFramework/Core/View/studooBarreDebug.php b/src/EduFramework/Core/View/studooBarreDebug.php index dcaec7c..99ec27b 100644 --- a/src/EduFramework/Core/View/studooBarreDebug.php +++ b/src/EduFramework/Core/View/studooBarreDebug.php @@ -14,6 +14,7 @@ use Studoo\EduFramework\Core\ConfigCore; use Studoo\EduFramework\Core\Logs\HttpRequestLogger; use Studoo\EduFramework\Core\Logs\SqlQueryLogger; +use Studoo\EduFramework\Core\Profiler\CodeProfiler; /** * Class studooBarreDebug @@ -67,12 +68,12 @@ public function generateCssGlobal(): string box-shadow: 0 -2px 8px rgba(0, 0, 0, .4); z-index: 1; } #edu-tb .edu-tb-group.right .edu-tb-panel { left: auto; right: 0; } -#edu-tb .edu-tb-block:hover .edu-tb-panel { display: block; } +#edu-tb .edu-tb-block:hover .edu-tb-panel, #edu-tb .edu-tb-block:focus-within .edu-tb-panel { display: block; } #edu-tb .edu-tb-panel h4 { margin: 0 0 6px; font-weight: 600; font-size: 12px; line-height: 1.4; color: #fff; text-transform: uppercase; letter-spacing: .5px; } #edu-tb .edu-tb-panel div { display: flex; justify-content: space-between; gap: 18px; } #edu-tb .edu-tb-panel span { color: #aaa; } #edu-tb .edu-tb-panel em { font-style: normal; color: #fff; word-break: break-all; text-align: right; } -#edu-tb .edu-tb-panel em a { color: #9fc6ff; } +#edu-tb .edu-tb-panel em a { color: #9fc6ff; display: inline; line-height: 1.5; } #edu-tb .edu-tb-panel em a:hover { color: #c3d9ff; text-decoration: underline; } #edu-tb .edu-tb-panel a { display: inline; padding: 0; margin: 0; } #edu-tb .edu-tb-close { @@ -88,6 +89,18 @@ public function generateCssGlobal(): string align-items: center; } #edu-tb-mini img { width: 18px; height: 18px; } +#edu-tb .edu-tb-code.off, #edu-tb .edu-tb-code.missing { color: #999; } +#edu-tb .edu-tb-code .edu-tb-dot { display: inline-block; width: 8px; height: 8px; border-radius: 50%; border: 1px solid #999; margin-left: 6px; } +#edu-tb .edu-tb-code.on .edu-tb-dot { background: #4f805d; border-color: #4f805d; } +#edu-tb .edu-tb-code .edu-tb-code-label { margin-left: 6px; } +#edu-tb .edu-tb-code .edu-tb-panel { min-width: 440px; } +#edu-tb .edu-tb-panel .edu-tb-code-rows { display: block; } +#edu-tb .edu-tb-panel .edu-tb-code-rows span { flex-shrink: 0; } +#edu-tb .edu-tb-code > a { padding: 0; } +#edu-tb .edu-tb-panel button.edu-tb-action { + display: inline; height: auto; padding: 0; line-height: inherit; + color: #9fc6ff; cursor: pointer; text-decoration: underline; +} html.edu-tb-closed #edu-tb { display: none; } html.edu-tb-closed #edu-tb-mini { display: flex; } @@ -99,6 +112,70 @@ public function generateCssGlobal(): string root.classList.toggle('edu-tb-closed', close); try { localStorage.setItem(key, close ? '1' : '0'); } catch (e) {} }; + // Profiler de code : le cookie edu_profile active le profilage des requêtes suivantes + window.eduProfileToggle = function (on) { + document.cookie = 'edu_profile=' + (on ? '1' : '0') + '; path=/; SameSite=Lax' + (on ? '' : '; max-age=0'); + // Le paramètre ?_profile=1 réactiverait le profilage : il est retiré de l'URL + var url = new URL(window.location.href); + if (on === false && url.searchParams.has('_profile')) { + url.searchParams.delete('_profile'); + window.location.replace(url.href); + return; + } + window.location.reload(); + }; + // Le profil est enregistré en fin de requête, parfois après l'affichage de la page : + // le bloc Code le demande à la route JSON et réessaie tant qu'il n'est pas prêt + window.eduLoadCodeProfile = function () { + var block = document.getElementById('edu-tb-code'); + if (!block || !window.fetch) { return; } + var tries = 0; + (function load() { + fetch('/edu-code-profile?token=' + encodeURIComponent(block.getAttribute('data-token'))) + .then(function (response) { return response.json(); }) + .then(function (data) { + if (data.status === 'ready') { eduFillCodeBlock(block, data); return; } + if (++tries < 6) { setTimeout(load, 250 * tries); return; } + block.querySelector('.edu-tb-code-label').textContent = '?'; + }) + .catch(function () { block.querySelector('.edu-tb-code-label').textContent = '?'; }); + })(); + }; + window.eduFillCodeBlock = function (block, data) { + var ms = function (value) { return String(Math.round(value * 10) / 10).replace('.', ','); }; + var label = block.querySelector('.edu-tb-code-label'); + label.textContent = ''; + var strong = document.createElement('b'); + strong.textContent = ms(data.summary.wall_ms); + var unit = document.createElement('small'); + unit.textContent = 'ms'; + label.appendChild(strong); + label.appendChild(unit); + if (data.top.length > 0) { + // Nom court : sans le namespace ni le dossier (Exemple : LoadCouchCore::run) + var name = data.top[0].name.split(/[\\/]/).pop(); + label.appendChild(document.createTextNode(' ' + (name.length > 28 ? '…' + name.slice(-27) : name))); + } + var rows = block.querySelector('.edu-tb-code-rows'); + var row = function (title, value) { + var line = document.createElement('div'); + var span = document.createElement('span'); + var em = document.createElement('em'); + span.textContent = title; + em.textContent = value; + line.appendChild(span); + line.appendChild(em); + rows.appendChild(line); + }; + rows.textContent = ''; + row('Temps profilé', ms(data.summary.wall_ms) + ' ms'); + row('Échantillons', data.summary.samples + ' (1 toutes les ' + ms(data.summary.period_ms) + ' ms)'); + row('Fonctions vues', String(data.summary.functions_count)); + row('Classement', 'par temps propre'); + data.top.slice(0, 3).forEach(function (fn, index) { + row('Top ' + (index + 1), fn.name + ' — ' + ms(fn.self_ms) + ' ms (' + ms(fn.self_pct) + ' %)'); + }); + }; })(); HTML; @@ -146,6 +223,7 @@ public function generateBarDebug(): string ['Pic d\'utilisation' => number_format($peak, 2, ',', ' ') . ' Mo', 'Limite PHP' => (string) ini_get('memory_limit')] ), $this->sqlBlock(), + $this->codeBlock(), $this->devToolBlock(), ]; @@ -179,7 +257,8 @@ public function generateBarDebug(): string . '' . '' . ''; + . '' + . (CodeProfiler::isActive() === true ? '' : ''); } /** @@ -259,6 +338,69 @@ private function sqlBlock(): string ); } + /** + * Bloc Code de la barre : profiler du code PHP exécuté (extension Excimer). + * - extension absente : bloc grisé avec le lien vers la documentation ; + * - profilage inactif (EDU_PROFILER=trigger) : un clic pose le cookie edu_profile + * et recharge la page, qui est alors profilée, comme les suivantes ; + * - requête profilée : le résumé (temps, fonctions les plus coûteuses) est chargé + * en JavaScript après l'affichage de la page, car le profil n'est enregistré + * qu'en fin de requête ; un clic ouvre l'onglet Code du profiler. + * Le bloc est masqué si le profiler est désactivé (EDU_PROFILER=off). + * + * @return string + */ + private function codeBlock(): string + { + if (CodeProfiler::mode() === 'off') { + return ''; + } + + $title = '

Profiler de code

'; + + if (CodeProfiler::isAvailable() === false) { + return $this->block( + 'Code', + 'Profiler de code', + [ + 'Extension' => 'excimer non installée', + 'Documentation' => 'Installer le profiler', + ], + 'edu-tb-code missing', + 'https://studoo-app.github.io/edu-framework/boost/debug-bar.html' + ); + } + + $logId = HttpRequestLogger::getCurrentLogId(); + + if (CodeProfiler::isActive() === true && $logId !== null) { + // Le bouton Désactiver est un vrai bouton, hors du lien vers le profiler + // (accessible au clavier : le panneau s'ouvre aussi au focus) + $stop = (CodeProfiler::mode() === 'trigger') + ? '
Profilage
' + : ''; + $href = '/_debug/profiler#code/' . $logId; + + return '
' + . '' + . 'Code …' + . '
' . $title + . '
Profilenregistrement en cours…
' + . $stop + . '' + . '
'; + } + + // Profilage disponible mais inactif pour cette requête (mode trigger sans cookie) + return ''; + } + /** * Détails sur la base de données (affichés dans le panneau de survol du bloc DEV, * uniquement si elle est activée via DB_HOST_STATUS=true) : type, hôte (avec les @@ -278,7 +420,7 @@ private function databaseDetails(): array $get = static fn (string $key): string => (ConfigCore::existEnv($key) === true ? (string) ConfigCore::getEnv($key) : '—'); $env = static fn (string $key, string $default): string => (ConfigCore::existEnv($key) === true ? (string) ConfigCore::getEnv($key) : $default); - $link = static fn (string $url): array => ['text' => $url, 'href' => $url]; + $link = static fn (string $name, string $url): array => ['text' => $name, 'href' => $url]; return [ '---- database ----' => "--------", @@ -286,8 +428,8 @@ private function databaseDetails(): array 'DB_TYPE' => $get('DB_TYPE'), 'DB_HOST' => $env('DB_HOST', 'localhost') . ':' . $env('DB_SOCKET', '3306'), 'DB_NAME' => $get('DB_NAME'), - 'DbGate' => $link('http://localhost:' . $env('DBGATE_PORT', '8082')), - 'phpMyAdmin' => $link('http://localhost:' . $env('PMA_PORT', '8081')), + 'DbGate' => $link('localhost:' . $env('DBGATE_PORT', '8082') ,'http://localhost:' . $env('DBGATE_PORT', '8082')), + 'phpMyAdmin' => $link('localhost:' . $env('PMA_PORT', '8081'), 'http://localhost:' . $env('PMA_PORT', '8081')), ]; } @@ -303,11 +445,11 @@ private function devServicesDetails(): array { $env = static fn (string $key, string $default): string => (ConfigCore::existEnv($key) === true ? (string) ConfigCore::getEnv($key) : $default); - $link = static fn (string $url): array => ['text' => $url, 'href' => $url]; + $link = static fn (string $name, string $url): array => ['text' => $name, 'href' => $url]; return [ '---- smtp ----' => "--------", - 'Mailpit' => $link('http://localhost:' . $env('MAILER_UI_PORT', '8025')), + 'Mailpit' => $link('localhost:' . $env('MAILER_UI_PORT', '8025'), 'http://localhost:' . $env('MAILER_UI_PORT', '8025')), 'Mailpit SMTP' => 'localhost:' . $env('MAILER_SMTP_PORT', '1025') ]; } @@ -343,6 +485,12 @@ private function block(string $html, string $title, array $details, string $clas return '
' . $inner . '
'; } + /** + * Libellé du statut HTTP (Exemple : 404 => Not Found) + * + * @param int $status Code de statut HTTP + * @return string Libellé du statut, chaine vide si inconnu + */ private function statusText(int $status): string { return match ($status) { @@ -362,6 +510,12 @@ private function statusText(int $status): string }; } + /** + * Échappe une valeur pour un affichage HTML + * + * @param string $value Valeur à échapper + * @return string Valeur échappée + */ private function escape(string $value): string { return htmlspecialchars($value, ENT_QUOTES | ENT_SUBSTITUTE, 'UTF-8'); diff --git a/tests/Controller/DebugCodeProfileControllerTest.php b/tests/Controller/DebugCodeProfileControllerTest.php new file mode 100644 index 0000000..69b0296 --- /dev/null +++ b/tests/Controller/DebugCodeProfileControllerTest.php @@ -0,0 +1,172 @@ +setValue(null, null); + new ConfigCore([ + 'sqlite_logs_path' => self::$logsPath, + 'base_path' => '/projet/', + ]); + } + + /** + * Supprime la base SQLite des logs et le dossier temporaire des tests + */ + public static function tearDownAfterClass(): void + { + if (is_file(self::$logsPath . 'core_logs.sqlite') === true) { + unlink(self::$logsPath . 'core_logs.sqlite'); + } + if (is_dir(self::$logsPath) === true) { + rmdir(self::$logsPath); + } + } + + /** + * Exécute le contrôleur avec les paramètres GET donnés + */ + private function runController(array $params): mixed + { + $request = new Request('/edu-code-profile', 'GET'); + $request->setVars($params); + + return json_decode((string) (new DebugCodeProfileController())->execute($request), true); + } + + /** + * Profil Excimer simplifié : main() appelle work() (2 échantillons dans work, 1 dans main) + */ + private function saveProfile(int $token): void + { + $data = [ + 'period_ms' => 0.1, + 'samples' => 3, + 'functions' => [ + 'work' => ['self' => 2, 'inclusive' => 2, 'file' => '/projet/app/Work.php', 'line' => 10, 'function' => 'work'], + 'main' => ['self' => 1, 'inclusive' => 3, 'file' => '/projet/public/index.php', 'line' => 3, 'function' => 'main'], + ], + 'speedscope' => [ + 'shared' => ['frames' => [['name' => 'main'], ['name' => 'work']]], + 'profiles' => [[ + 'type' => 'sampled', + 'unit' => 'nanoseconds', + 'samples' => [[0, 1], [0, 1], [0]], + 'weights' => [100000, 100000, 100000], + ]], + ], + ]; + CodeProfileLogger::save($token, 'excimer', 1.5, 2.0, $data); + } + + /** + * Un token invalide retourne une réponse vide + */ + public function testInvalidTokenReturnsAnEmptyResponse(): void + { + foreach (['', 'abc', '7.5', '-1', '99999999999999999999'] as $token) { + $response = $this->runController(['token' => $token]); + + $this->assertNull($response['token'], 'Le token <' . $token . '> ne doit pas être accepté'); + $this->assertSame('pending', $response['status']); + $this->assertNull($response['summary']); + $this->assertSame([], $response['top']); + } + } + + /** + * Un token sans profil enregistré est en attente (la page s'affiche avant la fin de la requête) + */ + public function testUnknownTokenIsPending(): void + { + $response = $this->runController(['token' => '#404']); + + $this->assertSame(404, $response['token']); + $this->assertSame('pending', $response['status']); + } + + /** + * Un profil enregistré retourne le résumé et le top des fonctions + */ + public function testSavedProfileReturnsTheSummaryAndTop(): void + { + $this->saveProfile(21); + + $response = $this->runController(['token' => '21']); + + $this->assertSame('ready', $response['status']); + $this->assertSame('excimer', $response['summary']['driver']); + $this->assertSame(3, $response['summary']['samples']); + $this->assertSame(2, $response['summary']['functions_count']); + $this->assertSame('work', $response['top'][0]['name']); + $this->assertArrayNotHasKey('functions', $response); + $this->assertArrayNotHasKey('edges', $response); + } + + /** + * full=1 ajoute toutes les fonctions et le graphe d'appels + */ + public function testFullProfileAddsFunctionsAndEdges(): void + { + $this->saveProfile(22); + + $response = $this->runController(['token' => '22', 'full' => '1']); + + $this->assertCount(2, $response['functions']); + $this->assertSame('app', $response['functions'][0]['origin']); + $this->assertSame( + [['caller' => 'main', 'callee' => 'work', 'samples' => 2]], + array_map( + static fn (array $edge): array => [ + 'caller' => $edge['caller'], 'callee' => $edge['callee'], 'samples' => $edge['samples'], + ], + $response['edges'] + ) + ); + } + + /** + * format=speedscope retourne les piles d'appels au format Speedscope + */ + public function testSpeedscopeExport(): void + { + $this->saveProfile(23); + + $response = $this->runController(['token' => '23', 'format' => 'speedscope']); + + $this->assertSame('Edu Framework #23', $response['name']); + $this->assertSame('Requête #23', $response['profiles'][0]['name']); + $this->assertSame([[0, 1], [0, 1], [0]], $response['profiles'][0]['samples']); + } +} diff --git a/tests/Core/Profiler/CodeProfileAggregatorTest.php b/tests/Core/Profiler/CodeProfileAggregatorTest.php new file mode 100644 index 0000000..fab479f --- /dev/null +++ b/tests/Core/Profiler/CodeProfileAggregatorTest.php @@ -0,0 +1,132 @@ + '/projet/']); + } + + /** + * Données au format du driver Excimer : 100 échantillons à 0,1 ms + * @return array + */ + private function data(): array + { + return [ + 'period_ms' => 0.1, + 'samples' => 100, + 'functions' => [ + '/projet/public/index.php' => ['file' => '/projet/public/index.php', 'line' => 3, 'self' => 0, 'inclusive' => 100], + 'Controller\\HomeController::execute' => [ + 'file' => '/projet/app/Controller/HomeController.php', 'line' => 12, + 'class' => 'Controller\\HomeController', 'function' => 'execute', 'self' => 60, 'inclusive' => 80, + ], + 'Twig\\Environment::render' => [ + 'file' => '/projet/vendor/twig/twig/src/Environment.php', 'line' => 40, 'self' => 20, 'inclusive' => 20, + ], + 'Studoo\\EduFramework\\Core\\LoadCouchCore::run' => [ + 'file' => '/projet/src/EduFramework/Core/LoadCouchCore.php', 'line' => 50, 'self' => 20, 'inclusive' => 100, + ], + ], + ]; + } + + /** + * Vérifie le calcul des temps estimés (échantillons x période) et des pourcentages, + * et le tri par temps propre décroissant + */ + public function testByFunctionEstimatesTimesAndSortsBySelfTime(): void + { + $functions = CodeProfileAggregator::byFunction($this->data()); + + $this->assertCount(4, $functions); + $this->assertSame('Controller\\HomeController::execute', $functions[0]['name']); + $this->assertEquals(6.0, $functions[0]['self_ms']); + $this->assertEquals(8.0, $functions[0]['inclusive_ms']); + $this->assertEquals(60.0, $functions[0]['self_pct']); + $this->assertSame('app/Controller/HomeController.php', $functions[0]['file']); + $this->assertSame(12, $functions[0]['line']); + // Le code hors fonction de la page est affiché par son chemin relatif + $this->assertSame('public/index.php', $functions[3]['name']); + } + + /** + * Vérifie le classement des fonctions par origine (application, framework, dépendances, autre) + */ + public function testOriginIsDeducedFromTheFile(): void + { + $this->assertSame('app', CodeProfileAggregator::origin('/projet/app/Controller/HomeController.php')); + $this->assertSame('framework', CodeProfileAggregator::origin('/projet/src/EduFramework/Core/LoadCouchCore.php')); + $this->assertSame('framework', CodeProfileAggregator::origin('/projet/public/index.php')); + $this->assertSame('vendor', CodeProfileAggregator::origin('/projet/vendor/twig/twig/src/Environment.php')); + $this->assertSame('framework', CodeProfileAggregator::origin('/autre/vendor/studoo/edu-framework/src/Core/ConfigCore.php')); + $this->assertSame('other', CodeProfileAggregator::origin('/tmp/script.php')); + $this->assertSame('other', CodeProfileAggregator::origin(null)); + } + + /** + * Vérifie que le top ne garde que les fonctions avec du temps propre, dans la limite demandée + */ + public function testTopKeepsFunctionsWithSelfTime(): void + { + $top = CodeProfileAggregator::top(CodeProfileAggregator::byFunction($this->data()), 2); + + $this->assertCount(2, $top); + $this->assertSame('Controller\\HomeController::execute', $top[0]['name']); + foreach (CodeProfileAggregator::top(CodeProfileAggregator::byFunction($this->data())) as $function) { + $this->assertGreaterThan(0, $function['self']); + } + } + + /** + * Vérifie la reconstruction du graphe d'appels depuis les piles Speedscope : + * une fonction récursive ne compte qu'une fois par échantillon et un échantillon + * peut représenter plusieurs périodes + */ + public function testCallGraphCountsSamplesPerCallerCalleePair(): void + { + $speedscope = [ + 'shared' => ['frames' => [['name' => 'main'], ['name' => 'a'], ['name' => 'b']]], + 'profiles' => [[ + 'samples' => [[0, 1], [0, 1, 2], [0, 1, 1, 1]], + // 100 000 ns = 1 période de 0,1 ms ; 200 000 ns = 2 périodes + 'weights' => [100000, 200000, 100000], + ]], + ]; + + $edges = CodeProfileAggregator::callGraph($speedscope, 0.1); + $byPair = []; + foreach ($edges as $edge) { + $byPair[$edge['caller'] . '>' . $edge['callee']] = $edge; + } + + $this->assertSame(4, $byPair['main>a']['samples']); + $this->assertEquals(0.4, $byPair['main>a']['ms']); + $this->assertSame(2, $byPair['a>b']['samples']); + // Récursion a > a > a : comptée une seule fois dans son échantillon + $this->assertSame(1, $byPair['a>a']['samples']); + } + + /** + * Vérifie que des données vides ne provoquent pas d'erreur + */ + public function testEmptyDataGivesEmptyResults(): void + { + $this->assertSame([], CodeProfileAggregator::byFunction([])); + $this->assertSame([], CodeProfileAggregator::callGraph([], 0.1)); + } +} diff --git a/tests/Core/Profiler/CodeProfileLoggerTest.php b/tests/Core/Profiler/CodeProfileLoggerTest.php new file mode 100644 index 0000000..4d8c7d4 --- /dev/null +++ b/tests/Core/Profiler/CodeProfileLoggerTest.php @@ -0,0 +1,155 @@ +setValue(null, null); + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, null); + new ConfigCore(['sqlite_logs_path' => self::$logsPath]); + LogsService::getConnect()->exec('DELETE FROM serv_code_profiles'); + } + + /** + * Supprime la base SQLite des logs et le dossier temporaire des tests + */ + public static function tearDownAfterClass(): void + { + (new ReflectionProperty(LogsService::class, 'dbConnectLogs'))->setValue(null, null); + if (is_file(self::$logsPath . 'core_logs.sqlite') === true) { + unlink(self::$logsPath . 'core_logs.sqlite'); + } + if (is_dir(self::$logsPath) === true) { + rmdir(self::$logsPath); + } + } + + /** + * @return array Profil au format du driver Excimer + */ + private function data(int $samples = 20): array + { + return [ + 'period_ms' => 0.1, + 'samples' => $samples, + 'functions' => [ + 'a' => ['file' => '/tmp/a.php', 'line' => 1, 'self' => $samples, 'inclusive' => $samples], + 'b' => ['file' => '/tmp/b.php', 'line' => 2, 'self' => 0, 'inclusive' => $samples], + ], + 'speedscope' => ['shared' => ['frames' => [['name' => 'b'], ['name' => 'a']]], 'profiles' => [['samples' => [[0, 1]], 'weights' => [100000]]]], + ]; + } + + /** + * Vérifie l'écriture puis la lecture d'un profil, résumé et données complètes + */ + public function testSavedProfileCanBeReadBack(): void + { + CodeProfileLogger::save(5, 'excimer', 2.5, 4.0, $this->data()); + + $summary = LogsService::getCodeProfile(5); + $this->assertSame('excimer', $summary['driver']); + $this->assertEquals(2.5, $summary['wall_ms']); + $this->assertSame(20, $summary['samples']); + $this->assertSame(2, $summary['functions_count']); + // Seules les fonctions avec du temps propre sont dans le top + $this->assertCount(1, $summary['top']); + $this->assertArrayNotHasKey('data', $summary); + + $full = LogsService::getCodeProfile(5, true); + $this->assertSame($this->data(), $full['data']); + } + + /** + * Vérifie qu'un profil corrompu est lu sans erreur, avec des données vides + */ + public function testCorruptedProfileDataIsReadAsEmpty(): void + { + CodeProfileLogger::save(6, 'excimer', 2.5, 4.0, $this->data()); + LogsService::getConnect()->exec("UPDATE serv_code_profiles SET data = 'pas du gzip' WHERE request_id = 6"); + + $errorLog = ini_get('error_log'); + ini_set('error_log', '/dev/null'); + try { + $full = LogsService::getCodeProfile(6, true); + } finally { + ini_set('error_log', (string) $errorLog); + } + + $this->assertSame('excimer', $full['driver']); + $this->assertSame([], $full['data']); + } + + /** + * Vérifie qu'un token sans profil retourne null + */ + public function testUnknownTokenHasNoProfile(): void + { + $this->assertNull(LogsService::getCodeProfile(999)); + } + + /** + * Vérifie que seuls les derniers profils sont conservés + */ + public function testPurgeKeepsTheLatestProfiles(): void + { + foreach ([1, 2, 3, 4] as $token) { + CodeProfileLogger::save($token, 'excimer', 1.0, 1.0, $this->data()); + } + + CodeProfileLogger::purge(2); + + $this->assertNull(LogsService::getCodeProfile(1)); + $this->assertNull(LogsService::getCodeProfile(2)); + $this->assertNotNull(LogsService::getCodeProfile(3)); + $this->assertNotNull(LogsService::getCodeProfile(4)); + } + + /** + * Vérifie que la liste des logs signale les requêtes qui ont un profil de code + */ + public function testLogsListFlagsProfiledRequests(): void + { + $profiledId = LogsService::addLog('{"method":"GET","path":"\/profilee"}'); + $plainId = LogsService::addLog('{"method":"GET","path":"\/simple"}'); + CodeProfileLogger::save($profiledId, 'excimer', 1.0, 1.0, $this->data()); + + $flags = []; + foreach (LogsService::getLogs(10) as $log) { + $flags[$log['id']] = $log['profiled']; + } + + $this->assertTrue($flags[$profiledId]); + $this->assertFalse($flags[$plainId]); + } +} diff --git a/tests/Core/Profiler/CodeProfilerTest.php b/tests/Core/Profiler/CodeProfilerTest.php new file mode 100644 index 0000000..a491097 --- /dev/null +++ b/tests/Core/Profiler/CodeProfilerTest.php @@ -0,0 +1,203 @@ + + */ + private array $backup = []; + + /** + * Crée le dossier temporaire dédié aux logs avant l'ensemble des tests + */ + public static function setUpBeforeClass(): void + { + self::$logsPath = sys_get_temp_dir() . '/edu-framework-profiler-test/'; + if (is_dir(self::$logsPath) === false) { + mkdir(self::$logsPath, 0755, true); + } + } + + /** + * Réinitialise les états statiques et sauvegarde les variables modifiées par les tests + */ + protected function setUp(): void + { + (new ReflectionProperty(LogsService::class, 'dbConnectLogs'))->setValue(null, null); + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, null); + CodeProfiler::reset(); + new ConfigCore(['sqlite_logs_path' => self::$logsPath]); + $this->backup = [ + 'env' => $_ENV['EDU_PROFILER'] ?? null, + 'cookie' => $_COOKIE[CodeProfiler::COOKIE] ?? null, + 'get' => $_GET['_profile'] ?? null, + 'error_log' => ini_get('error_log'), + ]; + unset($_ENV['EDU_PROFILER'], $_COOKIE[CodeProfiler::COOKIE], $_GET['_profile']); + } + + /** + * Réinitialise le profiler et restaure les variables modifiées par le test + */ + protected function tearDown(): void + { + CodeProfiler::reset(); + CodeProfiler::setDriver(null); + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, null); + foreach (['env' => 'EDU_PROFILER'] as $key => $name) { + if ($this->backup[$key] === null) { + unset($_ENV[$name]); + } else { + $_ENV[$name] = $this->backup[$key]; + } + } + unset($_COOKIE[CodeProfiler::COOKIE], $_GET['_profile']); + if ($this->backup['cookie'] !== null) { + $_COOKIE[CodeProfiler::COOKIE] = $this->backup['cookie']; + } + if ($this->backup['get'] !== null) { + $_GET['_profile'] = $this->backup['get']; + } + ini_set('error_log', (string) $this->backup['error_log']); + } + + /** + * Supprime la base SQLite des logs et le dossier temporaire des tests + */ + public static function tearDownAfterClass(): void + { + (new ReflectionProperty(LogsService::class, 'dbConnectLogs'))->setValue(null, null); + if (is_file(self::$logsPath . 'core_logs.sqlite') === true) { + unlink(self::$logsPath . 'core_logs.sqlite'); + } + if (is_dir(self::$logsPath) === true) { + rmdir(self::$logsPath); + } + } + + /** + * Simule une requête HTTP journalisée (token réservé par HttpRequestLogger) + */ + private function withToken(int $token): void + { + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, $token); + } + + /** + * Vérifie le mode par défaut et la validation de EDU_PROFILER + */ + public function testModeDefaultsToTrigger(): void + { + $this->assertSame('trigger', CodeProfiler::mode()); + $_ENV['EDU_PROFILER'] = 'on'; + $this->assertSame('on', CodeProfiler::mode()); + $_ENV['EDU_PROFILER'] = 'nimporte'; + $this->assertSame('trigger', CodeProfiler::mode()); + } + + /** + * Vérifie qu'en mode trigger la requête n'est profilée qu'avec le cookie ou ?_profile=1 + */ + public function testTriggerModeNeedsTheCookieOrTheQueryParameter(): void + { + $this->assertFalse(CodeProfiler::isRequested()); + $_COOKIE[CodeProfiler::COOKIE] = '1'; + $this->assertTrue(CodeProfiler::isRequested()); + unset($_COOKIE[CodeProfiler::COOKIE]); + $_GET['_profile'] = '1'; + $this->assertTrue(CodeProfiler::isRequested()); + $_ENV['EDU_PROFILER'] = 'off'; + $this->assertFalse(CodeProfiler::isRequested()); + } + + /** + * Vérifie qu'une requête profilée enregistre son profil, rattaché au token + */ + public function testProfiledRequestSavesItsProfile(): void + { + $_ENV['EDU_PROFILER'] = 'on'; + $driver = new FakeProfilerDriver(); + CodeProfiler::setDriver($driver); + $this->withToken(42); + + CodeProfiler::start(); + $this->assertTrue(CodeProfiler::isActive()); + CodeProfiler::stop(); + + $this->assertFalse(CodeProfiler::isActive()); + $this->assertSame(1, $driver->starts); + $profile = LogsService::getCodeProfile(42); + $this->assertNotNull($profile); + $this->assertSame('fake', $profile['driver']); + $this->assertSame(10, $profile['samples']); + $this->assertSame('f', $profile['top'][0]['name']); + } + + /** + * Vérifie qu'une requête sans token (CLI, hors mode dev, route du profiler) n'est pas profilée + */ + public function testRequestWithoutTokenIsNotProfiled(): void + { + $_ENV['EDU_PROFILER'] = 'on'; + $driver = new FakeProfilerDriver(); + CodeProfiler::setDriver($driver); + + CodeProfiler::start(); + + $this->assertFalse(CodeProfiler::isActive()); + $this->assertSame(0, $driver->starts); + } + + /** + * Vérifie que rien n'est démarré sans demande de profilage ou sans extension + */ + public function testNothingStartsWhenNotRequestedOrUnavailable(): void + { + $this->withToken(43); + $driver = new FakeProfilerDriver(); + CodeProfiler::setDriver($driver); + CodeProfiler::start(); + $this->assertFalse(CodeProfiler::isActive()); + + $_ENV['EDU_PROFILER'] = 'on'; + $unavailable = new FakeProfilerDriver(false); + CodeProfiler::setDriver($unavailable); + CodeProfiler::start(); + $this->assertFalse(CodeProfiler::isActive()); + $this->assertSame(0, $driver->starts + $unavailable->starts); + } + + /** + * Vérifie qu'une erreur du driver ne fait jamais échouer la requête + */ + public function testDriverErrorDoesNotBreakTheRequest(): void + { + ini_set('error_log', '/dev/null'); + $_ENV['EDU_PROFILER'] = 'on'; + CodeProfiler::setDriver(new FakeProfilerDriver(true, true)); + $this->withToken(44); + + CodeProfiler::start(); + CodeProfiler::stop(); + + $this->assertFalse(CodeProfiler::isActive()); + $this->assertNull(LogsService::getCodeProfile(44)); + } +} diff --git a/tests/Core/Profiler/ExcimerDriverTest.php b/tests/Core/Profiler/ExcimerDriverTest.php new file mode 100644 index 0000000..9df3ebd --- /dev/null +++ b/tests/Core/Profiler/ExcimerDriverTest.php @@ -0,0 +1,70 @@ +markTestSkipped('Extension excimer non installée'); + } + } + + /** + * Vérifie qu'un vrai profil contient des échantillons, la fonction profilée + * et les piles d'appels au format Speedscope + */ + public function testProfilesARealWorkload(): void + { + $driver = new ExcimerDriver(); + $this->assertTrue($driver->isAvailable()); + + $driver->start(); + $this->busyLoop(); + $data = $driver->stop(); + + $this->assertEquals(0.1, $data['period_ms']); + $this->assertGreaterThan(0, $data['samples']); + $this->assertArrayHasKey(self::class . '::busyLoop', $data['functions']); + $this->assertArrayHasKey('profiles', $data['speedscope']); + } + + /** + * Vérifie que deux requêtes successives ont des profils séparés (mode worker) + */ + public function testEachStopReturnsOnlyItsOwnSamples(): void + { + $driver = new ExcimerDriver(); + $driver->start(); + $this->busyLoop(); + $driver->stop(); + + $driver->start(); + $second = $driver->stop(); + + $this->assertArrayNotHasKey(self::class . '::busyLoop', $second['functions']); + } + + /** + * Charge CPU d'environ 20 ms, assez pour plusieurs échantillons à 0,1 ms + */ + private function busyLoop(): void + { + $end = microtime(true) + 0.02; + $x = 0; + while (microtime(true) < $end) { + $x += sqrt($x + 1); + } + } +} diff --git a/tests/Core/Profiler/FakeProfilerDriver.php b/tests/Core/Profiler/FakeProfilerDriver.php new file mode 100644 index 0000000..12a302a --- /dev/null +++ b/tests/Core/Profiler/FakeProfilerDriver.php @@ -0,0 +1,69 @@ +available; + } + + /** + * Compte les démarrages + * + * @return void + */ + public function start(): void + { + $this->starts++; + } + + /** + * @return array Profil fixe (ou exception si failOnStop) + */ + public function stop(): array + { + if ($this->failOnStop === true) { + throw new \RuntimeException('panne du driver'); + } + + return [ + 'period_ms' => 0.1, + 'samples' => 10, + 'functions' => ['f' => ['file' => '/tmp/f.php', 'line' => 1, 'self' => 10, 'inclusive' => 10]], + 'speedscope' => [], + ]; + } +} diff --git a/tests/Core/View/StudooBarreDebugTest.php b/tests/Core/View/StudooBarreDebugTest.php index 3b7e1ec..be522bd 100644 --- a/tests/Core/View/StudooBarreDebugTest.php +++ b/tests/Core/View/StudooBarreDebugTest.php @@ -2,11 +2,13 @@ namespace Core\View; +use Core\Profiler\FakeProfilerDriver; use PHPUnit\Framework\TestCase; use ReflectionProperty; use Studoo\EduFramework\Core\ConfigCore; use Studoo\EduFramework\Core\Controller\Request; use Studoo\EduFramework\Core\Logs\HttpRequestLogger; +use Studoo\EduFramework\Core\Profiler\CodeProfiler; use Studoo\EduFramework\Core\View\studooBarreDebug; /** @@ -22,6 +24,9 @@ class StudooBarreDebugTest extends TestCase */ private array $envBackup = []; + /** + * Initialise la configuration du framework avant chaque test + */ protected function setUp(): void { new ConfigCore([]); @@ -34,6 +39,10 @@ protected function tearDown(): void { // Réinitialisation de l'identifiant de requête statique entre les tests (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, null); + // Réinitialisation du profiler de code (driver factice, cookie du bouton Code) + CodeProfiler::reset(); + CodeProfiler::setDriver(null); + unset($_COOKIE[CodeProfiler::COOKIE]); // Restauration des variables d'environnement modifiées par les tests foreach ($this->envBackup as $key => $value) { if ($value === null) { @@ -62,6 +71,9 @@ private function setEnv(array $values): void } } + /** + * Vérifie que la barre affiche la route, le contrôleur et la version de PHP + */ public function testToolbarDisplaysMethodRouteAndController(): void { ConfigCore::setRequest((new Request('/users/12', 'GET'))->setHander('App\\Controller\\UserController')); @@ -75,6 +87,9 @@ public function testToolbarDisplaysMethodRouteAndController(): void $this->assertStringContainsString('PHP' . PHP_VERSION . '', $html); } + /** + * Vérifie que la route est échappée (pas d'injection HTML) + */ public function testToolbarEscapesTheRoute(): void { ConfigCore::setRequest(new Request('/', 'GET')); @@ -85,6 +100,9 @@ public function testToolbarEscapesTheRoute(): void $this->assertStringContainsString('<script>alert(1)</script>', $html); } + /** + * Vérifie que la barre s'affiche sans contrôleur + */ public function testToolbarWithoutControllerDoesNotFail(): void { ConfigCore::setRequest(new Request('/', 'GET')); @@ -159,16 +177,17 @@ public function testDevBlockListsTheDevelopmentServicesWithDefaultPorts(): void $html = (new studooBarreDebug())->generateBarDebug(); // Les interfaces web sont des liens cliquables ouverts dans un nouvel onglet + // (le texte du lien n'affiche pas le protocole) $this->assertStringContainsString( - 'Mailpithttp://localhost:8025', + 'Mailpitlocalhost:8025', $html ); $this->assertStringContainsString( - 'DbGatehttp://localhost:8082', + 'DbGatelocalhost:8082', $html ); $this->assertStringContainsString( - 'phpMyAdminhttp://localhost:8081', + 'phpMyAdminlocalhost:8081', $html ); // La base de données et le SMTP de Mailpit sont des services TCP : simple texte @@ -211,4 +230,74 @@ public function testDevBlockEscapesTheServiceUrls(): void $this->assertStringNotContainsString('"&port=9090"', $html); $this->assertStringContainsString('"&port=9090', $html); } + + /** + * Le bloc Code est masqué quand le profiler est désactivé (EDU_PROFILER=off) + */ + public function testCodeBlockIsHiddenWhenTheProfilerIsOff(): void + { + $this->setEnv(['EDU_PROFILER' => 'off']); + CodeProfiler::setDriver(new FakeProfilerDriver(true)); + ConfigCore::setRequest(new Request('/', 'GET')); + + $html = (new studooBarreDebug())->generateBarDebug(); + + $this->assertStringNotContainsString('edu-tb-code', $html); + } + + /** + * Sans l'extension Excimer, le bloc Code est grisé et renvoie à la documentation + */ + public function testCodeBlockShowsTheMissingExtension(): void + { + $this->setEnv(['EDU_PROFILER' => null]); + CodeProfiler::setDriver(new FakeProfilerDriver(false)); + ConfigCore::setRequest(new Request('/', 'GET')); + + $html = (new studooBarreDebug())->generateBarDebug(); + + $this->assertStringContainsString('edu-tb-code missing', $html); + $this->assertStringContainsString('excimer non installée', $html); + $this->assertStringNotContainsString('eduProfileToggle(true)', $html); + } + + /** + * En mode trigger sans cookie, le bloc Code est un bouton qui active le profilage + */ + public function testCodeBlockIsAButtonWhenProfilingIsInactive(): void + { + $this->setEnv(['EDU_PROFILER' => 'trigger']); + CodeProfiler::setDriver(new FakeProfilerDriver(true)); + ConfigCore::setRequest(new Request('/', 'GET')); + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, 42); + + $html = (new studooBarreDebug())->generateBarDebug(); + + $this->assertStringContainsString('edu-tb-code off', $html); + $this->assertStringContainsString('onclick="eduProfileToggle(true)"', $html); + $this->assertStringNotContainsString('id="edu-tb-code"', $html); + $this->assertStringNotContainsString('eduLoadCodeProfile();', $html); + } + + /** + * Requête profilée : le bloc Code renvoie à l'onglet Code du profiler et + * charge le résumé du profil en JavaScript + */ + public function testCodeBlockLinksToTheProfileWhenProfilingIsActive(): void + { + $this->setEnv(['EDU_PROFILER' => 'trigger']); + $_COOKIE[CodeProfiler::COOKIE] = '1'; + CodeProfiler::setDriver(new FakeProfilerDriver(true)); + ConfigCore::setRequest(new Request('/', 'GET')); + (new ReflectionProperty(HttpRequestLogger::class, 'currentLogId'))->setValue(null, 42); + CodeProfiler::start(); + + $html = (new studooBarreDebug())->generateBarDebug(); + + $this->assertStringContainsString('id="edu-tb-code" data-token="42"', $html); + $this->assertStringContainsString('href="/_debug/profiler#code/42"', $html); + // En mode trigger, le panneau permet de désactiver le profilage + $this->assertStringContainsString('