Too many old packets, resetting buffer
I'm having a problem with my setup. I'm getting the error "Too many old packets, resetting buffer". The setup is as follows:
/usr/local/bin/ristsender -S 30000 -i 'udp://@239.5.15.5:10300' -o 'rist://10.21.15.87:13300?cname=SENDER01&bandwidth=10000&buffer-min=125&buffer-max=400&rtt-min=10&rtt-max=200&reorder-buffer=60&congestion-control=1' -b 2000 -v 6 -p 1 -e 0
/usr/local/bin/ristreceiver -S 30000 -i 'rist://@10.21.15.87:13300?cname=RECEIVER01&bandwidth=2560&buffer-min=125&buffer-max=400&rtt-min=10&rtt-max=200&reorder-buffer=60&congestion-control=1' -o 'udp://10.21.15.241:14300' -p 1 -v 6
Average ping between sender and receiver is 30ms.
Sender log:
Sep 1 18:27:42 sky-ubuntu-gre ristsender[2528]: 1693592862.490828|0.0|[INFO] {"sender-stats":{"peer":{"flow_id":1786625494,"id":1,"cname":"RECEIVER01","type":"data","stats":{"quality":99.91,"sent":26262,"received":610,"retransmitted":22,"bandwidth":9197925,"retry_bandwidth":13651,"bandwidth_skipped":0,"bloat_skipped":0,"retransmit_skipped":0,"rtt":28.996839090963913,"avg_rtt":28.677740248062442,"retry_buffer_size":1,"cooldown_time":0}}}}
Sep 1 18:28:12 sky-ubuntu-gre ristsender[2528]: 1693592892.491272|0.0|[INFO] {"sender-stats":{"peer":{"flow_id":1786625494,"id":1,"cname":"RECEIVER01","type":"data","stats":{"quality":99.92,"sent":26257,"received":606,"retransmitted":19,"bandwidth":9203425,"retry_bandwidth":16007,"bandwidth_skipped":0,"bloat_skipped":1,"retransmit_skipped":0,"rtt":25.987188725780662,"avg_rtt":28.848676835002458,"retry_buffer_size":1,"cooldown_time":0}}}}
And the receiver log:
Sep 1 18:27:13 srv-tv-1 ristreceiver[3277]: 1693592833.498735|139991688605712.0|[ERROR] Lost 1 packets
Sep 1 18:27:13 srv-tv-1 ristreceiver[3277]: 1693592833.498960|0.0|[INFO] {"receiver-stats":{"flowinstant":{"flow_id":1786625494,"dead":0,"stats":{"quality":99.98,"received":19239,"dropped_late":0,"dropped_full":0,"missing":2,"recovered_total":2,"reordered":1,"retries":2,"recovered_one_nack":2,"recovered_two_nacks":0,"recovered_three_nacks":0,"recovered_four_nacks":0,"recovered_more_nacks":0,"lost":1,"avg_buffer_time":265,"duplicates":0,"missing_queue":0,"missing_queue_max":18,"min_inter_packet_spacing":0,"cur_inter_packet_spacing":1169,"max_inter_packet_spacing":10096,"bitrate":8990579},"peers":[{"id":2,"dead":0,"stats":{"received_data":25644,"received_rtcp":593,"sent_rtcp":596,"rtt":29.974114120085208,"avg_rtt":29.176168641109467,"bitrate":8989512,"avg_bitrate":9013477}}]}}}
Sep 1 18:27:13 srv-tv-1 ristreceiver[3277]: 1693592833.498986|0.0|[INFO] {"flow_cumulative_stats":{"flow_id":1786625494,"received":255984,"recovered":135,"lost":10}}
Sep 1 18:27:19 srv-tv-1 ristreceiver[3277]: 1693592839.968650|139991688605712.0|[ERROR] Too many old packets, resetting buffer
Sep 1 18:27:19 srv-tv-1 ristreceiver[3277]: 1693592839.973494|139991688605712.0|[INFO] Clearing up old 688268 bytes of old buffer data
Sep 1 18:27:19 srv-tv-1 ristreceiver[3277]: 1693592839.973747|139991688605712.0|[INFO] Storing first packet seq 60521, idx 60521, 36261166823307, offset -2085925094529 ms, output_idx 60521
Sep 1 18:27:28 srv-tv-1 ristreceiver[3277]: 1693592848.233638|139991688605712.0|[ERROR] Too many old packets, resetting buffer
Sep 1 18:27:28 srv-tv-1 ristreceiver[3277]: 1693592848.233815|139991688605712.0|[INFO] Clearing up old 985684 bytes of old buffer data
Sep 1 18:27:28 srv-tv-1 ristreceiver[3277]: 1693592848.234249|139991688605712.0|[INFO] Storing first packet seq 2050, idx 2050, 36296664059903, offset -2085925094534 ms, output_idx 2050
Sep 1 18:27:33 srv-tv-1 ristreceiver[3277]: 1693592853.788547|139991688605712.0|[ERROR] Discontinuity, expected 6330 got 6349
Sep 1 18:27:36 srv-tv-1 ristreceiver[3277]: 1693592856.808532|139991688605712.0|[ERROR] Discontinuity, expected 8895 got 8933
Sep 1 18:27:43 srv-tv-1 ristreceiver[3277]: 1693592863.498804|139991688605712.0|[ERROR] Lost 2 packets
Sep 1 18:27:43 srv-tv-1 ristreceiver[3277]: 1693592863.499091|0.0|[INFO] {"receiver-stats":{"flowinstant":{"flow_id":1786625494,"dead":0,"stats":{"quality":99.93,"received":13048,"dropped_late":0,"dropped_full":0,"missing":9,"recovered_total":9,"reordered":0,"retries":9,"recovered_one_nack":9,"recovered_two_nacks":0,"recovered_three_nacks":0,"recovered_four_nacks":0,"recovered_more_nacks":0,"lost":2,"avg_buffer_time":263,"duplicates":0,"missing_queue":0,"missing_queue_max":18,"min_inter_packet_spacing":0,"cur_inter_packet_spacing":1169,"max_inter_packet_spacing":10177,"bitrate":9019995},"peers":[{"id":2,"dead":0,"stats":{"received_data":25645,"received_rtcp":592,"sent_rtcp":609,"rtt":25.337509694486592,"avg_rtt":28.973293304698267,"bitrate":9036056,"avg_bitrate":9012092}}]}}}
Sep 1 18:27:43 srv-tv-1 ristreceiver[3277]: 1693592863.499121|0.0|[INFO] {"flow_cumulative_stats":{"flow_id":1786625494,"received":269032,"recovered":144,"lost":12}}
Sep 1 18:27:47 srv-tv-1 ristreceiver[3277]: 1693592867.798503|139991688605712.0|[ERROR] Discontinuity, expected 18298 got 18328
Sep 1 18:27:50 srv-tv-1 ristreceiver[3277]: 1693592870.858778|139991688605712.0|[ERROR] Discontinuity, expected 20863 got 20943
Sep 1 18:28:04 srv-tv-1 ristreceiver[3277]: 1693592884.783767|139991688605712.0|[ERROR] Discontinuity, expected 32831 got 32848
Sep 1 18:28:13 srv-tv-1 ristreceiver[3277]: 1693592893.498759|139991688605712.0|[ERROR] Lost 3 packets
Sep 1 18:28:13 srv-tv-1 ristreceiver[3277]: 1693592893.499034|0.0|[INFO] {"receiver-stats":{"flowinstant":{"flow_id":1786625494,"dead":0,"stats":{"quality":99.92,"received":25646,"dropped_late":0,"dropped_full":0,"missing":19,"recovered_total":19,"reordered":0,"retries":20,"recovered_one_nack":18,"recovered_two_nacks":1,"recovered_three_nacks":0,"recovered_four_nacks":0,"recovered_more_nacks":0,"lost":3,"avg_buffer_time":264,"duplicates":0,"missing_queue":0,"missing_queue_max":18,"min_inter_packet_spacing":3,"cur_inter_packet_spacing":1169,"max_inter_packet_spacing":10392,"bitrate":8959215},"peers":[{"id":2,"dead":0,"stats":{"received_data":25646,"received_rtcp":593,"sent_rtcp":606,"rtt":30.081571988795258,"avg_rtt":28.887596487935763,"bitrate":9027847,"avg_bitrate":9011154}}]}}}
Sep 1 18:28:13 srv-tv-1 ristreceiver[3277]: 1693592893.499061|0.0|[INFO] {"flow_cumulative_stats":{"flow_id":1786625494,"received":294678,"recovered":163,"lost":15}}
Sep 1 18:28:43 srv-tv-1 ristreceiver[3277]: 1693592923.499095|0.0|[INFO] {"receiver-stats":{"flowinstant":{"flow_id":1786625494,"dead":0,"stats":{"quality":99.96,"received":25645,"dropped_late":0,"dropped_full":0,"missing":10,"recovered_total":10,"reordered":2,"retries":11,"recovered_one_nack":9,"recovered_two_nacks":1,"recovered_three_nacks":0,"recovered_four_nacks":0,"recovered_more_nacks":0,"lost":0,"avg_buffer_time":264,"duplicates":1,"missing_queue":0,"missing_queue_max":18,"min_inter_packet_spacing":3,"cur_inter_packet_spacing":1169,"max_inter_packet_spacing":10323,"bitrate":8936479},"peers":[{"id":2,"dead":0,"stats":{"received_data":25646,"received_rtcp":591,"sent_rtcp":598,"rtt":30.0118119650279,"avg_rtt":28.818631901013443,"bitrate":8928038,"avg_bitrate":9013691}}]}}}
Sep 1 18:28:43 srv-tv-1 ristreceiver[3277]: 1693592923.499180|0.0|[INFO] {"flow_cumulative_stats":{"flow_id":1786625494,"received":320323,"recovered":173,"lost":15}}
Sep 1 18:28:51 srv-tv-1 ristreceiver[3277]: 1693592931.173687|139991688605712.0|[ERROR] Too many old packets, resetting buffer
Sep 1 18:28:51 srv-tv-1 ristreceiver[3277]: 1693592931.178457|139991688605712.0|[INFO] Clearing up old 917252 bytes of old buffer data
Sep 1 18:28:51 srv-tv-1 ristreceiver[3277]: 1693592931.178984|139991688605712.0|[INFO] Storing first packet seq 7416, idx 7416, 36652886261340, offset -2085925094528 ms, output_idx 7416
Sep 1 18:29:13 srv-tv-1 ristreceiver[3277]: 1693592953.499102|0.0|[INFO] {"receiver-stats":{"flowinstant":{"flow_id":1786625494,"dead":0,"stats":{"quality":99.95,"received":19083,"dropped_late":0,"dropped_full":0,"missing":8,"recovered_total":8,"reordered":1,"retries":9,"recovered_one_nack":7,"recovered_two_nacks":1,"recovered_three_nacks":0,"recovered_four_nacks":0,"recovered_more_nacks":0,"lost":0,"avg_buffer_time":266,"duplicates":0,"missing_queue":0,"missing_queue_max":18,"min_inter_packet_spacing":0,"cur_inter_packet_spacing":1169,"max_inter_packet_spacing":54809,"bitrate":8966717},"peers":[{"id":2,"dead":0,"stats":{"received_data":25646,"received_rtcp":591,"sent_rtcp":601,"rtt":29.94033597929856,"avg_rtt":28.264894904896824,"bitrate":9012759,"avg_bitrate":9017105}}]}}}
Sep 1 18:29:13 srv-tv-1 ristreceiver[3277]: 1693592953.499209|0.0|[INFO] {"flow_cumulative_stats":{"flow_id":1786625494,"received":339406,"recovered":181,"lost":15}}
UDP buffers on the receiver:
net.core.rmem_max = 52428800
I've searched the Gist for similar issues but did not find any.
Any pointers on resolving this would be appreciated!