tqam-loggable

tqam-loggable is petite Python package providing logging friendly TQDM progress bars.

If your Python application has tqdm progress bars and you use them in a non-interactive session like...

• Background worker
• Docker container
• Edge computing
• Logstash, Sentry, Datadog or other external log tools
• Long-running machine learning tasks
• ...or stdout stream is otherwise not available or redirected

...you cannot have nice ANSI coloured progress bar. What happens is that if you are observing your application using monitoring tools you usually do not see anything happening while your application is doing some task and tracking progress using tqdm. This is fixed by tqdm-logging by sending a regular reports about your progress to logging backend like files and log monitoring tools.

In these situations tqdm-loggable will automatically turn your tqdm progress bars to loggable progress messages that can be read in headless systems.

tqdm-loggable...

• Is a drop-in replacement for the normal tqdm - nothing changes unless non-interactive session is detected
• Uses Python logging subsystem to report status instead of terminal
• Print a log line for every X seconds
• The logging messages are structured, so they work with Sentry, LogStash, etc. rich logging services which provide advanced searching and tagging by variables

Here is a sample tqdm log message output in plain text logs:

tqdm_logging.py     :139  2022-09-21 12:13:44,138 Progress on:Progress bar without total -/- rate:- remaining:? elapsed:00:00 postfix:-
tqdm_logging.py     :139  2022-09-21 12:13:46,225 Progress on:Progress bar without total 10000/- rate:- remaining:? elapsed:00:02 postfix:-

tqdm_logging.py     :139  2022-09-21 12:13:46,225 Progress on:Sample progress -/60000 rate:- remaining:? elapsed:00:00 postfix:-
tqdm_logging.py     :139  2022-09-21 12:13:56,307 Progress on:Sample progress 21.0kit/60.0kit rate:1,982.9it/s remaining:00:19 elapsed:00:10 postfix:Current time=2022-09-21 10:13:55.801787
tqdm_logging.py     :139  2022-09-21 12:14:06,392 Progress on:Sample progress 41.0kit/60.0kit rate:1,984.1it/s remaining:00:09 elapsed:00:20 postfix:Current time=2022-09-21 10:14:05.890220

Note that tqdm-loggable is not to be confused with tqdm.contrib.logging that is very different approach for a different problem.

Installation

The package name is tqdm-loggable. Read Python packaging manual on how to install packages on your system.

Usage

The only things you need to do

• Change import from from tqdm.auto import tqdm to from tqdm_loggable.auto import tqdm
• Optionally call tqdm_logging.set_level() at the init of your application
• Optionally call tqdm_logging.set_log_rate() at the init of your application

Here is an example script:

import datetime
import logging
import time

from tqdm_loggable.auto import tqdm
from tqdm_loggable.tqdm_logging import tqdm_logging


logger = logging.getLogger(__name__)


def main():
    fmt = f"%(filename)-20s:%(lineno)-4d %(asctime)s %(message)s"
    logging.basicConfig(level=logging.INFO, format=fmt, handlers=[logging.StreamHandler()])

    # Set the log level to all tqdm-logging progress bars.
    # Defaults to info - no need to set if you do not want to change the level
    tqdm_logging.set_level(logging.INFO)
    
    # Set the rate how often we update logs
    # Defaults to 10 seconds - optional
    tqdm_logging.set_log_rate(datetime.timedelta(seconds=10))    

    logger.info("This is an INFO test message using Python logging")

    with tqdm(total=60_000, desc="Sample progress", unit_scale=True) as progress_bar:
        for i in range(60_000):
            progress_bar.update(1000)

            # Test postfix output
            progress_bar.set_postfix({"Current time": datetime.datetime.utcnow()})

            time.sleep(0.5)

tqdm_loggable will detect non-interactive sessions. If the application is running without a proper terminal, non-interactive progress messages will be used. Otherwise progress bar is delegated tqdm.auto module to maintain the compatibility with any tqdm system without any changes to code.

The Python logger instance used to log the messages is named tqqm_loggable.tqm_logging.

Development

You can use tqdm_loggable/manual_tests.py to run the various checks to see what different interactive and non-interactive sessions give for you.

# Normal interactive terminal run
poetry run manual-tests 

Because this is a normal shell session you will get a normal progress bar:

Sample progress:  20%|████████▏                                | 12.0k/60.0k [00:05<00:24, 1.98kit/s, Current time=2022-09-21 15:40:24.274670]

...then test without without a proper TERM environment variable:

# Disable interactive terminal by fiddling with TERM environment variable
TERM=dumb poetry run manual-tests 

You get log messages:

tqdm_logging.py     :139  2022-09-21 17:41:20,720 Progress on:Sample progress -/60000 rate:- remaining:? elapsed:00:00 postfix:-
tqdm_logging.py     :139  2022-09-21 17:41:30,803 Progress on:Sample progress 21.0kit/60.0kit rate:1,984.7it/s remaining:00:19 elapsed:00:10 postfix:Current time=2022-09-21 15:41:30.300714

...or with different Docker sessions:

# This will display log mesages
docker build -t manual-tests . && docker run manual-tests

# This will allocate a terminal and display normal tqdm progress bar
docker build -t manual-tests . && docker run -ti manual-tests

or with redirected stdout:

poetry run manual-tests > output.txt
cat output.txt

These will output our terminal detection info and draw a progress bar, total 30 seconds.

tqdm-loggable manual tests
sys.stdout.isatty(): False
TERM: -
is_interactive_session(): False

and further progress bar or progress messages will follow depending if you run the manual test interactively or not.

See also

See other relevant logging packages:

• python-discord-logging-handler
• python-logstash

Kudos

Originally build for Trading Strategy blockchain trade automation.

See the original StackOverflow question.

License

MIT