solprop.log#

Logging and progress reporting.

Library modules log through logging.getLogger(__name__) and never configure handlers; scripts call configure_logging() once. Progress during a propagation is reported by the driver through a ProgressReporter, never from inside compiled kernels (docs/dev/architecture.md section 14).

This module is deliberately free of every other part of the package. import solprop imports it eagerly, and reaching the seam from here – for the type of the summary a save plane hands a reporter – would pull NumPy and jaxtyping into that import and take it from 0.06 s to 0.6 s, past the budget tests/test_package.py holds. Hence PlaneSummary, which is the structural half of solprop.backends.protocol.StepSummary that a reporter actually reads.

Module Attributes

`DEFAULT_PROGRESS_PERIOD`	Seconds between periodic progress lines when nothing says otherwise.
`DEFAULT_BAR_PERIOD`	Seconds between redraws of a progress bar.
`NOT_ESTIMATED`	What a line prints in place of a tolerance ratio the march did not estimate.
`ProgressChoice`	The names `progress=` accepts beside a reporter of its own.
`BAR_FORMAT`	What a bar shows: no `{remaining}` and no `{rate}`.

Functions

`configure_logging`([level, file, fmt, progress])	Attach a handler to the package logger and set its level.
`default_progress`()	Return the process-wide progress default.
`default_reporter`(*[, choice, period, ...])	Build the reporter a progress choice means.
`format_duration`(seconds)	Render a duration as `H:MM:SS`, or `N days, H:MM:SS` beyond a day.
`is_interactive`([stream])	Return whether a progress bar would be seen by a person.
`resolve_reporter`(progress, *[, period, ...])	Turn a `progress=` argument into a reporter.
`set_default_progress`(choice)	Set how a run reports progress when its call does not say.

Classes

`BarReporter`(*[, period, file, position, ...])	Draw one line that redraws in place: a bar over z with the counts and the ETA.
`InterruptibleReporter`(args, *kwargs)	A reporter that also wants to hear that the run stopped before its end.
`LogReporter`(*[, period, logger, clock, ...])	Report progress as log records: a periodic line, one per plane, one at the end.
`NullReporter`()	A reporter that does nothing, and the base class for one that does something.
`PlaneSummary`(args, *kwargs)	The scalars a reporter reads from a save plane.
`ProgressReporter`(args, *kwargs)	Receive progress events from the propagation driver.
`ProgressStatus`(elapsed, fraction, eta, ...)	Where a run is and what it expects, as the line reporter forms it each period.

solprop.log.BAR_FORMAT = '{desc}{percentage:5.1f}%|{bar}| {n:.4g}/{total:.4g} {unit} [{elapsed}{postfix}]'#

What a bar shows: no {remaining} and no {rate}.

tqdm’s own remaining-time estimate is the whole-run one, which was measured to be 1.6 to 23 times worse than the windowed estimate of LogReporter; the windowed one rides in the postfix, and a bar must not show two ETAs.

class solprop.log.BarReporter(*, period=0.5, file=None, position=None, leave=True, ncols=None, ascii=None, logger=None, clock=<built-in function perf_counter>, n_steps=None, level=20, estimated=True)[source]#

Bases: LogReporter

Draw one line that redraws in place: a bar over z with the counts and the ETA.

A LogReporter whose periodic event redraws a tqdm bar instead of logging a line, so the counters, the clock, the windowed ETA and its measured error are the same code as the line’s. What the bar shows is the periodic line’s content: the fraction of the run, the position against the extent (metres, or steps when a fixed schedule is replayed and the count is known), the elapsed time, and in the postfix the attempted and rejected steps, the current step and this package’s ETA with the window it came from. tqdm’s own remaining-time estimate is not shown (BAR_FORMAT). The plane line is demoted to DEBUG and the bar’s description says which plane the run is on; the closing line is logged as on the line reporter, after the bar has been closed. Log records written to the bar’s console while it is up go above it (_BarHandler), and the handlers are put back when the bar closes – also when the run is interrupted.

tqdm.auto draws an ipywidgets widget in a notebook that has the package and a text bar otherwise; ipywidgets is optional and not a dependency. step never calls into tqdm: the redraw happens on the period, so the per-step cost is the line reporter’s.

Parameters:

periodfloat, optional: Seconds between redraws, positive and finite. Default DEFAULT_BAR_PERIOD. It is also the period of the estimator’s window rule (max(5 periods, 10 % of the elapsed time)).
fileio.TextIOBase or None, optional: The stream to draw on; None is standard error. Tests inject an io.StringIO.
positionint or None, optional: The bar’s line offset, for a parent drawing several (tqdm’s position).
leavebool, optional: Whether the finished bar stays on the screen. Default True.
ncolsint or None, optional: A fixed width; None follows the terminal. Tests fix it.
asciibool, str or None, optional: The ascii option of tqdm: True for # characters, None for its default.
loggerlogging.Logger or None, optional: See LogReporter.
clockcallable, optional: See LogReporter.
n_stepsint or None, optional: See LogReporter.
levelint, optional: Level of the closing line; the plane line is DEBUG regardless.
estimatedbool, optional: See LogReporter.

Raises:

ValueError: If the period is not positive and finite.

Examples

>>> import io
>>> reporter = BarReporter(file=io.StringIO(), ncols=60, ascii=True)
>>> reporter.started(0.0, 0.1, 2)
>>> reporter.bar is not None
True
>>> reporter.finished(0.0)
>>> reporter.bar is None
True

property bar: Any[source]#

Return the tqdm instance while the bar is up, else None.

Returns:

tqdm.tqdm or None: The bar, for a parent placing its own beside it.

finished(total)[source]#

Fill the bar, close it, put the handlers back and log the closing line.

Parameters:

totalfloat: See ProgressReporter.finished().

interrupted(z, error)[source]#

Leave the bar where it stopped, put the handlers back and log the warning.

Parameters:

zfloat: See solprop.log.InterruptibleReporter.interrupted().
errorBaseException: See solprop.log.InterruptibleReporter.interrupted().

plane(z, summary)[source]#

Count the plane, log it at DEBUG and name it on the bar.

Parameters:

zfloat: See ProgressReporter.plane().
summaryPlaneSummary: See ProgressReporter.plane().

started(z_start, z_end, n_planes)[source]#

Open the bar and route console logging above it.

Parameters:

z_start, z_endfloat: See ProgressReporter.started().
n_planesint: See ProgressReporter.started().

solprop.log.DEFAULT_BAR_PERIOD = 0.5#: Seconds between redraws of a progress bar.

solprop.log.DEFAULT_PROGRESS_PERIOD = 10.0#: Seconds between periodic progress lines when nothing says otherwise.

class solprop.log.InterruptibleReporter(*args, **kwargs)[source]#

Bases: ProgressReporter, Protocol

A reporter that also wants to hear that the run stopped before its end.

The driver calls interrupted() from its finally when the loop raised, and re-raises. NullReporter implements it as a no-op, so a subclass has it; a reporter written to the four calls alone is still a ProgressReporter and is simply not told.

Examples

>>> isinstance(NullReporter(), InterruptibleReporter)
True

interrupted(z, error)[source]#

Record that the run stopped before its end.

Parameters:

zfloat: The last save plane the run reached, m.
errorBaseException: What stopped it; the driver re-raises it after this call.

class solprop.log.LogReporter(*, period=10.0, logger=None, clock=<built-in function perf_counter>, n_steps=None, level=20, estimated=True)[source]#

Bases: object

Report progress as log records: a periodic line, one per plane, one at the end.

Three kinds of line, all at level (INFO by default) on this module’s logger. A periodic line, at most one per period seconds however fast the steps come, says where the run is and when it expects to finish. A plane line says what the last save plane cost. The closing line says what the run achieved against what it asked for, and how far off its own ETAs turned out to be. Nothing is printed; call solprop.log.configure_logging() to see the lines.

The ETA is from the recent rate, and it is measured. Two estimates are formed at every periodic line: the whole-run one, remaining z / (z done / elapsed), and one from the rate of z over a trailing window of max(5 periods, 10 % of the elapsed time). The windowed one is reported, because the whole-run one is linear in z from the first step and most runs are not: the steps are short while a pulse compresses and long after it, a gradient fill changes the operator and the plasma cost along z, and a plane-dense run pays its planes unevenly. When a fixed schedule is replayed the total step count is known, so the estimate is the remaining steps at the recent cost per step. Both estimates’ median absolute relative errors are kept, and finished() logs the reported one, so the estimator is measured on every run rather than assumed.

Parameters:

periodfloat, optional: Seconds between periodic lines, s. 0 disables them and leaves the plane and closing lines.
loggerlogging.Logger or None, optional: Logger to use; defaults to this module’s.
clockcallable, optional: Returns a monotonic time in seconds. Injected so that the period and the ETA can be tested without waiting.
n_stepsint or None, optional: Total steps of a replayed fixed schedule, which turns the ETA into a remaining-steps estimate. None for an adaptive run.
levelint, optional: Level the three lines are logged at.
estimatedbool, optional: Whether the steps carry an error estimate. False for the low-storage march, whose 0.0 norms mean “not estimated”: the closing line then prints solprop.log.NOT_ESTIMATED in place of the tolerance ratio.

Examples

>>> import logging
>>> from types import SimpleNamespace
>>> reporter = LogReporter(level=logging.DEBUG)
>>> reporter.plane(0.5, SimpleNamespace(n_steps=40, n_rejected=1, max_norm=0.7,
...                                     wall_time=0.03))
>>> reporter.finished(0.06)
>>> reporter.n_steps, reporter.tolerance_ratio
(40, 0.7)

property eta_error: float[source]#

Return how far off the reported ETAs were.

Returns:

float: Median absolute relative error of the windowed estimate over every periodic line that published one; NaN before finished(), or when no line did.

property eta_error_whole_run: float[source]#

Return how far off the whole-run estimator would have been.

Formed on the same lines as eta_error but never reported, so that the two can be compared on every run.

Returns:

float: Median absolute relative error of the whole-run estimate; NaN as for eta_error.

finished(total)[source]#

Log the closing line, with the ETA error the run’s own estimates made.

Parameters:

totalfloat: See ProgressReporter.finished().

interrupted(z, error)[source]#

Log one warning saying where the run stopped and what stopped it.

Parameters:

zfloat: See solprop.log.InterruptibleReporter.interrupted().
errorBaseException: See solprop.log.InterruptibleReporter.interrupted().

property n_rejected: int[source]#

Return the rejected steps of the run so far.

Returns:

int: Counted from whichever channel is live; see n_steps.

property n_steps: int[source]#

Return the attempted steps of the run so far.

Returns:

int: The larger of the two channels that count: the per-step calls when a driver is attached, and the plane summaries otherwise. Both count every attempted step, so when both are live they agree.

plane(z, summary)[source]#

Log one line for a save plane.

Parameters:

zfloat: See ProgressReporter.plane().
summaryPlaneSummary: See ProgressReporter.plane().

started(z_start, z_end, n_planes)[source]#

Take the run’s extent and start the clock.

Emits nothing: the promise is one periodic line per period, and a run shorter than its period says nothing until its first plane.

Parameters:

z_start, z_endfloat: See ProgressReporter.started().
n_planesint: See ProgressReporter.started().

step(z, dz, accepted)[source]#

Count one attempted step and emit a periodic line if one is due.

Parameters:

z, dzfloat: See ProgressReporter.step().
acceptedbool: See ProgressReporter.step().

property tolerance_ratio: float[source]#

Return what the run achieved against what it asked for.

Returns:

float: The largest scaled error norm any accepted step scored (solprop.stepper.controller.ControlRecord.tolerance_ratio); 0 before the first plane.

solprop.log.NOT_ESTIMATED = 'not estimated (replayed schedule)'#

What a line prints in place of a tolerance ratio the march did not estimate.

The low-storage march records 0.0 in the norm column, meaning “not estimated” (SEP 24 section 6.3); printed as a ratio it would read as a perfect step.

class solprop.log.NullReporter[source]#

Bases: object

A reporter that does nothing, and the base class for one that does something.

Every method is a no-op, so a subclass overrides only what it wants:

Examples

>>> class Bar(NullReporter):
...     def plane(self, z, summary):
...         print(f"reached {z} m")
>>> isinstance(Bar(), ProgressReporter)
True

finished(total)[source]#

Ignore the event.

Parameters:

totalfloat: See ProgressReporter.finished().

interrupted(z, error)[source]#

Ignore the event.

Parameters:

zfloat: See solprop.log.InterruptibleReporter.interrupted().
errorBaseException: See solprop.log.InterruptibleReporter.interrupted().

plane(z, summary)[source]#

Ignore the event.

Parameters:

zfloat: See ProgressReporter.plane().
summaryPlaneSummary: See ProgressReporter.plane().

started(z_start, z_end, n_planes)[source]#

Ignore the event.

Parameters:

z_start, z_endfloat: See ProgressReporter.started().
n_planesint: See ProgressReporter.started().

step(z, dz, accepted)[source]#

Ignore the event.

Parameters:

z, dzfloat: See ProgressReporter.step().
acceptedbool: See ProgressReporter.step().

class solprop.log.PlaneSummary(*args, **kwargs)[source]#

Bases: Protocol

The scalars a reporter reads from a save plane.

Structural rather than imported, so that this module stays free of the seam and import solprop keeps its budget (see the module docstring). solprop.backends.protocol.StepSummary satisfies it. The four are properties rather than attributes because the class that satisfies it is a frozen dataclass, and a writable protocol member would not accept one.

Examples

>>> from types import SimpleNamespace
>>> isinstance(SimpleNamespace(n_steps=8, n_rejected=0, max_norm=0.4,
...                            wall_time=0.1), PlaneSummary)
True

property max_norm: float[source]#

Return the largest scaled error norm over the accepted steps.

Returns:

float: The norm; 1 is the tolerance the run asked for.

property n_rejected: int[source]#

Return the rejected steps among them.

Returns:

int: The rejected steps.

property n_steps: int[source]#

Return the steps taken to reach the plane, accepted and rejected together.

Returns:

int: The attempted steps.

property wall_time: float[source]#

Return the seconds the plane took.

Returns:

float: Wall time, s.

solprop.log.ProgressChoice#

The names progress= accepts beside a reporter of its own.

"auto" draws a bar when the process is interactive (is_interactive()) and logs lines otherwise; "bar" and "log" force one or the other; "none" reports nothing.

alias of Literal[‘auto’, ‘bar’, ‘log’, ‘none’]

class solprop.log.ProgressReporter(*args, **kwargs)[source]#

Bases: Protocol

Receive progress events from the propagation driver.

Four calls, in this order: started() once, step() once per attempted step including the rejected ones, plane() once per save plane, and finished() once at the end. A reporter may also implement the fifth call of solprop.log.InterruptibleReporter, which the driver makes instead of finished() when the loop raises, KeyboardInterrupt included, so that a reporter holding a terminal can give it back; a reporter without it is still complete. The driver holds no state on a reporter’s behalf and never inspects what it returns.

step() is on the hot path – one attribute lookup and one call inside the step loop – so a reporter that does real work there must do it on a wall-clock period, not on every call. Nothing a reporter does may change the propagation: a run with a reporter is bitwise the run without one.

Subclass solprop.log.NullReporter to implement only the calls you care about.

Examples

>>> isinstance(NullReporter(), ProgressReporter)
True

finished(total)[source]#

Record that the run ended.

Parameters:

totalfloat: Wall time of the whole run, s.

plane(z, summary)[source]#

Record that a save plane was reached.

Parameters:

zfloat: Position of the plane, m.
summaryPlaneSummary: What the call to the plane cost and achieved.

started(z_start, z_end, n_planes)[source]#

Record that a run has begun.

Parameters:

z_startfloat: Position the run starts from, m; non-zero on a resume.
z_endfloat: Position the run ends at, m.
n_planesint: Save planes the run will write.

step(z, dz, accepted)[source]#

Record one attempted step.

Parameters:

zfloat: Position at the end of the attempt, m. On a rejected step this is where the attempt would have landed, which is ahead of the run’s true position.
dzfloat: Length of the attempt, m.
acceptedbool: Whether the step was kept.

class solprop.log.ProgressStatus(elapsed, fraction, eta, window, known)[source]#

Bases: object

Where a run is and what it expects, as the line reporter forms it each period.

Attributes:

elapsedfloat: Seconds since ProgressReporter.started().
fractionfloat: The fraction of the run’s extent covered, in [0, 1].
etafloat: The windowed estimate of the seconds remaining; infinite when none can be formed.
windowfloat: The length of the trailing window the estimate was taken over, s.
knownbool: Whether the estimate is published: past both thresholds and finite.

elapsed: float#

eta: float#

fraction: float#

known: bool#

window: float#

solprop.log.configure_logging(level=20, file=None, fmt='%(asctime)s %(levelname)-7s %(name)s: %(message)s', *, progress=None)[source]#

Attach a handler to the package logger and set its level.

Parameters:

levelint or str, optional: Logging level for the package logger, e.g. logging.DEBUG or "DEBUG".
filePath or None, optional: If given, log to this file instead of standard error.
fmtstr, optional: Log record format.
progress{‘auto’, ‘bar’, ‘log’, ‘none’} or None, optional: The process-wide default for how a run reports progress when a call does not say (set_default_progress()). None leaves the current default.

Returns:

logging.Logger: The package logger, configured. Calling this function again replaces the handler it installed before, so repeated calls do not duplicate output.

Examples

>>> import logging
>>> logger = configure_logging("WARNING")
>>> logger.level == logging.WARNING
True
>>> logger.setLevel(logging.NOTSET)  # back to inheriting the root logger's level

solprop.log.default_progress()[source]#

Return the process-wide progress default.

Returns:

{‘auto’, ‘bar’, ‘log’, ‘none’}: What set_default_progress() last set, "auto" until then.

solprop.log.default_reporter(*, choice=None, period=10.0, n_steps=None, stream=None, estimated=True)[source]#

Build the reporter a progress choice means.

Parameters:

choice{‘auto’, ‘bar’, ‘log’, ‘none’} or None, optional: The choice; None takes default_progress().
periodfloat, optional: The line reporter’s period, s; a bar has its own redraw period.
n_stepsint or None, optional: The step count of a replayed schedule, for the ETA.
streamio.TextIOBase or None, optional: Where a bar would draw, and what "auto" tests; None is standard error.
estimatedbool, optional: Whether the steps carry an error estimate (LogReporter).

Returns:

ProgressReporter: A BarReporter, a LogReporter or a NullReporter.

Raises:

ValueError: If the choice is not one of the four names.

Examples

>>> import io
>>> from solprop.log import LogReporter, default_reporter
>>> isinstance(default_reporter(choice="auto", stream=io.StringIO()), LogReporter)
True

solprop.log.format_duration(seconds)[source]#

Render a duration as H:MM:SS, or N days, H:MM:SS beyond a day.

Whole seconds: a progress line that resolves an ETA finer than that is claiming an accuracy no estimator here has. A duration that is negative or not finite – an ETA formed from a rate of zero, say – reads unknown rather than raising, because a reporter must not be able to end a run.

Parameters:

secondsfloat: The duration, s.

Returns:

str: The duration, or "unknown".

Examples

>>> format_duration(751.4)
'0:12:31'
>>> format_duration(3600.0)
'1:00:00'
>>> format_duration(90061.0)
'1 day, 1:01:01'
>>> format_duration(float("inf"))
'unknown'

solprop.log.is_interactive(stream=None)[source]#

Return whether a progress bar would be seen by a person.

True inside a Jupyter kernel (the shell get_ipython() returns is a ZMQInteractiveShell, the test tqdm.autonotebook itself makes) and when the stream is a terminal. A redirect, a pipe, a batch scheduler and pytest’s capture are none of these, so they get log lines and never carriage returns.

Parameters:

streamio.TextIOBase or None, optional: The stream a bar would draw on; None is standard error.

Returns:

bool: Whether to draw a bar under progress="auto".

Examples

>>> import io
>>> from solprop.log import is_interactive
>>> is_interactive(io.StringIO())
False

solprop.log.resolve_reporter(progress, *, period=10.0, n_steps=None, estimated=True)[source]#

Turn a progress= argument into a reporter.

Parameters:

progressProgressReporter, {‘auto’, ‘bar’, ‘log’, ‘none’} or None: A reporter, which is returned as given, or a choice; None takes the process default.
periodfloat, optional: See default_reporter().
n_stepsint or None, optional: See default_reporter().
estimatedbool, optional: See default_reporter().

Returns:

ProgressReporter: The reporter to attach to the backend.

solprop.log.set_default_progress(choice)[source]#

Set how a run reports progress when its call does not say.

Parameters:

choice{‘auto’, ‘bar’, ‘log’, ‘none’}: See ProgressChoice. A per-call progress= keyword beats this default, which beats "auto".

Raises:

ValueError: If the choice is not one of the four names.

Examples

>>> from solprop.log import default_progress, set_default_progress
>>> set_default_progress("log")
>>> default_progress()
'log'
>>> set_default_progress("auto")