CODEWITHSUNDEEP
pythonloggingpython-asyncioaiohttppython-logging
UpTheIrons
UpTheIrons

Reputation: 85

python asyncio logger not logging aiohttp errors

Here is a python script that includes an async class which awaits a task and starts a background loop at initialization:

import asyncio, aiohttp, logging

logging.basicConfig(level=logging.DEBUG, filename='test.log', filemode='w')


class Client:

    async def _async_init(self):
        self.session = aiohttp.ClientSession()
        self.bg_task = asyncio.create_task(self._background_task())
        await self.make_request()
        logging.debug('async client initialized.')
        return self

    async def make_request(self):
        async with self.session.get('https://google.com') as response:
            self.info = await response.text()

    async def _background_task(self):
        while True:
            await asyncio.sleep(1000)


async def main():
    client = await Client()._async_init()
    # Intentionally leaving the aiohttp client session unclosed...
    # ...to log the 'unclosed client session' error.

asyncio.run(main())

Output (not desired):

# test.log

DEBUG:asyncio:Using proactor: IocpProactor
DEBUG:root:async client initialized.

What I want is to log certain asyncio errors to the test.log file. These errors normally get printed out to the terminal if I don't use any logging. These errors are also logged on program exit since they are logged for unclosed client session and unclosed connector situations.

I figured that if I remove the background task from the class:

# These lines are removed from the class

...
# self.bg_task = asyncio.create_task(self._background_task())
...
# async def _background_loop(self):
#     while True:
#         await asyncio.sleep(1000)
...

Output (desired):

# test.log

DEBUG:asyncio:Using proactor: IocpProactor
DEBUG:root:async client initialized.
ERROR:asyncio:Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x000002043315D6D0>
ERROR:asyncio:Unclosed connector
connections: ['[(<aiohttp.client_proto.ResponseHandler object at 0x000002043312B230>, 44091.562)]', '[(<aiohttp.client_proto.ResponseHandler object at 0x000002043312B7E0>, 44092.468)]']
connector: <aiohttp.connector.TCPConnector object at 0x000002043315D710>

The question is, how can I get this output while also keeping the background task in the class?

Upvotes: 0

Views: 1532

Answers (1)

UpTheIrons
UpTheIrons

Reputation: 85

I found one solution, which is catching the asyncio.CancelledError that the event loop will automatically throw into the _background_task when the loop completes:

...
async def _background_task(self):
    try:
        while True:
            await asyncio.sleep(1000)
    except asyncio.CancelledError:
        pass  # catch the exception that the event loop throws
...

After running the script, the desired output is logged.

# test.log

DEBUG:asyncio:Using proactor: IocpProactor
DEBUG:root:async client initialized.
ERROR:asyncio:Unclosed client session
client_session: <aiohttp.client.ClientSession object at 0x000001187C9F9C90>
ERROR:asyncio:Unclosed connector
connections: ['[(<aiohttp.client_proto.ResponseHandler object at 0x000001187C9C7690>, 24429.703)]', '[(<aiohttp.client_proto.ResponseHandler object at 0x000001187C9C7C40>, 24430.015)]']
connector: <aiohttp.connector.TCPConnector object at 0x000001187C9F9CD0>

Not sure about why it works though, but this answer is useful to learn more about task creation and termination.

Upvotes: 1

Related Questions