handle: When warning about an unclosed recource, print its source tb

Author: 1st1

tests/test_tcp.py

@@ -1,5 +1,5 @@
 import asyncio
-import logging
+import gc
 import socket
 import unittest.mock
 import uvloop
@@ -584,6 +584,42 @@ async def run():
 
         self.loop.run_until_complete(run())
 
+    def test_tcp_handle_unclosed_gc(self):
+        fut = self.loop.create_future()
+
+        async def server(reader, writer):
+            writer.transport.abort()
+            fut.set_result(True)
+
+        async def run():
+            addr = srv.sockets[0].getsockname()
+            await asyncio.open_connection(*addr, loop=self.loop)
+            await fut
+            srv.close()
+            await srv.wait_closed()
+
+        srv = self.loop.run_until_complete(asyncio.start_server(
+            server,
+            '127.0.0.1', 0,
+            family=socket.AF_INET,
+            loop=self.loop))
+
+        if self.loop.get_debug():
+            rx = r'unclosed resource <TCP.*; ' \
+                 r'object created at(.|\n)*test_tcp_handle_unclosed_gc'
+        else:
+            rx = r'unclosed resource <TCP.*'
+
+        with self.assertWarnsRegex(ResourceWarning, rx):
+            self.loop.create_task(run())
+            self.loop.run_until_complete(srv.wait_closed())
+            gc.collect()
+            self.loop.run_until_complete(asyncio.sleep(0.1))
+
+        # Since one TCPTransport handle wasn't closed correctly,
+        # we need to disable this check:
+        self.skip_unclosed_handles_check()
+
 
 class Test_AIO_TCP(_TestTCP, tb.AIOTestCase):
     pass

uvloop/_testbase.py

@@ -69,10 +69,14 @@ def is_asyncio_loop(self):
     def setUp(self):
         self.loop = self.new_loop()
         asyncio.set_event_loop(self.loop)
+        self._check_unclosed_resources_in_debug = True
 
     def tearDown(self):
         self.loop.close()
 
+        if not self._check_unclosed_resources_in_debug:
+            return
+
         # GC to show any resource warnings as the test completes
         gc.collect()
         gc.collect()
@@ -83,24 +87,37 @@ def tearDown(self):
             gc.collect()
             gc.collect()
 
-            self.assertEqual(self.loop._debug_cb_handles_count, 0)
-            self.assertEqual(self.loop._debug_cb_timer_handles_count, 0)
-            self.assertEqual(self.loop._debug_stream_write_ctx_cnt, 0)
+            self.assertEqual(
+                self.loop._debug_cb_handles_count, 0,
+                'not all callbacks (call_soon) are GCed')
+
+            self.assertEqual(
+                self.loop._debug_cb_timer_handles_count, 0,
+                'not all timer callbacks (call_later) are GCed')
+
+            self.assertEqual(
+                self.loop._debug_stream_write_ctx_cnt, 0,
+                'not all stream write contexts are GCed')
 
             for h_name, h_cnt in self.loop._debug_handles_current.items():
                 with self.subTest('Alive handle after test',
                                   handle_name=h_name):
-                    self.assertEqual(h_cnt, 0)
+                    self.assertEqual(
+                        h_cnt, 0,
+                        'alive {} after test'.format(h_name))
 
             for h_name, h_cnt in self.loop._debug_handles_total.items():
                 with self.subTest('Total/closed handles',
                                   handle_name=h_name):
                     self.assertEqual(
-                        h_cnt, self.loop._debug_handles_closed[h_name])
+                        h_cnt, self.loop._debug_handles_closed[h_name],
+                        'total != closed for {}'.format(h_name))
 
         asyncio.set_event_loop(None)
         self.loop = None
 
+    def skip_unclosed_handles_check(self):
+        self._check_unclosed_resources_in_debug = False
 
 def _cert_fullname(name):
     fullname = os.path.join(

uvloop/handles/handle.pxd

@@ -4,6 +4,7 @@ cdef class UVHandle:
         bint _closed
         bint _inited
         Loop _loop
+        readonly _source_traceback
 
     # All "inline" methods are final
 
@@ -17,6 +18,8 @@ cdef class UVHandle:
     cdef _error(self, exc, throw)
     cdef _fatal_error(self, exc, throw, reason=?)
 
+    cdef _warn_unclosed(self)
+
     cdef inline _free(self)
     cdef _close(self)
 

uvloop/handles/handle.pyx

@@ -17,6 +17,7 @@ cdef class UVHandle:
         self._inited = 0
         self._handle = NULL
         self._loop = None
+        self._source_traceback = None
 
     def __init__(self):
         raise TypeError(
@@ -60,8 +61,7 @@ cdef class UVHandle:
             self._handle.data = NULL
             uv.uv_close(self._handle, __uv_close_handle_cb) # void; no errors
             self._handle = NULL
-            warnings_warn("unclosed resource {!r}".format(self),
-                ResourceWarning)
+            self._warn_unclosed()
         else:
             # The handle was allocated, but not initialized
             self._closed = 1
@@ -71,6 +71,16 @@ cdef class UVHandle:
         PyMem_Free(self._handle)
         self._handle = NULL
 
+    cdef _warn_unclosed(self):
+        if self._source_traceback is not None:
+            tb = ''.join(tb_format_list(self._source_traceback))
+            tb = 'object created at (most recent call last):\n{}'.format(
+                tb.rstrip())
+            msg = 'unclosed resource {!r}; {}'.format(self, tb)
+        else:
+            msg = 'unclosed resource {!r}'.format(self)
+        warnings_warn(msg, ResourceWarning)
+
     cdef inline _abort_init(self):
         if self._handle is not NULL:
             self._free()
@@ -89,6 +99,8 @@ cdef class UVHandle:
     cdef inline _finish_init(self):
         self._inited = 1
         self._handle.data = <void*>self
+        if self._loop._debug:
+            self._source_traceback = tb_extract_stack(sys_getframe(0))
 
     cdef inline _start_init(self, Loop loop):
         IF DEBUG:
@@ -322,5 +334,5 @@ cdef void __uv_walk_close_all_handles_cb(uv.uv_handle_t* handle, void* arg) with
 
     h = <UVHandle>handle.data
     if not h._closed:
-        warnings_warn("unclosed resource {!r}".format(h), ResourceWarning)
+        h._warn_unclosed()
         h._close()