LifePlay-Revival/Docs/Migration/etat/ST/STE/STE-H9-TRACE.md

73 lines
4.9 KiB
Markdown
Raw Normal View History

# STE-H9-TRACE : trace Unreal Insights des saccades (archive STE-J5, HEAD 4283c13) — 2026-10-11
Décision de l'utilisateur : « Trace Insights » (après les DIAG H7 et H8, qui ont réfuté leurs pistes). Fenêtre « mesure » de
Big Boss (MACHINE CALME 04:44 ; fin envoyée à la fermeture du jeu, 04:59).
## 1. Capture et analyse
- Lancement par l'utilisateur :
`& "D:\Game\LifePlay_Build_5.8_STE-J5_Development\Windows\LifePlay.exe" '-trace=cpu,frame,bookmark,loadtime' -statnamedevents -LPHitchLog '-tracefile=...\Saved\Profiling\STE-H9.utrace'`
Parcours comme J5. Trace : `D:\Game\LifePlay_Build_5.8_STE-J5_Development\Windows\LifePlay\Saved\Profiling\STE-H9.utrace`
(1 813 013 815 o) ; `-LPHitchLog` : 120 à-coups en 546,4 s, max 1 564 ms (journal de l'archive).
- Analyse hors jeu, sans interface : `UnrealInsights.exe -OpenTraceFile=<trace> -AutoQuit -NoUI -unattended -nullrhi
-ExecOnAnalysisCompleteCmd="@=<fichier de commandes>"` (syntaxe des tests moteur `ExportCommandsTests.cpp:86-234`), commandes
`TimingInsights.ExportTimerStatistics` / `ExportTimingEvents` / `ExportThreads` ; 4 passes, toutes code 0. Exports et scripts
dans `scratchpad\h9\` (non suivis) : `tick.csv` (31 758 trames `FEngineLoop::Tick`), `lf_000…119.csv` (statistiques du
GameThread par trame ≥ 50 ms), `ev_*.csv` et `nc_*.csv` (événements complets de 12 trames).
- Les durées viennent des scopes de la trace (mesurées), pas de l'horodatage du journal : le décalage d'une trame des
analyses par journal (`STE-H4-MESURE.md` § 6) ne s'applique pas ici.
## 2. Les 120 trames ≥ 50 ms (18,6 s sur 545,6 s)
| Déclencheur (contenu de la trame) | Trames | Durée |
|---|---|---|
| Sans clic (actions latentes Blueprint, SPAWN, rafales) | 78 | 10,8 s (médiane 84 ms) |
| Clic « Suivant » d'une scène (`ContinueScene`) | 18 | 4,1 s |
| Autre clic d'interface (carte, CharGen, menus) | 24 | 3,7 s |
Une trame isolée de 1 564 ms au début (trame 48) est dans `STAT_FTicker_Tick` sans scope enfant : démarrage, hors périmètre.
## 3. Trames sans clic : chargement synchrone des cheveux (établi sur 3 trames détaillées)
Sous `UWorld_Tick > Blueprint Latent Actions > ExecuteUbergraph_Person` (code repris après un `Delay`) :
`LoadHairMeshIfNeeded` → `getSkeletalMeshFromPath` → `GetAsset` → `LoadPackageInternal` → `FlushAsyncLoading` :
**285 ms sur 442 ms** d'actions latentes (64 %), 89 appels, 5 à 9 ms chacun ; dont 252 ms d'attente du thread de chargement
(`MainThreadWaitingOnAsyncLoadingThread`). Exemple (trame 1, 305 ms) : 8 chargements de cheveux de 5 à 9 ms à la suite.
Correction de `STE-H7-DIAG.md` (FAL ≈ 5 %) : le journal et la colonne `EVENTS` du CSV ne voyaient que le premier FAL de chaque
trame ; la trace mesure tous les appels.
## 4. Clic « Suivant » de fin de scène (8 trames les plus lourdes détaillées, 2 454 ms)
Inclusif, sans double compte en récursion :
| Fonction (chaîne) | Durée | Appels |
|---|---|---|
| `ContinueScene` | 1 900 ms | 7 |
| `clearScenePersons` → `DestroyPerson` → **`SavePreset`** | 1 182 → 934 → **879 ms** | 8 → 14 → 14 |
| **`RevertStripAll`** → `GetSMBoolForSMC_Cloth` / `ShowAppropriateGenital` → `IsGenitalExposed` | 822 → 644 / 594 ms | 44 → 309 / 60 |
| `ReadSceneLine` / `CallFunction` | 819 / 815 ms | 28 / 25 |
| **`Current`** et `ShowUI` → `CopyActionsToScroll` (350 widgets `Action_C` créés) | 616 et 380 → 132 ms | 16, 8 |
| `Dress` → `ClearProxies` | 390 → 307 ms | 38 |
| `clearDaily` | 363 ms | 30 |
Points chauds internes : des boucles Blueprint à très grand nombre d'itérations (`Array_Get` : 190 079 appels sous
`IsGenitalExposed > GetSMBoolForSMC_Cloth`, 82 986 sous `Dress > ClearProxies` ; `GetObjectName` 388 071, `GetSkeletalMesh`
449 565, `GetMorphTargetsPtrConv` 147 045 dans ces 8 trames).
## 5. Autres clics d'interface
`StreetMap_Static.ActualLeftMouseInput` (clic sur la carte) : 168 574 `Array_Get` (295 ms) ; `ClickButtonHairstyle` 456 ms (7
trames) ; `DelayedStart` / nouvelle partie 1 279 ms (une fois).
## 6. Conclusions
1. **Apparition des PNJ / rafales** : le premier coût est le chargement **synchrone** des maillages de cheveux
(`LoadHairMeshIfNeeded` → `getSkeletalMeshFromPath`), environ 2/3 du temps des actions latentes. Correctifs possibles :
chargement asynchrone, préchargement des coiffures à l'entrée d'un lieu, cache des maillages déjà chargés.
2. **Fin de scène** : `SavePreset` dans `DestroyPerson` (≈ 110 ms par fin de scène dans ces trames), puis `RevertStripAll` /
`IsGenitalExposed` (boucles sur les vêtements, ≈ 75 ms), puis la reconstruction de l'interface d'actions (`Current`,
`ShowUI`, ≈ 120 ms).
3. Aucun de ces points n'est un défaut de la migration 5.8 établi ; ce sont des coûts du code de jeu (à comparer avec la 5.5 si
l'utilisateur le souhaite). Les correctifs demandent les dumps de ces fonctions (lot STE-D9, copie UE après les lots en file)
puis des SPEC.