Output: Add render progress logging
This commit is contained in:
1 parent
69819bb24f
commit
9b23f3717e
7 files changed
+163
-35
No files matched your search
@@ -166,6 +166,12 @@ cached/direct-fallback image counts. Pass `--psf-direct` to use the slower
|
||||
whose required HDR-tail support exceeds the cache radius selects that reference
|
||||
path automatically.
|
||||
|
||||
The PSF-cache completion line is printed before tracing and catalog splatting
|
||||
begin. For long renders, pass `--verbose` to print catalog-prefetch state,
|
||||
splat and image-write boundaries without adding work to the splat hot path.
|
||||
Movie renders always print one summary per time slab; `--verbose` also prints
|
||||
the ray counts before each slab is loaded.
|
||||
|
||||
For PSF validation only, `make psf-hdr-test` builds
|
||||
`build/minkowski_psf_hdr_test`, a separate binary with a `--hdr-output PATH`
|
||||
option. It writes the pre-tone-mapping RGB framebuffer as a 32-bit float PFM
|
||||
|
||||
+15
-1
@@ -292,16 +292,27 @@ size_t frame_splat_catalog(const FrameLensMesh *mesh,
|
||||
const PsfKernelCache *psf_cache,
|
||||
int catalog_load_workers,
|
||||
CatalogPrefetchStats *prefetch_stats,
|
||||
PsfSplatStats *psf_stats) {
|
||||
PsfSplatStats *psf_stats,
|
||||
const FrameSplatProgress *progress) {
|
||||
if (mesh == NULL || catalog == NULL || hdr == NULL || exposure <= 0.0 ||
|
||||
psf == NULL || width <= 0 || height <= 0 || catalog_load_workers <= 0)
|
||||
return 0;
|
||||
|
||||
/* A bounded parallel read phase completes before splatting. Its serial cache
|
||||
* commit leaves immutable tile data for the OpenMP splat workers. */
|
||||
if (progress != NULL && progress->callback != NULL)
|
||||
progress->callback(progress->context, FRAME_SPLAT_PROGRESS_PREFETCH_BEGIN,
|
||||
0, mesh->triangle_count);
|
||||
prefetch_catalog_for_mesh(mesh, catalog, catalog_load_workers, prefetch_stats);
|
||||
if (progress != NULL && progress->callback != NULL)
|
||||
progress->callback(progress->context, FRAME_SPLAT_PROGRESS_PREFETCH_END,
|
||||
prefetch_stats == NULL ? 0 : prefetch_stats->requested_tiles,
|
||||
prefetch_stats == NULL ? 0 : prefetch_stats->requested_tiles);
|
||||
if (psf_stats != NULL)
|
||||
*psf_stats = (PsfSplatStats){0};
|
||||
if (progress != NULL && progress->callback != NULL)
|
||||
progress->callback(progress->context, FRAME_SPLAT_PROGRESS_BEGIN, 0,
|
||||
mesh->triangle_count);
|
||||
|
||||
const size_t pixel_count = (size_t)width * height * 3;
|
||||
if (pixel_count > SIZE_MAX / sizeof(double) ||
|
||||
@@ -381,6 +392,9 @@ size_t frame_splat_catalog(const FrameLensMesh *mesh,
|
||||
free(private_hdr);
|
||||
if (psf_stats != NULL)
|
||||
*psf_stats = (PsfSplatStats){images - direct_fallbacks, direct_fallbacks};
|
||||
if (progress != NULL && progress->callback != NULL)
|
||||
progress->callback(progress->context, FRAME_SPLAT_PROGRESS_END,
|
||||
mesh->triangle_count, mesh->triangle_count);
|
||||
return images;
|
||||
}
|
||||
|
||||
|
||||
+18
-1
@@ -27,6 +27,22 @@ typedef struct {
|
||||
size_t vertex_count, triangle_count;
|
||||
} FrameLensMesh;
|
||||
|
||||
typedef enum {
|
||||
FRAME_SPLAT_PROGRESS_PREFETCH_BEGIN,
|
||||
FRAME_SPLAT_PROGRESS_PREFETCH_END,
|
||||
FRAME_SPLAT_PROGRESS_BEGIN,
|
||||
FRAME_SPLAT_PROGRESS_END
|
||||
} FrameSplatProgressStage;
|
||||
|
||||
typedef void (*FrameSplatProgressCallback)(void *context,
|
||||
FrameSplatProgressStage stage,
|
||||
size_t completed, size_t total);
|
||||
|
||||
typedef struct {
|
||||
FrameSplatProgressCallback callback;
|
||||
void *context;
|
||||
} FrameSplatProgress;
|
||||
|
||||
int frame_lens_mesh_build_coarse(FrameLensMesh *mesh, int width, int height,
|
||||
int cell_pixels, double horizontal_fov_deg);
|
||||
int frame_lens_mesh_trace(FrameLensMesh *mesh, const SpacetimeSource *spacetime,
|
||||
@@ -42,7 +58,8 @@ size_t frame_splat_catalog(const FrameLensMesh *mesh,
|
||||
const PsfKernelCache *psf_cache,
|
||||
int catalog_load_workers,
|
||||
CatalogPrefetchStats *prefetch_stats,
|
||||
PsfSplatStats *psf_stats);
|
||||
PsfSplatStats *psf_stats,
|
||||
const FrameSplatProgress *progress);
|
||||
void frame_draw_mesh(const FrameLensMesh *mesh, double *hdr, int width,
|
||||
int height, double gray, double opacity);
|
||||
void frame_lens_mesh_destroy(FrameLensMesh *mesh);
|
||||
|
||||
+103
-19
@@ -9,6 +9,7 @@
|
||||
#include <errno.h>
|
||||
#include <limits.h>
|
||||
#include <math.h>
|
||||
#include <omp.h>
|
||||
#include <stdio.h>
|
||||
#include <stdlib.h>
|
||||
#include <string.h>
|
||||
@@ -19,6 +20,7 @@ typedef struct {
|
||||
int coarse_cell_pixels;
|
||||
int draw_mesh;
|
||||
int psf_direct;
|
||||
int verbose;
|
||||
double horizontal_fov_deg, look_ra_deg, look_dec_deg, exposure;
|
||||
double observer_radius;
|
||||
double observer_inward_speed;
|
||||
@@ -161,6 +163,8 @@ static int parse_args(int argc, char **argv, Settings *s,
|
||||
!parse_moffat_beta(argv[++i], &s->psf.moffat_beta)) {
|
||||
} else if (!strcmp(argv[i], "--psf-direct")) {
|
||||
s->psf_direct = 1;
|
||||
} else if (!strcmp(argv[i], "--verbose")) {
|
||||
s->verbose = 1;
|
||||
} else if (!strcmp(argv[i], "--write-catalog") && i + 1 < argc)
|
||||
*write_path = argv[++i];
|
||||
else if (!strcmp(argv[i], "--observer-track") && i + 1 < argc)
|
||||
@@ -191,6 +195,66 @@ static int parse_args(int argc, char **argv, Settings *s,
|
||||
return 0;
|
||||
}
|
||||
|
||||
typedef struct {
|
||||
int verbose;
|
||||
size_t frame_id;
|
||||
double splat_start;
|
||||
const CatalogPrefetchStats *prefetch;
|
||||
int catalog_load_workers;
|
||||
int all_sky_catalog;
|
||||
} RenderProgress;
|
||||
|
||||
static void report_splat_progress(void *context, FrameSplatProgressStage stage,
|
||||
size_t completed, size_t total) {
|
||||
RenderProgress *progress = context;
|
||||
(void)completed;
|
||||
if (progress == NULL)
|
||||
return;
|
||||
if (stage == FRAME_SPLAT_PROGRESS_PREFETCH_END && progress->all_sky_catalog) {
|
||||
const CatalogPrefetchStats *prefetch = progress->prefetch;
|
||||
fprintf(stderr,
|
||||
"Catalog prefetch: %zu requested, %zu newly loaded (%zu stars), "
|
||||
"%zu unavailable in %.3f s; %d loader workers\n",
|
||||
prefetch->requested_tiles, prefetch->newly_loaded_tiles,
|
||||
prefetch->newly_loaded_stars, prefetch->unavailable_tiles,
|
||||
prefetch->load_seconds, progress->catalog_load_workers);
|
||||
}
|
||||
if (!progress->verbose)
|
||||
return;
|
||||
switch (stage) {
|
||||
case FRAME_SPLAT_PROGRESS_PREFETCH_BEGIN:
|
||||
fprintf(stderr, "Frame %zu: finding and prefetching catalog tiles...\n",
|
||||
progress->frame_id);
|
||||
break;
|
||||
case FRAME_SPLAT_PROGRESS_PREFETCH_END:
|
||||
fprintf(stderr, "Frame %zu: catalog prefetch finished (%zu candidate tiles).\n",
|
||||
progress->frame_id, total);
|
||||
break;
|
||||
case FRAME_SPLAT_PROGRESS_BEGIN:
|
||||
progress->splat_start = omp_get_wtime();
|
||||
fprintf(stderr, "Frame %zu: splatting %zu lens triangles...\n",
|
||||
progress->frame_id, total);
|
||||
break;
|
||||
case FRAME_SPLAT_PROGRESS_END:
|
||||
fprintf(stderr, "Frame %zu: catalog splatting finished in %.1f s; writing image...\n",
|
||||
progress->frame_id, omp_get_wtime() - progress->splat_start);
|
||||
break;
|
||||
}
|
||||
}
|
||||
|
||||
static void ray_pool_status_counts(const RayPool *rays, size_t *pending,
|
||||
size_t *active, size_t *terminated,
|
||||
size_t *failed) {
|
||||
*pending = *active = *terminated = *failed = 0;
|
||||
for (size_t i = 0; i < rays->count; ++i)
|
||||
switch (rays->status[i]) {
|
||||
case RAY_POOL_PENDING: ++*pending; break;
|
||||
case RAY_POOL_ACTIVE: ++*active; break;
|
||||
case RAY_POOL_TERMINATED: ++*terminated; break;
|
||||
case RAY_POOL_FAILED: ++*failed; break;
|
||||
}
|
||||
}
|
||||
|
||||
static GeodesicTraceConfig trace_config(void) {
|
||||
#ifdef SPACETIME_SCHWARZSCHILD
|
||||
return (GeodesicTraceConfig){.coordinate_time_step = 0.1,
|
||||
@@ -229,11 +293,20 @@ static int render_observer_frame(const Settings *s, StarCatalog *catalog,
|
||||
free(hdr);
|
||||
return -1;
|
||||
}
|
||||
if (s->verbose)
|
||||
fprintf(stderr, "Frame 0: traced %zu lens vertices; starting catalog render.\n",
|
||||
mesh.vertex_count);
|
||||
CatalogPrefetchStats prefetch = {0};
|
||||
PsfSplatStats psf_stats = {0};
|
||||
RenderProgress progress = {.verbose = s->verbose,
|
||||
.frame_id = 0,
|
||||
.prefetch = &prefetch,
|
||||
.catalog_load_workers = s->catalog_load_workers,
|
||||
.all_sky_catalog = catalog->kind == STAR_CATALOG_ALL_SKY};
|
||||
size_t images = frame_splat_catalog(
|
||||
&mesh, catalog, hdr, s->width, s->height, s->exposure, &s->psf,
|
||||
&s->psf_cache, s->catalog_load_workers, &prefetch, &psf_stats);
|
||||
&s->psf_cache, s->catalog_load_workers, &prefetch, &psf_stats,
|
||||
&(FrameSplatProgress){report_splat_progress, &progress});
|
||||
if (s->draw_mesh)
|
||||
frame_draw_mesh(&mesh, hdr, s->width, s->height, 0.5, 0.5);
|
||||
#ifdef ENABLE_HDR_DEBUG
|
||||
@@ -250,14 +323,6 @@ static int render_observer_frame(const Settings *s, StarCatalog *catalog,
|
||||
images, catalog->count, output_path,
|
||||
result == 0 ? "ok" : "write failed");
|
||||
psf_kernel_cache_report(&s->psf_cache, &psf_stats, stderr);
|
||||
if (catalog->kind == STAR_CATALOG_ALL_SKY)
|
||||
fprintf(stderr,
|
||||
"Catalog prefetch: %zu requested, %zu newly loaded (%zu stars), "
|
||||
"%zu unavailable in %.3f s; %d loader workers\n",
|
||||
prefetch.requested_tiles, prefetch.newly_loaded_tiles,
|
||||
prefetch.newly_loaded_stars, prefetch.unavailable_tiles,
|
||||
prefetch.load_seconds,
|
||||
s->catalog_load_workers);
|
||||
frame_lens_mesh_destroy(&mesh);
|
||||
free(hdr);
|
||||
return result;
|
||||
@@ -314,14 +379,33 @@ static int render_movie(const Settings *s, StarCatalog *catalog,
|
||||
f, v))
|
||||
goto done;
|
||||
double slab_hi = movie.frames[movie.frame_count - 1].coordinate_time;
|
||||
size_t slab_id = 0;
|
||||
while (ray_pool_has_live(&rays)) {
|
||||
const double slab_lo = slab_hi - s->slab_duration;
|
||||
MetricSlab *slab = NULL;
|
||||
size_t pending_before, active_before, terminated_before, failed_before;
|
||||
ray_pool_status_counts(&rays, &pending_before, &active_before,
|
||||
&terminated_before, &failed_before);
|
||||
if (s->verbose)
|
||||
fprintf(stderr, "Time slab %zu: loading [%.6g, %.6g] with %zu pending and %zu active rays.\n",
|
||||
slab_id + 1, slab_hi, slab_lo, pending_before, active_before);
|
||||
if (spacetime_load_slab(spacetime, slab_hi, slab_lo, &slab))
|
||||
goto done;
|
||||
ray_pool_activate_in_time_range(&rays, slab);
|
||||
size_t pending_active, active_active, terminated_active, failed_active;
|
||||
ray_pool_status_counts(&rays, &pending_active, &active_active,
|
||||
&terminated_active, &failed_active);
|
||||
ray_pool_advance_active(&rays, slab, &trace);
|
||||
spacetime_free_slab(slab);
|
||||
size_t pending_after, active_after, terminated_after, failed_after;
|
||||
ray_pool_status_counts(&rays, &pending_after, &active_after,
|
||||
&terminated_after, &failed_after);
|
||||
fprintf(stderr,
|
||||
"Time slab %zu [%.6g, %.6g]: activated %zu; live %zu -> %zu, "
|
||||
"terminated %zu, failed %zu\n",
|
||||
++slab_id, slab_hi, slab_lo, active_active - active_before,
|
||||
pending_before + active_before, pending_after + active_after,
|
||||
terminated_after, failed_after);
|
||||
slab_hi = slab_lo;
|
||||
}
|
||||
for (size_t i = 0; i < rays.count; ++i) {
|
||||
@@ -342,9 +426,16 @@ static int render_movie(const Settings *s, StarCatalog *catalog,
|
||||
}
|
||||
CatalogPrefetchStats prefetch = {0};
|
||||
PsfSplatStats psf_stats = {0};
|
||||
RenderProgress progress = {
|
||||
.verbose = s->verbose,
|
||||
.frame_id = movie.frames[i].frame_id,
|
||||
.prefetch = &prefetch,
|
||||
.catalog_load_workers = s->catalog_load_workers,
|
||||
.all_sky_catalog = catalog->kind == STAR_CATALOG_ALL_SKY};
|
||||
const size_t images = frame_splat_catalog(
|
||||
&movie.frames[i].mesh, catalog, hdr, s->width, s->height, s->exposure,
|
||||
&s->psf, &s->psf_cache, s->catalog_load_workers, &prefetch, &psf_stats);
|
||||
&s->psf, &s->psf_cache, s->catalog_load_workers, &prefetch, &psf_stats,
|
||||
&(FrameSplatProgress){report_splat_progress, &progress});
|
||||
if (s->draw_mesh)
|
||||
frame_draw_mesh(&movie.frames[i].mesh, hdr, s->width, s->height, 0.5, 0.5);
|
||||
const int write_result = write_tonemapped_image(output_path, hdr, s->width, s->height);
|
||||
@@ -352,14 +443,6 @@ static int render_movie(const Settings *s, StarCatalog *catalog,
|
||||
fprintf(stderr, "Rendered %zu images from %zu catalog stars to %s (%s)\n",
|
||||
images, catalog->count, output_path, write_result == 0 ? "ok" : "write failed");
|
||||
psf_kernel_cache_report(&s->psf_cache, &psf_stats, stderr);
|
||||
if (catalog->kind == STAR_CATALOG_ALL_SKY)
|
||||
fprintf(stderr,
|
||||
"Catalog prefetch: %zu requested, %zu newly loaded (%zu stars), "
|
||||
"%zu unavailable in %.3f s; %d loader workers\n",
|
||||
prefetch.requested_tiles, prefetch.newly_loaded_tiles,
|
||||
prefetch.newly_loaded_stars, prefetch.unavailable_tiles,
|
||||
prefetch.load_seconds,
|
||||
s->catalog_load_workers);
|
||||
if (write_result)
|
||||
goto done;
|
||||
}
|
||||
@@ -393,7 +476,7 @@ int main(int argc, char **argv) {
|
||||
"N] [--fov-deg D] [--look-ra-deg D] [--look-dec-deg D] "
|
||||
"[--exposure E] [--observer-radius R] [--observer-inward-speed V] "
|
||||
"[--psf-fwhm-pixels N] [--psf-moffat-beta N] "
|
||||
"[--psf-direct] "
|
||||
"[--psf-direct] [--verbose] "
|
||||
#ifdef ENABLE_HDR_DEBUG
|
||||
"[--hdr-output PATH] "
|
||||
#endif
|
||||
@@ -440,6 +523,7 @@ int main(int argc, char **argv) {
|
||||
}
|
||||
if (!settings.psf_direct && psf_kernel_cache_init(&settings.psf_cache, &settings.psf))
|
||||
fputs("PSF cache construction failed; using direct evaluator.\n", stderr);
|
||||
psf_kernel_cache_report_ready(&settings.psf_cache, stderr);
|
||||
int result = settings.frames_dir != NULL
|
||||
? render_movie(&settings, &catalog, &spacetime)
|
||||
: render_frame(&settings, &catalog, &spacetime);
|
||||
|
||||
+16
-10
@@ -263,22 +263,28 @@ int psf_kernel_cache_init(PsfKernelCache *cache, const PointSpreadFunction *psf)
|
||||
return 0;
|
||||
}
|
||||
|
||||
void psf_kernel_cache_report(const PsfKernelCache *cache,
|
||||
const PsfSplatStats *stats, FILE *stream)
|
||||
{
|
||||
void psf_kernel_cache_report_ready(const PsfKernelCache *cache, FILE *stream) {
|
||||
if (stream == NULL)
|
||||
return;
|
||||
if (cache == NULL || !cache->ready) {
|
||||
fprintf(stream, "PSF cache: disabled; cached splats 0, direct fallbacks %zu\n",
|
||||
stats == NULL ? 0u : stats->direct_fallbacks);
|
||||
fputs("PSF cache: disabled; using the direct evaluator.\n", stream);
|
||||
return;
|
||||
}
|
||||
fprintf(stream, "PSF cache: 64x64 phases, radius %.0f px, tail abs %.0e, "
|
||||
"boundary %.0e, build %.3f s; cached splats %zu, direct fallbacks %zu\n",
|
||||
fprintf(stream, "PSF cache ready: 64x64 phases, radius %.0f px, tail abs %.0e, "
|
||||
"boundary %.0e, build %.3f s\n",
|
||||
cache->max_radius_pixels, psf_tail_absolute_hdr_budget,
|
||||
psf_boundary_hdr_budget, cache->build_seconds,
|
||||
stats == NULL ? 0u : stats->cached_splats,
|
||||
stats == NULL ? 0u : stats->direct_fallbacks);
|
||||
psf_boundary_hdr_budget, cache->build_seconds);
|
||||
}
|
||||
|
||||
void psf_kernel_cache_report(const PsfKernelCache *cache,
|
||||
const PsfSplatStats *stats, FILE *stream)
|
||||
{
|
||||
if (stream == NULL)
|
||||
return;
|
||||
(void)cache;
|
||||
fprintf(stream, "PSF splats: cached %zu, direct fallbacks %zu\n",
|
||||
stats == NULL ? 0u : stats->cached_splats,
|
||||
stats == NULL ? 0u : stats->direct_fallbacks);
|
||||
}
|
||||
|
||||
void splat_moffat_direct(double *hdr, int width, int height, double x, double y,
|
||||
|
||||
@@ -31,6 +31,7 @@ LinearRgb blackbody_to_linear_rgb(double temperature_K);
|
||||
int psf_kernel_cache_init(PsfKernelCache *cache,
|
||||
const PointSpreadFunction *psf);
|
||||
void psf_kernel_cache_destroy(PsfKernelCache *cache);
|
||||
void psf_kernel_cache_report_ready(const PsfKernelCache *cache, FILE *stream);
|
||||
void psf_kernel_cache_report(const PsfKernelCache *cache,
|
||||
const PsfSplatStats *stats, FILE *stream);
|
||||
/* Reference implementation: pixel-area-integrated Moffat with the same tail
|
||||
|
||||
+4
-4
@@ -27,7 +27,7 @@ int main(void) {
|
||||
goto done;
|
||||
const size_t images =
|
||||
frame_splat_catalog(&mesh, &catalog, hdr, width, height, test_exposure,
|
||||
&psf, NULL, 1, NULL, NULL);
|
||||
&psf, NULL, 1, NULL, NULL, NULL);
|
||||
if (images != 1 || hdr[3 * (50 * width + 50)] <= 0.0) {
|
||||
fputs("flat-space inverse lens-map regression failed\n", stderr);
|
||||
goto done;
|
||||
@@ -44,10 +44,10 @@ int main(void) {
|
||||
omp_set_dynamic(0);
|
||||
omp_set_num_threads(1);
|
||||
const size_t serial_images = frame_splat_catalog(
|
||||
&mesh, &catalog, serial_hdr, width, height, test_exposure, &psf, NULL, 1, NULL, NULL);
|
||||
&mesh, &catalog, serial_hdr, width, height, test_exposure, &psf, NULL, 1, NULL, NULL, NULL);
|
||||
omp_set_num_threads(4);
|
||||
const size_t parallel_images = frame_splat_catalog(
|
||||
&mesh, &catalog, parallel_hdr, width, height, test_exposure, &psf, NULL, 1, NULL, NULL);
|
||||
&mesh, &catalog, parallel_hdr, width, height, test_exposure, &psf, NULL, 1, NULL, NULL, NULL);
|
||||
omp_set_num_threads(original_threads);
|
||||
for (int value = 0; value < width * height * 3; ++value)
|
||||
if (fabs(serial_hdr[value] - parallel_hdr[value]) >
|
||||
@@ -152,7 +152,7 @@ int main(void) {
|
||||
if (frame_lens_mesh_build_coarse(&fine_mesh, width, height, 1, 0.1) ||
|
||||
frame_lens_mesh_trace(&fine_mesh, &spacetime, &observer, &trace) ||
|
||||
frame_splat_catalog(&fine_mesh, &fine_catalog, hdr, width, height,
|
||||
test_exposure, &psf, NULL, 1, NULL, NULL) != 1) {
|
||||
test_exposure, &psf, NULL, 1, NULL, NULL, NULL) != 1) {
|
||||
fputs("fine source-triangle containment regression failed\n", stderr);
|
||||
frame_lens_mesh_destroy(&fine_mesh);
|
||||
goto done;
|
||||
|
||||
Reference in new issue
Block a user