textual icon indicating copy to clipboard operation
textual copied to clipboard

Log leak from on_unmount when run_async is used

Open mzebrak opened this issue 1 year ago • 3 comments

Observed since 0.80.0, MRE works on the latest 0.82.0

When the Textual app is started via run_async, logs inside on_unmount are occasionally (often) displayed in the terminal. Occasionally (less often) there is also :

Unmount() >>> MyApp(title='MyApp', classes={'-dark-mode'}, pseudo_classes={'dark', 'focus'}) method=<MyApp.on_unmount>

being printed out.

In real app, there is also sometimes focus was removed visible from there

Running this MRE with:

MyApp().run()

instead of:

asyncio.run(MyApp().run_async())

works fine. When you close the application, nothing remains in the terminal output.

MRE:

from __future__ import annotations

import asyncio

from textual.app import App, ComposeResult
from textual.binding import Binding
from textual.widgets import Footer, Label


class MyApp(App):
    BINDINGS = [
        Binding("q", "quit", "Quit"),
    ]

    def on_load(self) -> None:
        self.log("Loaded")

    def on_mount(self) -> None:
        self.log("Mounted")

    def on_unmount(self) -> None:
        self.log("Unmounted")

    def compose(self) -> ComposeResult:
        yield Label("Press 'q' to quit.")
        yield Footer()


asyncio.run(MyApp().run_async())

terminal output:

image

This has some consequences when the app is performing startup/shutdown actions. It works OK on the startup because logs happening in on_load/on_mount are not printed to the terminal and are not visible when the app is closed. But those of the shutdown actions placed in on_unmount are.

mzebrak avatar Oct 04 '24 10:10 mzebrak

Thank you for your issue. Give us a little time to review it.

PS. You might want to check the FAQ if you haven't done so already.

This is an automated reply, generated by FAQtory

github-actions[bot] avatar Oct 04 '24 10:10 github-actions[bot]

asyncio.run(MyApp().run_async())

Why are you running apps like this?

willmcgugan avatar Oct 04 '24 16:10 willmcgugan

This is an MRE. A real scenario is that the asyncio.run call is the entry to our main which launches either TUI or CLI. So we use run_async to run App from a loop started by us. TUI is is not our only interface and we need our own loop.

Of course, using run instead of run_async results in

  File "/home/mzebrak/.pyenv/versions/3.10.12/envs/clive/lib/python3.10/site-packages/textual/app.py", line 1943, in run
    asyncio.run(run_app())
  File "/home/mzebrak/.pyenv/versions/3.10.12/lib/python3.10/asyncio/runners.py", line 33, in run
    raise RuntimeError(
RuntimeError: asyncio.run() cannot be called from a running event loop

Is the run_async incorrect usage? That's a public interface.


Edit

Additionally, previously we used run_async so we could do some async stuff before startup, but since 0.80.0, there has been an issue that Textual started to print things to the terminal (in the same way as in this issue) . So the solution was to do that async stuff not before run_async, but in on_load, because when there is no active_app set, the textual logger uses raw print. So doing some preparation in on_load fixed that, but now there is an issue with cleanup actions.

Another thing blocking us before switching from run_async to run is that part of the code:

    def _register_quit_signals(self) -> None:
        import signal

        def callback() -> None:
            self.exit()

        loop = asyncio.get_running_loop()  # can't use self._loop since it's not set yet
        for signal_number in [signal.SIGHUP, signal.SIGINT, signal.SIGQUIT, signal.SIGTERM]:
            loop.add_signal_handler(signal_number, callback)

that gets called in app initializer. And it needs to be called as early as possible but requires the loop.


Edit2

Looks like we can workaround this issue by using run instead of run_async. This would also require calling _register_quit_signals in on_load instead of in the initializer but it also seems like an okay place. It's doable because we can wrap only the CLI launch in our asyncio loop and let the TUI app create its own.

However, I've seen on the discord that run_async is the recommended way to use your own loop since run stopped taking the loop parameter. What I don't like about this workaround is that we are now forced to use 2 different loops. And when we would like to do some async preparation for both interfaces, we may have a problem.

mzebrak avatar Oct 09 '24 06:10 mzebrak

I'm having the same problem where I need to run the app with run_async() because I want to run some code which interacts with my TUI:


async def launch_with_async_gui():
    tui = TrainingUI(run_name, project_conf.LOG_SCALE_PLOT)
    task = asyncio.create_task(tui.run_async())
    await asyncio.sleep(0.5)  # Wait for the app to start up
    while not tui.is_running:
        await asyncio.sleep(0.01)  # Wait for the app to start up
    model_ckpt_path = load_model_ckpt(run.load_from, run.training_mode)
    common_args = dict(
        run_name=run_name,
        model=model_inst,
        model_ckpt_path=model_ckpt_path,
        training_loss=training_loss_inst,
        tui=tui,
    )
    if run.training_mode:
        print("Training started!")
        if training_loss_inst is None:
            raise ValueError("training_loss must be defined in training mode!")
        if val_loader_inst is None or train_loader_inst is None:
            raise ValueError(
                "val_loader and train_loader must be defined in training mode!"
            )
        await trainer(
            train_loader=train_loader_inst,
            val_loader=val_loader_inst,
            opt=opt_inst,
            scheduler=scheduler_inst,
            **common_args,
            **asdict(run),
        ).train(
            epochs=run.epochs,
            val_every=run.val_every,
            visualize_every=run.viz_every,
            visualize_train_every=run.viz_train_every,
            visualize_n_samples=run.viz_num_samples,
        )
        print("Training finished!")
    else:
        print("Testing started!")
        if test_loader_inst is None:
            raise ValueError("test_loader must be defined in testing mode!")
        await tester(
            data_loader=test_loader_inst,
            **common_args,
        ).test(
            visualize_every=run.viz_every,
            **asdict(run),
        )
        print("Testing finished!")
    _ = await task

asyncio.run(launch_with_async_gui())

This is a real problem because I use a RichLog widget with begin_capture_print() which gets polluted by loads of on_mount or all sorts of weird events when I mount CheckBox widgets to a ScrollableContainer widget. @willmcgugan is this not the right approach for my case?

Thanks!

DubiousCactus avatar Nov 03 '24 15:11 DubiousCactus

Running into this issue too.

Why are you running apps like this?

Just to share my use case:

def run_dev_mode(
    yaml_file: str | Path,
    chapter_index: int | None = None,
    step_index: int = 0,
) -> None:
    """Parses a YAML config, runs the tutorial, and watches for changes."""
    chapters, title_slide = parse_yaml_config(yaml_file)
    app = TuitorialApp(chapters, title_slide, chapter_index, step_index)

    async def run_app_and_watch() -> None:
        """Run the app and the file watcher concurrently."""
        app_task = asyncio.create_task(app.run_async())
        watch_task = asyncio.create_task(watch_for_changes(app, yaml_file))
        await asyncio.gather(app_task, watch_task)

    try:
        asyncio.run(run_app_and_watch())
    except KeyboardInterrupt:
        print("Exiting development mode.")

I want to schedule another task alongside app.run_async.

Is there another recommended way to do this?

basnijholt avatar Jan 03 '25 22:01 basnijholt

My application also falls victim to this issue. It is usually when the user quits the application just after starting it. We have to make some async requests before starting the TUI so we use run_async.

maciek-es avatar Apr 07 '25 07:04 maciek-es

I've hit this error as well; the workaround I've found essentially amounts to replicating the body of App.run():

import asyncio
import threading

app = MyApp()  # the textual app
loop = asyncio.new_event_loop()
asyncio.set_event_loop(loop)

with app._context():
    try:
        app._loop = loop
        app._thread_id = threading.get_ident()

        loop.run_until_complete(app.run_async())
    finally:
        app._loop = None
        app._thread_id = 0

In Python 3.9, this isn't needed - if you create the event loop with new_event_loop(), the subsequent logic in App.run() that calls get_event_loop() returns the loop created by the user. However, the logic that adapts for Python 3.10 uses asyncio.run(), which doesn't given any control over the loop factory that is used to create the event loop.

The best long-term fix I can see would be a change to the API for App.run() to allow explicitly providing the event loop instance to use for running the app (or, at the very least, a loop_factory instance, which is the API exposed by asyncio.run())


To answer the meta-question of why this is needed - In my case, I'm the maintainer of Toga, a GUI toolkit that can target Textual as one of it's backends (in addition to macOS, Windows, GTK, Android, iOS and single page web apps). To satisfy other requirements of the Toga API, I need to be able to expose the event loop that will be used to run the app before starting the app.

However, more generally - any situation where "the default asyncio event loop" isn't an option will be affected in the same way.

freakboy3742 avatar Apr 17 '25 06:04 freakboy3742

Don't forget to star the repository!

Follow @textualizeio for Textual updates.

github-actions[bot] avatar May 01 '25 15:05 github-actions[bot]