René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"Bad interaction between asyncio task cancellation and trace functions (only 3.11)","articleBody":"Something about cancelling tasks is interfering with tracing, but only in 3.11. Versions 3.10 and 3.12 are unaffected.  I'm sorry I don't understand enough to be more specific.\r\n\r\nHere is traced.py:\r\n\r\n```py\r\nimport linecache, sys\r\nimport asyncio\r\nfrom datetime import timedelta\r\nimport sys\r\n\r\ndef trace(frame, event, arg):\r\n    # The weird globals here is to avoid a NameError on shutdown...\r\n    if frame.f_code.co_filename == globals().get(\"__file__\"):\r\n        lineno = frame.f_lineno\r\n        line = linecache.getline(__file__, lineno).rstrip()\r\n        print(\"{} {}: {}\".format(event[:4], lineno, line))\r\n    return trace\r\n\r\nprint(sys.version)\r\nsys.settrace(trace)\r\n\r\ndef main():\r\n    async def cancel_task(task: asyncio.Task) -\u003e None:\r\n        task.cancel()\r\n\r\n        try:\r\n            await task\r\n        except asyncio.CancelledError:\r\n            pass\r\n\r\n    class TTLDict:\r\n        def __init__(self) -\u003e None:\r\n            self._data = {}\r\n            self._expiration_tasks = {}\r\n\r\n        def __setitem__(self, key, value) -\u003e None:\r\n            async def _waiter() -\u003e None:\r\n                await asyncio.sleep(1)\r\n\r\n            self._data[key] = value\r\n            self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\n\r\n        async def delete(self, key):\r\n            await cancel_task(self._expiration_tasks.pop(key))\r\n            return self._data.pop(key)\r\n\r\n    async def _main():\r\n        ttl_dict = TTLDict()\r\n        ttl_dict['foo'] = 42\r\n        await ttl_dict.delete('foo')\r\n        print('FINISH')\r\n\r\n    asyncio.run(_main())\r\n\r\n\r\nmain()\r\n```\r\n\r\nWhen run under Python 3.10.9:\r\n```\r\n3.10.9 (main, Dec  7 2022, 07:15:24) [Clang 12.0.0 (clang-1200.0.32.29)]\r\ncall 17: def main():\r\nline 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 26:     class TTLDict:\r\ncall 26:     class TTLDict:\r\nline 26:     class TTLDict:\r\nline 27:         def __init__(self) -\u003e None:\r\nline 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 38:         async def delete(self, key):\r\nretu 38:         async def delete(self, key):\r\nline 42:     async def _main():\r\nline 48:     asyncio.run(_main())\r\ncall 42:     async def _main():\r\nline 43:         ttl_dict = TTLDict()\r\ncall 27:         def __init__(self) -\u003e None:\r\nline 28:             self._data = {}\r\nline 29:             self._expiration_tasks = {}\r\nretu 29:             self._expiration_tasks = {}\r\nline 44:         ttl_dict['foo'] = 42\r\ncall 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 32:             async def _waiter() -\u003e None:\r\nline 35:             self._data[key] = value\r\nline 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nretu 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nline 45:         await ttl_dict.delete('foo')\r\ncall 38:         async def delete(self, key):\r\nline 39:             await cancel_task(self._expiration_tasks.pop(key))\r\ncall 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 19:         task.cancel()\r\nline 21:         try:\r\nline 22:             await task\r\nretu 22:             await task\r\nretu 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nretu 45:         await ttl_dict.delete('foo')\r\ncall 32:             async def _waiter() -\u003e None:\r\nexce 32:             async def _waiter() -\u003e None:\r\nretu 32:             async def _waiter() -\u003e None:\r\ncall 22:             await task\r\nexce 22:             await task\r\nline 23:         except asyncio.CancelledError:\r\nline 24:             pass\r\nretu 24:             pass\r\ncall 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nline 40:             return self._data.pop(key)\r\nretu 40:             return self._data.pop(key)\r\ncall 45:         await ttl_dict.delete('foo')\r\nline 46:         print('FINISH')\r\nFINISH\r\nretu 46:         print('FINISH')\r\nretu 48:     asyncio.run(_main())\r\n```\r\n\r\nUnder 3.11.4:\r\n\r\n```\r\n3.11.4 (main, Jun  7 2023, 08:42:37) [Clang 14.0.3 (clang-1403.0.22.14.1)]\r\ncall 17: def main():\r\nline 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 26:     class TTLDict:\r\ncall 26:     class TTLDict:\r\nline 26:     class TTLDict:\r\nline 27:         def __init__(self) -\u003e None:\r\nline 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 38:         async def delete(self, key):\r\nretu 38:         async def delete(self, key):\r\nline 42:     async def _main():\r\nline 48:     asyncio.run(_main())\r\ncall 42:     async def _main():\r\nline 43:         ttl_dict = TTLDict()\r\ncall 27:         def __init__(self) -\u003e None:\r\nline 28:             self._data = {}\r\nline 29:             self._expiration_tasks = {}\r\nretu 29:             self._expiration_tasks = {}\r\nline 44:         ttl_dict['foo'] = 42\r\ncall 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 32:             async def _waiter() -\u003e None:\r\nline 35:             self._data[key] = value\r\nline 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nretu 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nline 45:         await ttl_dict.delete('foo')\r\ncall 38:         async def delete(self, key):\r\nline 39:             await cancel_task(self._expiration_tasks.pop(key))\r\ncall 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 19:         task.cancel()\r\nline 21:         try:\r\nline 22:             await task\r\nretu 22:             await task\r\nretu 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nretu 45:         await ttl_dict.delete('foo')\r\ncall 32:             async def _waiter() -\u003e None:\r\nexce 32:             async def _waiter() -\u003e None:\r\nretu 32:             async def _waiter() -\u003e None:\r\ncall 22:             await task\r\nexce 22:             await task\r\nline 23:         except asyncio.CancelledError:\r\nline 24:             pass\r\nretu 24:             pass\r\nline 40:             return self._data.pop(key)\r\nretu 40:             return self._data.pop(key)\r\nline 46:         print('FINISH')\r\nFINISH\r\nretu 46:         print('FINISH')\r\nretu 48:     asyncio.run(_main())\r\n```\r\n\r\nUnder 3.12.0b4:\r\n\r\n```\r\n3.12.0b4 (main, Jul 11 2023, 20:38:26) [Clang 14.0.3 (clang-1403.0.22.14.1)]\r\ncall 17: def main():\r\nline 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 26:     class TTLDict:\r\ncall 26:     class TTLDict:\r\nline 26:     class TTLDict:\r\nline 27:         def __init__(self) -\u003e None:\r\nline 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 38:         async def delete(self, key):\r\nretu 38:         async def delete(self, key):\r\nline 42:     async def _main():\r\nline 48:     asyncio.run(_main())\r\ncall 42:     async def _main():\r\nline 43:         ttl_dict = TTLDict()\r\ncall 27:         def __init__(self) -\u003e None:\r\nline 28:             self._data = {}\r\nline 29:             self._expiration_tasks = {}\r\nretu 29:             self._expiration_tasks = {}\r\nline 44:         ttl_dict['foo'] = 42\r\ncall 31:         def __setitem__(self, key, value) -\u003e None:\r\nline 32:             async def _waiter() -\u003e None:\r\nline 35:             self._data[key] = value\r\nline 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nretu 36:             self._expiration_tasks[key] = asyncio.create_task(_waiter())\r\nline 45:         await ttl_dict.delete('foo')\r\ncall 38:         async def delete(self, key):\r\nline 39:             await cancel_task(self._expiration_tasks.pop(key))\r\ncall 18:     async def cancel_task(task: asyncio.Task) -\u003e None:\r\nline 19:         task.cancel()\r\nline 21:         try:\r\nline 22:             await task\r\nretu 22:             await task\r\nretu 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nretu 45:         await ttl_dict.delete('foo')\r\ncall 32:             async def _waiter() -\u003e None:\r\nexce 32:             async def _waiter() -\u003e None:\r\nretu 32:             async def _waiter() -\u003e None:\r\ncall 22:             await task\r\nexce 22:             await task\r\nline 23:         except asyncio.CancelledError:\r\nline 24:             pass\r\nretu 24:             pass\r\ncall 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nexce 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nline 39:             await cancel_task(self._expiration_tasks.pop(key))\r\nline 40:             return self._data.pop(key)\r\nretu 40:             return self._data.pop(key)\r\ncall 45:         await ttl_dict.delete('foo')\r\nexce 45:         await ttl_dict.delete('foo')\r\nline 45:         await ttl_dict.delete('foo')\r\nline 46:         print('FINISH')\r\nFINISH\r\nretu 46:         print('FINISH')\r\nretu 48:     asyncio.run(_main())\r\n```\r\n\r\n3.10.9 and 3.12.0b4 produce call events for lines 39 and 45, but 3.11.4 does not.\r\n\r\nFor comparison, here's the diff between the output for 3.10.9 and 3.11.4:\r\n```\r\n1c1\r\n\u003c 3.10.9 (main, Dec  7 2022, 07:15:24) [Clang 12.0.0 (clang-1200.0.32.29)]\r\n---\r\n\u003e 3.11.4 (main, Jun  7 2023, 08:42:37) [Clang 14.0.3 (clang-1403.0.22.14.1)]\r\n43d42\r\n\u003c call 39:             await cancel_task(self._expiration_tasks.pop(key))\r\n46d44\r\n\u003c call 45:         await ttl_dict.delete('foo')\r\n```\r\n\r\nAnd here's the difference between 3.11.4 and 3.12.0b4:\r\n```\r\n1c1\r\n\u003c 3.11.4 (main, Jun  7 2023, 08:42:37) [Clang 14.0.3 (clang-1403.0.22.14.1)]\r\n---\r\n\u003e 3.12.0b4 (main, Jul 11 2023, 20:38:26) [Clang 14.0.3 (clang-1403.0.22.14.1)]\r\n42a43,45\r\n\u003e call 39:             await cancel_task(self._expiration_tasks.pop(key))\r\n\u003e exce 39:             await cancel_task(self._expiration_tasks.pop(key))\r\n\u003e line 39:             await cancel_task(self._expiration_tasks.pop(key))\r\n44a48,50\r\n\u003e call 45:         await ttl_dict.delete('foo')\r\n\u003e exce 45:         await ttl_dict.delete('foo')\r\n\u003e line 45:         await ttl_dict.delete('foo')\r\n```\r\n\r\nThis was originally reported as https://github.com/nedbat/coveragepy/issues/1648","author":{"url":"https://github.com/nedbat","@type":"Person","name":"nedbat"},"datePublished":"2023-07-14T17:38:20.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":3},"url":"https://github.com/106749/cpython/issues/106749"}