audio/video recordings out of sync

[Michał Suchoń]

Hi

We are using janus as webrtc server and it works great. However we came across a problem with recording feature.

1. Janus is recording webrtc sessions
2 We process recorded mjr files *video -> webm and *audio -> opus
3. We use ffmpeg to merge opus and webm files into a single webm file without transcoding

When we play the the file there is audio/video sync at the very beginning but it is lost after a couple of minutes. The difference between audio and video is getting bigger and bigger. It is more than 20s at the end of 30 minute long file. I think this is because server has lost some video frames from the user webrtc session and the video file is shorter than audio file. This is perfectly ok to loose some frames as people have different connection quality to the network but we cannot lose sync because of that. The recording is pretty much useless for us. We tried to do some ffmpeg audio/video sync features but it did not fix the problem.

Any help appreciated.

[Lorenzo Miniero]

Losing video frames shouldn't impact anything. The timestamp of the RTP packet is adapted and written in the resulting WebM file, so you should just see some freezes or skipping in that case. Try reconverting the webm the janus-pp-rec tool generates to a different webm, as it can fix some issues (e.g., wrong headers, the dynamic resolution of WebRTC video not all players can digest and so on), and then mix that with the audio file.

L.

[Michał Suchoń]

I have tried creating different webm files and I tried to transcode webm to mp4 (with h.264 video) but all the files are useless. Is it possible that janus-pp-rec is corrupting streams or janus recording module is buggy ? I am worried we spent so much time integrating janus in our project and we never tried if recording is working properly. We never expected that.  Now when the project is almost finished we cannot use recorded files.

Any clues how to solve the problem is appreciated.

[Lorenzo Miniero]

Have you checked which of the two (audio/video) is out of sync? One simple way to check that would be to point the webcam o a clock of some sort, and check the recordings later on to see if the time that has passed matches. Boring but effective.

We never encountered this issue, and are using recording intensively.

L.

[Michał Suchoń]

What tool to you use to merge audio/video files ? Any specific commands ? We tried mkvmerge and ffmpeg.

I will try which to check which stream audio or video is out of sync. I also suspect the problems might be caused by virtual machine so I will install janus on physical machine to compare. 

[Lorenzo Miniero]

ffmpeg mostly, although most of the times we don't mux and replay them synchronously in a web page (see the recordings we do for IETF meeting sessions).

L.

[Lorenzo Miniero]

PS: have you tried replaying the recordings via the Record&Play demo application, to see if the sync gets lost there too?

L.

[mateusz...@4vod.tv]

Hi, I'm from the Michał's team.

Yep, our recordings played using demo are also out from sync. Moreover, even recordings that we did using demo app are unsynchronized. Sample ffmpeg info on pair of converted audio/video media:

Input #0, matroska,webm, from 'rec-3064898812-video.webm':
  Metadata:
    encoder         : Lavf54.20.4
  Duration: 00:33:35.56, start: 0.000000, bitrate: 87 kb/s
    Stream #0:0: Video: vp8, yuv420p, 640x480, SAR 1:1 DAR 4:3, 2 fps, 16.67 tbr, 1k tbn, 1k tbc (default)

 

Input #0, ogg, from 'rec-3064898812-audio.opus':
  Duration: 00:33:34.68, start: 0.020000, bitrate: 33 kb/s
    Stream #0:0: Audio: opus, 48000 Hz, stereo, fltp

As you can see, length differs. Furthermore, differences between audio and video aren't constant in different sessions of the same duration.

Any clues?

[Lorenzo Miniero]

I was starting to think it might have been a problem in setting the pts/dts stuff in the processor, but if even using the Record&Play demo to replay the recording you get a desync, then something's wrong with the RTP timestamps. That demo just goes through the recorded packets and waits the appropriate amount of time before sending each packet (according to the difference in timestamps), so what you replay is exactly what was received. If so, I'm not sure there's anyhing we can do, as the original timestamp is set by the browser, we just "normalize" them.

Can you share a couple of recordings that have this problem? Maybe not too long, and with info on about when a desync can be identified clearly.

L.

[mateusz...@4vod.tv]

Thanks for the quick reply, here you are:

https://drive.google.com/file/d/0ByaDcMOKDcnWX0dWOGZXWW5BUEU/view?usp=sharing 

If you convert these files and compare lengths of corresponding media in ffmpeg, you will see that these values differs. Also, if you merge corresponding files in ffmpeg, you will notice that audio and video are out of sync. Furthermore, if you play this files using demo, they also will be out of sync - I provided necessary nfo files. It's easiest to notice this issue watching videoroom-1434641900807-user-4243922205-955875491330* files (Sync test 1 - 1.nf0).

[Lorenzo Miniero]

The recording you mentioned seems perfectly synchronized (both in the record&play demo and in the muxed video via FFmpeg) for the first 400 seconds (6m40s). At that precise second, you can see/hear it loosing track: I don't know if it's video that is skipping or audio (or both?), as I can't understand what the girls say. Can you confirm it's the same for you too? Not sure why it's happening at that precise instant.

L.

[mateusz...@4vod.tv]

Wow, nice investigation, you're right. Moreover, that exact moment make my vlc crash while watching muxed video. So that's why we couldn't get sync by stretching audio to video length. I'll search now for other out of sync videos and check them for similar moments. 

And what do you think about different audio/video durations every time? Do you think that this problem occurs every time, but it's not so noticable?

[Lorenzo Miniero]

First of all, you'd better re-encode the video files janus-pp-rec generates for the reasons described here:

https://groups.google.com/forum/#!topic/discuss-webrtc/XjUkEOcx3ww

and only mux the resulting video. The WebRTC video has several video resolution changes that tend to confuse media players. A first round of re-encoding fixes that.

About that moment, can you let me know which medium you think is skipping? I definitely can see video jumping, not sure about audio as I don't know if that is a valid sentence or if it's truncated too.

Anyway, I guess this might happen when you have holes in the packets, e.g., missing packets that never arrived (but NACKs should handle that...). That said, in the post-processor we explicitly mark the presentation time for each frame, which means that if a frame is missing, you should see a freezed video until the upcoming frame is rendered at the specified presentation time. It's what happens, for instance, when you don't get a key frame right away (no video for the first seconds, and when the key frame arrives you see something).

L.

[mateusz...@4vod.tv]

I have taken a closer look at the mentioned video. 6:40 is a moment when resolution changes. That causes VLC to crash with error "main error: failed to resize display" and Totem to display some strange things (however it's clear that video was downsized - you can check attached images). Then video goes first, and sound goes afterwards. There is no sound shuttering or lags, so I suppose that it's only a video that skips. After re-encoding and then muxing, video stops crashing and looking weird, but it's still out of sync.

What do you mean by saying "post-processor"? Do you use some additional WebRTC functionalities or Janus plugin to mark each frame?

Images:

https://drive.google.com/file/d/0ByaDcMOKDcnWLUwtLXo0Y3FwVDg/view?usp=sharing

https://drive.google.com/file/d/0ByaDcMOKDcnWOFpZWEZlc0o2cWs/view?usp=sharing

[mateusz...@4vod.tv]

I randomly picked other media from our archive. In this media problem also occurs, but it's slightly different. It's interesting that in this case audio goes first and video goes afterwards. Problem is noticeable from the very beginning, but the reason is probably the same - I can see resolution change in 00:06. I attach mjr files (test2 - guy talking):

https://drive.google.com/file/d/0ByaDcMOKDcnWQ2M4dEtYN2h6RDQ/view?usp=sharing

Ffmpeg info about converted files:

Input #0, ogg, from 'audio.opus':

  Duration: 00:35:23.16, start: 0.000000, bitrate: 29 kb/s

    Stream #0:0: Audio: opus, 48000 Hz, stereo, fltp

Input #0, matroska,webm, from 'video.webm':

  Metadata:

    encoder         : Lavf54.20.4

  Duration: 00:36:36.43, start: 0.000000, bitrate: 172 kb/s

    Stream #0:0: Video: vp8, yuv420p, 1024x576, SAR 1:1 DAR 16:9, 1 fps, 25.42 tbr, 1k tbn, 1k tbc (default)

As you can see, there is above 1 min of difference in duration.

Ffmpeg commands that I use (FYI):

ffmpeg -i $VIDEO.webm -c:v libx264 $VIDEO_converted.mp4

ffmpeg -i $VIDEO_converted.mp4 -i $AUDIO.opus -c:v copy -c:a aac -strict experimental -y $VIDEO_merged.mp4

As before, after re-encoding, video works fine, there is no weird resize issues in Totem and no crashes in VLC, but audio/video is out of sync.

It seems that resolution changes messes up the sync. Unfortunately, it's said that making WebRTC to have fixed resolution is impossible, and can be overcomed in post-processing:

https://groups.google.com/forum/#!topic/discuss-webrtc/XjUkEOcx3ww

But, of course, it doesn't help us, as we lose sync at particular moment of resolution change, and later manipulations won't help.

On the other hand, I recorded some test video using demo (other samples that I provided were recorded using our config, where bitrates and resolutions were quite higher) in which I made some clapping and finger snapping at the end, and that was also out of sync. The problem is, that I couldn't find a moment when resolution changes, not re-encoded video works fine. That may lead to conclusion that losing sync isn't related with resolution changes, what is kinda interesting, as before sync was lost exactly when resolution was changed. I also attach this files (test3 - window and clapping):

https://drive.google.com/file/d/0ByaDcMOKDcnWR1hOYl9ncGZKQ1E/view?usp=sharing

Well, that findings exclude each other. I'm confused.

[Lorenzo Miniero]

The resolution change is not the cause of the desync. I only mentioned it to clarify that you need to re-encode the video, or players are likely to crash: it has nothing to do with the desync. For instance, in the video of the girls talking, there are several resolution changes in the video before the sync happens at about 400s.

The cause is likely different. I'll have to give a deeper look at sequence numbers and timestamps, but I'm not sure I'll have time to do so by the end of the week. I'll try and add some debugging info to the Janus processing tool by tomorrow, so that you guys can also inspect more in depth what is happening and what the tool is doing on your recordings, and as soon as I can I'll do the same.

L.

[mateusz...@4vod.tv]

That's great, thanks a lot. 

[mateusz...@4vod.tv]

After some more investigation I noticed that when I record using demo on localhost (all tests before were performed on cloud virtual machines) audio is exactly one second shorter than video every time, and I have managed to keep this files in sync by adding appropriate offset in ffmpeg using command like this:

ffmpeg  -itsoffset -00:00:01 -i $NAME-video.webm -i $NAME-audio.opus -c:v copy -c:a aac -strict experimental -y output.mkv

The problem is that when some more movement is performed on screen sync is lost. However, after few seconds of calm, video and audio goes back to sync. This scenario repeat every time when some more stuff happens on video. I have tried to increase bitrate and decrease keyframe interval in recordplaytest.js, but it seems that it makes no difference for video size and quality. I must have done something wrong, I haven't took a closer look at this yet.

Maybe this will be a clue for you somehow.

[Lorenzo Miniero]

I added some more debugging info to the post processor, and I also added an option for increased debugging in the post processor. Just pass JANUS_PPREC_DEBUG=5 before the actual command line. Since the debug can be huge, it's best to redirect the output to a file, e.g.,

    JANUS_PPREC_DEBUG=5 /path/to/janus-pp-rec /path/to/file.mjr /path/to/file.webm > debug.log

so that you can inspect it more easily.

I've tried looking at that 1.nfo files, but for both audio and video at about 400s nothing strange happens. All packets seem to be there in the video, no gap in sequence numbers. The audio file is missing three packets, but in different time frames (e.g., ~267 seconds or much layer). I did fix an issue in the audio processing, where the position was always increased by 1 despite any missing frame, but I doubt that was the cause.

Try using the new post processor on the tests you're making, and look for info like "Lost a packet" or too high steps when writing audio frames.

As a side note, you still haven't told me which file is loosing sync. Is it audio? video? is the affected medium faster or slower? Have you checked with the phone trick I told you while speaking on it to evaluate this?

Cheers,

Lorenzo

[mateusz...@4vod.tv]

Thanks a lot, I'll give it a try.

I've told you before about these files: "[after 6:40] Then video goes first, and sound goes afterwards. There is no sound shuttering or lags, so I suppose that it's only a video that skips. ". Moreover, speed of audio and video looks fine. Maybe you would like to know something else - in that case you have to be more specific. Just tell me what you want to know - I'll provide you any informations you want.

I haven't used phone trick, I've just shared my observations regarding existing videos, but I'll try this trick also.

[Lorenzo Miniero]

Sorry, I missed that part. Anyway, the trick I gave you should tell us precisely which medium is wrong, as otherwise all you have are subjective feelings: in fact, without a specific reference (e.g., a digital timer the webcam is pointing at that tells you how much time really passed), you can't know if video is too fast/slow or if it's audio.

My feeling is that audio is to blame, and we're probably doing something wrong with libogg, but that's just what I'm thinking. An explicit confirmation of what we should look into would help.

L.

[mateusz...@4vod.tv]

A few experiments with timer show that videos have correct length. Local test finished with audio 2s shorter once, but in all other cases returned audio was 1s shorter, like in previous cases - I was using up-to-date janus version. I don't know if that's because of your recent fix, but I couldn't get janus to generate media so different in lengths. As you probably remember, first video I showed you - girls talking - has a 14s longer audio, and video with guy talking has 76s shorter audio.

Two first videos were perfectly in sync after muxing with 1s shift. In third test audio was also one second shorter than video, but I haven't managed to get media synchronized - without shifting audio was before video, and with shifting audio was after video - shifting by 0.5s would probably synchronize media. Unfortunately, delay before audio and video isn't predictable. 

Now I'm investigating generated logs.

[mateusz...@4vod.tv]

Interesting thing is that in girls recording there were no video packets lost and only 3 audio packets lost. This video has 14s longer audio and is out of sync. In my today's tests much more packets were lost, but sync was much better.

[Lorenzo Miniero]

But we may be talking of different problems, then...

If audio and video are in sync with each other, but just have different starting times and so moving one of them fixes it, then it's one kind of issue. If audio and video are NOT in sync with each other even by synchronizing their start times, it's a different issue entirely. My main concern is issue #2, as issue #1 may be annoying but it's not something that totally breaks recordings.

Can you confirm that, when #2 happens (if #2 is what you're getting), video is always recorded right, while audio has problems? If so, I know that I have audio to fix, otherwise I may be looking in the wrong direction and I don't want to waste cycles on something that's not broken.

L.

[mateusz...@4vod.tv]

I'm aware that there are two kinds of problems.

After some more tests I have managed to obtain a few recordings containing media with different lengths, so it seems that problem #2 still occurs. 

In general, in some cases problem #2 occurs - media lengths differ much - then everything is messed up and can't be synchronized, and in some cases problem #1 occurs - audio is exactly 1s shorter than video, but shifting media by 1s not always fixes delay - sometimes it's 0.5s, sometimes it's 0.75s - you have to do some attempts, so it can't be automated, what is also a big problem for us.

I have made 4 recordings ~40min where camera was pointing at stopwatch, and I'm sure, that these videos have correct length. 

I've just set up similar recording session, which will last for about 1h, to tell with even larger probability that all videos have correct length.

[Lorenzo Miniero]

I'll try making a version of the opus post processor that uses FFmpeg/libav just as it does for webm, instead of using libogg for the purpose. My guess is that we're doing something wrong with the audio management with libogg, something that may be prevented using FFmpeg/libav instead. That said, I'm not sure all FFmpeg/libav versions out there support Opus: the easiest approach probably is to try FFmpeg/libav and, if it doesn't work, fallback on the existing libogg code instead.

I'll let you know when this can be tried.

L.

[Lorenzo Miniero]

This pull request provides a version of the post processor which can make use of FFmpeg instead if libogg for audio, in case it turns out it's a better way of getting files synced. I haven't tested it yet, so any feedback is welcome: https://github.com/meetecho/janus-gateway/pull/272

L.

[mateusz...@4vod.tv]

Thanks a lot, I'm starting tests.

[mateusz...@4vod.tv]

I'm getting following errors:

Using libogg: false

[31m[ERR] [0m [postprocessing/pp-opus.c:janus_pp_opus_create:100] Error guessing format

[31m[ERR] [0m [postprocessing/janus-pp-rec.c:main:299] Error creating .opus file...

When I do the same using old mode everything works fine.

[Lorenzo Miniero]

I think it means your FFmpeg/libav is too old, or simply does not support writing to Opus containers.

This command will tell you more:

     ffmpeg -formats | grep opus

If Opus is not listed, e.g.:

     E opus            Ogg Opus

then Opus is not supported by your version, and you have to stick to libogg.

L.

[mateusz...@4vod.tv]

Well, it is listed in my ffmpeg formats.

[marius...@4vod.tv]

I got:
Using libogg: false
[opus @ 0x37146c0] No extradata present
[ERR] [postprocessing/pp-opus.c:janus_pp_opus_create:130] Error writing header
[ERR] [postprocessing/janus-pp-rec.c:main:299] Error creating .opus file...

Tested under ubuntu 14.04.2 and Centos7

On Centos 7 I installed fresh ffmpeg from source:
# ffmpeg -formats | grep opus
ffmpeg version N-73368-gdb89f45 Copyright (c) 2000-2015 the FFmpeg developers
  built with gcc 4.8.3 (GCC) 20140911 (Red Hat 4.8.3-9)
  configuration: --enable-libopus
  libavutil      54. 27.100 / 54. 27.100
  libavcodec     56. 46.100 / 56. 46.100
  libavformat    56. 40.100 / 56. 40.100
  libavdevice    56.  4.100 / 56.  4.100
  libavfilter     5. 19.100 /  5. 19.100
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  2.100 /  1.  2.100
  E opus            Ogg Opus

[Lorenzo Miniero]

The "no extradata" thing was fixed already yesterday. That said, I known it's still not working. Unfortunately I don't have much time to look into this right now. Hopefully I'll find some early next week.

L.

[mateusz...@4vod.tv]

I have succeded to convert audio using new branch. I have performed instalation using following script on fresh install of Ubuntu 11.04.2:

#!/bin/bash

aptitude update
aptitude -y full-upgrade
aptitude -y install libmicrohttpd-dev libjansson-dev libnice-dev \
    libssl-dev libsrtp-dev libsofia-sip-ua-dev libglib2.0-dev \
    libopus-dev libogg-dev libini-config-dev libcollection-dev \
    pkg-config gengetopt libtool automake checkinstall git yasm

cd
git clone git://source.ffmpeg.org/ffmpeg
cd ~/ffmpeg
./configure --enable-libopus
make
checkinstall -y --pkgversion="1.0.0"
cd

git clone https://github.com/meetecho/janus-gateway.git
cd ~/janus-gateway
git checkout pprec-opus-libav
sh autogen.sh
./configure --prefix=/opt/janus --enable-post-processing --disable-websockets --disable-data-channels --disable-rabbitmq --disable-docs
make
checkinstall -y --pkgversion="1.0.0"
make configs
cd

Conversion succedeed with following output:

./rec-2215547545-audio.mjr --> ./audio_nolibogg.opus
File is 23034642 bytes
Pre-parsing file to generate ordered index...
This is an audio recording, assuming Opus
Counted 44959 RTP packets
Counted 44959 frame packets
Using libogg: false
[WARN] Lost a packet here? (got seq 50176 after 50171, time ~733s)
[WARN] Lost a packet here? (got seq 50225 after 50192, time ~734s)
[WARN] Lost a packet here? (got seq 50285 after 50244, time ~735s)
[WARN] Lost a packet here? (got seq 50335 after 50320, time ~736s)
[WARN] Lost a packet here? (got seq 50345 after 50343, time ~736s)
[WARN] Lost a packet here? (got seq 50366 after 50360, time ~736s)
[WARN] Lost a packet here? (got seq 53043 after 53010, time ~790s)
[WARN] Lost a packet here? (got seq 53366 after 53364, time ~2107s)
[WARN] Lost a packet here? (got seq 54579 after 54577, time ~2131s)
[WARN] Lost a packet here? (got seq 55190 after 55188, time ~3454s)
./audio_nolibogg.opus is 17987445 bytes
Bye!

Returned data is a lil bit smaller than data obtained using libogg:

-rw-r--r-- 1 mateusz mateusz  17987445 lip  8 11:58 rec-2215547545-audio-nolibogg.opus
-rw-r--r-- 1 mateusz mateusz 221841174 lip  8 11:56 rec-2215547545-video.webm
-rw-r--r-- 1 mateusz mateusz  18074102 lip  8 11:52 rec-2215547545-audio-libogg.opus

In addition, nolibogg data is somehow corrupted - ffmpeg info results for nolibogg version:

[ogg @ 0x4336540] Codec not found
rec-2215547545-audio-nolibogg.opus: End of file

and for libogg version:

Input #0, ogg, from 'rec-2215547545-audio-libogg.opus':
  Duration: 01:20:32.98, start: 0.000000, bitrate: 29 kb/s
    Stream #0:0: Audio: opus, 48000 Hz, stereo, fltp

Moreover, no player can play this file - VLC just does nothing, and Rythmbox says "Can't play file: {null}".

[Lorenzo Miniero]

Yes, the audio processing using FFmpeg/libav is currently broken, I'm afraid.

I'll be quite busy this week and the next so I don't know when I'll be able to come back to more experiments with that.

Any contribution in this sense from the community is more than welcome.

L.

[William MANCON]

Hi lorenzo,
Just to ask if something changed since the last message.
To reduce the risk of sync issues, i modified the videoroom plugin in order to start recording audio & video at the same time (on a key frame). 

But in the case of lost packets, there is always sync issues.
Is the post processor still broken ?

If audio & video starts at the same time, it should be possible to skip "audio" packets on video packet lost, or add silence in the case of audio packet lost.
 

[Lorenzo Miniero]

We modified the mjr header a long time ago, and added some more info there that can help with that, specifically when the file was created and when the first frame written, both in microseconds, and those are written down when you invoke the postprocessor. If you're only interested in the header, pass --header to janus-pp-rec:

    janus-pp-rec --header source.mjr

Besides, when postprocessing video you now also get a message printing out when, relatively speaking, you got the first key frame, meaning you can skip the previous part for syncing reasons (as most tools will jump to that point and ignore the "garbage" before).

Those two pieces of info together can allow you to tell your tools how much time should be skipped on either media.

Lorenzo

[Lorenzo Miniero]

PS: of course the postprocessor must be updated, and the .mjr files must have been created by a more recent version of Janus, that is one that added those info to the headers. janus-pp-rec will still be able to postprocess older mjr files, but you won't get any of that timing information.

L.

[QMING CAI]

any new about this problem does it bug fixed? i have same problem with it....

[Anil Wadghule]

Same issue here.

On Thu, Feb 1, 2018 at 12:14 PM, QMING CAI <cqm...@gmail.com> wrote:

any new about this problem does it bug fixed? i have same problem with it....

--
You received this message because you are subscribed to the Google Groups "meetecho-janus" group.
To unsubscribe from this group and stop receiving emails from it, send an email to meetecho-janus+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Best,

Anil

[Alessandro Amirante]

This is a 2.5 years old thread! As Lorenzo explained, since then you can rely upon the information contained in the mjr header to sync audio with video.

A.