Opened 7 years ago

Last modified 7 years ago

#10797 new Bug Report - General

Audio/Video sync problems especially after seeking to start of recording

Reported by: dmoo1790@… Owned by:
Priority: minor Milestone: unknown
Component: MythTV - Video Playback Version: 0.25-fixes
Severity: medium Keywords: audio video sync 0.25 seek
Cc: Ticket locked: no

Description

I have A/V sync problems after upgrading from 0.23 to 0.25. Most noticeable when seeking back to the start of a recording but under other circumstances also. See this post: http://www.mythtv.org/pipermail/mythtv-users/2012-June/334992.html

Attachments (4)

mythfrontend.20120604155806.2992.log.gz (359.4 KB) - added by dmoo1790@… 7 years ago.
mythfrontend log
log_analysis.txt (7.3 KB) - added by David Moore <dmoo1790@…> 7 years ago.
Analysis of log file
mythfrontend.20120609131557.3142.log.gz (162.1 KB) - added by David Moore <dmoo1790@…> 7 years ago.
mythfrontend.20120609132758.3337.log.gz (134.6 KB) - added by David Moore <dmoo1790@…> 7 years ago.
This one has FORCE_DTS_TIMESTAMPS=1

Download all attachments as: .zip

Change History (19)

Changed 7 years ago by dmoo1790@…

mythfrontend log

Changed 7 years ago by David Moore <dmoo1790@…>

Attachment: log_analysis.txt added

Analysis of log file

comment:1 Changed 7 years ago by David Moore <dmoo1790@…>

I tried analysing the log file and found some weird things with timecodes. See attached file log_analysis.txt. This file has extracts from filtering with egrep 'audio timecode|video timecode|DoPlayerSeek?|behind|error' mythfrontend.20120604155806.2992.log

It seems to me there is a genuine bug rather than a config problem on my system. Three reasons: (1) the odd sequence of video/audio timecodes in the log, (2) no problem before upgrading to 0.25 and (3) others in NZ have reported the same behaviour when trying to seek back to the start of a recording.

comment:2 Changed 7 years ago by tralph

Could you try the FORCE_DTS_TIMESTAMPS=1 environment variable? Just run the following command.

FORCE_DTS_TIMESTAMPS=1 mythfrontend

Thanks.

comment:3 in reply to:  2 Changed 7 years ago by David Moore <dmoo1790@…>

Replying to tralph:

Could you try the FORCE_DTS_TIMESTAMPS=1 environment variable? Just run the following command.

FORCE_DTS_TIMESTAMPS=1 mythfrontend

Thanks.

I tried it. Didn't seem to make any difference. Would you like any log info? If so, which log options?

comment:4 Changed 7 years ago by tralph

You need to provide a frontend log with --loglevel debug -v playback,timestamp.

Changed 7 years ago by David Moore <dmoo1790@…>

comment:5 in reply to:  4 ; Changed 7 years ago by David Moore <dmoo1790@…>

Replying to tralph:

You need to provide a frontend log with --loglevel debug -v playback,timestamp.

Done.

comment:6 in reply to:  5 ; Changed 7 years ago by David Moore <dmoo1790@…>

Replying to David Moore <dmoo1790@…>:

Replying to tralph:

You need to provide a frontend log with --loglevel debug -v playback,timestamp.

Done.

Oops. Ignore the file. Forget the enviro variable. Wait one...

Changed 7 years ago by David Moore <dmoo1790@…>

This one has FORCE_DTS_TIMESTAMPS=1

comment:7 in reply to:  6 Changed 7 years ago by David Moore <dmoo1790@…>

Replying to David Moore <dmoo1790@…>:

Replying to David Moore <dmoo1790@…>:

Replying to tralph:

You need to provide a frontend log with --loglevel debug -v playback,timestamp.

Done.

Oops. Ignore the file. Forget the enviro variable. Wait one...

OK. File uploaded with FORCE_DTS_TIMESTAMPS=1 set.

comment:8 Changed 7 years ago by tralph

So the log below definitely shows a timestamp issue right after the audio decoding errors. The audio timestamp jumps way back in time after the decoding error. These errors and timestamps are provided by the ffmpeg demuxer. So it appears that the regression is probably due to the ffmpeg sync done for 0.25. I'm not sure how this should be handled because it's really an ffmpeg bug. The first step is to create a small sample that triggers the issue and then see if the ffmpeg devs might be interested in looking at it.

2012-06-09 13:29:34.008873 D [3337/3401] Decoder avformatdecoder.cpp:3138 (ProcessVideoPacket) - AFD: video packet timestamps reordered 435110682 pts 435134082 dts 435116082 (dts forced)
2012-06-09 13:29:34.008889 I [3337/3401] Decoder avformatdecoder.cpp:3245 (ProcessVideoFrame) - AFD: video timecode 435116082 4834623 4834623 4834503
2012-06-09 13:29:34.009287 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 435115988 435115988 4834622 4834664
2012-06-09 13:29:34.009586 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 435119828 435119828 4834664 4834706
2012-06-09 13:29:34.009874 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 435123668 435123668 4834707 4834749
2012-06-09 13:29:34.015554 D [3337/3401] Decoder avformatdecoder.cpp:3138 (ProcessVideoPacket) - AFD: video packet timestamps reordered 435117882 pts 435126882 dts 435119682 (dts forced)
2012-06-09 13:29:34.015572 I [3337/3401] Decoder avformatdecoder.cpp:3245 (ProcessVideoFrame) - AFD: video timecode 435119682 4834663 4834663 4834623
2012-06-09 13:29:34.016136 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 435127508 435127508 4834750 4834792
2012-06-09 13:29:34.021747 D [3337/3401] Decoder avformatdecoder.cpp:3138 (ProcessVideoPacket) - AFD: video packet timestamps reordered 435121482 pts 435123282 dts 435123282 (dts forced)
2012-06-09 13:29:34.021765 I [3337/3401] Decoder avformatdecoder.cpp:3245 (ProcessVideoFrame) - AFD: video timecode 435123282 4834703 4834703 4834663
2012-06-09 13:29:34.021853 E [3337/3401] Decoder avformatdecoder.cpp:4216 (ProcessAudioPacket) - AFD: Unknown audio decoding error
2012-06-09 13:29:34.021860 E [3337/3401] Decoder avformatdecoder.cpp:4216 (ProcessAudioPacket) - AFD: Unknown audio decoding error
2012-06-09 13:29:34.022245 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 424763348 424763348 4719592 4719634
2012-06-09 13:29:34.022602 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 424767188 424767188 4719635 4719677
2012-06-09 13:29:34.023178 I [3337/3401] Decoder avformatdecoder.cpp:4248 (ProcessAudioPacket) - AFD: audio timecode 424774868 424774868 4719720 4719762

comment:9 Changed 7 years ago by steven@…

I'm also based in NZ and updated to 0.25 today. I haven't tried any DVB-T recordings yet, but with DVB-S material off TVNZ i'm seeing exactly the same issue.

At the moment the only way to re-sync is to exit playback and re-open the file. As soon as I skip forwards, for example to bypass an advert, then sync is totally lost.

comment:10 Changed 7 years ago by Steven Ellis <steven@…>

I've upgraded from MythTV 0.23 to 0.25 and I'm seeing the issue on existing as well as new DVB-S MPEG-2 recordings with MP2 audio.

I'm running a GT220 card with an M2NPV-VM board and an Athlon X2 5050BE CPU.

I noticed that my de-interlacers were disabled during the upgrade so I've turned Advanced 2x back on. Display is generally 1920x1080 50Hz unless I'm watching US content.

All my audio is going out over SPDIF to my amp. I haven't setup audio over HDMI yet with the new upgrade.

In order to get any reasonable sync I need to exit playback and re-enter the file. Otherwise its a real mess.

comment:11 Changed 7 years ago by Steven Ellis <steven@…>

Ok I think I have a fix. Checking logs I saw the following alsa error

Jun 17 20:30:10 mythtv mythfrontend[20861]: E CoreContext audio/audiooutputalsa.cpp:545 (OpenDevice) ALSA: Unable to sufficiently increase ALSA hardware buffer size - underruns are likely

and recommendation

Jun 17 22:36:39 mythtv mythfrontend[26876]: E CoreContext audio/audiooutputalsa.cpp:213 (SetPreallocBufferSize) ALSA: Try to manually increase audio buffer with: echo 128 | sudo tee /proc/asound/card0/pcm1p/sub0/prealloc

I've actually bumped the prealloc up a bit higher to be certain

 echo 256 > /proc/asound/card0/pcm1p/sub0/prealloc

Just tested some files and sync is close to perfect and I'm not seeing any audio centric errors.

Steve

comment:12 Changed 7 years ago by beirdo

Resolution: Invalid
Status: newclosed

Closing as the problem seems to be solved.

comment:13 Changed 7 years ago by peper03@…

Setting the audio buffers to 256 does not solve the problem on my system (they were already set to 256). Even setting them to the maximum of 32768 didn't make any difference. Disabling the setting 'Separate video modes for GUI and TV playback' does seem to fix it but I think there are several variables involved which makes tracking down the cause difficult. See http://www.gossamer-threads.com/lists/mythtv/users/522376#522376

comment:14 Changed 7 years ago by danielk

Resolution: Invalid
Status: closednew

I can still reproduce this.

Steps:

Skip forward 10 minutes Skip back 1 minute Wait 2 seconds Skip back 10 minutes Wait 1 second Skip back 10 minutes

The A/V sync will now be out for a second or two and then jump back into sync.

comment:15 Changed 7 years ago by mark@…

I have the same issue as well. I have tried increasing the prealloc setting to 256, but I'm still seeing AV Sync issues, so I don't think this is fixed.

Note: See TracTickets for help on using tickets.