Poor datagram extension send performance

[birneee]

I noticed that the sending rate of datagram frames is much lower than that of stream frames.

Example measurement with streams:

$ qperf client --addr [::1]:18080 --receive-stream
{"qlog_format":"NDJSON","qlog_version":"draft-02","title":"quic-go qlog","code_version":"v0.33.0","trace":{"vantage_point":{"type":"client"},"common_fields":{"ODCID":"a7a4f894c0eb3547b4","group_id":"a7a4f894c0eb3547b4","reference_time":1680959374739.0117,"time_format":"relative"}}}
{"time":0.009531,"name":"transport:connection_started","data":{"ip_version":"ipv6","src_ip":"::","src_port":36664,"dst_ip":"::1","dst_port":18080,"src_cid":"(empty)","dst_cid":"a7a4f894c0eb3547b4"}}
{"time":2.909691,"name":"qperf:handshake_completed","data":{}}
{"time":3.156259,"name":"qperf:handshake_confirmed","data":{}}
{"time":3.194904,"name":"qperf:first_app_data_received","data":{}}
{"time":1003.043641,"name":"qperf:report","data":{"stream_mbps_received":1795.8972,"stream_bytes_received":225188568,"max_rtt":2.245394,"packets_lost":0,"period":1003.1245}}
{"time":2003.067291,"name":"qperf:report","data":{"stream_mbps_received":1830.302,"stream_bytes_received":228793158,"max_rtt":0.318308,"packets_lost":0,"period":1000.0236}}
{"time":3003.103221,"name":"qperf:report","data":{"stream_mbps_received":1851.251,"stream_bytes_received":231414678,"max_rtt":0.323288,"packets_lost":0,"period":1000.0359}}
{"time":4003.111423,"name":"qperf:report","data":{"stream_mbps_received":1771.6084,"stream_bytes_received":221452902,"max_rtt":0.360415,"packets_lost":0,"period":1000.0083}}
{"time":5003.120854,"name":"qperf:report","data":{"stream_mbps_received":1726.5168,"stream_bytes_received":215816634,"max_rtt":0.314119,"packets_lost":0,"period":1000.0094}}
{"time":6003.125988,"name":"qperf:report","data":{"stream_mbps_received":1813.5583,"stream_bytes_received":226695942,"max_rtt":0.449681,"packets_lost":0,"period":1000.005}}
{"time":7003.172815,"name":"qperf:report","data":{"stream_mbps_received":1794.6083,"stream_bytes_received":224336574,"max_rtt":0.344474,"packets_lost":0,"period":1000.04694}}
{"time":8003.190618,"name":"qperf:report","data":{"stream_mbps_received":1827.6912,"stream_bytes_received":228465468,"max_rtt":0.314881,"packets_lost":0,"period":1000.0179}}
{"time":9003.246401,"name":"qperf:report","data":{"stream_mbps_received":1836.0106,"stream_bytes_received":229514076,"max_rtt":0.989975,"packets_lost":0,"period":1000.0556}}
{"time":10003.279565,"name":"qperf:report","data":{"stream_mbps_received":1825.5658,"stream_bytes_received":228203316,"max_rtt":1.303156,"packets_lost":0,"period":1000.03326}}
{"time":10003.284284,"name":"qperf:total","data":{"stream_mbps_received":1807.2968,"stream_bytes_received":2259881316,"max_rtt":2.245394,"packets_lost":0,"period":10003.365}}
{"time":10003.305172,"name":"transport:connection_closed","data":{"owner":"local","application_code":0,"reason":"no error"}}

Example measurement with datagrams:

$ qperf client --addr [::1]:18080 --receive-datagram
{"qlog_format":"NDJSON","qlog_version":"draft-02","title":"quic-go qlog","code_version":"v0.33.0","trace":{"vantage_point":{"type":"client"},"common_fields":{"ODCID":"9e300937c45af3898daf61a0908e01b8db96","group_id":"9e300937c45af3898daf61a0908e01b8db96","reference_time":1680959355161.2058,"time_format":"relative"}}}
{"time":0.00856,"name":"transport:connection_started","data":{"ip_version":"ipv6","src_ip":"::","src_port":48185,"dst_ip":"::1","dst_port":18080,"src_cid":"(empty)","dst_cid":"9e300937c45af3898daf61a0908e01b8db96"}}
{"time":2.485886,"name":"qperf:handshake_completed","data":{}}
{"time":2.820795,"name":"qperf:first_app_data_received","data":{}}
{"time":3.490911,"name":"qperf:handshake_confirmed","data":{}}
{"time":1002.568919,"name":"qperf:report","data":{"datagram_mbps_received":882.97943,"datagram_bytes_received":110665044,"max_rtt":1.745657,"packets_lost":0,"period":1002.6511}}
{"time":2002.587988,"name":"qperf:report","data":{"datagram_mbps_received":911.00494,"datagram_bytes_received":113877792,"max_rtt":0.262073,"packets_lost":0,"period":1000.01904}}
{"time":3002.59966,"name":"qperf:report","data":{"datagram_mbps_received":904.002,"datagram_bytes_received":113001588,"max_rtt":0.22669,"packets_lost":0,"period":1000.0118}}
{"time":4002.610865,"name":"qperf:report","data":{"datagram_mbps_received":896.38965,"datagram_bytes_received":112049973,"max_rtt":0.196076,"packets_lost":0,"period":1000.0113}}
{"time":5002.665301,"name":"qperf:report","data":{"datagram_mbps_received":906.9607,"datagram_bytes_received":113376249,"max_rtt":0.192185,"packets_lost":0,"period":1000.0544}}
{"time":6002.71468,"name":"qperf:report","data":{"datagram_mbps_received":899.3048,"datagram_bytes_received":112418649,"max_rtt":0.565357,"packets_lost":0,"period":1000.0493}}
{"time":7002.767639,"name":"qperf:report","data":{"datagram_mbps_received":899.80896,"datagram_bytes_received":112482090,"max_rtt":0.171022,"packets_lost":0,"period":1000.05304}}
{"time":8002.79533,"name":"qperf:report","data":{"datagram_mbps_received":907.004,"datagram_bytes_received":113378643,"max_rtt":0.238366,"packets_lost":0,"period":1000.02765}}
{"time":9002.826728,"name":"qperf:report","data":{"datagram_mbps_received":919.2863,"datagram_bytes_received":114914394,"max_rtt":0.250257,"packets_lost":0,"period":1000.0314}}
{"time":10002.835764,"name":"qperf:report","data":{"datagram_mbps_received":896.7557,"datagram_bytes_received":112095459,"max_rtt":0.263642,"packets_lost":0,"period":1000.0089}}
{"time":10002.838008,"name":"qperf:total","data":{"datagram_mbps_received":902.34436,"datagram_bytes_received":1128259881,"max_rtt":1.745657,"packets_lost":0,"period":10002.921}}
{"time":10002.859898,"name":"transport:connection_closed","data":{"owner":"local","application_code":0,"reason":"no error"}}

I narrowed the problem down to the send queue of capacity one and the blocking until the datagram is dequeued, i.e.,
sendQueue: make(chan *wire.DatagramFrame, 1) and h.dequeued <- struct{}{} in datagram_queue.go.

[marten-seemann]

Your analysis is correct. We haven't spent any effort optimizing the sending / receiving of datagrams yet.

[dongcarl]

Would like to do some work on this if I can be pointed in the right direction. For the send queue it seems like we just need to increase the channel size to something reasonable. There's a lot of locking in the receive path and I'm thinking perhaps rcvQueue and rcvMx could be replaced with a channel?

[andrewmoise]

I'm also interested in this - it's not critical for my use case and I'm still trying to get some other things working, but good throughput is critical for me and in a perfect world it'd be slightly better to use datagrams as opposed to streams. @dongcarl have you been doing any work on it?

[markovic97]

Is this performance issue fully fixed now?
It still reads as unfixed in the main README.