Log leak from on_unmount when run_async is used

[mzebrak]

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:

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.

[github-actions]

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

[willmcgugan]

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

Why are you running apps like this?

[mzebrak]

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.