Skip to content

fix: sampler CLI prints variable name, JAX compile msg fires early #1434

Description

@Jammy2211

Overview

Two things the CLI tells a user during a non-linear search are wrong, and both cost the user the same thing: they cannot tell what the run is doing, or how long a silence will last.

  1. A variable name reaches the terminal instead of its value. 23 workspace scripts print On-the-fly updates every iterations_per_quick_update are printed to the notebook. — the literal token, not the cadence.
  2. The JAX compile message fires before any compilation happens. autofit/non_linear/fitness.py:508/528/549 log at wrapper-construction time, but jax.jit(...) returns instantly; tracing, lowering and XLA compilation all happen on the first call to the returned function (fitness.py:310). The user sees "applied in 0.0002 seconds", then sits through an unexplained wait that can run to minutes.

A complication found while scoping: the packaged default for iterations_per_quick_update is 1e99 (config/general.yaml, updates: block) — the codebase's documented inf-like "never" sentinel (see the _steps_until_full_update docstring, abstract_search.py:1040-1088). Only hpc_mode sets a real value (250000). So for almost every user the truthful message is not a number at all: it is "these updates are off". A naive f-string would render 1e+99, which is worse than the placeholder it replaces.

Decision: the library owns the cadence message. PyAutoFit logs it once at search start; the 23 workspace scripts drop that sentence entirely — one source of truth instead of the same conditional pasted into 23 files. This issue is Phase 1 (PyAutoFit); the workspace sweep is Phase 2, a separate follow-up issue.

Plan

  • Add an AbstractSearch.quick_update_message property that renders the real integer cadence, or — when the value is the 1e99 "never" sentinel — states plainly that on-the-fly updates are disabled and names the config key that enables them.
  • Log that message once at search start, alongside the existing "Starting non-linear search…" line.
  • Replace the three misleading JAX pre-wrap log pairs with a one-shot wrapper that logs JAX jit compiling <what>, could take seconds or minutes... on the first call — where the wait actually is — and reports the true elapsed compile time after it.
  • Cover both with unit tests (neither needs JAX installed).
  • File Phase 2 (remove the now-duplicated sentence from 23 workspace scripts, regenerate notebooks/markdown) as a follow-up.
Detailed implementation plan

Affected Repositories

  • PyAutoFit (primary, Phase 1 — this issue)
  • autolens_workspace / autogalaxy_workspace / HowToLens (Phase 2, separate issue)

Branch Survey

Repository Current Branch Dirty?
./PyAutoFit main clean
./autolens_workspace main clean
./autogalaxy_workspace main clean
./HowToLens main clean

Suggested branch: feature/sampler-cli-output-numbers

Phase 2 is additionally gated on contention: autolens_workspace currently has two live worktree claims (multi-galaxy-slam-followup, scaling-relation-degraded-profile-fixes).

Brain scored this large (8) and wanted a phase split. The score comes from its repo-count proxy; the library change is one property plus one wrapper. Size overridden to medium, split kept.

Implementation Steps

1a — cadence message. autofit/non_linear/search/abstract_search.py

Add a module constant:

#: Values at or above this disable periodic updates. The packaged config
#: default is the inf-like ``1e99`` sentinel documented on
#: ``_steps_until_full_update`` — kept as a float so ``search.json`` stores a
#: readable ``1e99`` rather than a 99-digit integer.
ITERATIONS_NEVER = 1e90

and a property on AbstractSearch:

@property
def quick_update_message(self) -> str:
    n = self.iterations_per_quick_update
    if not np.isfinite(n) or n >= ITERATIONS_NEVER:
        return (
            "On-the-fly updates of the maximum likelihood model are disabled. "
            "Set `updates: iterations_per_quick_update` in config/general.yaml "
            "to a finite number of iterations to enable them."
        )
    return (
        "On-the-fly updates of the maximum likelihood model every "
        f"{int(n)} iterations."
    )

np is already imported (abstract_search.py:6). Log it in fit() immediately after the existing "Starting non-linear search…" block (abstract_search.py:496-510):

logger.info(self.quick_update_message)

Unconditional, matching the adjacent call — not gated on self.silence.

1b — JAX compile message. autofit/non_linear/fitness.py

Add a one-shot wrapper helper on Fitness:

def _log_on_first_compile(self, func, description):
    """Wrap ``func`` so its first invocation reports the JAX compile it triggers.

    ``jax.jit`` / ``jax.vmap`` / ``jax.grad`` return immediately — tracing,
    lowering and XLA compilation all happen on the first call to the returned
    function. This is therefore the only point at which the user can be told
    why the run appears to hang.
    """
    state = {"compiled": False}

    def wrapper(*args, **kwargs):
        if state["compiled"]:
            return func(*args, **kwargs)
        logger.info(
            f"JAX jit compiling {description}, could take seconds or minutes..."
        )
        start = time.time()
        try:
            result = func(*args, **kwargs)
            # JAX dispatches asynchronously; block once so the reported time is
            # the real wall-clock wait rather than the dispatch latency.
            try:
                import jax
                jax.block_until_ready(result)
            except Exception:
                pass
        finally:
            state["compiled"] = True
        logger.info(
            f"JAX jit compilation of {description} complete in "
            f"{time.time() - start:.1f} seconds."
        )
        return result

    return wrapper

Then collapse the three cached_property bodies (currently fitness.py:494-553) to use it, deleting the misleading pre-wrap timing logs:

  • _vmapjax.vmap(jax.jit(self.call)), description "vectorized (vmap) likelihood function"
  • _jitjax.jit(self.call), description "likelihood function"
  • _gradjax.grad(self.call), description "likelihood function gradient"

Constraints that shaped this (all verified against the source):

  • fitness._jit is passed to scipy as fun= in autofit/non_linear/search/mle/bfgs/search.py:183 — the wrapper must stay a plain callable, which it is.
  • __getstate__ / __setstate__ (fitness.py:474-491) already strip and lazily rebuild _call/_jit/_vmap/_grad, so the non-picklable closure never reaches pickle and the flag resets per process — correct, since an unpickled process really does recompile. Keeps test_autofit/non_linear/test_fitness_jax_dispatch.py green.
  • _warmup_visualization (fitness.py:177-200) already logs "Warming up visualization (one-time JAX compilation)…" — left as is; the new wording is consistent with it.

1c — tests. test_autofit/non_linear/

  • _log_on_first_compile: wrap a plain lambda, assert the "could take seconds or minutes" line is logged exactly once across two calls (via caplog) and the return value passes through. No JAX needed.
  • quick_update_message: parametrize a finite cadence (renders the integer, no .0) against the 1e99 sentinel (renders the disabled wording naming the config key).

Key Files

  • autofit/non_linear/search/abstract_search.pyITERATIONS_NEVER, quick_update_message, the fit() log call (~line 510)
  • autofit/non_linear/fitness.py_log_on_first_compile, and the _jit / _vmap / _grad cached properties
  • autofit/non_linear/search/mle/bfgs/search.py:183 — consumer of fitness._jit, constrains the wrapper to a plain callable
  • test_autofit/non_linear/test_fitness_jax_dispatch.py — existing pickle-roundtrip coverage that must stay green

Verification

cd PyAutoFit
NUMBA_CACHE_DIR=/tmp/numba_cache MPLCONFIGDIR=/tmp/matplotlib \
  python -m pytest test_autofit/

Then end-to-end, which is what actually proves the fix — unit tests cannot see message ordering against a real compile:

  • Run a JAX-backed fit and confirm the compile line appears before the long wait, and that the reported elapsed time matches the observed wait rather than ~0s.
  • Same run under the default config: confirm the "updates are disabled" wording naming iterations_per_quick_update.
  • Re-run with iterations_per_quick_update set to a small finite value: confirm the printed integer matches the config and that quick updates then actually occur at that cadence.

Original Prompt

Click to expand starting prompt

On-the-fly updates every iterations_per_quick_update is the command line output
when a sampler runs, the actuallyh number should be printed to the CLI should say
the actual number

follow up, when JAX compiles a LH function it should say Should say "JAX jit
compiling likelihood function, could take seconds or minutes..." in output so user
knows why theres a small wait so a user knows they are waiting

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions