python / python/cpython

asyncio: awaiting StreamWriter.wait_closed() in an except block rewrites the in-flight exception's traceback in place (same exception object shared between read futures and the close waiter)

未关闭
#156,278 2 条评论 0 个 reaction 已指派 0 人 在 GitHub 查看

还没有人认领这个 Issue。

stdlib topic-asyncio type-bug
主要语言
Python
星标
77.2k
派生
35.9k
PR 合并指标
PR 指标待抓取

描述

Bug description

While debugging a network client I found that the logged tracebacks for connection failures pointed at the cleanup code (writer.close() / await writer.wait_closed()) instead of the read call that actually failed. It turns out that a very common cleanup idiom silently rewrites the caught exception's __traceback__ in place.

When a stream transport dies (e.g. peer sends TCP RST), StreamReaderProtocol.connection_lost sets one and the same exception object on both the reader (and thus any pending read future) and the stream's _closed waiter:

https://github.com/python/cpython/blob/v3.14.3/Lib/asyncio/streams.py#L260-L271

def connection_lost(self, exc):
    reader = self._stream_reader
    if reader is not None:
        if exc is None:
            reader.feed_eof()
        else:
            reader.set_exception(exc)
    if not self._closed.done():
        if exc is None:
            self._closed.set_result(None)
        else:
            self._closed.set_exception(exc)

Since bpo-45924 / gh-90082 (the fix for traceback accumulation on repeated Future.result() calls), a future snapshots the exception's traceback at set_exception time and restores it with with_traceback() on every re-raise:

https://github.com/python/cpython/blob/v3.14.3/Lib/asyncio/futures.py#L208

raise self._exception.with_traceback(self._exception_tb)

with_traceback() mutates the exception object. That is harmless when the exception belongs to a single future, but here the same object is owned by two futures, so awaiting the second future (the close waiter) rewrites the traceback of the exception the user is currently handling — even if that second raise is caught/suppressed.

Consequence: the widely used cleanup idiom (the close() + wait_closed() sequence recommended by the asyncio.StreamWriter docs), e.g.

try:
    data = await reader.readexactly(n)      # raises ConnectionResetError E with the true traceback
except Exception:
    writer.close()
    with contextlib.suppress(OSError):
        await writer.wait_closed()          # re-raises the SAME object E; suppressed, but
                                            # Future.result() has already rewritten E.__traceback__
    raise                                    # propagates E with a misleading traceback

produces a final traceback that:

  1. points at the wrong raise site — the top-most application frame is the await writer.wait_closed() line, not the readexactly() call that actually failed;
  2. is missing intermediate frames — the frames added while E propagated out of readexactly() / _wait_for_data() are gone, replaced by wait_closed()'s frames;
  3. has no During handling of the above exception... chain — it is the same object, so no __context__ is attached and nothing hints that a second raise happened.

The result is a log/traceback.format_exc() output that claims the failure happened during cleanup, erasing the actual failing operation. This is quite misleading when debugging production failures.

Reproducer

import asyncio
import socket
import struct
import threading
import traceback
from contextlib import suppress


def fmt(tb):
    return " <- ".join(f"{f.name}:{f.lineno}" for f in traceback.extract_tb(tb))


port_holder = []


def server():
    # Accept one connection, read the request, then close with SO_LINGER(0)
    # so the client gets a TCP RST -> ConnectionResetError.
    srv = socket.socket()
    srv.bind(("127.0.0.1", 0))
    port_holder.append(srv.getsockname()[1])
    srv.listen(1)
    conn, _ = srv.accept()
    conn.recv(4)
    conn.setsockopt(socket.SOL_SOCKET, socket.SO_LINGER, struct.pack("ii", 1, 0))
    conn.close()
    srv.close()


async def main():
    threading.Thread(target=server, daemon=True).start()
    while not port_holder:
        await asyncio.sleep(0.01)
    reader, writer = await asyncio.open_connection("127.0.0.1", port_holder[0])
    try:
        writer.write(b"REQ1")
        await writer.drain()
        await reader.readexactly(4)  # <- the real raise site
    except Exception as e:
        print("BEFORE wait_closed:", fmt(e.__traceback__))
        writer.close()
        try:
            await writer.wait_closed()
        except Exception as e2:
            print("wait_closed raised the identical object:", e2 is e)
        print("AFTER  wait_closed:", fmt(e.__traceback__))
        raise  # propagates e with the rewritten traceback


with suppress(ConnectionResetError):
    asyncio.run(main())

Output on 3.14.3 (3.12.4 and 3.13.5 differ only in stdlib line numbers):

BEFORE wait_closed: main:38 <- readexactly:769 <- _wait_for_data:539 <- _read_ready__data_received:1009
wait_closed raised the identical object: True
AFTER  wait_closed: main:43 <- wait_closed:358 <- _read_ready__data_received:1009

Before wait_closed(), the traceback correctly shows readexactly_wait_for_data. After it, those frames are gone: the traceback now claims the exception surfaced at the await writer.wait_closed() line (main:43), and readexactly/_wait_for_data have been replaced by wait_closed. The exception object raised by wait_closed() is id-identical to the one being handled.

Expected behavior

Handling (even suppressing) the exception raised by await writer.wait_closed() should not mutate the traceback of the in-flight exception being handled in the except block. Either the traceback restore should not mutate a shared exception object in place, or the two waiters should not share one exception object.

Notes

  • The mechanism is the interaction of two individually reasonable behaviors: (a) connection_lost sharing one exception object across the read future and the close waiter (Lib/asyncio/streams.py), and (b) the anti-accumulation traceback snapshot/restore from gh-90082 (Lib/asyncio/futures.py, both the Python and C implementations), which restores via with_traceback() and therefore writes to the shared object.
  • gh-154791 is related (it is about the C future clearing its stored traceback after the first result() call) but distinct: this report is about in-place mutation of an exception object that is shared between two futures, observable from an unrelated except block.
  • The same pattern presumably affects any place where one exception object is set on multiple futures, not just streams.

CPython versions tested on

3.12.4, 3.13.5, 3.14.3 (identical behavior on all three)

Operating systems tested on

macOS

Linked PRs
  • gh-156286

贡献指南

打开贡献指南

从这里开始

  1. 先读完整个 Issue,再读项目的贡献指南。
  2. 在 Issue 下留言说明你要接手 —— 这能避免两个人做同样的事。
  3. Fork 仓库,在一个分支上完成修改。
  4. 提交 Pull Request,并在描述里引用这个 Issue 编号。

调研方向

先运行 reproducer,然后阅读 Lib/asyncio/streams.py 和 Lib/asyncio/futures.py,包括报告中提到的对应 C future 实现。跟踪 connection_lost 如何共享 exception,以及 Future.result() 如何恢复其 traceback。完成的标准是 cleanup handling 不再修改原始 in-flight exception 的 traceback,并且为所演示的行为提供 regression coverage。

由索引模型根据 Issue 内容生成。

评估

技术栈
python
领域
backend, networking
Issue 类型
缺陷
难度
4/5
预计耗时
3-5 天
活跃度
停滞
描述清晰度
基本清楚
新手友好度
35/100

把新 issue 发到你的邮箱

精选适合新手参与的 GitHub issue 摘要。