diff --git a/Makefile b/Makefile index 8f07a03..87ba0bf 100644 --- a/Makefile +++ b/Makefile @@ -299,6 +299,7 @@ test: $(CAMERA_TEST_TARGETS) $(TEST_TARGET) $(ADAPTIVE_GEODESIC_TEST_TARGET) $(A $(SENSOR_BLOOM_TEST_TARGET) python3 tests/test_camera_cli.py $(BUILD_DIR) $(TEST_OUT_DIR) python3 tests/test_adaptive_cli.py $(BUILD_DIR) $(TEST_OUT_DIR) + python3 tests/test_ray_diagnostics.py $(BUILD_DIR) $(TEST_OUT_DIR) python3 tests/test_output_streams.py $(BUILD_DIR) $(TEST_OUT_DIR) tone-map-test: $(TONE_MAP_TEST_TARGET) diff --git a/nr_spacetime_movie_renderer_design.md b/nr_spacetime_movie_renderer_design.md index e608e36..40e054e 100644 --- a/nr_spacetime_movie_renderer_design.md +++ b/nr_spacetime_movie_renderer_design.md @@ -779,6 +779,17 @@ witness 提升为正式 midpoint 时原地复用同一 vertex id,只保留一 provenance 保存 coordinate-time step 与初始 step 预算,使实际积分来源与成本可 replay。 +诊断输出所有权:所有 ray 失败报告只在 CLI/main 的串行后处理阶段发出, +ray-tracing 的 OpenMP worker 与 geodesic 热循环不写任何日志(既有 PSF splat +诊断不属于此范围)。稳定的 `ray_reason_name` 覆盖全部 +`RayReason`;默认(非 verbose)也按 frame/phase 输出 `INCOMPLETE` 的 reason +直方图与真实 frame id、相机坐标时间,verbose 或 GR_DEBUG 才追加每 reason 有界 +数量的代表性样本(generation/phase、sample id/kind、持久 vertex id、film 坐标、 +可信 endpoint 的 stop 状态与 accepted/rejected/RHS 计数)并报告被抑制数量。 +`UNRESOLVED/BUDGET_EXHAUSTED` 只在帧边界统计确认存在 blocking triangle 时按帧 +报告,与数值 `INCOMPLETE` 区分;replay 使用文件中保存的几何与顶点诊断,不虚构 +stop 状态,也不把未重试的旧失败当作新失败重复计数。 + --- # 18A. 渐近外区、escape worldtube 与 endpoint 协议 diff --git a/src/geodesic.c b/src/geodesic.c index 7284fad..af2b84d 100644 --- a/src/geodesic.c +++ b/src/geodesic.c @@ -9,6 +9,32 @@ typedef struct { double x[3], Pi[3], log_alpha_p0; } Derivative; +const char *ray_reason_name(RayReason reason) { + switch (reason) { + case RAY_REASON_NONE: + return "NONE"; + case RAY_REASON_REDSHIFT_LIMIT: + return "REDSHIFT_LIMIT"; + case RAY_REASON_BUDGET_EXHAUSTED: + return "BUDGET_EXHAUSTED"; + case RAY_REASON_TIME_RANGE_EXHAUSTED: + return "TIME_RANGE_EXHAUSTED"; + case RAY_REASON_OUT_OF_DOMAIN: + return "OUT_OF_DOMAIN"; + case RAY_REASON_INVALID_METRIC: + return "INVALID_METRIC"; + case RAY_REASON_INTEGRATION_ERROR: + return "INTEGRATION_ERROR"; + case RAY_REASON_UNSUPPORTED: + return "UNSUPPORTED"; + case RAY_REASON_PROTOCOL_ERROR: + return "PROTOCOL_ERROR"; + case RAY_REASON_IO_ERROR: + return "IO_ERROR"; + } + return "UNKNOWN"; +} + static double dot(const double a[3], const double b[3]) { return a[0] * b[0] + a[1] * b[1] + a[2] * b[2]; } diff --git a/src/geodesic.h b/src/geodesic.h index 786ffd0..56a7f0c 100644 --- a/src/geodesic.h +++ b/src/geodesic.h @@ -28,6 +28,10 @@ typedef enum { RAY_REASON_IO_ERROR } RayReason; +/* Stable name for a RayReason (never NULL; out-of-range values return + * "UNKNOWN"). Pure and thread-safe, so it may be called from any reporter. */ +const char *ray_reason_name(RayReason reason); + /* Monitored quantity used by the dark-redshift termination policy. `LOG_P0` * is ln(p^0) = L - ln(alpha); it differs from `LOG_ALPHA_P0` by a local * function of position and must not be confused with the true infinity diff --git a/src/main.c b/src/main.c index fd3d4d1..fc45866 100644 --- a/src/main.c +++ b/src/main.c @@ -961,23 +961,463 @@ static void ray_pool_status_counts(const RayPool *rays, size_t *pending, } } +/* ------------------------------------------------------------------------- * + * Serial ray-failure diagnostics. + * + * Ray-failure reporting runs outside the ray-tracing workers and at the CLI + * only; it never logs from an OpenMP tracing loop. Bulk tracing results are + * inspected once it has returned. A compact per-frame histogram of INCOMPLETE + * endpoints is always written to stderr, even without --verbose. --verbose or + * a GR_DEBUG build adds a bounded number of representative samples with + * film/cost localization. Nothing here changes a physics outcome, a + * termination category, or a retry rule; it only makes an already-computed + * result visible with its reason and frame. + * ------------------------------------------------------------------------- */ + +#define RAY_DIAG_REASON_UNKNOWN_INDEX ((size_t)RAY_REASON_IO_ERROR + 1u) +#define RAY_DIAG_REASON_COUNT (RAY_DIAG_REASON_UNKNOWN_INDEX + 1u) +#define RAY_DIAG_REPS_PER_REASON 3u + +static const char *frame_sample_kind_name(FrameSampleKind kind) { + switch (kind) { + case FRAME_SAMPLE_VERTEX: + return "vertex"; + case FRAME_SAMPLE_PROBE: + return "probe"; + case FRAME_SAMPLE_RETRY: + return "retry"; + } + return "unknown"; +} + +/* Known reasons keep their own histogram bucket; an out-of-range value gets a + * dedicated UNKNOWN bucket instead of being folded into NONE. */ +static size_t raydiag_reason_index(RayReason reason) { + const size_t index = (size_t)reason; + return index < RAY_DIAG_REASON_UNKNOWN_INDEX ? index + : RAY_DIAG_REASON_UNKNOWN_INDEX; +} + +static const char *raydiag_reason_label(size_t index) { + return index == RAY_DIAG_REASON_UNKNOWN_INDEX + ? "UNKNOWN" + : ray_reason_name((RayReason)index); +} + +/* Representative detail is requested by --verbose or a GR_DEBUG build; the + * compact histogram is emitted regardless. */ +static int raydiag_wants_samples(const Settings *settings) { +#ifdef GR_DEBUG + (void)settings; + return 1; +#else + return settings != NULL && settings->verbose; +#endif +} + +/* One bounded, honest descriptor of a failed ray request. Every optional + * field carries a `has_*` flag so a report never invents a trusted stop state, + * a persistent vertex id, or a film position the source did not retain. */ +typedef struct { + size_t reason; + int has_sample; + size_t sample_id; + int has_kind; + FrameSampleKind kind; + int has_probe; + int probe; + int has_persistent; + size_t persistent_id; + int has_film; + double film_x, film_y; + int trusted; + double stop_time; + int has_position; + double position[3]; + unsigned long long accepted; + unsigned long long rejected; + unsigned long long rhs; +} RayDiagSample; + +typedef struct { + const Settings *settings; + size_t counts[RAY_DIAG_REASON_COUNT]; + size_t total; + size_t rep_count[RAY_DIAG_REASON_COUNT]; + RayDiagSample reps[RAY_DIAG_REASON_COUNT][RAY_DIAG_REPS_PER_REASON]; + size_t suppressed[RAY_DIAG_REASON_COUNT]; +} RayDiagReport; + +static void raydiag_report_init(RayDiagReport *report, + const Settings *settings) { + memset(report, 0, sizeof *report); + report->settings = settings; +} + +static void raydiag_report_add(RayDiagReport *report, RayReason reason, + const RayDiagSample *sample) { + const size_t index = raydiag_reason_index(reason); + ++report->counts[index]; + ++report->total; + if (!raydiag_wants_samples(report->settings)) + return; + if (report->rep_count[index] < RAY_DIAG_REPS_PER_REASON) { + report->reps[index][report->rep_count[index]] = *sample; + report->reps[index][report->rep_count[index]].reason = (size_t)reason; + ++report->rep_count[index]; + } else { + ++report->suppressed[index]; + } +} + +/* `generation`/`slab` are negative when the phase has no meaningful value. */ +static void raydiag_report_flush(const RayDiagReport *report, size_t frame_id, + double camera_time, const char *phase, + long long generation, long long slab) { + if (report->total == 0) + return; + fprintf(stderr, "Ray failures: frame %zu camera_t=%.9g phase=%s", frame_id, + camera_time, phase); + if (generation >= 0) + fprintf(stderr, " generation=%lld", generation); + if (slab >= 0) + fprintf(stderr, " slab=%lld", slab); + fprintf(stderr, ": INCOMPLETE=%zu [", report->total); + int first = 1; + for (size_t i = 0; i < RAY_DIAG_REASON_COUNT; ++i) { + if (report->counts[i] == 0) + continue; + fprintf(stderr, "%s%s=%zu", first ? "" : " ", raydiag_reason_label(i), + report->counts[i]); + first = 0; + } + fputs("]\n", stderr); + if (!raydiag_wants_samples(report->settings)) + return; + for (size_t i = 0; i < RAY_DIAG_REASON_COUNT; ++i) { + for (size_t r = 0; r < report->rep_count[i]; ++r) { + const RayDiagSample *d = &report->reps[i][r]; + fprintf(stderr, " ray failure: frame=%zu reason=%s", frame_id, + ray_reason_name((RayReason)d->reason)); + if (d->has_sample) + fprintf(stderr, " sample=%zu", d->sample_id); + if (d->has_kind) + fprintf(stderr, " kind=%s", frame_sample_kind_name(d->kind)); + if (d->has_probe) + fprintf(stderr, " probe=%d", d->probe); + if (d->has_persistent) + fprintf(stderr, " vertex=%zu", d->persistent_id); + if (d->has_film) + fprintf(stderr, " film=(%.6g, %.6g)", d->film_x, d->film_y); + fprintf(stderr, " trusted=%d", d->trusted); + if (d->trusted) { + fprintf(stderr, " stop_t=%.9g", d->stop_time); + if (d->has_position) + fprintf(stderr, " pos=(%.9g, %.9g, %.9g)", d->position[0], + d->position[1], d->position[2]); + } + fprintf(stderr, " accepted=%llu rejected=%llu rhs=%llu\n", d->accepted, + d->rejected, d->rhs); + } + if (report->suppressed[i] != 0) + fprintf(stderr, " ray failure: frame=%zu reason=%s suppressed=%zu\n", + frame_id, raydiag_reason_label(i), report->suppressed[i]); + } +} + +/* Growing byte map keyed by persistent vertex id, used to avoid re-reporting a + * failure that a later refinement generation still contains. */ +typedef struct { + unsigned char *bytes; + size_t capacity; +} RayDiagSeen; + +static int raydiag_seen_reserve(RayDiagSeen *seen, size_t count) { + if (count <= seen->capacity) + return 0; + size_t capacity = seen->capacity != 0 ? seen->capacity : 64; + while (capacity < count) { + if (capacity > SIZE_MAX / 2) { + capacity = count; + break; + } + capacity *= 2; + } + unsigned char *bytes = realloc(seen->bytes, capacity); + if (bytes == NULL) + return -1; + memset(bytes + seen->capacity, 0, capacity - seen->capacity); + seen->bytes = bytes; + seen->capacity = capacity; + return 0; +} + +static void raydiag_seen_destroy(RayDiagSeen *seen) { + free(seen->bytes); + seen->bytes = NULL; + seen->capacity = 0; +} + +/* Emit INCOMPLETE diagnostics for a finalized mesh. When `seen` is non-NULL + * every reported vertex is marked, so a refinement sequence never repeats an + * already-surfaced failure; a NULL `seen` reports every INCOMPLETE vertex (the + * one-shot imported-map scan). Vertices retain no trusted stop state, so the + * representative detail intentionally omits stop time/position. Returns 0 on + * success and -1 only when growing the seen set fails. */ +static int report_mesh_incomplete(const Settings *s, const FrameLensMesh *mesh, + RayDiagSeen *seen, size_t frame_id, + double camera_time, const char *phase, + long long generation, long long slab) { + if (mesh == NULL) + return 0; + if (seen != NULL && raydiag_seen_reserve(seen, mesh->vertex_count)) + return -1; + RayDiagReport report; + raydiag_report_init(&report, s); + for (size_t i = 0; i < mesh->vertex_count; ++i) { + const LensVertex *v = &mesh->vertices[i]; + if (!v->traced || v->outcome != RAY_OUTCOME_INCOMPLETE) + continue; + if (seen != NULL) { + if (seen->bytes[i]) + continue; + seen->bytes[i] = 1; + } + RayDiagSample sample = {0}; + sample.has_persistent = 1; + sample.persistent_id = i; + sample.has_probe = 1; + sample.probe = v->diagnostic_probe != 0; + sample.has_film = isfinite(v->image_x) && isfinite(v->image_y); + sample.film_x = v->image_x; + sample.film_y = v->image_y; + sample.accepted = v->trace_accepted_steps; + sample.rejected = v->trace_rejected_steps; + sample.rhs = v->trace_rhs_evaluations; + raydiag_report_add(&report, v->reason, &sample); + } + raydiag_report_flush(&report, frame_id, camera_time, phase, generation, slab); + return 0; +} + +/* Inspect this generation's pool for terminal INCOMPLETE endpoints not yet + * reported. Slots are appended grouped by frame, so one pass emits one + * summary per affected frame; `reported` is a per-slot byte map owned by the + * caller so later slabs never re-report an earlier failure. `phase` records + * whether the failure was found during preroute or a slab sweep. */ +static void report_pool_incomplete(const Settings *s, const Movie *movie, + const RayPool *rays, unsigned char *reported, + size_t generation, long long slab_id, + const char *phase) { + if (rays == NULL || reported == NULL || rays->count == 0) + return; + RayDiagReport report; + raydiag_report_init(&report, s); + long long frame_index = -1; + size_t frame_id = 0; + double camera_time = 0.0; + for (size_t i = 0; i < rays->count; ++i) { + if (reported[i]) + continue; + const RayPoolStatus status = rays->status[i]; + /* PENDING/ACTIVE slots still hold their zero-initialized INCOMPLETE + * placeholder; only a terminal status carries a real failure reason. */ + if (status != RAY_POOL_TERMINATED && status != RAY_POOL_FAILED) + continue; + const RayEndpoint *endpoint = &rays->endpoint[i]; + if (endpoint->outcome != RAY_OUTCOME_INCOMPLETE) + continue; + reported[i] = 1; + const long long frame = (long long)rays->frame_id[i]; + if (frame != frame_index) { + if (frame_index >= 0) + raydiag_report_flush(&report, frame_id, camera_time, phase, + (long long)generation, slab_id); + raydiag_report_init(&report, s); + frame_index = frame; + if (movie != NULL && frame >= 0 && (size_t)frame < movie->frame_count) { + frame_id = movie->frames[frame].frame_id; + camera_time = movie->frames[frame].coordinate_time; + } else { + frame_id = rays->frame_id[i]; + camera_time = NAN; + } + } + RayDiagSample sample = {0}; + sample.has_sample = 1; + sample.sample_id = rays->vertex_id[i]; + sample.has_film = 0; + if (movie != NULL && frame >= 0 && (size_t)frame < movie->frame_count) { + const FrameLensMesh *mesh = &movie->frames[frame].mesh; + size_t sample_count = 0; + const FrameSample *samples = + frame_lens_mesh_samples(mesh, &sample_count); + if (samples != NULL && sample.sample_id < sample_count) { + const FrameSample *fs = &samples[sample.sample_id]; + sample.has_kind = 1; + sample.kind = fs->kind; + sample.has_probe = 1; + /* Fresh probes have not become persistent witnesses yet; retries + * retain the witness flag even though their request kind is RETRY. */ + sample.probe = fs->kind == FRAME_SAMPLE_PROBE || + fs->vertex.diagnostic_probe != 0; + sample.has_film = + isfinite(fs->vertex.image_x) && isfinite(fs->vertex.image_y); + sample.film_x = fs->vertex.image_x; + sample.film_y = fs->vertex.image_y; + /* A vertex and a retry reference a persistent mesh vertex directly; a + * cached probe is an existing witness. A fresh probe has no persistent + * id yet and is left unset. */ + const int persistent_kind = + fs->kind == FRAME_SAMPLE_VERTEX || fs->kind == FRAME_SAMPLE_RETRY || + (fs->kind == FRAME_SAMPLE_PROBE && fs->cached); + if (persistent_kind && fs->vertex_id < mesh->vertex_count) { + sample.has_persistent = 1; + sample.persistent_id = fs->vertex_id; + } + } + } + sample.has_position = 1; + for (int axis = 0; axis < 3; ++axis) + sample.position[axis] = endpoint->final_x[axis]; + sample.trusted = isfinite(endpoint->stop_coordinate_time) && + isfinite(endpoint->final_x[0]) && + isfinite(endpoint->final_x[1]) && + isfinite(endpoint->final_x[2]); + sample.stop_time = endpoint->stop_coordinate_time; + sample.accepted = endpoint->accepted_steps; + sample.rejected = endpoint->rejected_steps; + sample.rhs = endpoint->rhs_evaluations; + raydiag_report_add(&report, endpoint->reason, &sample); + } + if (frame_index >= 0) + raydiag_report_flush(&report, frame_id, camera_time, phase, + (long long)generation, slab_id); +} + +/* Probes that failed but were not persisted as a mesh vertex (finish_generation + * may not have run after an error). Cached probes are deliberately skipped: + * they are pre-existing samples, not new failures of this generation. */ +static void report_pending_probes(const Settings *s, const FrameLensMesh *mesh, + size_t frame_id, double camera_time) { + if (mesh == NULL || mesh->samples == NULL) + return; + RayDiagReport report; + raydiag_report_init(&report, s); + for (size_t i = 0; i < mesh->sample_count; ++i) { + const FrameSample *fs = &mesh->samples[i]; + if (fs->cached || fs->kind != FRAME_SAMPLE_PROBE || + !fs->vertex.traced || fs->vertex.outcome != RAY_OUTCOME_INCOMPLETE) + continue; + RayDiagSample sample = {0}; + sample.has_sample = 1; + sample.sample_id = i; + sample.has_kind = 1; + sample.kind = FRAME_SAMPLE_PROBE; + sample.has_probe = 1; + sample.probe = 1; + sample.has_film = + isfinite(fs->vertex.image_x) && isfinite(fs->vertex.image_y); + sample.film_x = fs->vertex.image_x; + sample.film_y = fs->vertex.image_y; + sample.accepted = fs->vertex.trace_accepted_steps; + sample.rejected = fs->vertex.trace_rejected_steps; + sample.rhs = fs->vertex.trace_rhs_evaluations; + raydiag_report_add(&report, fs->vertex.reason, &sample); + } + raydiag_report_flush(&report, frame_id, camera_time, "refinement-error", -1, + -1); +} + +/* Per-frame UNRESOLVED/BUDGET_EXHAUSTED summary from finalized boundary stats. + * This is a resource quota result, not a numerical failure: it is emitted even + * without --verbose so a refused frame is never silent, while verbose/Debug + * adds bounded sample detail. Normal DARK and approximate-black triangles are + * not diagnosed here. `continuation_valid` is false for an imported map, + * whose wire format does not persist the resume state: replay must not present + * a zero-initialized continuation time as if it were observed. */ +static void report_unresolved_frame(const Settings *s, + const FrameLensMesh *mesh, size_t frame_id, + double camera_time, + const FrameBoundaryStats *stats, + int continuation_valid) { + if (mesh == NULL || stats == NULL || stats->budget_incomplete_triangles == 0) + return; + size_t unresolved_vertices = 0; + for (size_t i = 0; i < mesh->vertex_count; ++i) + if (mesh->vertices[i].traced && + mesh->vertices[i].outcome == RAY_OUTCOME_UNRESOLVED) + ++unresolved_vertices; + fprintf(stderr, + "UNRESOLVED/BUDGET_EXHAUSTED: frame %zu camera_t=%.9g " + "blocking_triangles=%zu unresolved_samples=%zu\n", + frame_id, camera_time, stats->budget_incomplete_triangles, + unresolved_vertices); + if (!raydiag_wants_samples(s)) + return; + size_t shown = 0; + for (size_t i = 0; + i < mesh->vertex_count && shown < RAY_DIAG_REPS_PER_REASON; ++i) { + const LensVertex *v = &mesh->vertices[i]; + if (!v->traced || v->outcome != RAY_OUTCOME_UNRESOLVED) + continue; + fprintf(stderr, + " unresolved sample: frame=%zu vertex=%zu film=(%.6g, %.6g) " + "continuation_t=", + frame_id, i, v->image_x, v->image_y); + if (continuation_valid) + fprintf(stderr, "%.9g", v->continuation_t); + else + fputs("-", stderr); + fprintf(stderr, " accepted=%llu rejected=%llu rhs=%llu\n", + (unsigned long long)v->trace_accepted_steps, + (unsigned long long)v->trace_rejected_steps, + (unsigned long long)v->trace_rhs_evaluations); + ++shown; + } +} + +typedef struct { + const Settings *settings; + const FrameLensMesh *mesh; + size_t frame_id; + double camera_time; + RayDiagSeen seen; + int alloc_failed; +} RefinementDiagnostics; + +/* Always installed as the refinement progress callback: normal progress text + * stays gated by --verbose, while completed generations always run the + * bounded INCOMPLETE scan. A growth failure cannot be returned through the + * void callback, so it is recorded in the context and surfaced by the caller. */ static void report_frame_refinement(void *context, size_t generation, size_t sample_count, size_t vertex_count, size_t triangle_count, int added_vertices, int finished) { - const Settings *settings = context; - if (settings == NULL || !settings->verbose) + RefinementDiagnostics *diag = context; + if (diag == NULL) return; - if (!finished) - fprintf(stdout, - "Frame 0: refinement generation %zu tracing %zu samples " - "from %zu vertices and %zu triangles.\n", - generation, sample_count, vertex_count, triangle_count); - else - fprintf(stdout, - "Frame 0: refinement generation %zu finished; added %d vertices, " - "now %zu vertices and %zu triangles.\n", - generation, added_vertices, vertex_count, triangle_count); + const Settings *settings = diag->settings; + if (settings != NULL && settings->verbose) { + if (!finished) + fprintf(stdout, + "Frame %zu: refinement generation %zu tracing %zu samples " + "from %zu vertices and %zu triangles.\n", + diag->frame_id, generation, sample_count, vertex_count, + triangle_count); + else + fprintf(stdout, + "Frame %zu: refinement generation %zu finished; added %d " + "vertices, now %zu vertices and %zu triangles.\n", + diag->frame_id, generation, added_vertices, vertex_count, + triangle_count); + } + if (!finished || diag->alloc_failed) + return; + if (report_mesh_incomplete(settings, diag->mesh, &diag->seen, diag->frame_id, + diag->camera_time, "refinement", + (long long)generation, -1)) + diag->alloc_failed = 1; } #ifdef SPACETIME_ALCUBIERRE @@ -1060,9 +1500,13 @@ static double alcubierre_step_budget(const Settings *s) { /* Recompute per-triangle approximate-black provenance and aggregate the E/D/U * accounting across the given frames. The caller uses the returned totals both - * for the verbose report and for boundary_allows_publish() production gating. */ + * for the verbose report and for boundary_allows_publish() production gating. + * `frame_ids`/`camera_times` label the always-on per-frame UNRESOLVED summary + * with the real frame id and camera coordinate time. */ static void report_boundary_stats(const Settings *s, FrameLensMesh *const *meshes, + const size_t *frame_ids, + const double *camera_times, size_t frame_count, const RefinementConfig *config, FrameBoundaryStats *out_total) { @@ -1070,6 +1514,11 @@ static void report_boundary_stats(const Settings *s, for (size_t i = 0; i < frame_count; ++i) { FrameBoundaryStats frame_stats; frame_lens_mesh_boundary_stats(meshes[i], config, &frame_stats); + /* Emitted before the publication gate so a budget-incomplete frame is + * never silent even when --verbose is off. These meshes come from live + * tracing, so the UNRESOLVED continuation state is real. */ + report_unresolved_frame(s, meshes[i], frame_ids[i], camera_times[i], + &frame_stats, 1); total.escaped_only += frame_stats.escaped_only; total.dark_only += frame_stats.dark_only; total.eed_edd += frame_stats.eed_edd; @@ -1178,7 +1627,9 @@ static LensMapProvenance lens_map_provenance(const Settings *s, /* Refuse to publish silently on true errors or on unresolved triangles that * exhausted the configured total budget. Approximate-black UUD/UDD boundary * triangles are an accepted finite-resolution error and do not block output. - * A diagnostic run may override this, but the incompleteness is reported. */ + * A diagnostic run may override this, but the incompleteness is reported. + * The refusal distinguishes a numerical/domain error -- which a larger retry + * budget cannot repair -- from a pure budget shortage. */ static int boundary_allows_publish(const Settings *s, const FrameBoundaryStats *total) { const size_t blocking = total->error + total->budget_incomplete_triangles; @@ -1191,11 +1642,28 @@ static int boundary_allows_publish(const Settings *s, total->error, total->budget_incomplete_triangles); return 1; } - fprintf(stderr, - "Incomplete render refused: %zu error triangle(s), %zu " - "budget-incomplete unresolved triangle(s). Raise the retry budget or " - "pass --allow-incomplete for a diagnostic output.\n", - total->error, total->budget_incomplete_triangles); + if (total->error != 0 && total->budget_incomplete_triangles != 0) { + fprintf(stderr, + "Incomplete render refused: %zu error triangle(s) and %zu " + "budget-incomplete unresolved triangle(s). The error triangles are " + "numerical/domain failures that a larger retry budget does not fix; " + "raise the retry budget only for the unresolved triangles, or pass " + "--allow-incomplete for a diagnostic output.\n", + total->error, total->budget_incomplete_triangles); + } else if (total->error != 0) { + fprintf(stderr, + "Incomplete render refused: %zu error triangle(s). These are " + "numerical/domain/integration failures, not a budget shortage, so a " + "larger retry budget does not fix them; pass --allow-incomplete for " + "a diagnostic output.\n", + total->error); + } else { + fprintf(stderr, + "Incomplete render refused: %zu budget-incomplete unresolved " + "triangle(s). Raise the retry budget or pass --allow-incomplete for " + "a diagnostic output.\n", + total->budget_incomplete_triangles); + } return 0; } @@ -1517,15 +1985,23 @@ static int render_observer_frame(const Settings *s, StarCatalog *catalog, if (hdr == NULL || frame_lens_mesh_build_coarse(&mesh, s->width, s->height, s->coarse_cell_pixels, s->horizontal_fov_deg)) { + fputs("Frame 0: initial HDR allocation or coarse lens mesh build failed.\n", + stderr); frame_lens_mesh_destroy(&mesh); free(hdr); return -1; } + RefinementDiagnostics diag = {.settings = s, + .mesh = &mesh, + .frame_id = 0, + .camera_time = observer->coordinate_time}; if (s->verbose) fprintf(stdout, "Frame 0: tracing %zu initial rays from %zu mesh triangles...\n", mesh.vertex_count, mesh.triangle_count); const double initial_trace_start = omp_get_wtime(); if (frame_lens_mesh_trace(&mesh, spacetime, observer, &trace)) { + fputs("Frame 0: initial ray trace failed.\n", stderr); + raydiag_seen_destroy(&diag.seen); frame_lens_mesh_destroy(&mesh); free(hdr); return -1; @@ -1533,17 +2009,45 @@ static int render_observer_frame(const Settings *s, StarCatalog *catalog, if (s->verbose) fprintf(stdout, "Frame 0: initial ray trace finished in %.3f s.\n", omp_get_wtime() - initial_trace_start); + /* The initial vertices had no prior report, so this first scan establishes + * the seen set the refinement callback extends across generations. */ + if (report_mesh_incomplete(s, &mesh, &diag.seen, 0, observer->coordinate_time, + "initial", -1, -1)) { + fputs("Frame 0: failed to allocate ray-failure diagnostics.\n", stderr); + raydiag_seen_destroy(&diag.seen); + frame_lens_mesh_destroy(&mesh); + free(hdr); + return -1; + } if (s->refinement.max_level > 0 && s->verbose) fprintf(stdout, "Frame 0: starting adaptive ray-trace refinement (max level %u)...\n", s->refinement.max_level); const double refinement_start = omp_get_wtime(); if (frame_lens_mesh_refine_with_progress( &mesh, spacetime, observer, &trace, &refinement_config, - s->verbose ? report_frame_refinement : NULL, (void *)s)) { + report_frame_refinement, &diag)) { + /* A failed finish_generation may not persist its pending probes, so surface + * both the mesh and the still-pending samples before destruction. */ + (void)report_mesh_incomplete(s, &mesh, &diag.seen, 0, + observer->coordinate_time, "refinement-error", + -1, -1); + report_pending_probes(s, &mesh, 0, observer->coordinate_time); + fputs("Frame 0: adaptive ray-trace refinement failed.\n", stderr); + raydiag_seen_destroy(&diag.seen); frame_lens_mesh_destroy(&mesh); free(hdr); return -1; } + if (diag.alloc_failed) { + fputs("Frame 0: failed to allocate ray-failure diagnostics.\n", stderr); + raydiag_seen_destroy(&diag.seen); + frame_lens_mesh_destroy(&mesh); + free(hdr); + return -1; + } + /* Diagnostics no longer need the vertex-provenance set once refinement has + * finished; release it before the render stage. */ + raydiag_seen_destroy(&diag.seen); if (s->refinement.max_level > 0 && s->verbose) fprintf(stdout, "Frame 0: adaptive ray-trace refinement finished in %.3f s; " @@ -1552,8 +2056,10 @@ static int render_observer_frame(const Settings *s, StarCatalog *catalog, mesh.triangle_count); FrameBoundaryStats boundary_totals; FrameLensMesh *frame_meshes[1] = {&mesh}; - report_boundary_stats(s, frame_meshes, 1, &refinement_config, - &boundary_totals); + const size_t frame_ids[1] = {0}; + const double camera_times[1] = {observer->coordinate_time}; + report_boundary_stats(s, frame_meshes, frame_ids, camera_times, 1, + &refinement_config, &boundary_totals); { FrameTraceStats trace_stats; frame_lens_mesh_trace_stats(&mesh, &trace_stats); @@ -1650,7 +2156,13 @@ static int trace_movie_generation(Movie *movie, const Settings *s, for (size_t f = 0; f < movie->frame_count; ++f) { const int prepared = frame_lens_mesh_prepare_generation( &movie->frames[f].mesh, &effective); - if (prepared < 0) return -1; + if (prepared < 0) { + fprintf(stderr, + "Ray trace generation %zu: frame %zu could not prepare its next " + "sample generation.\n", + generation, movie->frames[f].frame_id); + return -1; + } ray_count += (size_t)prepared; } if (ray_count == 0) return 0; @@ -1658,7 +2170,25 @@ static int trace_movie_generation(Movie *movie, const Settings *s, fprintf(stdout, "Ray trace generation %zu: collected %zu new samples across %zu frames.\n", generation, ray_count, movie->frame_count); - if (ray_pool_init(&rays, ray_count)) return -1; + if (ray_pool_init(&rays, ray_count)) { + fprintf(stderr, + "Ray trace generation %zu: ray pool allocation failed for %zu " + "samples.\n", + generation, ray_count); + return -1; + } + /* Per-slot failure census, owned by this generation and freed on every exit + * alongside the pool. It lets each slab report only the samples that newly + * failed instead of re-counting the whole run every sweep. */ + unsigned char *reported = calloc(ray_count, 1); + if (reported == NULL) { + fprintf(stderr, + "Ray trace generation %zu: failure-tracking allocation failed for " + "%zu samples.\n", + generation, ray_count); + ray_pool_destroy(&rays); + return -1; + } for (size_t f = 0; f < movie->frame_count; ++f) { size_t count = 0; const FrameSample *samples = frame_lens_mesh_samples(&movie->frames[f].mesh, &count); @@ -1669,6 +2199,11 @@ static int trace_movie_generation(Movie *movie, const Settings *s, if (fs->kind == FRAME_SAMPLE_RETRY) { GeodesicRayState state; if (frame_vertex_continuation_state(&fs->vertex, &state)) { + fprintf(stderr, + "Ray trace generation %zu: frame %zu sample %zu retry is " + "missing a valid continuation payload.\n", + generation, movie->frames[f].frame_id, sample); + free(reported); ray_pool_destroy(&rays); return -1; } @@ -1680,15 +2215,25 @@ static int trace_movie_generation(Movie *movie, const Settings *s, fs->vertex.camera_direction, f, sample); } if (rc) { + fprintf(stderr, + "Ray trace generation %zu: frame %zu sample %zu could not be " + "appended to the ray pool.\n", + generation, movie->frames[f].frame_id, sample); + free(reported); ray_pool_destroy(&rays); return -1; } } } ray_pool_preroute(&rays, spacetime); + /* Preroute may already terminate a ray as INCOMPLETE (unsupported chart, + * exhausted data time, protocol error). Report those before the sweep; the + * zero-initialized stop state is not trusted, so no stop details appear. */ + report_pool_incomplete(s, movie, &rays, reported, generation, -1, "preroute"); double slab_hi = movie->frames[movie->frame_count - 1].coordinate_time; size_t slab_id = 0; while (ray_pool_has_live(&rays)) { + const size_t current_slab = ++slab_id; const double slab_lo = slab_hi - s->slab_duration; MetricSlab *slab = NULL; size_t pending_before, active_before, terminated_before, unresolved_before, @@ -1697,6 +2242,13 @@ static int trace_movie_generation(Movie *movie, const Settings *s, &terminated_before, &unresolved_before, &failed_before); if (spacetime_load_slab(spacetime, slab_hi, slab_lo, &slab)) { + /* No RayReason exists for a backend with no slab data; state the + * infrastructure failure and the time range instead of fabricating one. */ + fprintf(stderr, + "Ray trace generation %zu: metric slab load failed for time range " + "[%.9g, %.9g].\n", + generation, slab_hi, slab_lo); + free(reported); ray_pool_destroy(&rays); return -1; } @@ -1708,6 +2260,9 @@ static int trace_movie_generation(Movie *movie, const Settings *s, &failed_active); ray_pool_advance_active(&rays, slab, trace); spacetime_free_slab(slab); + /* Serial, post-sweep reporting: never from an OpenMP worker. */ + report_pool_incomplete(s, movie, &rays, reported, generation, + (long long)current_slab, "slab"); size_t pending_after, active_after, terminated_after, unresolved_after, failed_after; ray_pool_status_counts(&rays, &pending_after, &active_after, @@ -1716,7 +2271,7 @@ static int trace_movie_generation(Movie *movie, const Settings *s, fprintf(stdout, "Ray trace generation %zu, slab %zu [%.6g, %.6g]: activated %zu; " "live %zu -> %zu, terminated %zu, unresolved %zu, failed %zu.\n", - generation, ++slab_id, slab_hi, slab_lo, + generation, current_slab, slab_hi, slab_lo, active_active - active_before, pending_before + active_before, pending_after + active_after, terminated_after, unresolved_after, failed_after); @@ -1725,9 +2280,16 @@ static int trace_movie_generation(Movie *movie, const Settings *s, for (size_t i = 0; i < rays.count; ++i) if (frame_lens_mesh_install_sample(&movie->frames[rays.frame_id[i]].mesh, rays.vertex_id[i], &rays.endpoint[i])) { + fprintf(stderr, + "Ray trace generation %zu: frame %zu sample %zu endpoint install " + "failed.\n", + generation, movie->frames[rays.frame_id[i]].frame_id, + rays.vertex_id[i]); + free(reported); ray_pool_destroy(&rays); return -1; } + free(reported); ray_pool_destroy(&rays); if (s->verbose) fprintf(stdout, "Ray trace generation %zu: installing endpoints and refining meshes.\n", @@ -1739,7 +2301,9 @@ static int trace_movie_generation(Movie *movie, const Settings *s, const int added = frame_lens_mesh_finish_generation(&movie->frames[f].mesh, &effective); if (added < 0) { - fprintf(stderr, "Ray trace generation %zu: frame %zu refinement failed.\n", + fprintf(stderr, + "Ray trace generation %zu: frame %zu refinement failed while " + "applying the completed generation.\n", generation, movie->frames[f].frame_id); return -1; } @@ -1898,18 +2462,29 @@ static int render_movie(const Settings *s, StarCatalog *catalog, { const RefinementConfig boundary_config = effective_refinement(s, &trace); FrameLensMesh **meshes = malloc(movie.frame_count * sizeof *meshes); - if (meshes == NULL) + size_t *frame_ids = malloc(movie.frame_count * sizeof *frame_ids); + double *camera_times = malloc(movie.frame_count * sizeof *camera_times); + if (meshes == NULL || frame_ids == NULL || camera_times == NULL) { + free(meshes); + free(frame_ids); + free(camera_times); goto done; - for (size_t i = 0; i < movie.frame_count; ++i) + } + for (size_t i = 0; i < movie.frame_count; ++i) { meshes[i] = &movie.frames[i].mesh; + frame_ids[i] = movie.frames[i].frame_id; + camera_times[i] = movie.frames[i].coordinate_time; + } FrameBoundaryStats boundary_totals; - report_boundary_stats(s, meshes, movie.frame_count, &boundary_config, - &boundary_totals); + report_boundary_stats(s, meshes, frame_ids, camera_times, movie.frame_count, + &boundary_config, &boundary_totals); FrameTraceStats trace_totals = {0}; for (size_t i = 0; i < movie.frame_count; ++i) accumulate_trace_stats(&movie.frames[i].mesh, &trace_totals); report_trace_stats(s, &trace_totals, "Movie"); free(meshes); + free(frame_ids); + free(camera_times); if (!boundary_allows_publish(s, &boundary_totals)) goto done; } @@ -2079,15 +2654,45 @@ static int render_lens_map(const Settings *s, StarCatalog *catalog) { .retry_lookback_increment = map.provenance.retry_lookback_increment, .max_total_lookback_time = map.provenance.max_total_lookback_time}; int replay_incomplete = 0; - /* Replay consumes stored decisions, not current CLI refinement defaults. */ + /* Replay consumes stored decisions, not current CLI refinement defaults. + * Boundary stats and diagnostics are computed for every frame first, so the + * publication gate can never hide a later frame's reported reason. */ + FrameBoundaryStats *replay_stats = + calloc(map.frame_count, sizeof *replay_stats); + if (replay_stats == NULL) { + fputs("Imported lens map: failed to allocate per-frame diagnostic state.\n", + stderr); + lens_map_destroy(&map); + return -1; + } + for (size_t f = 0; f < map.frame_count; ++f) + frame_lens_mesh_boundary_stats(&map.frames[f].mesh, &replay_config, + &replay_stats[f]); for (size_t f = 0; f < map.frame_count; ++f) { - FrameBoundaryStats completion; - frame_lens_mesh_boundary_stats(&map.frames[f].mesh, &replay_config, &completion); - replay_incomplete |= completion.error != 0 || completion.budget_incomplete_triangles != 0; - if (!boundary_allows_publish(s, &completion)) { - lens_map_destroy(&map); return -1; + const size_t frame_id = (size_t)map.frames[f].frame_id; + const double camera_time = map.frames[f].coordinate_time; + if (report_mesh_incomplete(s, &map.frames[f].mesh, NULL, frame_id, + camera_time, "import", -1, -1)) { + fputs("Imported lens map: failed to allocate ray-failure diagnostics.\n", + stderr); + free(replay_stats); + lens_map_destroy(&map); + return -1; + } + report_unresolved_frame(s, &map.frames[f].mesh, frame_id, camera_time, + &replay_stats[f], 0); + replay_incomplete |= + replay_stats[f].error != 0 || + replay_stats[f].budget_incomplete_triangles != 0; + } + for (size_t f = 0; f < map.frame_count; ++f) { + if (!boundary_allows_publish(s, &replay_stats[f])) { + free(replay_stats); + lens_map_destroy(&map); + return -1; } } + free(replay_stats); { FrameTraceStats trace_totals = {0}; for (size_t f = 0; f < map.frame_count; ++f) diff --git a/tests/test_geodesic.c b/tests/test_geodesic.c index da3c366..5a83e1c 100644 --- a/tests/test_geodesic.c +++ b/tests/test_geodesic.c @@ -3,9 +3,35 @@ #include #include +#include static int nearly_equal(double a, double b) { return fabs(a - b) < 1e-12; } +/* Every enumerator must have a stable label, and an out-of-range value must be + * reported as UNKNOWN rather than indexing past a table. */ +static int check_reason_names(void) { + const RayReason reasons[] = { + RAY_REASON_NONE, RAY_REASON_REDSHIFT_LIMIT, + RAY_REASON_BUDGET_EXHAUSTED, RAY_REASON_TIME_RANGE_EXHAUSTED, + RAY_REASON_OUT_OF_DOMAIN, RAY_REASON_INVALID_METRIC, + RAY_REASON_INTEGRATION_ERROR, RAY_REASON_UNSUPPORTED, + RAY_REASON_PROTOCOL_ERROR, RAY_REASON_IO_ERROR}; + int failed = 0; + for (size_t i = 0; i < sizeof reasons / sizeof reasons[0]; ++i) { + const char *name = ray_reason_name(reasons[i]); + if (name == NULL || name[0] == '\0' || strcmp(name, "UNKNOWN") == 0) { + fprintf(stderr, "reason %d has no stable label\n", (int)reasons[i]); + failed = 1; + } + } + const int unknown = (int)RAY_REASON_IO_ERROR + 7; + if (strcmp(ray_reason_name((RayReason)unknown), "UNKNOWN") != 0) { + fputs("out-of-range reason is not UNKNOWN\n", stderr); + failed = 1; + } + return failed; +} + static int check_ray(const SpacetimeSource *source, const ObserverState *observer, const double local_direction[3], @@ -36,7 +62,8 @@ int main(void) { metric.alpha != 1.0 || !spacetime_slab_eval(slab, 0.25, (double[]){0.0, 0.0, 0.0}, &metric)) return 1; - int result = check_ray(&source, &observer, (double[]){1.0, 0.0, 0.0}, + int result = check_reason_names() || + check_ray(&source, &observer, (double[]){1.0, 0.0, 0.0}, (double[]){0.0, 0.0, -1.0}) || check_ray(&source, &observer, (double[]){0.0, 0.0, 1.0}, (double[]){1.0, 0.0, 0.0}); diff --git a/tests/test_ray_diagnostics.py b/tests/test_ray_diagnostics.py new file mode 100644 index 0000000..20f0686 --- /dev/null +++ b/tests/test_ray_diagnostics.py @@ -0,0 +1,294 @@ +#!/usr/bin/env python3 +"""Regression test for always-on ray failure diagnostics. + +Every INCOMPLETE ray endpoint must be reported on stderr with its reason and +the affected frame id / camera coordinate time even without ``--verbose``, so a +long movie never needs a rerun to be diagnosed. ``--verbose`` (or any Debug +build) adds a bounded set of representative samples with film/cost +localization. Budget-incomplete ``UNRESOLVED/BUDGET_EXHAUSTED`` frames are +reported separately from numerical ``INCOMPLETE`` failures, and the publication +refusal must not recommend a larger retry budget for a pure integration error. + +A deterministic DP54 integration error is produced without a large workload: +strict tolerances, ``min == initial == max`` step, and one allowed rejection +make the first trial step fail as ``INTEGRATION_ERROR``. Small 16x8 scenes +keep every case short. Two-frame movie coverage uses the existing +``test_observer_`` fixture track duplicated to two rows (the +Schwarzschild metric is stationary, so the same tetrad is valid at both +times); the test then checks that each failing sample is counted once across +all time slabs. +""" +import os +import re +import struct +import subprocess +import sys +import tempfile +from pathlib import Path + +# Keep scratch data inside the pre-approved OpenCode scratch directory. +TMP_ROOT = Path('/tmp/opencode') +TMP_ROOT.mkdir(parents=True, exist_ok=True) + +BUILD = Path(sys.argv[1] if len(sys.argv) > 1 else 'build/Release').resolve() +TESTDIR = Path(sys.argv[2]).resolve() if len(sys.argv) > 2 else BUILD +ENV = dict(os.environ, OMP_NUM_THREADS='4') + +# v3 lens-map layout (see src/lens_map.c); only enough to count stored +# INCOMPLETE vertices. The first frame header follows the 40..176 v3 +# provenance block. +VERSION_OFFSET = 8 +FRAME_COUNT_OFFSET = 32 +FRAME_HEADER_START = 176 +VERTEX_SIZE = 108 +OUTCOME_INDEX = 10 +INCOMPLETE_OUTCOME = 3 + +COMMON = ['--catalog', 'assets/sky_grid_5deg.csv', '--width', 16, '--height', 8, + '--fov-deg', 80, '--exposure', 1e-3, '--coarse-cell-pixels', 8, + '--refine-max-level', 0, '--psf-relative-tail', 1e-4] + +# Deterministic DP54 integration failure: tight tolerances, a single fixed step +# bound, and one allowed rejection. Every ray rejects its first trial step and +# reports INTEGRATION_ERROR instead of a fabricated terminal category. +INJECT = ['--integrator', 'dp54', + '--ode-rtol', '1e-15', '--ode-atol-x', '1e-15', + '--ode-atol-pi', '1e-15', '--ode-atol-l', '1e-15', + '--ode-initial-step', '0.5', '--ode-min-step', '0.5', + '--ode-max-step', '0.5', '--ode-max-rejections', '1'] + + +def run(binary, *args, ok=True, env=ENV): + result = subprocess.run([str(binary), *map(str, args)], env=env, + capture_output=True, text=True) + if (result.returncode == 0) != ok: + raise AssertionError( + f'{binary.name} {args}: rc={result.returncode}\n' + f'stdout:\n{result.stdout}\nstderr:\n{result.stderr}') + return result + + +def is_debug(result): + return 'Debug build:' in result.stdout + + +def incomplete_total(stderr): + return sum(int(m) for m in re.findall(r'INCOMPLETE=(\d+)', stderr)) + + +def frame_reported(stderr, frame_id): + return re.search(rf'Ray failures: frame {frame_id} camera_t=', stderr) is not None + + +def map_incomplete_vertices(path): + data = path.read_bytes() + assert data[:8] == b'GRLENS\x01\x00', f'not a lens map: {path}' + version = struct.unpack_from(' 0 + assert incomplete_total(err) == stored, \ + f'refine histogram {incomplete_total(err)} != stored {stored}' + + # 5) Two-frame movie. (a) A default, non-verbose run must identify both + # frames and count each failing sample exactly once across the time + # slabs, matching the saved map. + track_single = tmp / 'track_single.csv' + run(observer_test, track_single) + rows = [line for line in track_single.read_text().splitlines() + if line.strip() and not line.startswith('#') + and not line[0].isalpha()] + assert len(rows) == 1, rows + fields = rows[0].split(',') + fields[0], fields[1] = '1', '1' + header = next(line for line in track_single.read_text().splitlines() + if line.startswith('t,')) + track = tmp / 'track2.csv' + track.write_text(header + '\n' + rows[0] + '\n' + ','.join(fields) + '\n') + + frames_dir = tmp / 'frames' + frames_dir.mkdir() + movie_map = tmp / 'movie.grlens' + movie_run = run(binary, *COMMON, *INJECT, '--allow-incomplete', + '--slab-duration', '0.4', '--observer-track', track, + '--movie-track-samples', '--frames-dir', frames_dir, + '--lens-map-output', movie_map) + err = movie_run.stderr + assert frame_reported(err, 0) and frame_reported(err, 1), err + stored = map_incomplete_vertices(movie_map) + assert stored > 0, 'movie map has no INCOMPLETE vertices' + assert incomplete_total(err) == stored, \ + f'histogram {incomplete_total(err)} != stored {stored}; ' \ + 'a sample was re-counted across slabs' + if not is_debug(movie_run): + assert 'ray failure:' not in err, err + + # (b) Verbose movie adds request kind, persistent vertex id, film position + # and cost, bounded per reason. + movie_verbose_dir = tmp / 'frames_verbose' + movie_verbose_dir.mkdir() + movie_verbose = run(binary, *COMMON, *INJECT, '--allow-incomplete', + '--verbose', '--slab-duration', '0.4', + '--observer-track', track, '--movie-track-samples', + '--frames-dir', movie_verbose_dir) + err = movie_verbose.stderr + assert 'sample=' in err and 'kind=vertex' in err and 'vertex=' in err, err + assert 'film=(' in err, err + assert 'accepted=' in err and 'rejected=' in err and 'rhs=' in err, err + reps = sum(1 for line in err.splitlines() + if 'ray failure:' in line and 'suppressed=' not in line) + assert reps <= 6, err # two frames, one reason each, <=3 reps per reason + + # (c) Render-only replay of the two-frame map without --allow-incomplete + # reports both frames' reasons before the publication gate refuses, and + # never invents an unpersisted trusted stop state. + map_frames_dir = tmp / 'map_frames' + map_frames_dir.mkdir() + refused = run(binary, '--catalog', 'assets/sky_grid_5deg.csv', + '--lens-map-input', movie_map, '--frames-dir', map_frames_dir, + '--output', tmp / f'map_refused.{ext}', ok=False) + err = refused.stderr + assert frame_reported(err, 0) and frame_reported(err, 1), err + assert 'INTEGRATION_ERROR' in err, err + assert 'phase=import' in err, err + assert 'Incomplete render refused' in err, err + assert err.index('frame 0') < err.index('Incomplete render refused'), err + + single_map = tmp / 'single.grlens' + run(binary, *COMMON, *INJECT, '--allow-incomplete', '--lens-map-output', + single_map, '--output', tmp / f'maplive.{ext}') + replay = tmp / f'replay.{ext}' + replay_run = run(binary, '--catalog', 'assets/sky_grid_5deg.csv', + '--lens-map-input', single_map, '--allow-incomplete', + '--verbose', '--output', replay) + err = replay_run.stderr + assert 'Ray failures:' in err and frame_reported(err, 0), err + assert 'INTEGRATION_ERROR' in err and 'phase=import' in err, err + assert 'stop_t=' not in err and 'trusted=1' not in err, err + + # 6) Budget exhaustion is a distinct, always-on message, and its refusal + # still points at the retry budget. A replay of an allowed budget map + # must not present the unpersisted continuation time as observed. + budget_map = tmp / 'budget.grlens' + run(binary, *COMMON, '--integrator', 'dp54', + '--trace-lookback-time', '1e-6', '--retry-lookback-increment', '0', + '--max-total-lookback-time', '1e-6', '--allow-incomplete', + '--lens-map-output', budget_map, '--output', tmp / f'budget_allow.{ext}') + replay_budget = run(binary, '--catalog', 'assets/sky_grid_5deg.csv', + '--lens-map-input', budget_map, '--allow-incomplete', + '--verbose', '--output', tmp / f'budget_replay.{ext}') + err = replay_budget.stderr + assert 'UNRESOLVED/BUDGET_EXHAUSTED' in err, err + assert 'continuation_t=-' in err, err + assert 'continuation_t=-1' not in err, \ + 'replay invented an unpersisted continuation time' + + budget = tmp / f'budget.{ext}' + budget_run = run(binary, *COMMON, '--integrator', 'dp54', + '--trace-lookback-time', '1e-6', + '--retry-lookback-increment', '0', + '--max-total-lookback-time', '1e-6', + '--output', budget, ok=False) + err = budget_run.stderr + assert 'UNRESOLVED/BUDGET_EXHAUSTED' in err, err + assert re.search(r'UNRESOLVED/BUDGET_EXHAUSTED: frame 0 camera_t=', err), err + assert 'blocking_triangles=' in err and 'unresolved_samples=' in err, err + assert 'Incomplete render refused' in err, err + assert 'budget' in err.lower(), err + assert not budget.exists() + + print('ray diagnostics checks passed: always-on reasons + frame/time, ' + 'bounded verbose samples, movie slab de-duplication and replay', + flush=True) diff --git a/usage.md b/usage.md index 950605f..fada54f 100644 --- a/usage.md +++ b/usage.md @@ -625,6 +625,10 @@ coverage-based antialiasing. Normal progress and summaries go to stdout; warnings, errors, and Debug diagnostics go to stderr. Successful runs exit `0` even if warnings are emitted. +Incomplete ray failures and budget-exhausted frames report their reasons and +affected frames on stderr even without `--verbose`; `--verbose` and Debug builds +add bounded per-sample localization (film position and integration cost). + ## HDR output To preserve a single-frame render for later exposure and tone-mapping work,