Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

transport/webrtc: Short buffer to be filled #4049

Open
melekes opened this issue Jun 7, 2023 · 3 comments
Open

transport/webrtc: Short buffer to be filled #4049

melekes opened this issue Jun 7, 2023 · 3 comments

Comments

@melekes
Copy link
Contributor

melekes commented Jun 7, 2023

Summary

Our integration test failed because on one node all peers had been disconnected due to "Short buffer to be filled" error. The read buffer capacity is set here. Error means that somewhere (?) we're sending/reading messages more than 16kB, which should not be possible if all nodes are using the same webrtc FRAMED transport.

Refs paritytech/substrate#12529 (comment)

Expected behaviour

Expect nodes sending messages to respect the read buffer capacity.

Actual behaviour

2023-06-07 09:36:43.459 TRACE tokio-runtime-worker sub-libp2p: Handler(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby")) <= Sync notification    
2023-06-07 09:36:43.459 TRACE tokio-runtime-worker sub-libp2p: Handler(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby"), ConnectionId(4)]) => OpenDesiredByRemote(SetId(2))    
2023-06-07 09:36:43.459 TRACE tokio-runtime-worker sub-libp2p: PSM <= Incoming(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, IncomingIndex(2)).    
2023-06-07 09:36:43.459 TRACE tokio-runtime-worker sub-libp2p: PSM => Accept(IncomingIndex(2), 12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(2)): Enabling connections.    
2023-06-07 09:36:43.459 TRACE tokio-runtime-worker sub-libp2p: Handler(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby"), ConnectionId(4)) <= Open(SetId(2))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: Handler(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby"), ConnectionId(4)]) => OpenDesiredByRemote(SetId(3))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: PSM <= Incoming(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, IncomingIndex(3)).    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: PSM => Accept(IncomingIndex(3), 12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(3)): Enabling connections.    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: Handler(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby"), ConnectionId(4)) <= Open(SetId(3))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: Handler(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, ConnectionId(3)) => OpenResultOk(SetId(2))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: External API <= Open(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(2))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: Handler(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, ConnectionId(4)) => OpenResultOk(SetId(2))    
2023-06-07 09:36:43.460 TRACE tokio-runtime-worker sub-libp2p: External API <= Open(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(2))    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: Handler(ConnectionId(4)) => Notification(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(1), 22 bytes)    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: External API <= Message(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(1))    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: Handler(ConnectionId(3)) => Notification(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(1), 22 bytes)    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: External API <= Message(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(1))    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: Handler(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, ConnectionId(4)) => OpenResultOk(SetId(3))    
2023-06-07 09:36:43.461 TRACE tokio-runtime-worker sub-libp2p: External API <= Open(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(3))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(0), ConnectionId(4)): Enabled.    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(0))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(0))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(1), ConnectionId(4)): Enabled.    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(1))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(1))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(2), ConnectionId(4)): Enabled.    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(2))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(2))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(3), ConnectionId(4)): Enabled.    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(3))    
2023-06-07 09:36:43.472 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby, SetId(3))    
2023-06-07 09:36:43.472 DEBUG tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(PeerId("12D3KooWRkZhiRhsqmrQ28rt73K7V3aCBpqKrLGSXmZ99PTcTZby"), Some(Handler(Right(Upgrade(Apply(Custom { kind: InvalidInput, error: Io(Custom { kind: InvalidData, error: Error(Custom { kind: Other, error: "Short buffer to be filled" }) }) }))))))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(0), ConnectionId(3)): Enabled.    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(0))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(0))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(1), ConnectionId(3)): Enabled.    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(1))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(1))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(2), ConnectionId(3)): Enabled.    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(2))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(2))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(3), ConnectionId(3)): Enabled.    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(3))    
2023-06-07 09:36:43.508 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S, SetId(3))    
2023-06-07 09:36:43.508 DEBUG tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(PeerId("12D3KooWPKzmmE2uYgF3z13xjpbFTp63g9dZFag8pG6MgnpSLF4S"), Some(Handler(Right(Upgrade(Apply(Custom { kind: InvalidInput, error: Io(Custom { kind: InvalidData, error: Error(Custom { kind: Other, error: "Short buffer to be filled" }) }) }))))))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(0), ConnectionId(1)): Enabled.    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(0))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(0))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(1), ConnectionId(1)): Enabled.    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(1))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(1))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(2), ConnectionId(1)): Enabled.    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(2))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(2))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(3), ConnectionId(1)): Enabled.    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: External API <= Closed(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(3))    
2023-06-07 09:36:43.525 TRACE tokio-runtime-worker sub-libp2p: PSM <= Dropped(12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm, SetId(3))    
2023-06-07 09:36:43.525 DEBUG tokio-runtime-worker sub-libp2p: Libp2p => Disconnected(PeerId("12D3KooWQCkBm1BYtkHpocxCwMgR8yjitEeHGx8spzcDLGt2gkBm"), Some(Handler(Right(Upgrade(Apply(Custom { kind: InvalidInput, error: Io(Custom { kind: InvalidData, error: Error(Custom { kind: Other, error: "Short buffer to be filled" }) }) }))))))    

Possible Solution

webrtc-rs/webrtc#273 although that requires more thinking... plus I think we want to switch to str0m #3659

Version

  • libp2p version (version number, commit, or branch): 0.51.3

Would you like to work on fixing this bug?

Yes

@melekes
Copy link
Contributor Author

melekes commented Jun 12, 2023

Opened webrtc-rs/webrtc#456 which should hopefully give us more insight

@thomaseizinger
Copy link
Contributor

Opened webrtc-rs/webrtc#456 which should hopefully give us more insight

Thanks!

We are behind on the webrtc-rs updates because thus far, we were been blocked on webrtc-rs/webrtc#413 not being fixed. But the next release should fix this and we can upgrade, I think.

@thomaseizinger
Copy link
Contributor

I think we want to switch to str0m #3659

Yes, very much in favor of that but unfortunately, we don't have any resources ourselves to push that forward.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants