facebook / mvfst

An implementation of the QUIC transport protocol.
MIT License
1.5k stars 244 forks source link

[tperf] Crash when client connects to Server (Debain 12) #339

Open Vollidiotischer opened 6 months ago

Vollidiotischer commented 6 months ago

Info

I am trying to perform some tests but tperf seems to crash as soon as the Client connects to the server. This was not a problem a couple months ago (specifically on Commit 4b03b63802990ac79bc549f92d585bcdd9631e79 (March 19th))

When I try to perform local measurements using tperf (e.g. via localhost) it works fine on both ends (Server&Client). When trying to use another OS for the Client (On Ubuntu 20) the Server-Side still crashes which leads me to believe the problem lies somewhere with Debian 12.

The Current Setup is as follows:

On Commit: df1b77cfce3666bf5b475b915ca1143bcf40c33a (On Client and Server) OS-Info: (Server)

PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian

OS-Info (Client):

NAME="Fedora Linux" VERSION="39 (Workstation Edition)" ID=fedora VERSION_ID=39 VERSION_CODENAME="" PLATFORM_ID="platform:f39" PRETTY_NAME="Fedora Linux 39 (Workstation Edition)"

The Server & Client Outputs are as follows:

Server output:

$ ./tperf -mode=server -host=0.0.0.0 -v=4 I20240505 13:34:54.775065 3747126 QuicServer.cpp:311] No valid takenover fd found for address=0.0.0.0:6666. binding on worker=0x55b328683d70 workerId=0 processId=0 I20240505 13:34:54.775225 3747126 QuicServer.cpp:322] Initialized all workers in the eventbase I20240505 13:34:54.775493 3747126 tperf.cpp:167] TPerfAcceptObserver attached I20240505 13:34:54.775604 3747125 tperf.cpp:497] tperf server started at: 0.0.0.0:6666 I20240505 13:34:57.816308 3747126 QuicServerWorker.cpp:882] Creating new connection for client=2.210.213.55:4543, routingInfo=CID=746e50ebcc63a8e2, cidVersion=1, workerId=0, processId=0, hostId=0, threadId=140222459406016, cidVersion in packet=1, workerId in packet=67, processId in packet=1, hostId in packet=53689, I20240505 13:34:57.819614 3747126 QuicServerWorker.cpp:1290] Adding into connectionIdMap_ for CID=4000001da19ad191 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.819643 3747126 tperf.cpp:239] Starting sends to client. I20240505 13:34:57.819713 3747126 QuicPacketScheduler.cpp:815] Wrote crypto frame offset=0 bytesWritten=90 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.819876 3747126 QuicPacketScheduler.cpp:815] Wrote crypto frame offset=0 bytesWritten=713 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.819984 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=0 bytesWritten=1430 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820039 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=1430 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820072 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=2858 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820120 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=4286 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820158 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=5714 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820201 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=7142 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820233 3747126 QuicPacketScheduler.cpp:558] Wrote stream frame stream=3 offset=8570 bytesWritten=1428 finWritten=0 client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.820304 3747126 IoBufQuicBatch.cpp:146] Error writing to the socket Input/output error, 2.210.213.55:4543 I20240505 13:34:57.821170 3747126 QuicTransportBase.cpp:3201] writeSocketDataAndCatchError on socket write Input/output error, client CID= server CID=4000001da19ad191 peer address=2.210.213.55:4543 I20240505 13:34:57.821202 3747126 QuicTransportBase.cpp:2886] Clearing datagram callback I20240505 13:34:57.821210 3747126 QuicTransportBase.cpp:2889] Clearing ping callback I20240505 13:34:57.821218 3747126 QuicTransportBase.cpp:2892] Clearing 0 peek callbacks E20240505 13:34:57.821234 3747126 tperf.cpp:231] Conn errorCoded=Internal Error, errorMsg=Error on socket write Input/output error, F20240505 13:34:57.821369 3747126 tperf.cpp:265] Connection closed Check failure stack trace: Aborted at 1714908897 (Unix time, try 'date -d @1714908897') Signal 6 (SIGABRT) (0x392d35) received by PID 3747125 (pthread TID 0x7f8815e1e6c0) (linux TID 3747126) (maybe from PID 3747125, UID 0) (code: -6), stack trace: @ 000000000017cdd7 folly::symbolizer::(anonymous namespace)::signalHandler(int, siginfo_t, void) /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/experimental/symbolizer/SignalHandler.cpp:453 @ 000000000003c04f (unknown) @ 000000000008ae2c (unknown) @ 000000000003bfb1 gsignal @ 0000000000026471 abort @ 0000000000070c9d folly::(anonymous namespace)::wrapped_abort() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/init/Init.cpp:62 @ 000000000000efcc google::LogMessage::Fail() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/extracted/glog-v0.5.0.tar.gz/glog-0.5.0/src/logging.cc:1920 @ 00000000000114ed google::LogMessage::SendToLog() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/extracted/glog-v0.5.0.tar.gz/glog-0.5.0/src/logging.cc:1877 @ 000000000000eb17 google::LogMessage::Flush() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/extracted/glog-v0.5.0.tar.gz/glog-0.5.0/src/logging.cc:1737 @ 0000000000011a68 google::LogMessageFatal::~LogMessageFatal() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/extracted/glog-v0.5.0.tar.gz/glog-0.5.0/src/logging.cc:2496 @ 00000000000bbd61 quic::tperf::ServerStreamHandler::notifyDataForStream(unsigned long)::{lambda()#1}::operator()() const /home/username/mvfst/quic/tools/tperf/tperf.cpp:265 @ 00000000000fdb2a folly::EventBase::FunctionLoopCallback::runLoopCallback() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/Function.h:370 -> /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp @ 00000000000f7598 folly::EventBase::runLoopCallbacks(boost::intrusive::list<folly::EventBase::LoopCallback, boost::intrusive::constant_time_size >&) /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:913 @ 00000000000f7718 folly::EventBase::runLoopCallbacks() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:932 @ 00000000000f9407 folly::EventBase::loopMain(int, folly::EventBase::LoopOptions) /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:586 @ 00000000000f9d6d folly::EventBase::loopBody(int, folly::EventBase::LoopOptions) /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:474 @ 00000000000f9e07 folly::EventBase::loop() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:435 @ 00000000000fbed6 folly::EventBase::loopForever() /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/EventBase.cpp:732 @ 0000000000404ba7 folly::run(folly::EventBaseManager, folly::EventBase, folly::Baton<true, std::atomic>, folly::Range<char const> const&) /tmp/fbcode_builder_getdeps-ZhomeZusernameZmvfstZbuildZfbcode_builder-root/repos/github.com-facebook-folly.git/folly/io/async/ScopedEventBaseThread.cpp:40 @ 00000000000d44a2 (unknown) @ 0000000000089133 (unknown) @ 00000000001097db (unknown)

Client output:

$ ./tperf -mode=client -host=xxx.xxx.xxx.xxx -v=4 I0505 13:34:57.794664 156127 QuicClientTransport.cpp:86] initial dcid: 746e50ebcc63a8e2 I0505 13:34:57.794744 156127 tperf.cpp:710] TPerfClient connecting to xxx.xxx.xxx.xxx:6666 I0505 13:34:57.797061 156127 QuicPacketScheduler.cpp:815] Wrote crypto frame offset=0 bytesWritten=209 client CID= server CID=None peer address=xxx.xxx.xxx.xxx:6666 I0505 13:34:57.836753 156127 QuicReadCodec.cpp:404] Client cannot read key phase zero packet I0505 13:34:57.836798 156127 QuicClientTransport.cpp:590] Client closed by peer reason=writeSocketDataAndCatch() error client CID= server CID=4000001da19ad191 peer address=xxx.xxx.xxx.xxx:6666 I0505 13:34:57.836817 156127 QuicTransportBase.cpp:2886] Clearing datagram callback I0505 13:34:57.836822 156127 QuicTransportBase.cpp:2889] Clearing ping callback I0505 13:34:57.836823 156127 QuicTransportBase.cpp:2892] Clearing 0 peek callbacks E0505 13:34:57.836830 156127 tperf.cpp:636] TPerfClient error: Internal Error E0505 13:34:57.836993 156127 QuicTransportBase.cpp:434] close threw exception Cannot encrypt (insufficient space for tag) client CID= server CID=4000001da19ad191 peer address=xxx.xxx.xxx.xxx:6666 E0505 13:34:57.838029 156127 EventHandler.cpp:90] EventBase: failed to register event handler for fd 9: Resource temporarily unavailable

Any help would be greatly appreciated. Thanks in advance!