the mina iosession.write packets can't keep up with mina recv

[airmelody5211]

Issue

Short description

the mina iosession.write packets can't keep up with mina recv, so that in the function pushMessage (in the playEngine.java) will drop packet because the RED5 consider client has insufficient bandwidth. In fact the bandwidth is enough, and the Issues 100% reproduce

Environment

Intel(R) Xeon(R) CPU E5620 @ 2.40GHz 12 threads 8G memory 1T Strorage
[] Operating system and version: centos 6.5 kernel 2.6.32
[] Java version: JDK1.7.0_75
[] Red5 version:red5-1.0.0-RC1

the RED5 property, i set the paramter as follow
rtmp.io_threads=16
rtmp.connect_threads=4
rtmp.send_buffer_size=271360
rtmp.receive_buffer_size=65536
rtmp.ping_interval=1000
rtmp.max_inactivity=60000
rtmp.tcp_nodelay=true

Expected behavior

start up Red5 application, publish a stream , and only one user to play the stream, there should fluent all the time.

Actual behavior

start up Red5 application, publish a stream , and only one user to play the stream, some times later
the penddingVideoMessage is arise, more and more. Finally, the RED5 drop the packet when the pendingVideoMessage count large than maxPendingVideoFramesThreshold

Steps to reproduce

1. start up Red5 application
2. publish a stream
3. play the published stream

Logs

Line 4517: 2017-03-08 17:16:49,974 [NioProcessor-3] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 1, type 9, timeStamp 11456
Line 4520: 2017-03-08 17:16:49,978 [NioProcessor-3] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 4, timeStamp 0
Line 4526: 2017-03-08 17:16:49,984 [NioProcessor-3] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 1, type 8, timeStamp 11471
Line 4532: 2017-03-08 17:16:50,008 [NioProcessor-3] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 1, type 8, timeStamp 11494
Line 4627: 2017-03-08 17:16:50,194 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 4818: 2017-03-08 17:16:50,586 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 4940: 2017-03-08 17:16:50,841 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 5063: 2017-03-08 17:16:51,091 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 5125: 2017-03-08 17:16:51,218 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 5468: 2017-03-08 17:16:51,939 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 6892: 2017-03-08 17:16:54,837 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 8317: 2017-03-08 17:16:57,755 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 10806: 2017-03-08 17:17:02,850 [NioProcessor-2] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 0, type 3, timeStamp 0
Line 12127: 2017-03-08 17:17:05,578 [NioProcessor-3] WARN o.r.server.net.rtmp.RTMPConnection - RTMPConnection messageSent streamId 1, type 9, timeStamp 11496

there 10 seconds no packets sent success, And the emergence of the cyclical

[solomax]

I believe this issue is caused by not configurable maxPendingVideoFramesThreshold and maxSequentialPendingVideoFrames in https://github.com/Red5/red5-server-common/blob/master/src/main/java/org/red5/server/stream/PlayEngine.java#L156

@mondain is aware of this :) hope this parameters will be configurable soon :)

[airmelody5211]

I believe this issue is caused by not configurable maxPendingVideoFramesThreshold and maxSequentialPendingVideoFrames in https://github.com/Red5/red5-server-common/blob/master/src/main/java/org/red5/server/stream/PlayEngine.java#L156

@mondain is aware of this :) hope this parameters will be configurable soon :)

Hi, solomax
thanks for your answer :) .
Actually, I have set the maxPendingVideoFramesThreshold=maxSequentialPendingVideoFrames=2500,
When the publisher fps is 25, it's means 100 seconds data.
I confused is why the messageSent should be suspend 10 seconds(not fixed, The periodic suspend some time), so that the pendingVideoCount will large than the maxPendingVideoFramesThreshold. I think it's no matter with the value of maxPendingVideoFramesThreshold, Because if the messageSent is slower than messageRecv, This will certainly into the dropPacket case.
At the beginning, I doubt that is mina's issue. And I look up mina's Api document find the iosession.write is Async, so I tried use the writeFuture.awit(), But it will block the thread... at last i give up this way.
And also i doubt it's mina's version issue, and i write a case test mina 2.0.2. and mina 2.0.13 (A simple case just print the iosession.wirte time difference with messageSent). the test result is validates the mina is works fine.
Could you give me some suggestions to solve the problem
Looking forward to your answer
Best Regards

[solomax]

Hello @airmelody5211 it seems you dig in the problem 👍
@mondain Can you comment this?
I'll try to check the code, since our users has the same problem :(

[airmelody5211]

Hi solomax,
Today I have a new discovery, when I publish a stream by camera, it send rate in strict with 25 fps , and the pendingVideoCount never arise. But when I publish a stream by jmeter use a media file.(the file fps is 25), the jemter send rate faster than the file true fps may arrived 30fps, in this case, the pendingVideoCount is very faster to exceed the maxPendingVideoFramesThreshold.
And I still doubt mina, I add executor (either orderThreadPoolExecutor or unorderedThreadPoolExecutor) to the mina ChainFilter, expect use threadPool to accelerate send rate, but it didn't work.
If you have any progress, please tell me, thank you!
Best Regards

[solomax]

We face this issue using ffmpeg:
While sending video stream to the scope using ffmpeg -re

[airmelody5211]

yeah, our product could control the fps in strict. I confused is the red5 is just a forward server, even if the send rate is faster, it should still can do well.

[solomax]

@airmelody5211 could you check if M6 works better for you?

additionally maxPendingVideoFramesThreshold and maxSequentialPendingVideoFrames are now configurable via red5.properties

[airmelody5211]

Hi, @solomax
Recently, I catch the tcpdump when the pendingVideoCount is increasingly, the tcpdump has very more TCP Zero Window packets, which is come from the receiver. So i think it's maybe the Receiver is decoder According to FPS, If the red5 send data more than fps or network jitter, may cause the TCP Window FULL.
And red5 recv the packets will stop send data. do you think it possible ?

[mondain]

Bugs #191 and #192 may be related to this.