From 3b76b6dcb995fb65c4f09c3df4840b33344fac26 Mon Sep 17 00:00:00 2001 From: Musa Mahmood Date: Sat, 17 Oct 2026 21:13:30 -0400 Subject: [PATCH] [0.1.26] gpu-bench: a memory trace per step, -ocr-workers and -ort-log Each result now has the GPU's memory over the baseline after loading, the first image, each warm-up pass and each timed pass (with the pass's peak), in the output and as trace= in the results file, so growth across passes (a leak) shows apart from a working set. -ocr-workers sets OCR's GPU worker threads, and -ort-log info prints onnxruntime's arena extensions: what found the cause of 0.1.24's memory fix. --- check_targets.jai | 2 +- first.jai | 2 +- tools/gpu_bench/gpu_bench.jai | 48 +++++++++++++++++++++++++++++++++-- 3 files changed, 48 insertions(+), 4 deletions(-) diff --git a/check_targets.jai b/check_targets.jai index c5769cb..10275bc 100644 --- a/check_targets.jai +++ b/check_targets.jai @@ -47,7 +47,7 @@ APP_NAME :: "mcap"; APP_FOLDER_NAME :: "mcap"; GIT_BRANCH :: "check"; GIT_HASH :: "-"; -VERSION :: "0.1.25"; +VERSION :: "0.1.26"; BUILD_DATE :: "-"; DEBUG :: true; COMPILE_TESTS :: true; diff --git a/first.jai b/first.jai index 24778c6..a40768a 100644 --- a/first.jai +++ b/first.jai @@ -8,7 +8,7 @@ APP_NAME :: "mcap"; APP_FOLDER_NAME :: "mcap"; APP_BUNDLE_IDENTIFIER :: "com.example.mcap"; -VERSION :: "0.1.25"; +VERSION :: "0.1.26"; // Where everything goes: bin/, or bin-headless/ for builds made with no_crash_dialog, so automated // builds never write over the ones you run by hand. build_directory := "bin"; diff --git a/tools/gpu_bench/gpu_bench.jai b/tools/gpu_bench/gpu_bench.jai index 12e0e8c..16f0d4e 100644 --- a/tools/gpu_bench/gpu_bench.jai +++ b/tools/gpu_bench/gpu_bench.jai @@ -19,10 +19,12 @@ // -out where the results file goes (default gpu-bench-results beside this program) // -note a few words kept with the results, such as "plugged in, max performance" // -progress also print @progress lines, for the GPU Benchmark window +// -ocr-workers N OCR's worker threads on the GPU, in place of Ocr_Options' (for investigating memory) +// -ort-log LEVEL onnxruntime's console log: verbose, info (each GPU arena extension), warning (default) // // Build: jai first.jai - release (it is built with mcap on the gpu-bench branch). -USAGE :: "Usage: gpu-bench [-only ocr,labels,segment] [-models a,b] [-repeats N] [-warmup N] [-cpu | -cpu-only] [-corpus FOLDER] [-out FOLDER] [-note TEXT] [-progress]\n"; +USAGE :: "Usage: gpu-bench [-only ocr,labels,segment] [-models a,b] [-repeats N] [-warmup N] [-cpu | -cpu-only] [-corpus FOLDER] [-out FOLDER] [-note TEXT] [-progress] [-ocr-workers N] [-ort-log LEVEL]\n"; options: struct { only: [..] string; @@ -32,6 +34,7 @@ options: struct { gpu := true; cpu := false; progress := false; + ocr_workers: s32; // 0: Ocr_Options' default corpus_folder, out_folder, note: string; }; @@ -56,6 +59,15 @@ main :: () { case "-out"; options.out_folder = value; i += 2; case "-note"; options.note = value; i += 2; case "-progress"; options.progress = true; i += 1; + case "-ocr-workers"; options.ocr_workers = cast(s32) max(1, string_to_int(value)); i += 2; + case "-ort-log"; + if value == { + case "verbose"; ort.log_level = .ORT_LOGGING_LEVEL_VERBOSE; + case "info"; ort.log_level = .ORT_LOGGING_LEVEL_INFO; + case "warning"; ort.log_level = .ORT_LOGGING_LEVEL_WARNING; + case; print("-ort-log takes verbose, info or warning.\n"); exit(2); + } + i += 2; case "-help"; print(USAGE); exit(0); case; print("Unknown option %.\n%", arg, USAGE); exit(2); } @@ -139,12 +151,14 @@ Run :: struct { stages: string; // where the time went, per item batch: s64; gpu: Gpu_Stats; + trace: [..] string; // the GPU's memory above the baseline, MB, after each step: load:812 first:1020 warm1:... pass1:.../peak... explanation: string; // why a GPU run is on the CPU } Gpu_Stats :: struct { sampled: bool; baseline_mb, peak_mb: float64; // device memory before the engine, and the most during the timed passes + pass_peak_mb: float64; // the most during the current timed pass util_sum, power_sum, clock_sum: float64; temperature_max: float64; samples: s64; @@ -300,7 +314,9 @@ run_task :: (task: *Task, prefer_gpu: bool, corpus: *Corpus) -> Run { phrase_vectors: [] float; if task.kind == { case .OCR; - engine.ocr, ok, error = ocr_create(task.models_folder, task.model, prefer_gpu); + ocr_options: Ocr_Options; + if options.ocr_workers ocr_options.gpu_workers = options.ocr_workers; + engine.ocr, ok, error = ocr_create(task.models_folder, task.model, prefer_gpu, ocr_options); if ok { ocr_gpu, ocr_why := ocr_gpu_status(engine.ocr); if prefer_gpu && !ocr_gpu run.explanation = copy_string(ocr_why); @@ -327,6 +343,7 @@ run_task :: (task: *Task, prefer_gpu: bool, corpus: *Corpus) -> Run { } } run.load_s = seconds_since(load_start); + trace(*run, "load"); if !ok { sampler_stop(); run.error = copy_string(error); return run; } defer { ocr_destroy(engine.ocr); @@ -413,10 +430,12 @@ run_task :: (task: *Task, prefer_gpu: bool, corpus: *Corpus) -> Run { first_start := current_time_monotonic(); pass(true); run.first_s = seconds_since(first_start); + trace(*run, "first"); reset_temporary_storage(); for 1..options.warmup { progress(task.name, run.provider, "warm-up", it, options.warmup); pass(false); + trace(*run, tprint("warm%", it)); reset_temporary_storage(); } if task.kind == .OCR ocr_reset_stats(engine.ocr); @@ -426,8 +445,10 @@ run_task :: (task: *Task, prefer_gpu: bool, corpus: *Corpus) -> Run { for 1..options.repeats { progress(task.name, run.provider, "timing", it, options.repeats); start := current_time_monotonic(); + sampler_pass_start(); output, digest := pass(false); array_add(*run.pass_s, seconds_since(start)); + trace(*run, tprint("pass%", it), sampler_pass_peak()); if it == 1 { run.output = copy_string(output); run.digest = copy_string(short(digest)); } reset_temporary_storage(); } @@ -483,6 +504,7 @@ print_run :: (task: *Task, run: Run) { if run.gpu.samples print(" GPU: % MB more memory at the peak, % percent busy, % W, % MHz, up to % C\n", FF(run.gpu.peak_mb - run.gpu.baseline_mb, 0), FF(run.gpu.util_sum / run.gpu.samples, 0), FF(run.gpu.power_sum / run.gpu.samples, 0), FF(run.gpu.clock_sum / run.gpu.samples, 0), FF(run.gpu.temperature_max, 0)); + if run.trace.count print(" GPU memory over the baseline (MB), after each step [and its peak]: %\n", join(..run.trace, " ",, temp)); print(" found % (digest %)\n\n", run.output, run.digest); } @@ -529,6 +551,7 @@ write_results :: (info: System_Info, started_at: Apollo_Time, corpus: *Corpus, t FF(g.power_sum / g.samples, 0), FF(g.clock_sum / g.samples, 0), FF(g.temperature_max, 0)); } if run.stages print_to_builder(*b, " stages=%", run.stages); + if run.trace.count print_to_builder(*b, " trace=%", join(..run.trace, ",",, temp)); print_to_builder(*b, " output=% digest=%\n", run.output, run.digest); } name := tprint("%_%-%-%_%-%-%.txt", file_safe(info.machine), date.year, pad2(date.month_starting_at_0 + 1), pad2(date.day_of_month_starting_at_0 + 1), @@ -572,6 +595,7 @@ sampler_start :: (stats: *Gpu_Stats) { if ok && !sampler.paused && sampler.running { g := sampler.stats; g.peak_mb = max(g.peak_mb, s.memory_used_mb); + g.pass_peak_mb = max(g.pass_peak_mb, s.memory_used_mb); g.util_sum += s.util_percent; g.power_sum += s.power_w; g.clock_sum += s.sm_clock_mhz; @@ -585,6 +609,26 @@ sampler_start :: (stats: *Gpu_Stats) { thread_start(*sampler.thread); } +// The GPU's memory now, over the run's baseline, as a step of its trace; with the step's peak when known. +trace :: (run: *Run, step: string, peak: float64 = -1) { + if !run.gpu.sampled return; + s, ok := gpu_sample(); + if !ok return; + now := s.memory_used_mb - run.gpu.baseline_mb; + if peak >= 0 array_add(*run.trace, sprint("%:%[%]", step, FF(now, 0), FF(peak - run.gpu.baseline_mb, 0))); + else array_add(*run.trace, sprint("%:%", step, FF(now, 0))); +} + +// The peak of one timed pass: reset as it starts, read as it ends. +sampler_pass_start :: () { if !sampler.running return; lock(*sampler.mutex); sampler.stats.pass_peak_mb = 0; unlock(*sampler.mutex); } +sampler_pass_peak :: () -> float64 { + if !sampler.running return -1; + lock(*sampler.mutex); + peak := sampler.stats.pass_peak_mb; + unlock(*sampler.mutex); + return peak; +} + sampler_pause :: () { if !sampler.running return; lock(*sampler.mutex); sampler.paused = true; unlock(*sampler.mutex); } sampler_resume :: () { if !sampler.running return; lock(*sampler.mutex); sampler.paused = false; unlock(*sampler.mutex); }