V3Xengine works for Victoria 3
Unofficial · not affiliated with Paradox Interactive

Docs · Engine notes

Session 2026-11-13 evening (16:26-18:10): what the player felt, what changed, what to flip

A measured 1 h 44 m play session: what the player felt and what to flip.

Copied from docs/sessions/2026-11-13-evening.md in the V3X repository, file dated 2026-11-13.

Worker session. Tags: [M] measured in the files below, [I] inferred, [V] read in plugin source. L<n> = line of binaries/v3x/v3x.log; other files are relative to binaries/v3x/ unless they start with docs/ or plugins/.

Sources: v3x.log (4887 lines), crash.log, crash.prev.log, tick_profile.csv, sim_opt_diag.csv, alloc_report.txt (#210, written 18:10:13), lazy_gfx_report.txt, lazy_gfx_textures.csv, map_cache_report.txt, mod_report.txt, par_load_report.txt, load_timeline.txt, log_filter_stats.txt, devtools.log (last block, pid 14492, 592 reports), game logs in Documents/Paradox Interactive/Victoria 3/logs, save games/. The analysis scripts were throwaway (job tmp dir); every number below can be re-derived from the cited lines.

1. Session facts

item value source
process pid 14492, start 16:26:00.9, process exit (code 0) 18:10:35.0 = 1 h 44 m 34 s, clean exit L1, L4883, crash.log:1
also today 15:31:41-16:01:17 (pid 7584, 30 min): crash ACCESS_VIOLATION in mi_free via console_plus (#03/#05 frames), already fixed (chat #4351) crash.prev.log:1,44-75
“~4 h” not in these files: the two sessions above total 2 h 15 m; the devtools blocks before 15:31 are 3-12 min test runs devtools.log session headers
in-game first tick 16:30:08 (L810) to autosave_exit 18:09:30 (L4779) = 99.4 min
game dates ends 1847-06-17 (manual save name, L4777). 746 daily runs (UpdatePopGrowth, tick_profile.csv:6), 106 weekly, 24 monthly (tick_profile.csv:16), 2 yearly pulses (sim_opt_diag.csv:44) -> start about 1845-06-01 [I: 365-day years] = 2.04 game years
sim pace 746 days in 99.4 min = 7.5 days per wall minute incl. pauses; tick task time 1018.4 s = 17 % of in-game wall L4852
plugins 28/28 loaded (L173). tick_par is not installed (not in binaries/v3x/plugins/)
crashes / hangs none; no EXCEPTION in crash.log crash.log
machine at launch 16.1 GB RAM with only 6.0 GB free, commit 15.4 GB already used by other processes (limit 38.2 GB) crash.log:2

Modes [M, startup lines]:

plugin mode this session line
fast_lookup measure (token_cache + indent) L68
lazy_gfx measure, png_cache=build (turned itself OFF at L313) L90
par_load measure, 13/14 anchors (realdir FAILED) L161-162
sim_opt diag + diag_trades + diag_journal, throttle=0 L168
alloc_tracker on (diagnostic; periodic report every 30 s) L13-15
mod_loader on (verify_every=64) L142
map_cache on (keep-alive budget 256 MB, max 32 MB/texture) L122-123
lazy_mesh lazy (defer portraits + military, prefetch on Game) L106
mem_tuner options set (eager_commit 0, decommit delays), thread collect, periodic collect, census, anim-pool diag L124-138
enhance binary_saves_in_debug, save hook, lean_debug/tooltips/theater_cache L54
frame_pacer on, idle/background caps, tick_render_hz=0 (MinLockTime 1 ms) L71, frame_pacer.ini:35
others asset_stream (streaming 512 MB), cpu_sched (main on P-cores), keep_history record_all, console_plus, content_packs, crash_logger, devbridge, devconsole, devtools (profiler off), fast_load, gfx_driver, hello, ironman_console, loc_fallback, log_filter (aggressive), mod_menu, tick_profiler L17-172

2. What the player felt, ranked

2.1 Weekly market tick UpdateStateTrades (UST): the worst sim stall [M]

  • 106 runs, 173.2 s = 17.0 % of task time, avg 1.63 s, max 9.52 s (tick_profile.csv:3). 49 of 106 runs >= 1 s (sim_opt_diag.csv:269). Largest: 9519 ms (L4696), 8730 ms (L3042), 8004 ms (L4025), 6820 ms, 5978 ms, 5788 ms.
  • It gets worse with game time: the first 61 runs averaged 0.79 s, the last 45 runs 2.78 s (cumulative values in the periodic reports at 17:24:29 and L4852).
  • Shape: every run needs >= 16 iterations (sim_opt_diag.csv:275); 1,320 iterations per run on average, max 8,380; 139,944 iterations evaluated 590,389 records = 4.2 records per iteration (sim_opt_diag.csv:263-265). A typical slow run is “records 270 -> 1”: one big first iteration (longest iteration 21-413 ms), then thousands of iterations over 1-4 records. Cost per iteration = 172.7 s / 139,944 = 1.23 ms, of which the parallel-for (dispatch + evaluation + help-while-waiting) is 0.59 ms (parallel phase 82.7 s = 48 %, sim_opt_diag.csv:267, L4795). So the run time is a long tail of tiny iterations, not a large n.
  • During the 8.7 s run the game still rendered 21.5 fps (L3039), so the player sees days stop, not a frozen window.

2.2 HandleAutonomousInvestment (HAI) [M]

  • 2,984 runs (every tick), 262.4 s = 25.8 %, avg 88 ms, max 5.97 s (tick_profile.csv:2). Execute itself is 27 ms total; the time is in the parallel range over 267 countries (sim_opt_diag.csv:31).
  • Not uniform: 16:52-16:59 averaged 328 ms per tick (119 runs, 39.0 s), 16:30-16:52 51 ms, after 17:50 41 ms (cumulative values of the periodic tick_profiler reports). A max of 5.97 s with this shape points at one heavy country or event window [I].
  • No 6 s frame appears anywhere (largest in-game frame outside load/exit is 2.84 s, L3236), so long ticks slow the sim but do not freeze rendering [M].

2.3 Other tick tasks [M]

UpdateAI 77.6 s (7.6 %, 26 ms/tick, max 668 ms, tick_profile.csv:4); RecalculateModifierNodes 50.2 s (4.9 %); UpdatePopGrowth 43.3 s (4.3 %, 58 ms/day); CreateNewPoliticalMovements max 1.41 s (tick_profile.csv:29). MonthlyPulseJournalEntries: avg 338 ms, max 413 ms (tick_profile.csv:16), of which stage 1 (ExecuteOnPulse in Execute) is only 104 ms in total (sim_opt_diag.csv:14): stage 2, the per-country serial loop, is 98.7 % of it. That answers the open question in docs/re/simulation.md:90.

2.4 Frame stalls [M]

  • In game (16:28:48-18:09:30): 174,238 engine frames, avg 28.8 fps, 3,582 frames > 100 ms, 56,124 > 33 ms (sum of 601 frame_pacer lines). 220 of the 592 ten-second windows had a frame > 0.5 s, 43 had one > 1 s, 2 had one > 2 s.
  • map_cache logs every frame > 250 ms with the texture reads inside it. 613 such frames from 16:29:40 to 18:09:00, 332 s in total:
cause (co-logged in the same frame) frames total avg
alloc_tracker periodic report on the main thread (report written ... periodic, main thread) 199 111.4 s 0.56 s
texture disk reads in the frame 51 30.9 s 0.61 s
tick_profiler report, lazy_gfx, heap compact, census 8 3.5 s
nothing logged (unattributed) 355 186.2 s 0.52 s

Cross-check by phase: spikes falling 0-2 s after an alloc_tracker report: 217 (121 s); every other 2-s bin of the 30-s cycle holds 18-37 (avg 28, ~14.6 s). Excess ~190 stalls, ~106 s. So ~190-200 stalls of ~0.55 s, one every 30 s, are caused by V3X’s own alloc_tracker (196 main-thread reports in the log). Example pairs: L3486/L3487 (report 17:37:37.165, spike 653 ms 2 ms later), 18:07:07.806/18:07:07.808 (548 ms).

  • Texture stalls: the main thread reloaded the 150 MB flat-map textures 26 times (flatmap_ap1 x7, flatmap_ep1 x6, flatmap_overlay_ap1 x7, flatmap_overlay_ep1 x6: 6.0 s, 150-660 ms each, lazy_gfx_textures.csv, lazy_gfx_report.txt:38-78); main-thread texture time in Game 9.18 s in total (L4885). [I] Triggered by zooming out to the paper map / map-mode switches.
  • lazy_mesh on-demand loads on the main thread: 22 loads, 1.47 s, max 136 ms (L4787) - small.
  • The 355 unattributed stalls grow late in the session (18:02-18:04: 50 stalls, 19.8 s) while tick activity was low; their cause is not in any log [M count, cause unknown]. The devtools profiler was off (devtools.log [profiler] OFF).

2.5 The 46 s map_cache spike is an exit artifact [M]

spike 46093 ms at 18:10:16.422 (L4881) -> the frame began at 18:09:30.33, 80 ms after autosave_exit ended (L4779). That frame contains the whole Game -> Empty transition (42.8 s, L4784; BEGIN at +6209.5 s = 18:09:30.4 per load_timeline.txt:184) plus ~3 s of end-of-state plugin reports on the main thread (L4785-L4878). frame_pacer state was paused-idle, never minimized; background occurs once in the whole log (L786). Verdict: real, single frame, caused by quitting to the menu; not gameplay, not pause/minimize. Exclude it.

2.6 Loading [M]

  • Startup Empty -> Game (database load, ends in the main menu): 153.5 s (L566, debug.log:152), process start to menu 167.4 s. par_load: game_init 150.9 s on one task worker, of which VFSOpen 68.4 s (12,580 opens), lexer 29.4 s, blend shapes 18.7 s; gui_load 27.3 s, asset_load 39.8 s, db_init 41.4 s (CAccessoryVariationDatabase 8.5 s = 21 %), render_ls 5.7 s (par_load_report.txt:5-27).
  • Textures on the init thread (tid 10516) during the load: 5,423 files, 52.4 s, of which “open” 43.5 s (8.0 ms per file), 2.1 GB (lazy_gfx_textures.csv). Over all load-phase textures, open is 87.3 of 101.6 s; mod_loader’s misses cost only 205 ms in this load (L577), so the open cost is the hit open itself [I: filter drivers / AV or cold metadata; not measurable from these files].
  • Save load from the menu: one 29.3 s frame (L786, window in background) with map_cache spikes of 16.8 s and 13.6 s (L777, L787: 1,003 texture reads, 649 MB); private memory 12.4 -> 17.3 GB and free RAM down to 475-802 MB (crash.log:17-22). Smooth again by 16:29:57 (60.4 fps window, L806). Process start to first tick: 4 min 7 s.
  • Exit Game -> Empty: 42.8 s incl. checksum 9.6 s (L4784).

2.7 Autosaves [M]

24 monthly autosaves, zipped binary (format 3): avg 3.10 s, min 2.85, max 3.52 s, rising with game time (L1014 … L4714); manual save 3.69 s (L4777), exit save 3.32 s (L4779). Files are 28 MB (save games/autosave*.v3). The visible frame stall per autosave is ~1.2-1.4 s (e.g. 1281 ms at L1012 before save #1, 1415 ms before save #9, 1220 ms before save #15); the rest of the save runs off the frame. fast_lookup counted ~7.9 M WriteIndent and ~30-50 k token lookups per save interval (L1013-L4778).

2.8 Memory [M unless tagged]

  • Private bytes (crash.log): 35 MB at launch; 17.3 GB after the save load; post-load floor 17.5 GB (16:36:28, crash.log:29); 20.6 GB floor at 18:06:28 (crash.log:84); peak 21.3 GB at 18:05:57 (crash.log:82); RAM free mostly 1.4-3.0 GB, minimum 475 MB in the load.
  • Growth: +3.08 GB in 90 min = 2.05 GB per wall hour = 1.66 GB per game year (4.5 MB per game day), floor to floor (16:36:28 -> 18:06:28; 678 game days between the 16:36:27 and 18:06:31 tick reports). Last 30 min slowed to 1.2 GB/h (17:37:31 20,012 -> 18:06:28 20,607). Not flat yet at session end.
  • Commit limit 38,192 -> 39,222 MB at 17:29:56 and -> 40,264 MB at 18:01:34 (crash.log:62-63, 79-80): Windows grew the pagefile by ~1 GB twice, each time when commit available fell to 4.2-4.8 GB. System commit at 17:29:51 = 34.0 GB, of which the game 20.1 GB: other processes held ~14 GB of commit (15.4 GB before the game started, crash.log:2).
  • Split (mem_tuner census, L1023 vs L4651, 16:36:16 -> 18:06:50, private +2,924 MiB):
part 16:36 18:06 delta
mimalloc 32 MiB segments 7,362 9,101 +1,739 (walk IN USE 6,759 -> 8,522: live data, not slack; slack 377 MiB, pending decommit 167 MiB, L1024/L4652)
mimalloc huge 1,798 2,205 +407 (includes the anim-pool array 230 -> 517 MiB)
other (non-mimalloc) 8,475 9,252 +777 (<16M +274, <64M +334, >=64M +169)
main-thread mimalloc heap 1,614 3,153 +1,539 (L1026, L4654); every worker heap moved < 100 MiB
gui anim pool 1 live states 241,463 592,382 +351k (234k per hour); slots 311k -> 700k, array 230 -> 517 MiB (L1023, L4651)
  • Owners at the end (alloc_report.txt, live, sampled small blocks): pdx_gui_factory.cpp sites 697 MiB (:113), the anim pool 518 MiB (:114, site 039305ec), fn 007db700 345 MiB, fn 006c2020 297 MiB, fn 02320680 290 MiB, texture reserve 0x84800b 244 MiB (73.8 GB allocated over the session, :66). VM owners: 7,947 MiB of committed private memory has no user-mode reserve (kernel/driver mapping, [I] iGPU), Intel UMD 514 MiB, mimalloc os.c 10,223 MiB (:144-147).
  • Leak verdict: the growth is on the main thread (GUI) and the anim pool live count kept rising across the session with dips (485,602 at 17:26:44 -> 462,020 at 17:36:37 -> 592,382 at 18:06:50). That is the condition docs/re/memory.md:241 set for “a leak in the engine” [M growth; I cause: widgets kept alive or never torn down; a GUI-heavy mod in the playset is possible].
  • mem_tuner fixes: periodic mi_collect returned 1,548 MiB in 16 runs, each <= 16 ms (L4612); thread collects move tens of MiB per generation (L845…L4770); heap compact gains 0-10 MiB for 516-828 ms of work (L1022, L1452). Answers to memory.md:286-292: (a) os committed 9,210 vs IN USE 8,522 MiB; (b) slack 377, empty 5, free spans 178 MiB; (c) 32 MiB RW chunks = no user-mode reserve; (d) thread collect helps little.

3. Compared with the earlier 4-hour session (00:26-03:39)

Different save and game date, so per-task growth may be game state, not code [I].

metric earlier now change
Empty -> Game 163 s (docs/re/memory.md:157) 153.5 s (L566) -10 s
autosave 156 MB text, ~3.2 s frame each; 129 windows with a frame > 2 s (docs/re/enhance.md:15-28) 28 MB zipped binary, 3.10 s save, ~1.2-1.4 s frame; 2 windows > 2 s better
task time per game day 2,201 s / 2,746 days = 0.80 s (docs/re/tick_par.md:78,82) 1,018 s / 746 days = 1.37 s +70 %
HAI 11.1 %, max 1.9 s (docs/re/simulation.md:67); 244 s / 9,612 ticks = 25 ms/tick 25.8 %, max 5.97 s, 88 ms/tick 3.5x per tick
UST 5.8 %, max 3.1 s (simulation.md:71); 128 s / 353 runs = 0.36 s/run 17.0 %, max 9.52 s, 1.63 s/run 4.5x per run
UpdateAI 10.6 % (simulation.md:68), 24 ms/tick 7.6 %, 26 ms/tick same
RecalculateModifierNodes 6.8 %, 15.6 ms/tick 4.9 %, 16.8 ms/tick same
MonthlyPulseJournalEntries avg 490 ms, max 4.5 s (simulation.md:73) avg 338 ms, max 413 ms better
private growth +2.2 GB h1, +1.1 GB/h h2-3, flat near 20 GB at 3 h (memory.md:159-165) 20 GB after ~1 h of play (17:24), 2.05 GB/h, peak 21.3 GB worse
anim pool ~80k live states/h; 524 MiB array after 2.5 h (memory.md:173,224) 234k/h; 517 MiB after 1 h (17:26:33) ~3x faster
commit limit 54 GB (memory.md:166) 38.2 -> 40.3 GB pagefile smaller than then

4. Measure-mode plugins: is the evidence enough to switch?

plugin criterion (source) evidence this session verdict
fast_lookup measure compares every answer, any mismatch turns the cache off (docs/re/datastructures.md:105-107, plugins/fast_lookup/fast_lookup.ini.example:5-6); then “run measure, then on, compare save_end with enhance save timing” (datastructures.md:135-137) 1,722,908 calls, 1,717,010 compared, MISMATCHES 0, 99.7 % hits, engine 547 cyc vs cache 32 cyc, 26 saves (L4884); indent 204.8 M calls. Installed DLL 15:30:32 is newer than the r8-thunk source 15:29:03 (chat #4347), and 1 h 44 m ran with the detour live Met: switch to mode=on. Gain is small: token cache ~0.9 G cycles per session [I]; indent is the bulk, bounded by the ~8 % token-lock share of a save (datastructures.md:135) = <= ~0.25 s per 3.1 s save [I]. Suggest verify_every=64
lazy_gfx prefetch (mode=on) on = prefetch the previous run’s manifest (lazy_gfx.ini.example:9-10) manifest 0 files (L212; lazy_gfx_prefetch.txt is a header only): Empty -> Game starts at +13.9 s (load_timeline.txt:11), before any texture. manifest_game=0 (lazy_gfx.ini:19) Not met: on would prefetch nothing. Needs one run with manifest_game=1 (8,959 files, 3.77 GB > prefetch_max_mb=1024, lazy_gfx.ini:22) first
lazy_gfx png_cache acts only after layout_min confirmations and zero contradictions; verify mismatch = off (docs/re/lazy_gfx.md:154-160) 15,457 confirmations, 7 contradictions, verify bad 1, built 0 (lazy_gfx_report.txt:2); contradictions are malformed mod DDS (L331, L336, L347; debug.log:111-112); digest mismatch on a sakuya PNG (L313) Not met. Set png_cache=off until the gate skips malformed files (plugin work)
par_load mode=on: no step proven safe, runs as measure (docs/re/par_load.md:77) 13/14 anchors No: on changes nothing.
par_load blendshape_cache only if the blend step is I/O-bound after mod_loader=on (par_load.md:115) list “3786 entries, 0 native paths exist” (par_load_report.txt:69), because the realdir anchor FAILED (L161) Not possible: the prefetch list has no paths. Fix the realdir anchor first
mod_loader (already on) index mismatches must be 0 (mod_report.txt:119) 0 mismatches, 0 false hits, 98,786 verified skips, coverage 99.8 %, misses 1.43 s for the whole session (mod_report.txt:3) Keep on.
map_cache keep-alive (already on) pin after repeat_min disk reads, files <= max_texture_mb (plugins/map_cache/mc_core.c:179-180) pins added 4, pin hits 0, repeated reads 4,113 / 15.3 s, path table full at 6,144 (map_cache_report.txt:2-3; full at 3/4 of MC_MAX_PATHS 8192, mc_core.c:125, mc_core.h:29); the session saw 10,024 distinct paths (CSV) On does nothing now. Needs a bigger table; flat maps (150 MB) stay excluded by design
sim_opt throttle changes the simulation, single-player only (plugins/sim_opt/sim_opt.c:21-25) not a measure-to-on question lead decision
tick_par mode=on refused by design (docs/re/tick_par.md:66) not installed n/a

5. Top 10 actions (gain / risk; [M] = measured bound, [I] = estimate)

Flip a setting (no new code)

  1. alloc_tracker.ini: enabled = 0 (alloc_tracker.ini:6; its own header says “then set enabled=0 again”, :2). Removes ~190-200 main-thread stalls of ~0.55 s, one every 30 s, ~106-111 s per 100 min [M], plus the mi_new/mi_free hook cost on ~12 M events [I]. Risk: none (diagnostic). Re-enable only for a dedicated memory run, or set report_interval_s=0.
  2. fast_lookup.ini: mode = on, verify_every = 64 (fast_lookup.ini:9,19). Criterion met (section 4). Gain <= ~0.25 s per save [I]; verify with enhance’s save ms (baseline avg 3,103 ms over 24 autosaves). Risk: low.
  3. frame_pacer.ini: tick_render_hz = 30 (MinLockTime 1 -> 33 ms; frame_pacer.ini:35). UST alone runs ~140k iterations per session of ~1.2 ms, each ending at RenderFrameIfNeeded (docs/re/simulation.md:105). Expected 5-15 % tick throughput (docs/re/stellaris_techniques.md:340) [I]. Risk: choppier frames while the sim runs (10 Hz gave > 100 ms frames, frame_pacer.ini:21). A/B with tick_profiler totals.
  4. lazy_gfx two-step: run once with manifest_game = 1 and prefetch_max_mb = 4096, then mode = on. Bound: the init thread’s 43.5 s of texture opens in the 153.5 s load [M bound; gain I, only if prefetch makes the later open cheap]. Risk: 3.8 GB of background reads compete with the loader; standby-cache pressure on a machine with 6 GB free.
  5. Machine (lead): start the game with fewer background apps, or a fixed pagefile >= 16 GB. Other processes held ~14-15 GB commit and ~10 GB RAM (crash.log:2,62); RAM free fell to 475 MB in the load. Gain: fewer pagefile growths and paging stalls [I]. Risk: none.

Needs new engine work 6. UST small-n path: when the parallel-for 00e02c90 gets n <= threshold (tail iterations have 1-4 records), run the job body 00dd26e0 inline. The body writes only its own record and seeds per record (docs/re/simulation.md:100-104 [V]), so the result is identical. Bound: parallel phase 82.7 s of 172.7 s [M]; realistic gain the dispatch + wait share of 1,320 tail iterations per run [I]. First a read-only probe: which record keys survive the last 100 iterations (oscillation, possibly a mod) [I]. Risk: medium. 7. GUI growth RE (diag only): count anim-pool records in M+0x88 by widget vtable (docs/re/memory.md:241) and attribute the pdx_gui_factory.cpp live sites (697 MiB). Target: the main-thread heap’s +1.54 GB per 90 min [M]. Risk: none (read-only). 8. devtools profiler for one session (profile=1 or Ctrl+F10) to attribute the 355 unexplained stalls (186 s) [M]. Do it with alloc_tracker off, or the profile is dominated by the reports. Risk: sampling overhead. 9. HAI per-country probe: time each range item of HAI to find the country behind 5.97 s / the 328 ms-per-tick window [M]. Enables a targeted fix; the only generic lever, sim_opt throttle of HAI (1 run in 3 skipped, ~-87 s per session [I]), changes the simulation (lead decision). 10. Plugin fixes that unblock existing features: map_cache MC_MAX_PATHS 8192 -> 32768 (10,024 paths seen; repeated small-texture reads ~16 s of the 21.5 s repeat time, mostly off the main thread [I]); par_load realdir anchor so the blend prefetch list gets native paths (blend step 18.7 s in the load [M], gain only if I/O-bound [I]); lazy_gfx png_cache gate to skip non-multiple-of-4 / short-mip DDS.

Not verified

  • Cause of the 355 unattributed frame stalls; whether HAI/UST spikes come from a specific country or mod.
  • That the 8 ms texture open is AV/filter-driver cost (no ETW or profiler data).
  • Game start date (derived from task counts, not read from a save).
  • Gains of items 2-4, 6, 9, 10 (estimates; each needs an A/B session).