Skip to content

Asyncio exception handling breaks convention by logging callback parameter values #112997

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
CendioZeijlon opened this issue Dec 12, 2023 · 2 comments
Labels
topic-asyncio type-bug An unexpected behavior, bug, or error

Comments

@CendioZeijlon
Copy link

CendioZeijlon commented Dec 12, 2023

Bug report

Bug description:

My understanding is that Python usually does not attempt to log or show parameter and variable values when errors occur. It seems uncharacteristic that asyncio does so, e.g. when it handles uncaught exceptions.

This type of logging can also occur when asyncio reports on tasks with too slow execution times, but then only in debug mode.

When not in debug mode, parameter values are logged for uncaught exceptions, but not for slow execution times. I don't see why these two cases behave differently. If you think that this logging is necessary, perhaps it can be limited to debug mode only?

Input:

import asyncio
import functools

loop = asyncio.new_event_loop()
asyncio.set_event_loop(loop)

def test_callback(a, b, c, *, x, y, z):
    raise RuntimeError('Some uncaught error')

loop.call_soon(
    functools.partial(
        test_callback,
        {'key': 'value'},
        ['value'],
        ('value',),
        x = {'key': 'value'},
        y = ['value'],
        z = ('value',)
    )
)
loop.call_soon(loop.stop)

res = ''
try:
    loop.run_forever()
finally:
    loop.close()

Output:

Exception in callback test_callback({'key': 'value'}, ['value'], ('value',), x={'key': 'value'}, y=['value'], z=('value',))() at /home/aleze/Documents/scenario.py:7
handle: <Handle test_callback({'key': 'value'}, ['value'], ('value',), x={'key': 'value'}, y=['value'], z=('value',))() at /home/aleze/Documents/scenario.py:7>
Traceback (most recent call last):
  File "/usr/lib64/python3.11/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/home/aleze/Documents/scenario.py", line 8, in test_callback
    raise RuntimeError('Some uncaught error')
RuntimeError: Some uncaught error

Extra:

The function that actually creates the output is format_helpers._format_args_and_kwargs().

CPython versions tested on:

3.12

Operating systems tested on:

Linux

Linked PRs

@CendioZeijlon CendioZeijlon added the type-bug An unexpected behavior, bug, or error label Dec 12, 2023
@CendioOssman
Copy link
Contributor

Note that this is a potential security issue, as you would not expect the contents of your sensitive variables to leak out this easily.

@gvanrossum
Copy link
Member

I think it's reasonable to restrict this to debug mode. Could one of you submit a PR?

CendioOssman added a commit to CendioOssman/cpython that referenced this issue Feb 19, 2024
Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
gvanrossum pushed a commit that referenced this issue Feb 28, 2024
Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
@github-project-automation github-project-automation bot moved this from Todo to Done in asyncio Feb 28, 2024
gvanrossum pushed a commit to gvanrossum/cpython that referenced this issue Feb 28, 2024
…hon#115667)

Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
woodruffw pushed a commit to woodruffw-forks/cpython that referenced this issue Mar 4, 2024
…hon#115667)

Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
adorilson pushed a commit to adorilson/cpython that referenced this issue Mar 25, 2024
…hon#115667)

Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
diegorusso pushed a commit to diegorusso/cpython that referenced this issue Apr 17, 2024
…hon#115667)

Nothing else in Python generally logs the contents of variables, so this
can be very unexpected for developers and could leak sensitive
information in to terminals and log files.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
topic-asyncio type-bug An unexpected behavior, bug, or error
Projects
Status: Done
Development

No branches or pull requests

4 participants