search

paullouisageneau / libdatachannel

C/C++ WebRTC network library featuring Data Channels, Media Transport, and WebSockets
https://libdatachannel.org/
Mozilla Public License 2.0
1.82k stars 365 forks source link

SCTP is not flushing buffer #352

Closed murat-dogan closed 3 years ago

murat-dogan commented 3 years ago

I am trying to setup a benchmark test for node-datachannel. Please check here for code sample; https://github.com/murat-dogan/node-datachannel/blob/master/examples/client-server/client-benchmark.js

I am waiting onBufferedAmountLow event to be fired for sending more data but at some point event never fires. As you see from log below SCTP dry event fires, send buffer is full but SCTP level is not sending data.

I also checked ICE log message Integrity check failed - bad request. and it seems harmless.

For whole log please visit https://pastebin.ubuntu.com/p/gYVzwGSKjK/

2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.263 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.263 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.263 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.263 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=536
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=536
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=573
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.263 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.263 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=536
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=536
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=573
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=1192
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=1192
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=1229
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=536
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=536
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=573
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=69
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.264 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=32
2021-03-03 13:59:54.265 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
2021-03-03 13:59:54.265 VERB  [33759] [rtc::impl::SctpTransport::doRecv@398] SCTP recv, len=12
2021-03-03 13:59:54.265 VERB  [33759] [rtc::impl::SctpTransport::processNotification@688] Processing notification, type=10
2021-03-03 13:59:54.265 VERB  [33759] [rtc::impl::SctpTransport::processNotification@710] SCTP dry event
16# Sent: 2621 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
17# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
18# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
19# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
20# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
21# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
22# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
2021-03-03 14:00:00.861 VERB  [33762] [rtc::impl::IceTransport::RecvCallback@748] Incoming size=93
2021-03-03 14:00:00.861 VERB  [33762] [rtc::impl::DtlsTransport::incoming@428] Incoming size=93
2021-03-03 14:00:00.861 VERB  [33771] [rtc::impl::SctpTransport::incoming@362] Incoming size=56
2021-03-03 14:00:00.861 VERB  [33771] [rtc::impl::SctpTransport::handleWrite@604] Handle write, len=56
2021-03-03 14:00:00.862 VERB  [33771] [rtc::impl::DtlsTransport::send@415] Send size=56
2021-03-03 14:00:00.862 VERB  [33771] [rtc::impl::IceTransport::send@638] Send size=93
2021-03-03 14:00:00.862 VERB  [33771] [rtc::impl::SctpTransport::handleUpcall@588] Handle upcall
23# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
24# Sent: 0 KB/s  Received: 0 KB/s  SendBufferAmount: 16000 DataChannelOpen: true
2021-03-03 14:00:02.924 VERB  [33762] [rtc::impl::IceTransport::LogCallback@783] nice: Agent 0x61a10a0 : resending STUN to keep the selected base address fe80::5a11:4075:bc3a:9694:34279 alive in s1/c1.
2021-03-03 14:00:02.924 VERB  [33762] [rtc::impl::IceTransport::LogCallback@783] nice: Agent 0x61a10a0: inbound STUN packet for 1/1 (stream/component) from [fe80::5a11:4075:bc3a:9694]:10764 (28 octets) :
2021-03-03 14:00:02.925 VERB  [33762] [rtc::impl::IceTransport::LogCallback@783] nice: Agent 0x61a10a0 : Integrity check failed - bad request.
2021-03-03 14:00:02.925 VERB  [33762] [rtc::impl::IceTransport::LogCallback@783] nice: agent_recv_message_unlocked: Valid STUN packet received.
paullouisageneau commented 3 years ago

There are two different buffers at play here: the send queue, whose size is reported as buffered amount, and the lower-level SCTP buffer. The SCTP dry event indicates the SCTP buffer is empty, which should trigger taking messages from the send queue and passing them to the SCTP layer.

Since this is not happening, I guess there are two possibilities: the send queue is actually empty or there is a deadlock somewhere when sending. The last SCTP send in the log was successful, meaning the send queue has been emptied, so I would guess SCTP might have actually sent everything but the reported buffered amount could be wrong.

What is SendBufferAmount in the log?

murat-dogan commented 3 years ago

SendBufferAmount is the size of the send queue, which is reported from Datachannel.

paullouisageneau commented 3 years ago

Does it take a value different from 16000? Also is 16000 the value of BUFFER_SIZE in your run? (it is 10000 in client-benchmark.js)

murat-dogan commented 3 years ago

Yes it is changing. Normally app is adding message till 11000 but it was 16000 when this happened.

murat-dogan commented 3 years ago

It seems it is reporting wrongly. I checked mSendQueue.size(). It was 0 but bufferedAmount was reporting 11000.

Please note that; This is happening sometimes after 2 minutes, sometimes after 30 minutes.

paullouisageneau commented 3 years ago

For some reason the buffered amount callback was not synchronized properly. Could you please test if https://github.com/paullouisageneau/libdatachannel/pull/353 fixes the issue?

murat-dogan commented 3 years ago

I am re-running test. It has been nearly 1 hour without any issue ! And buffer size is always <= 11000 which should be.

murat-dogan commented 3 years ago

I ended first test after 1 hour. Everything was ok. This is from my second test 

665# Sent: 52713 KB/s  Received: 2092 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
666# Sent: 54496 KB/s  Received: 5054 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
667# Sent: 49151 KB/s  Received: 4470 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
668# Sent: 56346 KB/s  Received: 6775 KB/s  SendBufferAmount: 0 DataChannelOpen: true
669# Sent: 51448 KB/s  Received: 6243 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
670# Sent: 63698 KB/s  Received: 5758 KB/s  SendBufferAmount: 0 DataChannelOpen: true
671# Sent: 53489 KB/s  Received: 4153 KB/s  SendBufferAmount: 0 DataChannelOpen: true
672# Sent: 50665 KB/s  Received: 4948 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
673# Sent: 50763 KB/s  Received: 4423 KB/s  SendBufferAmount: 0 DataChannelOpen: true
674# Sent: 50361 KB/s  Received: 5575 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
675# Sent: 46681 KB/s  Received: 10386 KB/s  SendBufferAmount: 0 DataChannelOpen: true
676# Sent: 49342 KB/s  Received: 9570 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
677# Sent: 54762 KB/s  Received: 6852 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
678# Sent: 58553 KB/s  Received: 4739 KB/s  SendBufferAmount: 0 DataChannelOpen: true
679# Sent: 52728 KB/s  Received: 4145 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
680# Sent: 60951 KB/s  Received: 6341 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
681# Sent: 48848 KB/s  Received: 7965 KB/s  SendBufferAmount: 0 DataChannelOpen: true
682# Sent: 49238 KB/s  Received: 7090 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
683# Sent: 49735 KB/s  Received: 7273 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
684# Sent: 48099 KB/s  Received: 7858 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
685# Sent: 55176 KB/s  Received: 6599 KB/s  SendBufferAmount: 0 DataChannelOpen: true
686# Sent: 44634 KB/s  Received: 4563 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
687# Sent: 53916 KB/s  Received: 7717 KB/s  SendBufferAmount: 0 DataChannelOpen: true
688# Sent: 58921 KB/s  Received: 7976 KB/s  SendBufferAmount: 0 DataChannelOpen: true
689# Sent: 52233 KB/s  Received: 6630 KB/s  SendBufferAmount: 5000 DataChannelOpen: true
690# Sent: 44727 KB/s  Received: 3446 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
691# Sent: 50961 KB/s  Received: 9301 KB/s  SendBufferAmount: 0 DataChannelOpen: true
692# Sent: 56286 KB/s  Received: 11005 KB/s  SendBufferAmount: 0 DataChannelOpen: true
693# Sent: 59328 KB/s  Received: 8656 KB/s  SendBufferAmount: 0 DataChannelOpen: true
694# Sent: 53216 KB/s  Received: 7653 KB/s  SendBufferAmount: 0 DataChannelOpen: true
695# Sent: 48889 KB/s  Received: 8984 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
696# Sent: 52912 KB/s  Received: 8980 KB/s  SendBufferAmount: 0 DataChannelOpen: true
697# Sent: 56620 KB/s  Received: 12356 KB/s  SendBufferAmount: 0 DataChannelOpen: true
698# Sent: 51447 KB/s  Received: 7052 KB/s  SendBufferAmount: 0 DataChannelOpen: true
699# Sent: 50047 KB/s  Received: 3364 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
700# Sent: 49913 KB/s  Received: 8396 KB/s  SendBufferAmount: 0 DataChannelOpen: true
701# Sent: 55505 KB/s  Received: 8764 KB/s  SendBufferAmount: 4000 DataChannelOpen: true
702# Sent: 62590 KB/s  Received: 8634 KB/s  SendBufferAmount: 0 DataChannelOpen: true
703# Sent: 48072 KB/s  Received: 4043 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
704# Sent: 52470 KB/s  Received: 5020 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
705# Sent: 49179 KB/s  Received: 6331 KB/s  SendBufferAmount: 0 DataChannelOpen: true
706# Sent: 46180 KB/s  Received: 10180 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
707# Sent: 44293 KB/s  Received: 10838 KB/s  SendBufferAmount: 0 DataChannelOpen: true
708# Sent: 47146 KB/s  Received: 6291 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
709# Sent: 52563 KB/s  Received: 3104 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
710# Sent: 65332 KB/s  Received: 8088 KB/s  SendBufferAmount: 0 DataChannelOpen: true
711# Sent: 46825 KB/s  Received: 9234 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
712# Sent: 47833 KB/s  Received: 7323 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
713# Sent: 51469 KB/s  Received: 6677 KB/s  SendBufferAmount: 0 DataChannelOpen: true
714# Sent: 52297 KB/s  Received: 11977 KB/s  SendBufferAmount: 0 DataChannelOpen: true
715# Sent: 44305 KB/s  Received: 10500 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
716# Sent: 54151 KB/s  Received: 11579 KB/s  SendBufferAmount: 0 DataChannelOpen: true
717# Sent: 47631 KB/s  Received: 9027 KB/s  SendBufferAmount: 0 DataChannelOpen: true
718# Sent: 51892 KB/s  Received: 6917 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
719# Sent: 50940 KB/s  Received: 7317 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
720# Sent: 48218 KB/s  Received: 7991 KB/s  SendBufferAmount: 0 DataChannelOpen: true
721# Sent: 50590 KB/s  Received: 11331 KB/s  SendBufferAmount: 0 DataChannelOpen: true
722# Sent: 48442 KB/s  Received: 8755 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
723# Sent: 46541 KB/s  Received: 10452 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
724# Sent: 51258 KB/s  Received: 7134 KB/s  SendBufferAmount: 0 DataChannelOpen: true
725# Sent: 52545 KB/s  Received: 7949 KB/s  SendBufferAmount: 0 DataChannelOpen: true
726# Sent: 51085 KB/s  Received: 7688 KB/s  SendBufferAmount: 11000 DataChannelOpen: true
727# Sent: 61557 KB/s  Received: 4713 KB/s  SendBufferAmount: 0 DataChannelOpen: true
728# Sent: 52822 KB/s  Received: 5205 KB/s  SendBufferAmount: 11000 DataChannelOpen: true

It seems like fix is working. Thanks.

paullouisageneau commented 3 years ago

Great, I'm merging it.

paullouisageneau commented 3 years ago

The fix is in version 0.11.7!