aiorun icon indicating copy to clipboard operation
aiorun copied to clipboard

SIGTERM, SIGINT seemingly ignored sometimes

Open Pirulax opened this issue 2 years ago • 6 comments

Hey, so I have this issue where, for some reason when I stop the process with ctrl + c (when debugging in vs:code) or (sometimes) restart the service with systemctl the shutdown function isnt triggered at all. When I stop the service with systemctl stop or using the UI button (break button) (when in vs:code) it works. Logs dont show any errors, or anything. Any idea?

Pirulax avatar Jun 29 '22 18:06 Pirulax

No idea, sorry. Is this a custom shutdown function, or the automatic one that aiorun provides?

cjrh avatar Jul 09 '22 04:07 cjrh

@Pirulax since there is no reproducer currently, are you ok to close this issue? If you later discover a reproducer we can always reopen.

cjrh avatar Jul 19 '22 11:07 cjrh

Hello, sorry for not replying, totally forgot! Um, I'm not sure how to exactly reproduce the issue. Right now it seemingly works. I think the issue is that I had an exception thrown in a function called from custom shutdown callback. This exception was uncaught, but it never was printed to the logs, but it caused the whole thing to shutdown abnormally.

Pirulax avatar Jul 19 '22 11:07 Pirulax

Ah ok. Let's keep this open then, I'll try to add an exception handler for that specific scenario.

cjrh avatar Jul 19 '22 11:07 cjrh

I took a look at the code this morning. It seems to me that exceptions from the shutdown_callback should still be getting handled. This is the section in aiorun.py where the shutdown_callback is managed (line 277 in current main):

    logger.info("Entering shutdown phase.")
    if shutdown_callback is not None:
        logger.info("Executing provided shutdown_callback.")
        try:
            if inspect.iscoroutine(shutdown_callback):
                loop.run_until_complete(shutdown_callback)
            elif inspect.iscoroutinefunction(shutdown_callback):
                loop.run_until_complete(shutdown_callback(loop))
            elif callable(shutdown_callback):
                shutdown_callback(loop)
            else:
                raise TypeError(
                    "The provided shutdown_callback must be either a function,"
                    "an awaitable, or a coroutine object, but it was "
                    + str(type(shutdown_callback))
                )
        except BaseException as exc:
            if pending_exception_to_raise:
                logger.exception(
                    "The shutdown_callback() raised an error, but there is "
                    "already a different exception raised from the loop, so "
                    "this log message is all you're going to see about it."
                )
            else:
                pending_exception_to_raise = exc

So what's happening here is that if shutdown_callback raises an exception, that will be assigned to identifier pending_exception_to_raise, unless there is already an exception raised from running the loop earlier. In this case, the original loop exception will be propagated through pending_exception_to_raise, and the exception raised from shutdown_callback will be dropped; although, it definitely should get printed to the logs in this case, see the logger.exception message above.

So at face value, I don't think an exception from a shutdown callback function should cause the behaviour you describe. I will try to make a reproducer of this exact scenario.

For completeness sake, pending_exception_to_raise, if not null, is later raised right at the very end:

    if pending_exception_to_raise:
        logger.info("Reraising unhandled exception")
        raise pending_exception_to_raise

So the basic summary is that if shutdown_callback is provided, an exception coming from it is dropped only if there is already an exception coming from the earlier loop run, and even then there should be a log message.

I'll try to make a small reproducer to see if I can get it to produce the behaviour you describe. If you happen to have a traceback for the scenario you describe, that would help a lot.

cjrh avatar Aug 06 '22 01:08 cjrh

I put together this short file:

import asyncio
import aiorun

async def shutdown_callback(loop):
    print('in shutdown callback')
    raise Exception('Something went wrong in shutdown_callback')

async def main():
    await asyncio.sleep(0.5)
    raise Exception('Something went wrong in main')

if __name__ == '__main__':
    aiorun.run(
        main(),
        shutdown_callback=shutdown_callback,
        # stop_on_unhandled_errors=True,
    )

I tried various ways of configuring an exception happening in the shutdown callback, but I still can't get the behaviour you've described. If you have time, could you try using the above file to set it up so that the shutdown callback doesn't trigger? If we can't get a reproducer I think we'll have to close the issue.

cjrh avatar Aug 06 '22 02:08 cjrh

I couldn't reproduce so I'll close the issue for now. If someone finds a reproducer we can reopen and investigate further.

cjrh avatar Sep 01 '22 11:09 cjrh

Hey! You can keep it closed. I haven't encountered the issue recently. I'm still unsure what the issue was. It was quite random, as sometimes it worked (tbh, it might not've been an issue with the lib at all, since it seemed like the program straight out crashed, I just assumed it might be the lib, because there was no log output, but othertime there was). Anyways, I did try running the code you posted, and it worked as expected, so I don't know what the issue was.

I'm also using Nutika, who knows, maybe a weird combo of things caused it.

Thank you for the work you put in, appreciate it!

Pirulax avatar Sep 01 '22 11:09 Pirulax