LifePlay-Revival/Docs/Migration/18_Build_Debug.md

290 lines
17 KiB
Markdown
Raw Normal View History

# 18 — Build debug (mesure, pas optimisation)
Capacité de mesure reproductible après l'audit O0. Le Shipping joueur ne change pas
(`IncludeDebugFiles=False` dans `Config/DefaultGame.ini`, aucun coût runtime : le sous-système
est compilé vide en Shipping). Skill agent : `.cursor/skills/lifeplay-debug-build/`.
Plan de pilotage du lot : [`19_Plan_Outillage_Debug.md`](19_Plan_Outillage_Debug.md).
## 1. Deux builds
| Config | Rôle | Comparer les ms absolues |
|---|---|---|
| **Development** | Baseline chiffrée, session C, non-régression vs O0 | Oui |
| **DebugGame** | Plongée (checks, PDB, sessions A et B) | Non — ratios, signatures, piles |
| **Shipping** | Joueurs | Hors sujet |
Ne pas reconstruire DebugGame à chaque itération. Itérer dans l'éditeur ou en Development ;
reconstruire DebugGame seulement quand les checks, les PDB ou un outil externe l'exigent.
## 2. Empaqueter
```powershell
.\Tools\BuildDebug.ps1 [-Config DebugGame|Development] [-ArchiveDir <chemin>] [-UE <moteur>] [-SkipBuild]
```
- Config par défaut : `DebugGame`.
- Archives : `D:\Game\LifePlay_Build_5.5_DebugGame` ou `D:\Game\LifePlay_Build_5.5_Development`.
- Jamais `-nodebuginfo`. Le PDB `Binaries\Win64\*Win64-<Config>.pdb` est recopié dans
`Windows\LifePlay\Binaries\Win64` parce que `IncludeDebugFiles` reste `False` (le Shipping
lancé depuis l'éditeur ne doit pas embarquer les PDB).
- Cuisson alignée sur le projet actuel (lot O2) : `-pak -iostore -compressed`. `Modules` reste en
fichiers nus via `DefaultGame.ini`.
- Après l'archive, les lanceurs `Tools/debug/*.bat` sont copiés à côté de `Windows\LifePlay.exe`.
Journal UAT : `Saved\Logs\portage\BuildDebug_<config>_<horodatage>.log`.
## 3. Lanceurs
Scénario unique (O0 §5, environ 15 min) : partie avancée → carte de la ville → intérieur peuplé →
extérieur peuplé → scène à plusieurs personnages → quitter normalement.
| Session | Build | Lanceur | But |
|---|---|---|---|
| A | DebugGame | `LifePlay_debug_sessionA_insights.bat` | À-coups / travail de `GI` (G6) |
| B | DebugGame | `LifePlay_debug_sessionB_mem.bat` | Fuites, physique, collisions |
| C | Development | `LifePlay_debug_sessionC_profil.bat` | Non-régression CSV + LLM |
Auxiliaires, hors chemin critique : `LifePlay_debug_bugs.bat`, `LifePlay_debug_gpu.bat` (PIX **ou**
RGP, jamais les deux), `LifePlay_debug_collision.bat`. `LifePlay_debug_ui.bat` ouvre une
fenêtre pour cocher ces options (le canal `memory` reste décoché ; `-csvCaptureFrames` n'est
pas proposé). Le `.ps1` du même nom doit rester à côté du `.bat`.
Flags des sessions :
| Lanceur | Ligne de commande |
|---|---|
| A | `-trace=cpu,frame,bookmark,loadtime,memory -statnamedevents -tracefile=<Saved>/Profiling/SessionA.utrace -LPHitchLog` |
| B | `-llm -llmcsv -LPCollisionLog -ExecCmds="LifePlay.MemSnapshot, p.Chaos.StartVDRecording"` |
| C | `-csvGpuStats -llm -llmcsv -ExecCmds="csvprofile repeat=20, csvprofile frames=9000"` |
| bugs | `-LogCmds="LogModdingExtra Verbose"` |
| gpu | `-d3d12` (PIX). RGP : attacher au processus, sans ce lanceur |
| collision | `-LPCollisionLog -ExecCmds="p.Chaos.StartVDRecording, show collision"` |
| ui | fenêtre : les mêmes options, une par une |
**Piège CSV.** Ne jamais passer `-csvCaptureFrames`. La capture démarre avant l'initialisation du
RHI et le moteur s'arrête (`IsRayTracingAllowed() may only be called once RHI is initialized`).
La session C démarre le CSV par `-ExecCmds`, après le rendu. Mesurer un jeu empaqueté, pas
`UnrealEditor.exe -game`, pour les chiffres comparables à O0.
## 4. Collecte
```powershell
.\Tools\CollectDebugArtifacts.ps1 -Lot <lot> -BuildDir <archive> -Session A|B|C|bugs|gpu|collision
```
Destination : `D:\Game\LifePlay_Backup_5.5\<lot>\Session<session>\` (journaux, CSV, LLM, `.utrace`,
MemReport, `Profiling\LPDebug`, enregistrements ChaosVD). Le script échoue si rien n'est copié.
Résumé CSV (session C) :
```powershell
.\Tools\SummarizeDebugCsv.ps1 -Csv <dossier ou fichier CSV>
```
Médiane `FrameTime`, images > 50 ms et > 100 ms. Référence O0 (build L7cdj, 36 004 images) :
médiane 16,7 ms ; 159 images > 50 ms ; 112 images > 100 ms ; physique Chaos environ 463 Mo.
## 5. Runtime non-Shipping
`ULPDebugSubsystem` (`UGameInstanceSubsystem`), derrière `#if !UE_BUILD_SHIPPING`.
| Entrée | Effet |
|---|---|
| `-LPHitchLog` | Journal des images ≥ seuil. Sans ce flag, aucun relevé d'image |
| `-LPHitchMs=N` | Seuil en millisecondes (50 par défaut) |
| `-LPCollisionLog` | Échantillon toutes les 2 s, dump dès qu'un trimesh a des triangles, avec l'acteur qui le porte. Inactif sans ce flag |
| `LifePlay.Bookmark <texte>` | `TRACE_BOOKMARK` et ligne `LPDebug bookmark :` |
| `LifePlay.MemSnapshot` | `Saved/Profiling/LPDebug/MemSnapshot_*.txt` + `memreport` |
| `LifePlay.CollisionDump` | `CollisionDump_*.txt` immédiat (console). Le suivi automatique est `-LPCollisionLog`, pas cette commande au démarrage |
| `LifePlay.HitchSummary` | Bilan courant (`LPDebug hitch : N hitch(s) en …`) |
Un bilan est aussi écrit à 2 minutes et à la fermeture quand `-LPHitchLog` est actif.
Ligne de hitch : `LPDebug hitch : <ms> ms (seuil <seuil>) #<n>`.
Événements nommés Insights (macro `TRACE_CPUPROFILER_EVENT_SCOPE`, canal CPU ; en 5.5 il n'y a pas
de macro publique `SCOPED_NAMED_EVENT`) : `LoadTxt`, `LPDataCache` (`TryGet`), `LPDataCache_LoadAll`.
Ils sont vides en Shipping (`CPUPROFILERTRACE_ENABLED` est 0).
ChaosVD est limité à l'éditeur dans `LifePlay.uproject`. En jeu empaqueté, si
`p.Chaos.StartVDRecording` n'existe pas, `LifePlay.CollisionDump` est la preuve collision. Pour un
enregistrement CVD, ouvrir l'éditeur et attacher le débogueur visuel Chaos au processus, ou jouer
en PIE.
Options déjà en place, inchangées : `-LPDump*`, `-LPTrace*`, `-LPNoDataCache`, `-LPDataCacheVerify`,
console `LifePlay.LogSummary` et `ModdingExtra.LoadTxtStats`.
## 6. Gates
| Étape | Vert seulement si |
|---|---|
| Build | UAT code 0, `LifePlay.exe`, 6 lanceurs à côté, PDB du projet présents |
| Hitch | Au moins une ligne `LPDebug hitch :`, ou `0 hitch(s)` après ≥ 2 min |
| Signet | Ligne `LPDebug bookmark :` |
| Mémoire | Fichier `MemSnapshot_*.txt` non vide |
| Session A | `.utrace` ouvrable, signets alignés sur les hitches, 3 à 5 causes avec ms ou % |
| Session B | Physique en Mo, MemReport ou snapshot, CVD **ou** CollisionDump, delta mémoire |
| Session C | Au moins une tranche de 9 000 images, LLM, médiane ≤ 17 ms (±1) ou écart expliqué, images > 100 ms comparées à O0 (112). Jouer **sans** `-LPHitchLog` |
Preuves attendues : `Dbg-I4`, `Dbg-I5`, `Dbg-I6` sous `D:\Game\LifePlay_Backup_5.5\`.
## 7. Agent
```
- [ ] Development pour les chiffres, DebugGame pour la plongée
- [ ] BuildDebug.ps1 si l'archive n'existe pas ou si le C++ a changé
- [ ] Une session (A, B ou C), pas un lanceur unique
- [ ] CollectDebugArtifacts.ps1
- [ ] Insights / SummarizeDebugCsv / ChaosVD selon la session
- [ ] Rien de Tracy, Optick, ASAN, ImGui
```
Outils et URLs : `.cursor/skills/lifeplay-debug-build/reference.md`.
Priorité : Unreal Insights → CSV/LLM → ChaosVD → RenderDoc / PIX / suite Radeon / µProf / diagnostics Visual Studio.
Écartés : Tracy, Optick, Superluminal, ASAN, Nsight par défaut (machine AMD).
## 8. Mesures du 2026-10-04 et décision
Build DebugGame : `D:\Game\LifePlay_Build_5.5_DebugGame` (UAT 243 s). Preuves :
`D:\Game\LifePlay_Backup_5.5\Dbg-I4` et `Dbg-I5`. Les millisecondes DebugGame ne se comparent
pas à O0.
### Session A (G6)
Trace CPU courte ouvrable (`SessionA_cpu.utrace`, 252 Mo, export
`Dbg-I4\GameThreadTimers.txt`) : 5 388 images, 32 à-coups ≥ 50 ms, max **2 389 ms**.
La trace avec canal `memory` (`SessionA.utrace`, 6,4 Go, 89 à-coups en 350 s, max 6,7 s)
a saturé Insights (51 Gio / 63). Les signets `TRACE_BOOKMARK` sont émis dans la même
fonction que chaque ligne `LPDebug hitch` ; le max 2,35 s des timers `FTimerManager` et
`ExecuteUbergraph_City` est le même à-coup que le journal (2 389 ms).
Temps inclus GameThread, budget de travail `GameEngine Tick` = 14,42 s (l'attente de
cadence, 69,6 s, est à part) :
| Cause | Inclus | Part du tick moteur | Max une fois |
|---|---:|---:|---:|
| `ExecuteUbergraph_GI` | 5,34 s | 37 % | 2,35 s |
| `FTimerManager` | 3,39 s | 24 % | 2,35 s |
| `ExecuteUbergraph_City` | 2,51 s | 17 % | 2,35 s |
| `ExecuteUbergraph_Person` | 1,73 s | 12 % | 0,30 s |
| `PopulateRaws` | 1,26 s | 9 % | 1,26 s |
| Actions latentes Blueprint | 1,03 s | 7 % | 0,30 s |
| `LoadTxt` | 5,5 ms | — | 0,2 ms |
| `LPDataCache` | 2,6 ms | — | 0,2 ms |
`LoadTxt` n'est pas la source des à-coups. Le pic de 2,35 s est le graphe de `GI` / `City`
déclenché par le gestionnaire de minuteries.
### Session B (physique)
LLM, fin de chargement de `CentralLondon` (textures 651 Mo, proche des 624 Mo d'O0) :
| Poste | Début | Fin |
|---|---:|---:|
| Physics | 6,3 Mo | **171,6 Mo** |
| Physics/ChaosTrimesh | — | 87,6 Mo |
| TrackedTotal | 843 Mo | 1 888 Mo |
Delta physique **+165 Mo**. `p.Chaos.StartVDRecording` a écrit
`ChaosVD-20261004_130550.utrace` (172 Mo). Le `CollisionDump` du `ExecCmds` de démarrage
compte 23 primitives et 1 trimesh, sans dire qui le porte. Le détail est au §10.
MemReport et `MemSnapshot_20261004_130550.txt` sont dans `Dbg-I5\SessionB`.
Les 463 Mo d'O0 ne se retrouvent pas : les collisions décoratives ont été retirées en O9.
La physique reste le second poste derrière les textures, plus le premier.
### Session C (Development, sans `-LPHitchLog`)
Build `D:\Game\LifePlay_Build_5.5_Development` (UAT 127 s). Une tranche complète :
`Profile(20261004_131659).csv`, 9 000 images. Preuves : `Dbg-I6\SessionC`.
| Mesure | Cette tranche | O0 (36 004 images) |
|---|---:|---:|
| Médiane temps d'image | **16,66 ms** | 16,7 ms |
| Médiane thread de jeu | 3,57 ms | 3,9 à 4,4 ms |
| Images > 50 ms | 52 (0,58 %) | 159 (0,44 %) |
| Images > 100 ms | 23 (0,26 %) | 112 (0,31 %) |
La médiane tient le plafond de 60 images/s (≤ 17 ms). Le taux d'images > 100 ms n'est pas
plus haut qu'en O0. Le parcours n'est pas les 15 minutes du scénario O0 (démarrage puis
`CentralLondon`), donc le décompte brut 23 contre 112 ne se compare pas tel quel. LLM en fin
de cette tranche : textures 605 Mo, physique 89 Mo (la session B, plus longue, monte à 172 Mo).
### Décision
Prochain lot d'optimisation : **G6**, pas O10 en premier. O10 reste un lot mémoire
(trimesh ~88 Mo en session B), après G6. Le sous-système debug, journal d'à-coups éteint,
ne déplace pas la médiane Development. La trace Development du §9 nomme la feuille :
ce n'est pas le graphe `GI` qu'il faut réécrire.
## 9. Trace Development courte (G6, 2026-10-04)
Build déjà en place : `D:\Game\LifePlay_Build_5.5_Development`. Trace
`Windows\LifePlay\Saved\Profiling\G6Dev.utrace` (464 Mo), canaux
`cpu,frame,bookmark,loadtime`, sans `memory`, avec `-LPHitchLog`. Durée 184 s, arrêt
après le premier à-coup > 500 ms. Copies : `D:\Game\LifePlay_Backup_5.5\Dbg-G6`.
Un seul à-coup > 500 ms : **3 621 ms** à l'image du clic Continuer (`DelayedStart`,
3,583 s). Le minuteur de 2 s qui rappelle `DelayedStart` dure ~13 µs. Aucun
`FTimerManager_Tick` > 200 ms : le 654 ms de l'image 3137 (CSV I6) n'est pas reproduit
sur ce démarrage automatique.
Feuille CPU, temps exclusif dans cette image (export `ExportTimerCallees`, thread de jeu) :
`FindCenterOfPolygon` **0,350 s** exclusif / 0,742 s inclus, 49 425 appels (centre de la
boîte englobante, pas le centroïde). `Array_Get` est plus haut en exclusif (0,536 s) mais
c'est un opcode de la machine virtuelle, pas une fonction. `PopulateRaws` et
`ExecuteUbergraph_City` restent des contenants (exclusif négligeable).
Lecture des ~164 Mo (CSV I6, image 395, colonnes exclusives vides) : le canal `loadtime`
nomme `/Game/Heavy/StreetMap/Static/CentralLondon` et
`/Game/Heavy/StreetMap/CentralLondon`. Disque chaud, l'attente synchrone de cette trace
est 0,325 s (`GetAsset` × 2 → `MainThreadWaitingOnAsyncLoadingThread`).
Deux lots, baseline = la tranche I6 (médiane 16,66 ms, une image à 6,2 s, une image
TimerManager à 654 ms) :
- CHG-115 : `FindCenterOfPolygon` en C++, quatre appels de `GI` rebranchés. Pas de
réécriture du graphe, pas de décalage des minuteries.
- CHG-116 : préchargement async de ces deux paquets à l'init de l'instance de jeu.
Séparé du correctif de la feuille.
Cuisson Development du 2026-10-04 14:26 (`BuildDebug_Development_20261004-142617.log`,
UAT 148 s) contient les deux lots. Partie 14:31–14:46, quittée normalement, sans
`-LPHitchLog` et sans CSV (journal archivé `Dbg-G6p\SessionC`). `Preload ville :
demande envoyee` dès l'init. Aucune erreur `FindCenterOfPolygon`. L'image du clic
Continuer (`StreetMap BeginPlay`, puis `PopulateRaws`) s'étale sur **1 017 ms** de
journal, contre 3 621 ms avant ces lots. Une autre image, à 14:33:02 (entrée
« Central London » / pièce `street`), s'étale sur 1 171 ms. Ce ne sont pas des temps
CSV : la médiane 16,66 ms et le rythme d'O0 restent à remesurer avec le lanceur
de la session C.
## 10. Rapport collisions (2026-10-04)
Les capsules des PNJ ne sont pas les 88 Mo. Un seul trimesh les explique, et le dump
de démarrage ne nomme pas son acteur. `-LPCollisionLog` (CHG-117) est dans la cuisson
de 15:16. La partie de 15:19 ne l'a pas activé : `LifePlay.exe` a été lancé sans ce switch.
| Preuve | Ce qu'elle montre |
|---|---|
| `Dbg-I5\SessionB\Profiling\LPDebug\CollisionDump_20261004_130550.txt` | Monde `CentralLondon`, 23 primitives dont **12 `Person_C`**, 6 `Room_C`, 2 `StreetMap_Static_C`, 1 `StaticMeshActor`. **1 trimesh** unique, 3 formes simples, 0 corps simulé. Pas de nombre de triangles ni d'acteur porteur. |
| `Dbg-I5\SessionB\Profiling\LLM\LLM_Pid12232_2026.10.04-13.05.50_Windows.csv` | 402 échantillons. Maximum : physique **176,7 Mo**, trimesh **93,5 Mo**, `ChaosUpdate` **83,0 Mo**, convexes **0,11 Mo**. Dès l'échantillon 17 le trimesh est déjà à 79,3 Mo. |
| `Dbg-I5\SessionB\Profiling\ChaosVD-20261004_130550.utrace` (180 Mo) | Enregistrement présent, non ouvert : il ne nomme pas le maillage. |
| `Dbg-I6\SessionC\Profiling\CSV\Profile(20261004_131659).csv` | Development, 9 000 images, médiane **16,66 ms**. Image 395 : **6 218 ms** et 164 Mo lus. Image 3137 : **664 ms** dans `TimerManager`. |
| `Dbg-G6p\SessionC\Profiling\G6Dev.utrace` (464 Mo ; original dans le Saved du build Development) | Canaux `cpu,frame,bookmark,loadtime`. Image Continuer **3 621 ms**. Feuille `FindCenterOfPolygon` 0,350 s exclusif. Paquets `/Game/Heavy/StreetMap/Static/CentralLondon` et `/Game/Heavy/StreetMap/CentralLondon`. |
| `Dbg-G6p\SessionC\Logs\LifePlay.log` | Partie 14:31–14:46 avec CHG-115/116. Préchargement envoyé. Image Continuer **1 017 ms** de journal. Entrée dans la ville **1 171 ms**. Pas de relevé de collision (lanceur sans `-LPCollisionLog`). |
Lecture. Les 12 capsules de PNJ sont des formes simples : les convexes du LLM culminent à 0,11 Mo. Le trimesh (93 Mo) et `ChaosUpdate` (83 Mo) apparaissent ensemble et font l'essentiel des 177 Mo de physique. Le dump de la même session ne voit qu'un trimesh, donc ce poste est un maillage complexe unique, parmi `StreetMap_Static_C`, `Room_C` ou le `StaticMeshActor`, pas une capsule de personnage. `StreetMap` sait construire cette collision (`UseComplexAsSimple`, profil `BlockAll`) ; le défaut du composant est de ne pas la générer, et le dump ne dit pas si l'instance de la ville l'a fait.
Le CVD et le dump de démarrage ne suffisent pas à désigner l'acteur. Le suivi `-LPCollisionLog` écrit `CollisionTrack_*.txt` (une ligne toutes les 2 s) et un `CollisionDump_*.txt` dès que des triangles sont comptés, avec la classe, l'acteur et le composant. Les lanceurs `LifePlay_debug_sessionB_mem.bat` et `LifePlay_debug_collision.bat` passent ce switch et ne lancent plus `LifePlay.CollisionDump` dans le `ExecCmds` de démarrage.
Partie de la cuisson 15:16, 15:19–15:27, sortie normale (`Dbg-G6r\LifePlay.log`). Lignes au démarrage : `LPDebug collision : inactif`, `Preload ville : demande envoyee`, aucune erreur `FindCenterOfPolygon`. Une image, à 15:20:00, s'étale sur **3 152 ms** de journal : `StreetMap BeginPlay`, puis les fichiers de monde, puis « Central London », puis le domicile (`home test310 UpdateWall`) et un clic. Environ **2 s** de cette image n'ont presque pas de lignes. Ce n'est pas un temps CSV. Le porteur du trimesh reste non nommé tant que la partie n'est pas lancée par `LifePlay_debug_collision.bat`.
Partie 15:37–15:50 avec `-LPCollisionLog` (réglage Collisions du lanceur). Sortie normale. 382 échantillons, 4 dumps, maximum **1 206 768** triangles (`Dbg-G6s`). À 7 s, le porteur est nommé :
| Triangles | Acteur | Composant | Profil |
|---:|---|---|---|
| **1 084 249** | `StreetMap_Static` | `CentralLondon` | `BlockAllDynamic` |
| 122 469 | `Room_C_0` (au pic, 61 primitives) | meubles `fnt_new*`, lampes `ls_lamp*` | `Custom` |
| 0 | 84 `Person_C` | une capsule `CollisionCylinder` partagée | `Custom` |
Le maillage de rue porte **90 %** des triangles de collision. Les PNJ n'en ont aucun. Preuve : `CollisionDump_20261004_153727.txt`. En fin de partie il reste 1 143 395 triangles. L'enregistrement ChaosVD (299 Mo) est dans le Saved du build.