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

Error: No room to store incoming packet #409

Open
msanis opened this issue Jun 8, 2018 · 49 comments
Open

Error: No room to store incoming packet #409

msanis opened this issue Jun 8, 2018 · 49 comments
Assignees
Labels
[core] Area: Changes in SRT library core Type: Maintenance Work required to maintain or clean up the code
Milestone

Comments

@msanis
Copy link

msanis commented Jun 8, 2018

Hello

We are experiencing "No room to store incoming packet" error on certain conditions. The source multicast is from a professional encoder (Tandberg)

Condition 1: When TS bit rate of source is up to 16Mbps, then SRT works perfect

Condition 2: When we increase the TS bit rate higher (eg. 17 Mbps), then we see the below error message
RX side:
Accepted SRT source connection
18:11:36.374843/SRT:RcvQ:workerE: SRT.c: %1005060842:No room to store incoming packet: offset=0 avail=0 ack.seq=489148889 pkt.seq=489148889 rcv-remain=8191
18:11:36.375572/SRT:RcvQ:worker
E: SRT.c: %1005060842:No room to store incoming packet: offset=1 avail=0 ack.seq=489148889 pkt.seq=489148890 rcv-remain=8191

TX side:
155288 bytes lost, 21560028 bytes sent, 31287900 bytes received
15353772 bytes lost, 21560028 bytes sent, 46486384 bytes received
31324748 bytes lost, 21560028 bytes sent, 62457360 bytes received
47340468 bytes lost, 21560028 bytes sent, 78473080 bytes received
63335132 bytes lost, 21560028 bytes sent, 94467744 bytes received

Condition 3: We start SRT streaming initially with 16Mbps and when it is fully functioning, we increase the source TS bit rate from the encoder settings on the fly to 25Mbps. Still SRT continues to function without any errors and at the RX side we see 25Mbps on output multicast.

It seems SRT is currently handling traffic only upto 16Mbps. Any suggestions ?

Our commands:
TX: stransmit "udp://@226.24.112.4:2000?ttl=64" "srt://1.2.3.4:7005?mode=caller&latency=5000" -t:-1 -s:3000

RX: stransmit "srt://:7005?mode=listener" "udp://@225.10.10.10:2000?ttl=64" -t:-1 -s:3000 -v

@ethouris
Copy link
Collaborator

The "No room to store incoming packet" message appears when the RX buffer gets completely full and is waiting for the receiving application to extract the waiting packets. This rcv-remain data shows how many buffers (each one containing data transmitted by a single UDP packet, typically 1316 bytes) are still waiting until the application extracts them.

If you are using the SRT 1.2 version stransmit, just note that this was at that time only a testing tool and choking on the output medium may prevent it from reading from SRT medium on time. Although I have never seen it happening on UDP output, only with file://con output with pipeline to another application.

I would keenly see the debug logs from this session and see how fast the data extraction on RX happens, especially at the moment when the RX buffer level increases.

Mind also that the "latency control" facility (TSBPD) is using the RX buffer to magazine the incoming packets until their "time to play" comes. I can see that you have set quite a long latency (5 seconds) and mind that effectively the RX buffer will have to magazine packets for 5 seconds of stream constantly. Might be that with high bitrates combined with high latency the RX buffer size might be too small, or at least balance on the edge. You can change the size of the receiver buffer through the rcvbuf option (mind that it will be fixed to not exceed the fc option). The default value for rcvbuf is 8192 and for fc - 25600.

@rmsoto
Copy link

rmsoto commented Jul 31, 2018

Hello Ethouris,

I´m also having a similar issue trying to send an hevc 60mbs TS, I can only get 42,5 at output of SRT whily trying the same with a 25TS its fine... where you can change the parameters you said above?

something like this?

./srt-live-transmit -v -r:30 -s:30 -t:0 "udp://@224.168.204.41:2041" "srt://:9001?latency=500&sndbuf=8192&fc=25600"

./srt-live-transmit -v -r:30 -s:30 -t:0 "srt://127.0.0.1:9001?latency=500&rcvbuf=8192&fc=25600" "udp://@224.168.204.250:2250"

Thanks

@jeandube
Copy link
Collaborator

@rmsoto you may want to set the max output bw that is capped at 30Mbps by default (this option is not working well and that could explain the 42.5 you get). The option "maxbw" is in bytes/sec.

@jeandube
Copy link
Collaborator

Sorry, I just read this issue again, my proposal would not fix the 'no room' on the receiver. but only ensure proper drainage of the sender's buffers.

@rmsoto
Copy link

rmsoto commented Jul 31, 2018

Hi @jeandube , the mxbw helped to achieve the same output bitrate than the input one but I still get the error:

14:44:53.373608/SRT:RcvQ:worker*E: SRT.c: %328810773:No room to store incoming packet: offset=0 avail=0 ack.seq=2053936868 pkt.seq=2053936868 rcv-remain=8191

_increasing the parameters rcvbuf=16384&fc=51200 does not make any good result as I get less bw than expected...I think I´m not introducing the correct units...

Thanks

@jeandube
Copy link
Collaborator

@rmsoto Good if you fixed the sender but the noroom problem on the receiver is an indication that the receiving app is not draining the received packets fast enough. Increasing the received buffer just delay the problem. By fixing the sender you just exacerbated the receiver's problem.

@rmsoto
Copy link

rmsoto commented Jul 31, 2018

I think its now working better since we changed the values of sdnbuf, rcvbuf and flight window inside core.cpp and recompile...let’s see how it works during 24h

Thanks!

@haozhenxiao
Copy link

@ethouris I also got the same error and I checked the number of packets dropped by the kernel is 0: RX errors 0 dropped 0 overruns 0 frame 0, as you mentioned

The "No room to store incoming packet" message appears when the RX buffer gets completely full

In this case, the kernel should start dropping packets, right? Or I misunderstood RX buffer you mentioned?

@ethouris
Copy link
Collaborator

ethouris commented Aug 17, 2018

Again: this "No room to store incoming packet" may happen in two cases:

  1. The application works slowly and doesn't do the calls to srt_recvmsg even though when it did it would read the packet of data immediately (IOW, it's not the app waiting for the data from SRT, but it's SRT waiting for the application to pick up what is already delivered to it).

  2. In some strict cases it may be the problem of too small reception buffer due to TSBPD. TSBPD keeps packets in the buffer until the "time to play" comes, so if you multiply the latency by the bitrate expressed as a number of 1316-byte packets, it should give you the size of the buffer used by TSBPD. By doing it in reverse you'll get the maximum time of the video that can be stored in the receiver buffer (and compare it to latency - the part taken by latency should be much less than the rest of the buffer).

Both these things happen when the packet has already passed the network link, that is, the work for transporting the packet through the network has been already successfully finished.

May happen that the application experiences some temporary slowdown, which will get evened up later; in this case increasing the size will help. But not in case when the application is systematically increasing the delay between the moment when the packet is given up to the application and the moment when the application reads it - in this case a buffer of any size will eventually be overflown.

@haozhenxiao
Copy link

@ethouris so RX buffer is not the linux kernel buffer, right? I increased rmem_default and rmem_max but still getting the same error.

@ethouris
Copy link
Collaborator

ethouris commented Aug 21, 2018

We are talking SRT here, the userspace solution, which uses instrumentally UDP to implement the transmission. It provides its own buffers that work according to the rules it defines. Kernel parameters have nothing to do with this.

Let me be more precise about the above: both these things happen when the packet has already passed the network link and all system buffers and is about to be stored by SRT in its private buffers.

@ethouris
Copy link
Collaborator

As you have once faced this problem that is likely to result from performance problems, would you be able to test the version from this branch?

https://github.com/ethouris/srt/tree/dev-rcvworker-sleeps

@maxsharabayko
Copy link
Collaborator

This looks like a problem with receiver buffer size.
The size should be at least Bufrcv >= bps × RTTsec / (8 × (1500 - 28)) + (latencysec × bps)
Bear in mind #700.

Default receiver buffer size is 8192 × (1500-28) = 12058624 bytes or approximately 96 Mbits.
Default flow control window size is 25600 packets or approximately 300 Mbits.

@maxsharabayko maxsharabayko modified the milestones: v.1.3.3, v.1.3.4 May 29, 2019
@maxsharabayko maxsharabayko modified the milestones: v1.3.4, v1.4.1 Aug 9, 2019
@ethouris
Copy link
Collaborator

Related to #355

@ethouris ethouris added [core] Area: Changes in SRT library core Status: Pending Type: Bug Indicates an unexpected problem or unintended behavior labels Aug 12, 2019
@maxsharabayko maxsharabayko modified the milestones: v1.4.1, v1.4.2 Nov 4, 2019
@maxsharabayko maxsharabayko added Status: Abandoned There is no reply from the issue reporter Type: Question Questions or things that require clarification and removed Status: Pending Type: Bug Indicates an unexpected problem or unintended behavior labels Dec 17, 2019
@maxsharabayko maxsharabayko modified the milestones: v1.5.1, v1.4.4 May 10, 2021
@maxsharabayko maxsharabayko added Type: Maintenance Work required to maintain or clean up the code and removed Type: Bug Indicates an unexpected problem or unintended behavior labels May 10, 2021
@maxsharabayko
Copy link
Collaborator

PR #1909 further improves the log message.
Note that the "no room to store" log message now has the level warning (since v1.4.2).

The following two reasons for this message to appear can now be distinguished from the log message.

1 App is not reading fast enough:

No room to store incoming packet seqno 1887365986, insert offset 1711. Space avail 190/849 pkts.
    Packets ACKed: 658 (TSBPD ready in -1680 : -1219 ms), not ACKed: 0, timespan 460 ms. STDCXX_STEADY drift 0 ms.

TSBPD ready in -1680 : -1219 ms indicates that there are 658 packets available for reading for already at least 1.6 seconds.

2. Too small buffer

Example log message when there is almost nothing for the app to read, and not enough receiver buffer. Knowing the configured SRT_RCVLATENCY is 1s, it can be seen the timestamp of the receiver buffer is less (593 ms). The first packet can be read only in 383 ms, which means the current target buffering delay is 593 + 383 = 976ms.

No room to store incoming packet seqno 2027222264, insert offset 0. Space avail 0/849 pkts.
    Packets ACKed: 848 (TSBPD ready in 383 : 977 ms), not ACKed: 0, timespan 593 ms. STDCXX_STEADY drift 0 ms.

Issue Status

Closing this issue due to the lack of activity (since Jun 11, 2020). Please feel free to reopen if further questions arise.

@ioram-devi
Copy link

ioram-devi commented Jul 24, 2021

Hello. The receiver buffer settings do not work according to your recommendations from:
#409 (comment)
and
#700

Use case:

  1. Publisher:
    ffmpeg -re -i "/home/my-videos/1920.mp4" -c copy -f mpegts "srt://localhost:9000?latency=200000&maxbw=12399073"
  2. Receiver
    ffmpeg -i "srt://localhost:9000?mode=listener&latency=200000&maxbw=12399073&rcvbuf=48234496&fc=102400" -f mp4 "/home/my-videos/recorded-1920.mp4"

The result:
No room to store incoming packet seqno.... and then recording process has been failed.

So, all your recommendations for receiver buffer settings are useless in my case.

I am currently considering using a message broker, please let me know if there is some other simple way to reliably write stream data to disk or wait HDD.

EDITED:
SRT: latest version.
FFmpeg: Latest version.

Thanks

@maxsharabayko
Copy link
Collaborator

maxsharabayko commented Jul 26, 2021

Hi @yuri-devi
Try this way (fc before rcvbuf):

ffmpeg -i "srt://localhost:9000?mode=listener&latency=200000&maxbw=12399073&fc=102400&rcvbuf=48234496"
       -f mp4 "/home/my-videos/recorded-1920.mp4"

It would further help if you could use the latest SRT master with the updated warning message.

@ioram-devi
Copy link

@maxsharabayko Thank you for the answer. I didn't know that the packet control window size property has priority over the receiver buffer parameter.

@ioram-devi
Copy link

ioram-devi commented Jul 27, 2021

This looks like a problem with receiver buffer size.
The size should be at least Bufrcv >= bps × RTTsec / (8 × (1500 - 28)) + (latencysec × bps)
Bear in mind #700.

Default receiver buffer size is 8192 × (1500-28) = 12058624 bytes or approximately 96 Mbits.
Default flow control window size is 25600 packets or approximately 300 Mbits.

@maxsharabayko Could you please check me with my network values:

Setting up the receiver buffer:

Video bitrate: 6000Kbit/s
RTT (Ping): 0.15
Latency: 0.6

The Result of rcvbuf:
((6000000 * 0.15) / (8 * (1500 - 28))) + (0.6 * 6000000) ~ 3600076 bytes

Setting up the flow control window size:

My network bandwidth: 11140518 byte/s
RTT: 0.15

The result of fc:
((((maxbw * 8) * (0.15) / 8 / 1472)) = ~ 1135 packets

Is it correct ?

Thanks

@maxsharabayko
Copy link
Collaborator

Hi @yuri-devi

I didn't know that the packet control window size property has priority over the receiver buffer parameter.

It is indeed not obvious at all and needs to be improved (#700).

Could you please check me with my network values: ...

The latest configuration guide can be found here.

Assuming 0.15 sec RTT and 0.6 sec latency you would roughly need to store your 6 Mbps stream for 0.6 seconds. So the buffer must around (0.6 s × 6 Mbps) = 450 000 bytes.

With the provided function I get target buffer size 565 248 bytes and FC = 384 packet.

CalculateTargetRBufSize(150, 6000000, 1316, 600, 1500);

With your environment the default configuration should be more than enough, unless you wold like to save memory.

@ioram-devi
Copy link

ioram-devi commented Jul 27, 2021

@maxsharabayko Thanks for your help. I tried CalculateTargetRBufSize logic by my side and it's not working. I still see errors like no room to store incoming packet...

According your recommendations and the result of calculate CalculateTargetRBufSize method it will be 565 248 bytes and FC = 384 packet but for my bitrate 6000Kbit/s isn't correct values because it's much less default values 12058624 and 25600 accordingly and it doesn't make the results better.

So, now I just increment the default rcvbuf and fc values the manual way but I still think what the control of these parameters can be user-friendly

@maxsharabayko
Copy link
Collaborator

@yuri-devi Could you share a network capture on the sender side at least up until the moment the receiver shows the warning?
We could look at packet sending times and the bitrate curve to reproduce the behavior. If you enable encryption the payload would be totally secured.

@ioram-devi
Copy link

@maxsharabayko Sorry for the delay. Yes, I will do it when i have the opportunity. Thanks.

@maxsharabayko maxsharabayko modified the milestones: v1.4.4, Backlog Aug 2, 2021
@Delitants
Copy link

Same problem in flussonic

Dec 26 21:41:59 localhost run[218599]: "21:41:59.274365/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3292 avail=3072 ack.seq=615021140 pkt.seq=615024432 rcv-remain=5119 drift=288\n"}
Dec 26 21:41:59 localhost run[218599]: {'$srt_log',4,"/root/srt-1.4.2/srtcore/core.cpp",9621,"processData",
Dec 26 21:41:59 localhost run[218599]: "21:41:59.274439/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3293 avail=3072 ack.seq=615021140 pkt.seq=615024433 rcv-remain=5119 drift=288\n"}
Dec 26 21:41:59 localhost run[218599]: {'$srt_log',4,"/root/srt-1.4.2/srtcore/core.cpp",9621,"processData",
Dec 26 21:41:59 localhost run[218599]: "21:41:59.274447/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3294 avail=3072 ack.seq=615021140 pkt.seq=615024434 rcv-remain=5119 drift=288\n"}
Dec 26 21:41:59 localhost run[218599]: {'$srt_log',4,"/root/srt-1.4.2/srtcore/core.cpp",9621,"processData",
Dec 26 21:41:59 localhost run[218599]: "21:41:59.274483/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3295 avail=3072 ack.seq=615021140 pkt.seq=615024435 rcv-remain=5119 drift=288\n"}
Dec 26 21:41:59 localhost run[218599]: {'$srt_log',4,"/root/srt-1.4.2/srtcore/core.cpp",9621,"processData",
Dec 26 21:41:59 localhost run[218599]: "21:41:59.274540/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3296 avail=3072 ack.seq=615021140 pkt.seq=615024436 rcv-remain=5119 drift=288\n"}
Dec 26 21:41:59 localhost run[218599]: {'$srt_log',4,"/root/srt-1.4.2/srtcore/core.cpp",9621,"processData",
Dec 26 21:41:59 localhost run[218599]: "21:41:59.274550/SRT:RcvQ:w45964!W:SRT.qr: @494418234:No room to store incoming packet: offset=3297 avail=3072 ack.seq=615021140 pkt.seq=615024437 rcv-remain=5119 drift=288\n"}

@maxsharabayko
Copy link
Collaborator

@Neolo please use a newer version of SRT library.
The log message has been improved. #409 (comment)
Usually, the issue is related to the app not reading the data from SRT. Therefore SRT has to store it and has no more room for newer packets.

@Delitants
Copy link

Delitants commented Jan 12, 2023

@Neolo please use a newer version of SRT library. The log message has been improved. #409 (comment) Usually, the issue is related to the app not reading the data from SRT. Therefore SRT has to store it and has no more room for newer packets.

App is Flussonic and it's latest version, log still floods with these messages. I see no reason why app wouldn't read data from SRT. Does not make any sense.

2023-01-12 03:41:46.712 <0.328.0> 03:41:46.712550/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3359 avail=3170 ack.seq=423736348 pkt.seq=423739707 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.712 <0.328.0> 03:41:46.712607/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3360 avail=3170 ack.seq=423736348 pkt.seq=423739708 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.713 <0.328.0> 03:41:46.712615/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3361 avail=3170 ack.seq=423736348 pkt.seq=423739709 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.713 <0.328.0> 03:41:46.712679/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3362 avail=3170 ack.seq=423736348 pkt.seq=423739710 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.713 <0.328.0> 03:41:46.712692/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3363 avail=3170 ack.seq=423736348 pkt.seq=423739711 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.713 <0.328.0> 03:41:46.712698/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3364 avail=3170 ack.seq=423736348 pkt.seq=423739712 rcv-remain=5021 drift=-422
2023-01-12 03:41:46.713 <0.328.0> 03:41:46.712747/SRT:RcvQ:w12379!W:SRT.qr: @518511538:No room to store incoming packet: offset=3365 avail=3171 ack.seq=423736348 pkt.seq=423739713 rcv-remain=5020 drift=-422

@ethouris
Copy link
Collaborator

ethouris commented Jan 12, 2023

The latest release is 1.5.1, and in this version this message looks more-less like this:

No room to store incoming packet seqno 12345578789, insert offset 1234. Space avail 123/4096 pkts. (TSBPD ready in ...

What you have shown is the message from the older version, and the information provided by this message is too sparse to allow to investigate anything.

The reason could be the application's too slow reading, but it can be as well some rare internal problem in SRT (clock skew, unusual drift, bitrate spike etc.), at least in theory, in result of which the number of packets not yet ready to be delivered are suddenly occupying too big portion of the buffer. Only in the 1.5.1 version this message contains enough information to determine whether it was the case and then what might have caused it.

Ah, and one more thing - we have seen sometimes applications that do not exactly follow the required rules of SRT to read the packets all the time, and sometimes allow themselves to stop reading for a longer while (treating SRT as if it were UDP, which will at worst drop packets that can't be stored in the buffer, but you can always resume reading and everything's ok). Anyway, from the latest SRT's messages this will be known - how many packets are waiting for the right time (so it's SRT to keep them) and how many packets are waiting for the application to be picked up (so it's the application).

@ggreco
Copy link

ggreco commented Mar 15, 2023

Version 1.5.1 here, I'm getting something like this while startupping a stream with a huge probe buffer in ffmpeg since the keyframe are sparse:

[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] decode_slice_header error
[h264 @ 0x7fc71e86b400] no frame!
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] decode_slice_header error
[h264 @ 0x7fc71e86b400] no frame!
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] decode_slice_header error
[h264 @ 0x7fc71e86b400] no frame!
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] sps_id 0 out of range
[h264 @ 0x7fc71e86b400] non-existing PPS 0 referenced
[h264 @ 0x7fc71e86b400] decode_slice_header error
[h264 @ 0x7fc71e86b400] no frame!
[h264 @ 0x7fc71f88c000] co located POCs unavailable
[h264 @ 0x7fc71f88c000] co located POCs unavailable
15:10:32.011497/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580591, insert offset 0. Space avail 0/339 pkts. (TSBPD ready in -280ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:32.012617/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580592, insert offset 1. Space avail 0/339 pkts. (TSBPD ready in -281ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:32.998721/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580593, insert offset 2. Space avail 0/339 pkts. (TSBPD ready in -1267ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:32.998772/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580594, insert offset 3. Space avail 0/339 pkts. (TSBPD ready in -1267ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.008760/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580597, insert offset 6. Space avail 0/339 pkts. (TSBPD ready in -1277ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.008788/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580598, insert offset 7. Space avail 0/339 pkts. (TSBPD ready in -1277ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.018906/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580604, insert offset 13. Space avail 0/339 pkts. (TSBPD ready in -1287ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.018998/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580605, insert offset 14. Space avail 0/339 pkts. (TSBPD ready in -1287ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.028949/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580616, insert offset 25. Space avail 0/339 pkts. (TSBPD ready in -1297ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.029116/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580617, insert offset 26. Space avail 0/339 pkts. (TSBPD ready in -1297ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.038952/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580623, insert offset 32. Space avail 0/339 pkts. (TSBPD ready in -1307ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.039003/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580624, insert offset 33. Space avail 0/339 pkts. (TSBPD ready in -1307ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.049094/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580632, insert offset 41. Space avail 0/339 pkts. (TSBPD ready in -1317ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.049173/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580633, insert offset 42. Space avail 0/339 pkts. (TSBPD ready in -1317ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.059151/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580640, insert offset 49. Space avail 0/339 pkts. (TSBPD ready in -1327ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.059205/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580641, insert offset 50. Space avail 0/339 pkts. (TSBPD ready in -1327ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.069266/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580649, insert offset 58. Space avail 0/339 pkts. (TSBPD ready in -1338ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.069312/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580650, insert offset 59. Space avail 0/339 pkts. (TSBPD ready in -1338ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.079313/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580657, insert offset 66. Space avail 0/339 pkts. (TSBPD ready in -1348ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.079358/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580658, insert offset 67. Space avail 0/339 pkts. (TSBPD ready in -1348ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.089425/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580666, insert offset 75. Space avail 0/339 pkts. (TSBPD ready in -1358ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.089471/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580667, insert offset 76. Space avail 0/339 pkts. (TSBPD ready in -1358ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.
15:10:33.099408/!W:SRT.qr: @1021962991:No room to store incoming packet seqno 1115580675, insert offset 84. Space avail 0/339 pkts. (TSBPD ready in -1368ms, timespan 394 ms). MACH_ABSTIME drift 0 ms.

I tried raising rcvbuf but it seems the problem here is with the packet number, it's possible to raise that one?

@ethouris
Copy link
Collaborator

ethouris commented Mar 15, 2023

The time in "TSBPD ready in" is the time remaining for the earliest packet that is ready for extraction (that is, in non-blocking mode this long time should be waited until the call to srt_recv* function, and in blocking mode this call will block for that long time).

If this time is negative, it means that the application doesn't read packets from the SRT socket fast enough (not as fast as they come in, or by some reason it has stopped or paused doing it).

@duffxp
Copy link

duffxp commented Nov 17, 2023

Hello.

I'm using srt-live-transmit for an SRT in listener mode while generating a multicast from that source.

I already made the recommended change:

┌─[lab@debian]─[~/srt]─[13:04:38]
└──╼ $ cat /proc/sys/net/core/rmem_max 
26214400

But even so, I still get the following log after some running time (≃12 minutes):

SRT parameters specified:

        mode = 'listener'
Opening SRT source listener on 192.168.10.52:5070
Binding a server on 192.168.10.52:5070 ...
 listen...
Multicast: home address: 10.50.3.169:5070
Multicast(POSIX): will bind to IGMP address: 234.50.99.200
 accept...
 connected.
Accepted SRT source connection
12:13:01.256038/SRT:RcvQ:w1!W:SRT.qr: @183037812: No room to store incoming packet seqno 1321227993, insert offset 8191. iFirstUnackSeqNo=1321219802 m_iStartSeqNo=1321219802 m_iStartPos=6605 m_iMaxPosOff=8191. Space avail 8191/8192 pkts. GETTIME_MONOTONIC drift 0 ms.
12:13:01.257595/SRT:RcvQ:w1!W:SRT.qr: @183037812: No room to store incoming packet seqno 1321227994, insert offset 8192. iFirstUnackSeqNo=1321219802 m_iStartSeqNo=1321219802 m_iStartPos=6605 m_iMaxPosOff=8191. Space avail 8191/8192 pkts. GETTIME_MONOTONIC drift 0 ms.
12:13:01.259440/SRT:RcvQ:w1!W:SRT.qr: @183037812: No room to store incoming packet seqno 1321227995, insert offset 8193. iFirstUnackSeqNo=1321219802 m_iStartSeqNo=1321219802 m_iStartPos=6605 m_iMaxPosOff=8191. Space avail 8191/8192 pkts. GETTIME_MONOTONIC drift 0 ms.
12:13:01.261164/SRT:RcvQ:w1!W:SRT.qr: @183037812: No room to store incoming packet seqno 1321227996, insert offset 8194. iFirstUnackSeqNo=1321219802 m_iStartSeqNo=1321219802 m_iStartPos=6605 m_iMaxPosOff=8191. Space avail 8191/8192 pkts. GETTIME_MONOTONIC drift 0 ms.
12:13:01.262178/SRT:RcvQ:w1!W:SRT.qr: @183037812: No room to store incoming packet seqno 1321227997, insert offset 8195. iFirstUnackSeqNo=1321219802 m_iStartSeqNo=1321219802 m_iStartPos=6605 m_iMaxPosOff=8191. Space avail 8191/8192 pkts. GETTIME_MONOTONIC drift 0 ms.

The encoder that is generating and transmitting the stream (obviously configured in caller mode) is configured at a bitrate of 6 Mbp/s. So, this is well below what could possibly cause a problem.

I'm using v1.5.3 and using this script:

#!/bin/bash

log_file="$(date +%Y-%m-%d).log"

start_stream() {
    /home/lab/srt/srt-live-transmit "srt://192.168.10.52:5070?mode=listener" -buffering:4 -chunk:1456 "udp://234.50.99.200:5070?adapter=10.50.3.169&rcvbuf=67108864" -v >> "$log_file" 2>&1
}

start_stream

@maxsharabayko
Copy link
Collaborator

@quintanaplaca Please see Configuration Guidelines

@ethouris
Copy link
Collaborator

I'm taking a look at what should be in this log and this condition seems not to be satisfied (as the content of it isn't printed in the log):

    if (m_tsbpd.isEnabled() && m_iMaxPosOff > 0)
    {

As m_iMaxPosOff is shown above and it's greater than 0, it means that you have TSBPD turned off. This is weird because this option is turned on by default and not modified in this command line. Might be though that it can be off if one side modified it.

@duffxp
Copy link

duffxp commented Nov 17, 2023

This is my first real contact with this protocol, so I feel like I missed something. However, even though it has a higher limit than expected, I think it should work.

Anyway, I did a simple test, but reversing the request side; that is, now I am as caller and the encoder as listener, and this has been working for over an hour:


Input #0, mpegts, from 'srt://{IP}:5070?mode=caller&latency=200000&maxbw=12399073&fc=102400&rcvbuf=48234496':
...
frame=125614 fps= 33 q=-1.0 size= 2674911kB time=01:03:31.69 bitrate=5748.8kbits/s speed=   1x    

So I suspect this is related to the listener ---> UDP or the lack of parameters on the receive (when I put it on the output instead). That is, something like:

srt://192.168.10.52:5070?mode=listener latency=200000&maxbw=12399073&fc=102400&rcvbuf=48234496" -buffering:4 -chunk:1316 "udp://234.50.99.200:5070?adapter=10.50.3 .169"

@ethouris
Copy link
Collaborator

The main reason for a receiver buffer overflow is that the application doesn't read packets as fast as the new ones come in. In live mode the situation is a bit specific because:

  • the sender can't stop sending just because the buffer is full (unlike in file mode)
  • some packets remain in the buffer as "latency compensation"

The latency compensation is simply the number of packets that represent the duration equal to the latency value - so it depends on the stream bitrate and the latency value. Might be that the default buffer size is not big enough for this - that should be checked with the guidelines, as Max showed you above.

Theoretically the latency compensation is the only reason for buffering, but for safety reasons the buffer should also have space for:

  • application compensation (the application delays with reading packets that should be extracted already)
  • flight improvement compensation (packets arrive from the network earlier than expected because network conditions have improved)

They should be normally empty, but they might temporarily grow and lead to buffer overflow if they grow too big.

We were suspecting many times problems with TSBPD calculation, which could result in that the latency compensation fragment of the buffer is temporarily too big. We have never detected for sure such a case so far, but then just in case this information about the TSBPD time span in the buffer is added to this log. As you didn't have it in your log, this is weird, but it must have resulted from some different settings set on the connection sides. But this information is vital to detect, what the reason was for this to happen.

@duffxp
Copy link

duffxp commented Nov 18, 2023

@ethouris, Thank you for your detailed explanation on the topic.

The flow has been working for almost a day, as I reported in the previous post. Anyway, I intend to debug that logic (receiving stream as listener and generating UDP) and share it with you.

I'm just a little worried because I'm using the latest version of the repository, and I did as per the guide, without removing any parameter that would imply hiding information about the TSBPD.

I may try to build this again.

@ethouris
Copy link
Collaborator

Note that settings set only on one side may influence the whole process, that is, apply to the peer, too. Therefore make sure what options are set on both connection sides.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
[core] Area: Changes in SRT library core Type: Maintenance Work required to maintain or clean up the code
Projects
None yet
Development

No branches or pull requests