Logging in Dash - LogTransform

[Emil]

While creating apps, I am often faced with the desire to route some kind of logs and/or notifications to the UI. It could be e.g info messages, warnings or errors that I would like to route to a particular UI element. It can be a bit tedious to do in Dash, so I decided to add a create a LogTransform to easy the pain. Now, if you pass log=True to a callback, a DashLogger object will be injected into the callback,

@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, logger: DashLogger):  # logger injected as an extra callback argument
    logger.info("Here goes some info")
    logger.warning("This is a warning")
    logger.error("Some error occurred")
    ...

The DashLogger has a syntax similar to the standard logging module, but directs logs to a UI element of your choice (configurable via the LogConfig parameter of the LogTransform). Per default, the dash-mantine-components notification system is used if the library is available. Here is a complete example,

import dash_mantine_components as dmc
from dash_extensions.enrich import Output, Input, html, DashProxy, LogTransform, DashLogger

app = DashProxy(transforms=[LogTransform()], prevent_initial_callbacks=True)
app.layout = html.Div([dmc.Button("Run", id="btn"), dmc.Text(id="txt")])

@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, logger: DashLogger):
    logger.info("Here goes some info")
    logger.info("Here goes some more info")
    logger.warning("This is a warning")
    logger.info("Even more info")
    logger.error("Some error occurred")
    return f"Run number {n_clicks} completed"

if __name__ == '__main__':
    app.run_server()

Running the example, this is what you get, when the button is clicked,

I haven’t done extensive testing, but I have used the system in a few apps, and it seems to work as intended

NB: The LogTransform is available in dash-extensions==0.0.71, and the notifications system integration has been tested with dash-mantine-components==0.4.1.

[adamschroeder]

Very helpful Emil, thank you. I’ve heard members in the community wanting this type of feature. I’m sure this will be used a lot.

[SamuelVT]

Hi Emil

Very good contribution thanks.

[snehilvj]

Thanks @Emil, this is going to be super helpful for a lot my apps.

[benn0]

This looks great @Emil, and is something that I had been thinking about trying to implement, so comes at a perfect time! One question - for my app, I’d like to differentiate between logging that is exposed to the user, and internal logging. It’s not simply a matter of setting the log level, it’s that I would probably put different levels of info in internal and external log messages. Is this something you have thought about?

[Emil]

The LogTransform provides an additional logger object that writes to Dash component(s). Hence you can still use other logging mechanisms as you would normally do also, e.g. to console. As an example, I typically use code along these lines for catching an exception,

import logging 

logger = logging.getLogger(name)

...

@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, dash_logger: DashLogger):
    try:
        ...
    except Exception as ex:
        dash_logger.error(str(ex), title=title)  # goes to the Dash UI
        logger.error(traceback.format_exc())  # normal logging, e.g. to console

Hence a short message will be shown on the UI for the user to give an indication of the error, while the complete strack trace is routed via the standard Python logging system to enable debugging by developers.

[benn0]

Oh right, thanks for the clarification! And apologies for not reading the documentation properly before posting my uninformed question!

[nixie]

Hi,
very nice, thanks for sharing!
I tried to combine the logging notification with “raise PreventUpdate” and it seems that PreventUpdate somehow kills the logged message. Is there some architectural obstackle for making it work together?

My use case is that I want to use logging to notify user about unsaved changes. In a close-button callback I am checking if the input was saved. If not, I use logger to notify user and prevent closing. But when I use PreventUpdate it also blocks the notification for some reason.

Edit: modified example for demonstration

...
@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, logger: DashLogger):
    logger.info("Here goes some info")
    logger.info("Here goes some more info")
    logger.warning("This is a warning")
    logger.info("Even more info")
    logger.error("Some error occurred")
    raise PreventUpdate
    return f"Run number {n_clicks} completed"

EDIT2: Solved. Instead of raise PreventUpdate, I need to use return dash.no_update as logger.info() call most probably adds some hidden outputs related to what was logged inside the callback. Makes sense now…

[Emil]

Yes, that is exactly the case. I guess it could be discussed what behavior makes most sense. I tend to think the current behavior is how it should be, i.e prevent update aborts all updates including log messages. But it could be changed.

[Isisgv]

First of all thank you for this contribution! It’s proving to be very useful in my project :))
I’ve been trying to get more familiar with the code of this extension but i still don’t know how I could set the Logger to dismiss automatically after a few seconds. Any help would be very appreciated

[Emil]

Thanks! You can pass keyword arguments to the log event directly. If you are using dmc, the syntax would be,

dash_logger.info("Here goes some info", autoClose=1000)

to make the notification go away after 1 second. You can see all available options in the docs,

Dash Mantine Components - Notification

[Isisgv]

Thank you so much :))

[ShamkhalHajiyev]

@Emil

DashLogger

Hi Emil, Thanks for your example. Can you give me example how can I save all log information in log file?

Thanks in advance.

[Emil]

The LogTransform is intended to output data to a Dash component. If you need to write to a file, I would recommend using the standard Python logging module instead with a FileHandler.

[tonydeck]

Hi, @Emil ,
When I tried to run the sample program, I got the following errors.
“do_stuff() got an unexpected keyword argument ‘dash_logger’” It appears that dash_logger does not be accepted as one type of logger.
any clew for the problem. I run the stuff in a docker environment and python 3.7.6
your help is highly appreciated.
thanks in advance.
Tony

[tonydeck]

the whole message from callback issue is .
Traceback (most recent call last):
File “/usr/local/lib/python3.7/site-packages/dash_extensions/enrich.py”, line 669, in decorated_function
outputs = f(*args, **kwargs, dash_logger=logger)
TypeError: do_stuff() got an unexpected keyword argument ‘dash_logger’
@Emil

[tonydeck]

Hi, @Emil ,
the following message is the more detailed information from the tracker.

File “/usr/local/lib/python3.7/site-packages/dash_extensions/enrich.py”, line 669, in decorated_function
def bind_logger(logger, single_output, out_flex_key):
def wrapper(f):
@functools.wraps(f)
def decorated_function(*args, **kwargs):
logger.clear()
outputs = f(*args, **kwargs, dash_logger=logger)
return _append_output(outputs, logger.get_output(), single_output, out_flex_key)

    return decorated_function

return wrapper

TypeError: do_stuff() got an unexpected keyword argument ‘dash_logger’

Thanks.
Tony

[Emil]

@Tony The argument was renamed to dash_logger to avoid confusion with standard Python logging objects. Hence, the code should be adapted to something like,

@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, dash_logger: DashLogger):
    dash_logger.info("Here goes some info")
    dash_logger.info("Here goes some more info")
    dash_logger.warning("This is a warning")
    dash_logger.info("Even more info")
    dash_logger.error("Some error occurred")
    raise PreventUpdate
    return f"Run number {n_clicks} completed"

[tonydeck]

Hi, @Emil ,
It works. thanks a lot! It really makes my dashboard real-time notification work much easier.
many thanks.
Tony

[yann_laurant]

Hi !
I just discovered this functionnality and it is very powerfull (and beatifull with mantine…), thanks a lot
I want now to provide a status of a long process to the user, something like :

dash_logger.info("Doing something long", loading=True)
time.sleep(5) #doing something long
dash_logger.info("Done", color=green)

As all notification seems do be launched at the end of the callback, I tried to chain 2 callbacks through a ghost div component:

app = DashProxy(transforms=[LogTransform()])
app.layout = html.Div([html.Button("Run", id="btn"), html.Button("Long", id="long"), html.Div(id="txt"), html.Div(id="ghost"), html.Div(id="txt2")])

@app.callback(Output("txt", "children"), Input("btn", "n_clicks"), log=True)
def do_stuff(n_clicks, dash_logger: DashLogger):
    if not n_clicks:
        raise PreventUpdate()
    dash_logger.info("Here goes some info")
    dash_logger.warning("This is a warning")
    dash_logger.error("Some error occurred")
    return f"Run number {n_clicks} completed"

@app.callback(Output("ghost", "children"), Input("long", "n_clicks"), log=True)
def do_stuff(n_clicks, dash_logger: DashLogger):
    if not n_clicks:
        raise PreventUpdate()
    dash_logger.info("work in progress")

    return "doing something long"

@app.callback(Output("txt2", "children"), Input("ghost", "children"), log=True)
def do_stuff(d, dash_logger: DashLogger):
    if not ctx.triggered:
        return no_update

    print("do something long")
    time.sleep(2)
    dash_logger.info("done", color="green")

    return f"Long run completed"

but the first notification wait for the second callback to be shown, and the last modification is never applied. Any idea on the best way to do it ?

Thanks for your support !