microsoft / msquic

Cross-platform, C implementation of the IETF QUIC protocol, exposed to C, C++, C# and Rust.
MIT License
4.05k stars 530 forks source link

AppData/WithSendArgs1.Send/411 failed - Wait for clients to complete timed out after 3010 ms. #3510

Open nibanks opened 1 year ago

nibanks commented 1 year ago

Describe the bug

[ RUN      ] AppData/WithSendArgs1.Send/411
D:\a\msquic\msquic\src\test\lib\DataTest.cpp(507): error: Wait for clients to complete timed out after 3010 ms.
D:\a\msquic\msquic\src\test\lib\DataTest.cpp(140): error: Not all data sent.
D:\a\msquic\msquic\src\test\lib\DataTest.cpp(140): error: Not all data sent.
D:\a\msquic\msquic\src\test\lib\DataTest.cpp(140): error: Not all data sent.
D:\a\msquic\msquic\src\test\lib\DataTest.cpp(140): error: Not all data sent.
[  FAILED  ] AppData/WithSendArgs1.Send/411, where GetParam() = v6/10000/4/1/NoSendBuffer/Uni/Server (3380 ms)

https://github.com/microsoft/msquic/actions/runs/4419829023/jobs/7748766534

Affected OS

Additional OS information

No response

MsQuic version

main

Steps taken to reproduce bug

Run BVT tests in automation

Expected behavior

All tests should pass

Actual outcome

Rarely, this test failed.

Additional details

windows-2022-x64-schannel-Sanitize.zip

ami-GS commented 1 year ago

Same src dst port? Just my guess

csujedihy commented 1 year ago

The information in the traces seems very limited. The server side started handshake and 2.1s later, the test timed out. I don't quite understand why Full.Light only collected these events?

1]1280.126C::2023/03/14-21:11:10.858242000 [Microsoft-Quic][conn][0x128C0D533090] Registered with 0x126E0D682A10 [1]1280.1650::2023/03/14-21:11:10.858644200 [Microsoft-Quic][strm][0x127C0D530C90] Created, Conn=0x128C0D533090 ID=3 IsLocal=1 [1]1280.1650::2023/03/14-21:11:10.858645300 [Microsoft-Quic][strm][0x127C0D530C90] Send State: 1(STARTED) [1]1280.1650::2023/03/14-21:11:10.858645900 [Microsoft-Quic][strm][0x127C0D530C90] Recv State: 0(DISABLED) [1]1280.1650::2023/03/14-21:11:10.858655900 [Microsoft-Quic][strm][0x127C0D530C90] Send State: 4(FIN) [1]1280.1650::2023/03/14-21:11:10.858707000 [Microsoft-Quic][conn][0x128C0D533090] Handshake start [1]1280.09EC::2023/03/14-21:11:13.011247900 [Microsoft-Quic][ lib] Perf counters Rundown [1]1280.0B58::2023/03/14-21:11:13.013328900 [Microsoft-Quic][list][0x126A0D521130] Stopped [1]1280.0B58::2023/03/14-21:11:13.013339600 [Microsoft-Quic][list][0x126A0D521130] Destroyed

csujedihy commented 1 year ago

Oh, #3512 we changed it to collect Full.Light on the same day this issue was filed. Well, I don't think it's actionable until we hit a repro.