Incorrect timestamp processing

[PyvesB]

Hello,

We are currently using the Red5 Client module to consume an RTMP input stream and proxy it to a different output destination. Nevertheless, Red5 seems to be ignoring most RTMP messages and streaming is not working as expected. See the following debug logs:

2018-09-12 13:55:34.206 DEBUG org.red5.client.net.rtmp.RTMPMinaIoHandler - messageReceived
2018-09-12 13:55:34.206 DEBUG org.red5.client.net.rtmp.RTMPConnManager - Getting connection by session id: AZZRP5I8SU291
2018-09-12 13:55:34.206 DEBUG org.red5.server.api.Red5 - Set connection: AZZRP5I8SU291 with thread: NioProcessor-75
2018-09-12 13:55:34.206 DEBUG org.red5.server.api.Red5 - Caller: org.red5.client.net.rtmp.RTMPMinaIoHandler.messageReceived #136
2018-09-12 13:55:34.206 DEBUG org.red5.server.net.rtmp.RTMPConnection - Executor is null on AZZRP5I8SU291 state: connected
2018-09-12 13:55:34.206 DEBUG org.red5.client.net.rtmp.BaseRTMPClientHandler - NetStream dispatchEvent: Video - ts: -837759002 length: 140
2018-09-12 13:55:34.206 DEBUG org.red5.client.net.rtmp.BaseRTMPClientHandler - publishStreamData - stream data map: {1.0=org.red5.client.net.rtmp.BaseRTMPClientHandler$NetStreamPrivateData@1497d1d9}
2018-09-12 13:55:34.206 DEBUG org.red5.server.stream.consumer.ConnectionConsumer - Message timestamp: -837759002
2018-09-12 13:55:34.206 DEBUG org.red5.server.stream.consumer.ConnectionConsumer - Message has negative timestamp: -837759002

The code responsible for this behaviour is coming from red5-server-common, in the pushMessage method. If an incoming RTMP message has a negative timestamp, it is simply ignored.

Monitoring the source RTMP input with the rtmpdump tool shows that none of the timestamps that are sent to Red5 are negative. However, they have large values, more specifically between 2³¹ and 2³². The IRTMPEvent defines the timestamp as int, which is a signed data type ranging from -2³¹ and 2³¹ - 1. Any value between 2³¹ and 2³² -1 will overflow and be interpreted as a negative timestamp by Red5.

Adobe's official RTMP specification states the following:

Timestamps in RTMP are given as an integer number of milliseconds relative to an unspecified epoch. Typically, each stream will start with a timestamp of 0, but this is not required, as long as the two endpoints agree on the epoch. Note that this means that any synchronization across multiple streams (especially from separate hosts) requires some additional mechanism outside of RTMP.

Because timestamps are 32 bits long, they roll over every 49 days, 17 hours, 2 minutes and 47.296 seconds. Because streams are allowed to run continuously, potentially for years on end, an RTMP application SHOULD use serial number arithmetic [RFC1982] when processing timestamps, and SHOULD be capable of handling wraparound. For example, an application assumes that all adjacent timestamps are within 2^31 - 1 milliseconds of each other, so 10000 comes after 4000000000, and 3000000000 comes before 000000000.

Timestamp deltas are also specified as an unsigned integer number of milliseconds, relative to the previous timestamp. Timestamp deltas may be either 24 or 32 bits long.

If my understanding is correct, according to the specification RTMP applications should be using unsigned integer arithmetic and not assume that timestamps start at 0 at the beginning of each stream.

Two of our current encoder vendors currently can't be used in conjunction with Red5 as they don't start the timestamp at 0 and may use a value between 2³¹ and 2³². Even for encoder vendors who reset their timestamps to 0, we believe that if the stream has been running for more than 24 days, 20 hours, 31 minutes and 23.648 seconds (2³¹ milliseconds), it will suddenly break down as the timestamps will be interpreted as negative by Red5 past that point.

Thanks in advance for your help!

Regards,

Pyves

[solomax]

@mondain I tried to address this one, but this seems to require lots of changes :((
I can't just change all timestmps to be long
Integer.toUnsignedLong should also be used with care :(

[mondain]

@Andy--S I know you've done a lot of work with timestamps; would you like to weigh-in on this?

[Andy--S]

It is correct that dropping negatives on a signed integer will limit live streams to 50% or their potential duration if the timestamps start at zero. more if they have an arbitrary start.

Ideally red5 wants a zero timestamp for the 'creationTime' of the ClientBroadcastStream.
As a workaround, subtract the first timestamp from all timestamps so your first video packet has a zero timestamp. Watch out for your source's timestamps roll over as well. might be 90,000 or whatever, and use the difference between the frame times to increment. (time+=delta)/scale convert to red5 milliseconds as needed.

[PyvesB]

Thank you for your responses.

Just to clarify, are there any plans on the Red5 team implementing a fix for this? I appreciate @solomax's observation that it would require a lot of changes, but such an issue is unlikely to be properly fixed by first time contributors unfamiliar with the Red5 code basis.

Is there any specific reason why Red5 discards RTMP messages if the int value is negative (see this code line)? More straightforward workarounds could consist in either removing the return statement or replacing it by a roll over of big unsigned timestamps 2³¹ and 2³² - 1 to timestamps between 0 and 2³¹ - 1. I have tested such fixes on a modified version of Red5, video streaming is working as expected on downstream platforms.