loguru icon indicating copy to clipboard operation
loguru copied to clipboard

How to log while using a progress bar from rich without breaking formatting?

Open taranlu-houzz opened this issue 3 years ago • 14 comments

Hello,

I am trying to figure out the best way to use loguru to log while also using a rich progress bar. In order to avoid formatting issues, it would seem that I need to use the progress bar's console.print function, since that is how you avoid breaking the progress bar and causing it to redraw.

I have a couple of thoughts on how to do this, but am still a bit lost:

  • Based on rich's documentation, it seems like maybe I could create a Console object for my app, add that as a sink somehow, and then pass that to the progress bar.
  • There might also be a way to use the regular logging handler that rich provides, and have loguru propegate messages to that, but I'm not sure how/if that can be hooked up to a rich Console object.

Any advice would be much appreciated! Thanks!

taranlu-houzz avatar May 18 '21 21:05 taranlu-houzz

Hey @taranlu-houzz.

By default the logger send messages using regular sys.stderr.write() method. As you realized, this causes compatibility problems with Rich's progressive bars. Both solutions you thought of should work.

You can either use Console.print() as a sink instead of sys.stderr. That way, Rich will be in charge of generating a proper output. As you said, it also requires to pass the console object to the Progress constructor.

import time
from loguru import logger
from rich.console import Console
from rich.progress import Progress

console = Console(color_system=None, stderr=None)

def work(i):
    logger.info("Working: {}", i)
    time.sleep(0.05)

def main():
    logger.info("Before")
    with Progress(console=console) as progress:
        for i in progress.track(range(100)):
            work(i)
    logger.info("After")


if __name__ == "__main__":
    logger.remove()  # Remove default 'stderr' handler

    # We need to specify end=''" as log message already ends with \n (thus the lambda function)
    # Also forcing 'colorize=True' otherwise Loguru won't recognize that the sink support colors
    logger.add(lambda m: console.print(m, end=""), colorize=True)

    main()

I guess it should work similarly using RichHandler(). Again, it seems you have to use your own console object.

handler = RichHandler(console=console)  # Note that RichHandler is adding extra info you may need to disable
logger.remove()
logger.add(handler, colorize=True)

Delgan avatar May 18 '21 23:05 Delgan

@Delgan Hey, thank you for the quick response. That will work. I do have a quick followup question though: if I want to be able to pass some of the more interesting rich constructs to be logged (tables, for example), and I want that to be logged to a file, do you know how I might set that up? I would assume that I would need to find a way to get a "ready to render" string out of rich to be sent to loguru (would I still be able to do colorization from rich in that case?).

taranlu-houzz avatar May 19 '21 00:05 taranlu-houzz

Indeed, it seems that you need to generate the table as a str that can be passed to the logger. See this question: https://github.com/willmcgugan/rich/issues/192

from rich.console import Console
from rich.table import Table
from io import StringIO

table = Table(title="Star Wars Movies")

table.add_column("Released", justify="right", style="cyan", no_wrap=True)
table.add_column("Title", style="magenta")
table.add_column("Box Office", justify="right", style="green")

table.add_row("Dec 20, 2019", "Star Wars: The Rise of Skywalker", "$952,110,690")
table.add_row("May 25, 2018", "Solo: A Star Wars Story", "$393,151,347")
table.add_row("Dec 15, 2017", "Star Wars Ep. V111: The Last Jedi", "$1,332,539,889")
table.add_row("Dec 16, 2016", "Rogue One: A Star Wars Story", "$1,332,439,889")

out = Console(file=StringIO())
out.print(table)

logger.info("Table:\n{}", out.file.getvalue())

About the colors, it is a little more tricky. The table generated by above code won't contain colors. You can easily force it by setting force_terminal=True in the Console constructor. However, there is a problem with Loguru. If you added two handlers, one logging to the terminal and another one logging to a file, then it's not easy to have colored table on terminal but colorless table on file.

This means that the handlers should be properly configured to take this into account. This is probably possible by stripping the ansi codes before writing to the file. Alternatively, one could get rid of Loguru colors and replace it with Rich markups formatting inside custom handler. I'm not sure how to do that, to be honest.

The main problem we face is that the handlers in Loguru expect to receive an already formatted string. However, it is Rich that handles formatting with or without colors. We probably need to somehow pass the Table object to the handlers instead of its string representation.

Maybe using bind() for example, but it's far from perfect:

from loguru import logger
from rich.console import Console
from rich.progress import Progress
from rich.table import Table
from io import StringIO

table = Table(title="Star Wars Movies")

table.add_column("Released", justify="right", style="cyan", no_wrap=True)
table.add_column("Title", style="magenta")
table.add_column("Box Office", justify="right", style="green")

table.add_row("Dec 20, 2019", "Star Wars: The Rise of Skywalker", "$952,110,690")
table.add_row("May 25, 2018", "Solo: A Star Wars Story", "$393,151,347")
table.add_row("Dec 15, 2017", "Star Wars Ep. V111: The Last Jedi", "$1,332,539,889")
table.add_row("Dec 16, 2016", "Rogue One: A Star Wars Story", "$1,332,439,889")

if __name__ == "__main__":
    terminal = Console(stderr=True)
    file = Console(file=open("file.log", "a"))

    def sink(message, console):
        console.print(message, end="")
        if "rich" in message.record["extra"]:
            console.print(message.record["extra"]["rich"])

    logger.remove()
    logger.add(lambda m: sink(m, terminal))
    logger.add(lambda m: sink(m, file))

    logger.info("Start")
    logger.bind(rich=table).info("Table:")
    logger.info("End")

I'm thinking of a way to customize the formatting of messages in a future version. This will permit to save an intermediate representation of the string to be logged. That way, one will be able to use logger.info() just like console.print() if desired. Maybe this will help.

Delgan avatar May 19 '21 09:05 Delgan

Hmm, okay, I may look into that. I don't actually need the functionality right now, but I thought it could be helpful. It would be really cool to see interoperability with rich. The combo of loguru + rich + click is a very potent cli toolkit!

taranlu-houzz avatar May 19 '21 19:05 taranlu-houzz

I just realized that the solution you posted for getting the progress bar working disables colorization of the progress bar itself, which is too bad... But I guess that is necessary, since getting rid of color_system=None breaks the logging output. Would be nice if there was a way to get them to work together.

taranlu-houzz avatar May 19 '21 20:05 taranlu-houzz

@Delgan I just noticed another issue with the above workaround is that if the output is redirected to a file, all of the colorization codes end up in the file making it hard to read. It seems that loguru handles this correctly by default, e.g. if just using the default stderr sink the output in the destination file does not have the colorization information, but the combination with the rich console seems to cause an issue.

Do you have any thoughts on how I might be able to tweak the workaround to allow for redirection to a file to have clean output?

taranlu-houzz avatar Aug 11 '21 21:08 taranlu-houzz

Hi @taranlu-houzz. Can you please share a small example to reproduce the problem? How are you redirecting the output? Adding a specific file handler should get rid of the ansi codes, but otherwise you may need to strip them yourself using a sed command for example.

Delgan avatar Aug 13 '21 10:08 Delgan

@Delgan So, with this basic example:

# just_loguru.py
from loguru import logger

logger.info("This is a test")

Running python just_loguru.py produces the expected colorized cli output, and running python just_loguru.py 2> out.txt produces a file with this output:

2021-08-13 10:22:27.634 | INFO     | __main__:<module>:7 - This is a test.

Then using the initial workaround you posted (and setting stderr=True):

# loguru_and_rich.py
import time
from loguru import logger
from rich.console import Console
from rich.progress import Progress

console = Console(color_system=None, stderr=True)

def work(i):
    logger.info("Working: {}", i)
    time.sleep(0.05)

def main():
    logger.info("Before")
    with Progress(console=console) as progress:
        for i in progress.track(range(100)):
            work(i)
    logger.info("After")


if __name__ == "__main__":
    logger.remove()  # Remove default 'stderr' handler

    # We need to specify end=''" as log message already ends with \n (thus the lambda function)
    # Also forcing 'colorize=True' otherwise Loguru won't recognize that the sink support colors
    logger.add(lambda m: console.print(m, end=""), colorize=True)

    main()

Running python loguru_and_rich.py produces the expected colorized cli output, but running python loguru_and_rich.py 2> out.txt produces a file that contains all of the color codes:

[32m2021-08-13 10:26:26.686[0m | [1mINFO    [0m | [36m__main__[0m:[36mmain[0m:[36m15[0m - [1mBefore[0m
[32m2021-08-13 10:26:26.690[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 0[0m
[32m2021-08-13 10:26:26.742[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 1[0m
[32m2021-08-13 10:26:26.797[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 2[0m
[32m2021-08-13 10:26:26.849[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 3[0m
[32m2021-08-13 10:26:26.905[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 4[0m
[32m2021-08-13 10:26:26.959[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 5[0m
[32m2021-08-13 10:26:27.014[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 6[0m
[32m2021-08-13 10:26:27.066[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 7[0m
[32m2021-08-13 10:26:27.123[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 8[0m
[32m2021-08-13 10:26:27.175[0m | [1mINFO    [0m | [36m__main__[0m:[36mwork[0m:[36m10[0m - [1mWorking: 9[0m
Working... ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100% 0:00:00[32m2021-08-13 10:26:27.234[0m | [1mINFO    [0m | [36m__main__[0m:[36mmain[0m:[36m19[0m - [1mAfter[0m

taranlu-houzz avatar Aug 13 '21 17:08 taranlu-houzz

Thanks for the code snippets @taranlu-houzz!

The color codes are added due to colorize=True. As you realized, this works fine when logs are printed to the console but not when the output is redirected to a file.

As a workaround, you can replace colorize=True with colorize=sys.stderr.isatty(). When colorize=None (the default), Loguru automatically checks if the sink supports colors using the isatty() method. Due to the lambda function, you have to do the same thing explicitly.

Delgan avatar Aug 14 '21 10:08 Delgan

Perfect, that does exactly what I need. Thank you!

taranlu-houzz avatar Aug 16 '21 17:08 taranlu-houzz

When using approach the log message is appended to the end of the progress bar.. Is there anyway to keep the progress bar on the last line and the log messages go above it?

stevezau avatar Apr 20 '22 03:04 stevezau

@stevezau I don't this is easily doable. You may need to implement your own sink writing to sys.stderr using ANSI escape code to put the cursor back at the beginning of the line. Besides, I don't know if that would be compatible with rich and tqdm.

Delgan avatar Apr 20 '22 06:04 Delgan

Hi this thread helped a lot. To use both rich & loguru, here's what I tried:

Setup 1: Rich & Loguru on separate sinks.

console = Console()
logger.remove()
logger.add(
    sys.stderr,
    level='TRACE',
    format='<green>{time:YYYY/MM/DD HH:mm:ss}</green> | {level.icon}'
    + '  - <level>{message}</level>',
    colorize=True,
)

Problem: Live updates are not properly cleared.

image

Setup 2: Rich & Loguru on the same sink - with Rich's color system

console = Console()
logger.remove()
logger.add(
    lambda _: console.print(_, end=''),
    level='TRACE',
    format='[not bold green]{time:YYYY/MM/DD HH:mm:ss}[/not bold green] | {level.icon}'
    + '  - [level]{message}[/level]', # NOTE: change in bracket style
    colorize=True,
)

Problem: Log messages are not dynamically colored.

image

Setup 3: Rich & Loguru on the same sink - disabling Rich's color system

console = Console(color_system=None)
logger.remove()
logger.add(
    lambda _: console.print(_, end=''),
    level='TRACE',
    format='<green>{time:YYYY/MM/DD HH:mm:ss}</green> | {level.icon}'
    + '  - <level>{message}</level>',
    colorize=True,
)

Problem: I lose the colors for non-logging statements.

image

  • Is there a way to change color dynamically for each level of log message (for Setup #2)?
  • Or use loguru colors & styles to create a new rich color scheme or theme?

yozachar avatar Jul 23 '22 17:07 yozachar

Hello,

I am trying to figure out the best way to use loguru to log while also using a rich progress bar. In order to avoid formatting issues, it would seem that I need to use the progress bar's console.print function, since that is how you avoid breaking the progress bar and causing it to redraw.

I have a couple of thoughts on how to do this, but am still a bit lost:

  • Based on rich's documentation, it seems like maybe I could create a Console object for my app, add that as a sink somehow, and then pass that to the progress bar.

  • There might also be a way to use the regular logging handler that rich provides, and have loguru propegate messages to that, but I'm not sure how/if that can be hooked up to a rich Console object.

Any advice would be much appreciated! Thanks!

I think this would work https://github.com/Textualize/rich/issues/2416#issuecomment-1193773381

yozachar avatar Jul 25 '22 09:07 yozachar