Skip to content

Reporting

The two modules behind reporting and progress: where messages go, and what draws a progress bar.

thresher.log

thresher.log

Where everything this package has to say goes.

Until 0.8.0 there were two answers to that, neither of them good. Most of it went to print() behind an if verbose: - twenty-odd branches threading a boolean down through the dispatcher into every solver, writing to stdout, unformattable, untimestamped, and impossible to route anywhere. The rest went to the standard library's logging, from dispatch and spark only. So the same run reported half of itself one way and half the other, and a caller who wanted the detail had to take it on stdout - the stream the command line reserves for the answer.

It all goes through loguru now, at a level per message, and one setting decides how much of it is emitted.

The level a caller asks for

verbosity names the lowest level that gets through: 'debug', 'info', 'warning' (the default), 'error' or 'critical'. It can be set three ways, in increasing precedence:

  • set_verbosity('info'), which lasts until it is changed;
  • Thresher(verbosity='info'), which applies to that instance's runs;
  • with verbosity('info'):, which applies to the block.

The default is 'warning', so an ordinary call still says nothing unless something is worth saying - which preserves the one message that was always emitted, the warning that the chosen algorithm is slow for this much data.

Why the level is checked here rather than at a sink

Both logging systems hold their level globally: one Thresher cannot be verbose while another, in the same process, is not. That is the wrong shape for a library whose verbosity is a per-instance option, so the check happens at the call site, against a ContextVar. Two consequences worth knowing: the level is per-context, so threads and async tasks do not read each other's setting; and a message below the level costs nothing, because it is never handed to loguru at all.

Why no sink is installed

A library that adds a loguru handler takes over an application's console. This adds none: records go to whatever the application has configured, which for an application that has configured nothing is loguru's own stderr handler. logger.disable('thresher') silences this package the loguru way, and works because nothing here bypasses the global logger.

Applications that route their logs through the standard library instead can have these records too - propagate_to_logging() bridges them, restoring what logging.getLogger('thresher') used to see. It is off by default because an application with both configured would otherwise print everything twice.

PropagateHandler

Bases: Handler

A loguru sink that re-emits records through the standard library.

Loguru's own recipe for the job. The record arrives here already formatted by the logging machinery loguru builds it from, so it needs only to be handed to the logger of the same name - thresher.dispatch, thresher.algs.exact.compute, and so on, which is the hierarchy logging.getLogger('thresher') sits above.

emit

emit(record: LogRecord) -> None

Pass one record to the standard library logger of the same name.

Parameters:

Name Type Description Default
record LogRecord

the record loguru built.

required

Returns:

Type Description
None

None.

Source code in src/thresher/log.py
def emit(self, record: logging.LogRecord) -> None:
    """Pass one record to the standard library logger of the same name.

    Args:
        record: the record loguru built.

    Returns:
        None.
    """
    logging.getLogger(record.name).handle(record)

resolve_verbosity

resolve_verbosity(
    verbosity: Any, verbose: Any = None
) -> str | None

Turn the two constructor options into one level name.

Parameters:

Name Type Description Default
verbosity Any

the verbosity option: a level name, or None if it was not given.

required
verbose Any

the older verbose boolean. True means 'debug' - it used to print every solver's per-iteration detail, which is what that level is for. False and None both mean "nothing asked for", so that leaving it at its default does not override a verbosity set elsewhere.

None

Returns:

Type Description
str | None

The level name, or None if neither option asked for anything.

Raises:

Type Description
ConfigurationError

if verbosity is not one of LEVELS. It is a ValueError.

Source code in src/thresher/log.py
def resolve_verbosity(verbosity: Any, verbose: Any = None) -> str | None:
    """Turn the two constructor options into one level name.

    Args:
        verbosity: the `verbosity` option: a level name, or None if it was not given.
        verbose: the older `verbose` boolean. True means `'debug'` - it used to print
            every solver's per-iteration detail, which is what that level is for. False
            and None both mean "nothing asked for", so that leaving it at its default
            does not override a `verbosity` set elsewhere.

    Returns:
        The level name, or None if neither option asked for anything.

    Raises:
        ConfigurationError: if `verbosity` is not one of `LEVELS`. It is a `ValueError`.
    """
    if verbosity is not None:
        return _validate_level(verbosity)

    return "debug" if verbose else None

set_verbosity

set_verbosity(level: str) -> None

Set how much this package reports, until it is set again.

Parameters:

Name Type Description Default
level str

one of LEVELS, case-insensitive. 'error' is the way to silence the "this algorithm is slow for this much data" warning.

required

Returns:

Type Description
None

None.

Raises:

Type Description
ConfigurationError

if level is not one of LEVELS. It is a ValueError.

Source code in src/thresher/log.py
def set_verbosity(level: str) -> None:
    """Set how much this package reports, until it is set again.

    Args:
        level: one of `LEVELS`, case-insensitive. `'error'` is the way to silence the
            "this algorithm is slow for this much data" warning.

    Returns:
        None.

    Raises:
        ConfigurationError: if `level` is not one of `LEVELS`. It is a `ValueError`.
    """
    global _default_verbosity
    _default_verbosity = _validate_level(level)

current_verbosity

current_verbosity() -> str

Report the level in force here.

Returns:

Type Description
str

The context-local level if a verbosity block or a Thresher set one, and the

str

process-wide default otherwise.

Source code in src/thresher/log.py
def current_verbosity() -> str:
    """Report the level in force here.

    Returns:
        The context-local level if a `verbosity` block or a `Thresher` set one, and the
        process-wide default otherwise.
    """
    return _verbosity.get() or _default_verbosity

is_enabled_for

is_enabled_for(level: str) -> bool

Say whether a message at this level would be emitted.

Worth asking before building a message that is expensive to format - the genetic solver's per-generation dump of every agent's trait, for instance.

Parameters:

Name Type Description Default
level str

one of LEVELS, case-insensitive.

required

Returns:

Type Description
bool

True if the level is at or above the one in force.

Source code in src/thresher/log.py
def is_enabled_for(level: str) -> bool:
    """Say whether a message at this level would be emitted.

    Worth asking before building a message that is expensive to format - the genetic
    solver's per-generation dump of every agent's trait, for instance.

    Args:
        level: one of `LEVELS`, case-insensitive.

    Returns:
        True if the level is at or above the one in force.
    """
    return SEVERITY[level.lower()] >= SEVERITY[current_verbosity()]

verbosity

verbosity(level: str | None) -> Generator[None, None, None]

Apply a level for the duration of a block, then put back what was there.

This is what Thresher.optimize_threshold wraps its run in, so that an instance built with verbosity='debug' is verbose for its own calls and for nothing else.

Parameters:

Name Type Description Default
level str | None

one of LEVELS, or None to leave the current setting alone - which is what a Thresher built without either option passes.

required

Yields:

Type Description
None

None, with the level in force.

Source code in src/thresher/log.py
@contextmanager
def verbosity(level: str | None) -> Generator[None, None, None]:
    """Apply a level for the duration of a block, then put back what was there.

    This is what `Thresher.optimize_threshold` wraps its run in, so that an instance built
    with `verbosity='debug'` is verbose for its own calls and for nothing else.

    Args:
        level: one of `LEVELS`, or None to leave the current setting alone - which is what
            a `Thresher` built without either option passes.

    Yields:
        None, with the level in force.
    """
    if level is None:
        yield
        return

    token = _verbosity.set(level.lower())
    try:
        yield
    finally:
        _verbosity.reset(token)

debug

debug(message: str, *args: Any) -> None

Log the detail of a run: one line per iteration, per generation, per step.

Parameters:

Name Type Description Default
message str

a loguru-style format string, using {} placeholders.

required
*args Any

values for those placeholders.

()

Returns:

Type Description
None

None.

Source code in src/thresher/log.py
def debug(message: str, *args: Any) -> None:
    """Log the detail of a run: one line per iteration, per generation, per step.

    Args:
        message: a loguru-style format string, using `{}` placeholders.
        *args: values for those placeholders.

    Returns:
        None.
    """
    _emit("debug", message, args)

info

info(message: str, *args: Any) -> None

Log what the run is doing: which algorithm, over how much data, with what result.

Parameters:

Name Type Description Default
message str

a loguru-style format string, using {} placeholders.

required
*args Any

values for those placeholders.

()

Returns:

Type Description
None

None.

Source code in src/thresher/log.py
def info(message: str, *args: Any) -> None:
    """Log what the run is doing: which algorithm, over how much data, with what result.

    Args:
        message: a loguru-style format string, using `{}` placeholders.
        *args: values for those placeholders.

    Returns:
        None.
    """
    _emit("info", message, args)

warning

warning(message: str, *args: Any) -> None

Log something the caller should know about a run that is going ahead anyway.

Parameters:

Name Type Description Default
message str

a loguru-style format string, using {} placeholders.

required
*args Any

values for those placeholders.

()

Returns:

Type Description
None

None.

Source code in src/thresher/log.py
def warning(message: str, *args: Any) -> None:
    """Log something the caller should know about a run that is going ahead anyway.

    Args:
        message: a loguru-style format string, using `{}` placeholders.
        *args: values for those placeholders.

    Returns:
        None.
    """
    _emit("warning", message, args)

propagate_to_logging

propagate_to_logging(enable: bool = True) -> None

Send this package's records into the standard library's logging as well.

Before 0.8.0 the two messages this package logged went through logging, so logging.getLogger('thresher').setLevel(logging.ERROR) silenced them and an application's file handler picked them up. Both now go through loguru, and this is what restores that: with it on, every record is handed to the logging logger named after the module that emitted it.

Off by default, and deliberately. An application with loguru and logging both writing to a console would print each record twice, and the duplicate is the harder problem to work out from the outside.

Parameters:

Name Type Description Default
enable bool

True to install the bridge, False to remove it. Installing twice is a no-op rather than a second copy of every record.

True

Returns:

Type Description
None

None.

Source code in src/thresher/log.py
def propagate_to_logging(enable: bool = True) -> None:
    """Send this package's records into the standard library's `logging` as well.

    Before 0.8.0 the two messages this package logged went through `logging`, so
    `logging.getLogger('thresher').setLevel(logging.ERROR)` silenced them and an
    application's file handler picked them up. Both now go through loguru, and this is
    what restores that: with it on, every record is handed to the `logging` logger named
    after the module that emitted it.

    Off by default, and deliberately. An application with loguru *and* `logging` both
    writing to a console would print each record twice, and the duplicate is the harder
    problem to work out from the outside.

    Args:
        enable: True to install the bridge, False to remove it. Installing twice is a
            no-op rather than a second copy of every record.

    Returns:
        None.
    """
    global _propagating

    if not enable:
        if _propagating is not None:
            logger.remove(_propagating)
            _propagating = None
        return

    if _propagating is not None:
        return

    # Filtered to this package. Loguru's handlers are global, so an unfiltered one here
    # would also drag every other library's loguru records into `logging` - which is not
    # this package's decision to make.
    _propagating = logger.add(
        PropagateHandler(),
        format="{message}",
        filter=lambda record: record["name"] is not None and record["name"].startswith("thresher"),
        level=0,
    )

cli_logging

cli_logging(level: str) -> Generator[None, None, None]

Give the command line a console handler of its own, for one invocation.

A library must not configure loguru; a program may, and the thresher command is a program. Loguru's default handler prints a timestamp, the module path and the line number, which is right for an application's log file and too much for a one-line answer in a terminal - so it is replaced, for the duration, with one printing the level and the message to stderr. stdout is left for the result.

Scoped rather than done once at start-up, because the command is importable as thresher.cli.main - the test suite calls it that way, and so may anyone else. A program that returns to its caller having removed that caller's log handler is a program that has broken something it did not own. Only loguru's own default handler is touched, and an equivalent one is put back on the way out.

It also sets the level process-wide, with set_verbosity. The two have to agree: handing a record to loguru is what the handler is for, and deciding whether to hand it over at all is what the level does.

Parameters:

Name Type Description Default
level str

the verbosity the invocation asked for, one of LEVELS.

required

Yields:

Type Description
None

None, with the handler installed and the level in force.

Source code in src/thresher/log.py
@contextmanager
def cli_logging(level: str) -> Generator[None, None, None]:
    """Give the command line a console handler of its own, for one invocation.

    A library must not configure loguru; a program may, and the `thresher` command is a
    program. Loguru's default handler prints a timestamp, the module path and the line
    number, which is right for an application's log file and too much for a one-line
    answer in a terminal - so it is replaced, for the duration, with one printing the
    level and the message to stderr. stdout is left for the result.

    Scoped rather than done once at start-up, because the command is importable as
    `thresher.cli.main` - the test suite calls it that way, and so may anyone else. A
    program that returns to its caller having removed that caller's log handler is a
    program that has broken something it did not own. Only loguru's own default handler is
    touched, and an equivalent one is put back on the way out.

    It also sets the level process-wide, with `set_verbosity`. The two have to agree:
    handing a record to loguru is what the handler is for, and deciding whether to hand it
    over at all is what the level does.

    Args:
        level: the verbosity the invocation asked for, one of `LEVELS`.

    Yields:
        None, with the handler installed and the level in force.
    """
    previous = current_verbosity()
    set_verbosity(level)

    # 0 is loguru's default stderr handler. Removing it raises if an application has
    # already done so itself, which is a state to accept rather than to report.
    had_default = True
    try:
        logger.remove(0)
    except ValueError:
        had_default = False

    handler = logger.add(_StandardError(), format=CLI_FORMAT, level=level.upper(), colorize=False)
    try:
        yield
    finally:
        logger.remove(handler)
        if had_default:
            # Not the same handler - loguru numbers them from a counter that only goes up -
            # but the same behaviour: its default format, at its default level, on stderr.
            logger.add(_StandardError())
        set_verbosity(previous)

thresher.progress

thresher.progress

Progress bars: tqdm where it is installed, the built-in bar where it is not.

tqdm is an optional extra - pip install 'thresher-py[progress]'. When it imports, it draws; when it does not, the bar this package has always carried draws instead, and nothing else changes. That is the whole contract, and it is worth stating the two halves of it explicitly:

  • The answer never depends on which one drew. A progress bar is output, not computation, so the two backends differ in appearance and in nothing else.
  • They are formatted to match. tqdm is given a bar_format shaped like the built-in bar - a percentage to one decimal place, then the counts - so installing the extra does not change what a script scraping stderr sees, and the tests can assert one thing about both.

Where a bar is drawn, and where it is not

A bar is a thing you watch. It is worth drawing when a person is waiting at a terminal, and is noise or corruption anywhere else, so:

  • It goes to stderr, never stdout. The command line prints the threshold on stdout so it can be piped onward; a bar redrawing itself with a carriage return in the middle of that would corrupt it. Before 0.8.0 the built-in bar wrote to stdout, which is the same stream - it went unnoticed only because the command line had no way to ask for a bar.
  • Nothing is drawn from a worker. The mp and ray backends run the counting in other processes, where several bars would interleave into nonsense on one terminal. The functions those backends ship to workers do no reporting at all, which is what makes them safe to ship.
  • Nothing is drawn from Spark. SparkThresher has no progress_bar option and calls the sweeps without one. The work there happens in the cluster, where there is nobody to watch it, and the driver's part is a few thousand bins - over before a bar could be read.
  • Not while the log is at DEBUG. Both write to stderr, so together they produce a bar interrupted by log lines and log lines interrupted by a bar. The level wins: someone who asked for the detail asked for the detail. Until 0.8.0 the genetic solver was alone in applying that rule, and announced it with a printed warning.

ProgressBar

Bases: Protocol

What the solvers need from a progress bar, and all they are given.

Two methods and a context manager. Small enough that the built-in bar, tqdm and the do-nothing bar can each satisfy it without pretending to be one another.

update

update(completed: int) -> None

Report the total number of steps finished so far.

Parameters:

Name Type Description Default
completed int

steps done, counted from the start rather than since the last call. An absolute count, because two of the call sites bracket one batched computation and know only "none of it" and "all of it".

required

Returns:

Type Description
None

None.

Source code in src/thresher/progress.py
def update(self, completed: int) -> None:
    """Report the total number of steps finished so far.

    Args:
        completed: steps done, counted from the start rather than since the last call.
            An absolute count, because two of the call sites bracket one batched
            computation and know only "none of it" and "all of it".

    Returns:
        None.
    """
    ...

close

close() -> None

Finish the bar off, leaving the line tidy.

Returns:

Type Description
None

None.

Source code in src/thresher/progress.py
def close(self) -> None:
    """Finish the bar off, leaving the line tidy.

    Returns:
        None.
    """
    ...

tqdm_available

tqdm_available() -> bool

Say whether the optional tqdm extra is installed.

Returns:

Type Description
bool

True if bars will be drawn by tqdm, False if the built-in bar will draw them.

Source code in src/thresher/progress.py
def tqdm_available() -> bool:
    """Say whether the optional `tqdm` extra is installed.

    Returns:
        True if bars will be drawn by tqdm, False if the built-in bar will draw them.
    """
    return _tqdm is not None

make_progress

make_progress(
    total: int,
    description: str = "",
    *,
    enabled: bool = False,
    stream: TextIO | None = None,
) -> ProgressBar

Build the progress bar for one job, or a bar that draws nothing.

Parameters:

Name Type Description Default
total int

how many steps the whole job is. A total of zero or less has no proportion to show, so nothing is drawn.

required
description str

what the job is, printed before the bar.

''
enabled bool

whether the caller asked for a bar at all - the progress_bar option.

False
stream TextIO | None

where to draw. Defaults to sys.stderr, read now rather than held from import, so that a redirected stream is honoured.

None

Returns:

Type Description
ProgressBar

A tqdm-backed bar, the built-in bar, or a bar that does nothing - see the module

ProgressBar

docstring for which and why. All three satisfy ProgressBar, so the caller does

ProgressBar

not branch.

Source code in src/thresher/progress.py
def make_progress(
    total: int, description: str = "", *, enabled: bool = False, stream: TextIO | None = None
) -> ProgressBar:
    """Build the progress bar for one job, or a bar that draws nothing.

    Args:
        total: how many steps the whole job is. A total of zero or less has no proportion
            to show, so nothing is drawn.
        description: what the job is, printed before the bar.
        enabled: whether the caller asked for a bar at all - the `progress_bar` option.
        stream: where to draw. Defaults to `sys.stderr`, read now rather than held from
            import, so that a redirected stream is honoured.

    Returns:
        A tqdm-backed bar, the built-in bar, or a bar that does nothing - see the module
        docstring for which and why. All three satisfy `ProgressBar`, so the caller does
        not branch.
    """
    # DEBUG puts a log line on stderr for every step of the very loops that draw bars, so
    # the two would overwrite each other. The level wins.
    if not enabled or total <= 0 or log.is_enabled_for("debug"):
        return _NoProgress()

    target = stream if stream is not None else sys.stderr

    if _tqdm is not None:
        return _TqdmBar(total, description, target)
    return _BuiltInBar(total, description, target)

print_progress_bar

print_progress_bar(
    iteration: int,
    total: int,
    prefix: str = "",
    suffix: str = "",
    decimals: int = 1,
    length: int = 100,
    fill: str = "#",
    stream: TextIO | None = None,
) -> None

Draw one frame of the built-in terminal progress bar, in place.

The fallback for when tqdm is not installed, and the bar this package drew for everyone before 0.8.0. Call it in a loop; each call overwrites the last.

Parameters:

Name Type Description Default
iteration int

current iteration.

required
total int

total number of iterations. The line is ended once the two match.

required
prefix str

string printed before the bar.

''
suffix str

string printed after the bar.

''
decimals int

number of decimals in the percentage.

1
length int

character length of the bar.

100
fill str

bar fill character.

'#'
stream TextIO | None

where to draw. Defaults to sys.stderr. It was stdout until 0.8.0, which is the stream the command line prints the threshold on - see the module docstring.

None

Returns:

Type Description
None

None. The bar is written to stream.

Source code in src/thresher/progress.py
def print_progress_bar(
    iteration: int,
    total: int,
    prefix: str = "",
    suffix: str = "",
    decimals: int = 1,
    length: int = 100,
    fill: str = "#",
    stream: TextIO | None = None,
) -> None:
    """Draw one frame of the built-in terminal progress bar, in place.

    The fallback for when `tqdm` is not installed, and the bar this package drew for
    everyone before 0.8.0. Call it in a loop; each call overwrites the last.

    Args:
        iteration: current iteration.
        total: total number of iterations. The line is ended once the two match.
        prefix: string printed before the bar.
        suffix: string printed after the bar.
        decimals: number of decimals in the percentage.
        length: character length of the bar.
        fill: bar fill character.
        stream: where to draw. Defaults to `sys.stderr`. It was stdout until 0.8.0, which
            is the stream the command line prints the threshold on - see the module
            docstring.

    Returns:
        None. The bar is written to `stream`.
    """
    target = stream if stream is not None else sys.stderr
    percent = f"{100 * (iteration / float(total)):.{decimals}f}"
    filled_length = int(length * iteration // total)
    bar = fill * filled_length + "-" * (length - filled_length)
    # Written rather than printed, and to the stream it was handed. A bar is the one thing
    # here that goes to a console directly rather than through the log: it is a picture of
    # how far along a run is, not a message about it, so it has no level and belongs in no
    # log file.
    target.write(f"\r{prefix} |{bar}| {percent}% {suffix}\r")
    # End the line once the job is done, so whatever writes next starts on a fresh one.
    if iteration == total:
        target.write("\n")
    target.flush()