ResourceWarnings with PYTHONDEVMOVE=1

[pikeas]

https://github.com/python-trio/trio/blob/master/docs/source/tutorial.rst#when-things-go-wrong-timeouts-cancellation-and-exceptions-in-concurrent-tasks

TODO: maybe a brief discussion of :exc:KeyboardInterrupt handling?

What's the Right Way to catch KeyboardInterrupt? Here's trio's channel example:

from random import randint
import trio

async def main():
    async with trio.open_nursery() as nursery:
        send_channel, receive_channel = trio.open_memory_channel(0)
        async with send_channel, receive_channel:
            nursery.start_soon(producer, "producer", send_channel.clone())
            nursery.start_soon(consumer, "consumer", receive_channel.clone())

async def producer(name, send_channel):
    async with send_channel:
        for i in range(30):
            await trio.sleep(randint(1, 2))
            await send_channel.send(f"{i} from {name}")

async def consumer(name, receive_channel):
    async with receive_channel:
        async for value in receive_channel:
            print(f"consumer {name} got {value=}")
            await trio.sleep(randint(3, 4))

trio.run(main)

Here's what happens when a ctrl-c occurs:

consumer consumer got value='0 from producer'
consumer consumer got value='1 from producer'
consumer consumer got value='2 from producer'
^CTraceback (most recent call last):
  File "foo.py", line 28, in <module>
    trio.run(main)
  File "[...]/lib/python3.8/site-packages/trio/_core/_run.py", line 1896, in run
    raise runner.main_task_outcome.error
  File "foo.py", line 11, in main
    nursery.start_soon(consumer, "consumer", receive_channel.clone())
  File "[...]/lib/python3.8/site-packages/trio/_core/_run.py", line 741, in __aexit__
    raise combined_error_from_nursery
  File "[...]lib/python3.8/site-packages/trio/_core/_run.py", line 1107, in raise_cancel
    raise KeyboardInterrupt
KeyboardInterrupt
sys:1: ResourceWarning: unclosed <socket.socket fd=4, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0>
sys:1: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0>

I've tried various try/except changes, none of which seem to properly close the socket.

Also, why does not cloning (.clone()) both channels cause an immediate raise trio.ClosedResourceError?

[njsmith]

So the issue here isn't KeyboardInterrupt per se... that code is closing the channels. The ResourceWarning is about something else. And unfortunately I don't see the ResourceWarning when I try running it here.

Could you try setting the environment variable PYTHONTRACEMALLOC=10 and then running again? That should add a lot more details to the ResourceWarning messages.

Also, why does not cloning (.clone()) both channels cause an immediate raise trio.ClosedResourceError?

The main function does async with send_channel, receive_channel:. So as soon as you've kicked off the two child tasks, it closes its copy of the channels. If you give the child tasks the same copy of the channels, then that means their copy gets closed too. If you give them a clone, then the cloned channel objects survive when the original channel objects are closed.

[pikeas]

A-ha! I made a clean poetry-based virtualenv with only trio (and its dependencies) and Python 3.8.3.

Test 1) poetry run python trio_test/foo.py raises KeyboardInterrupt and works as expected. Thanks for your hard work to make KeyboardInterrupt magically Just Work!

Test 2): PYTHONTRACEMALLOC=10 poetry run python trio_test/foo.py has identical output (sanity check: PYTHONTRACEMALLOC is present in os.environ).

Test 3): PYTHONDEVMODE=1 poetry run python trio_test/foo.py displays ResourceWarning.

So, either PYTHONDEVMODE is right, and something isn't being closed behind the scenes, or enabling PYTHONDEVMODE somehow causes different - and broken - behavior?

So as soon as you've kicked off the two child tasks, it closes its copy of the channels

Color me surprised that async with send_channel, receive_channel closes the channels "as soon as" the child tasks are kicked off! I was expecting them to be closed when the context manager closes (__aexit__()).

[njsmith]

So, either PYTHONDEVMODE is right, and something isn't being closed behind the scenes, or enabling PYTHONDEVMODE somehow causes different - and broken - behavior?

So ResourceWarnings are not a big deal. These warnings are letting you know that something, somewhere in your program called socket.socketpair(), and then didn't explicitly close the socket handles when it was done. The socket handles still got closed – the Python garbage collector took care of that. There are some exotic cases where leaving this to the garbage collector can cause problems, and it's considered a bit cleaner to close them explicitly. But usually, letting socket handles be collected like this doesn't cause any practical problems.

Because ResourceWarnings are so minor, they're hidden by default. One of the things PYTHONDEVMODE=1 does is un-hide them. So that's probably why you're seeing them in dev mode.

There probably is some minor bug in some piece of code you're using that's causing those sockets to be left unclosed, but it's hard to know what. Could be Trio, could be in poetry, I dunno.

Try:

PYTHONDEVMODE=1 PYTHONTRACEMALLOC=10 poetry run python trio_test/foo.py

I was expecting them to be closed when the context manager closes (__aexit__()).

Yes, that's when they close. Notice that the only thing inside the context manager's async with block is the two calls to start_soon, which are what kick off the child tasks :-). So main schedules the two child tasks to start soon, and then immediately runs the channel objects' __aexit__ methods.

[pikeas]

Poetry shouldn't be relevant, it's basically a newer, better virtualenvwrapper. However, I can remove it from the equation and activate the virtualenv directly:

$ source .venv/bin/activate.fish
$ PYTHONDEVMODE=1 PYTHONTRACEMALLOC=10 python trio_test/foo.py
consumer consumer got value='0 from producer'
produced: 0
consumer consumer got value='1 from producer'
produced: 1
^CTraceback (most recent call last):
  File "trio_test/foo.py", line 34, in <module>
    trio.run(main)
  File "<...>/trio-test/.venv/lib/python3.8/site-packages/trio/_core/_run.py", line 1896, in run
    raise runner.main_task_outcome.error
  File "trio_test/foo.py", line 16, in main
    nursery.start_soon(consumer, "consumer", receive_channel.clone())
  File "<...>/trio-test/.venv/lib/python3.8/site-packages/trio/_core/_run.py", line 741, in __aexit__
    raise combined_error_from_nursery
  File "<...?trio-test/.venv/lib/python3.8/site-packages/trio/_core/_run.py", line 1107, in raise_cancel
    raise KeyboardInterrupt
KeyboardInterrupt
sys:1: ResourceWarning: unclosed <socket.socket fd=4, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0>
sys:1: ResourceWarning: unclosed <socket.socket fd=5, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0>

The output appears to be identical with or without tracemalloc enabled. The only library (directly) invoked is trio - does trio itself open (and fail to close when handling KI) a socketpair somewhere deep in its bowels?

[njsmith]

Huh, that's frustrating.

The output appears to be identical with or without tracemalloc enabled. The only library (directly) invoked is trio - does trio itself open (and fail to close when handling KI) a socketpair somewhere deep in its bowels?

Trio does use some socketpairs. I think it closes them properly... it seems to here, anyway. But I could be wrong! That's what we're trying to figure out :-).

What version of Python are you using? What version of Trio? What OS are you using?

[pikeas]

What version of Python are you using? What version of Trio? What OS are you using?

Python: 3.8.3
trio: 0.16.0
OS: macOS 10.15.3

Here's a clue: I've tried reproducing in a Docker image (python:3.8.3-slim-buster) and failed to do so!

As an additional test on my Mac:

$ python -V
Python 3.8.3
$ python -m venv trio-test2
$ source trio-test2/bin/activate.fish
$ pip install trio
<add file>
$ PYTHONDEVMODE=1 PYTHONTRACEMALLOC=10 python foo.py
<ResourceWarnings happen>
$ pip list --format=freeze
async-generator==1.10
attrs==19.3.0
idna==2.9
outcome==1.0.1
pip==20.1.1
setuptools==41.2.0
sniffio==1.1.0
sortedcontainers==2.2.2
trio==0.16.0

[pquentin]

I'm seeing the same ResourceWarnings on macOS 10.15 + Python 3.8

[njsmith]

Ah-ha. If it's macOS specific, that makes it easy to track down :-). Fixed in #1623. Thanks for the report!

I am still super confused about why tracemalloc doesn't seem to work on your system. On my system, when I get a ResourceWarning, Python even prints a message suggesting that I turn tracemalloc on...