[Solved] Slight Visual Studder with TrueHD 7.1 Audio Track

Have a MythTV related problem? Ask for help from other MythTV users here.

Moderator: Forum Moderators

User avatar
mark_k
Developer
Posts: 61
Joined: Tue Jan 28, 2020 3:14 pm
Great Britain

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by mark_k »

So good news and bad news.

The good news is that both samples play without issue using TrueHD passthrough to the Onkyo receiver. The bad news - well, I can't reproduce the problem.

I've created a log using 'mythfrontend -v playback,audio' :-

https://pastebin.com/enCcM4yj

This is an Intel Coffeelake system, HDMI connection to an Onkyo TX-NR50 with VAAPI decoding and (as per the logs) passthrough enabled. Playback is the second posted sample.

Per the logs there is a small amount of jitter in the framerate - but this is primarily because the display is 60Hz.

I have no audio or video issues.

Can anyone create a similar log with v31/fixes for comparison when the problem is seen?

Regards
Mark
Lost Dog
Junior
Posts: 36
Joined: Sat Feb 08, 2014 4:18 pm
United States of America

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by Lost Dog »

Sorry for the delay on this... Here's what I've got. I used a .mkv rip of the Wonder Woman bluray. It has a TrueHD track that usually causes significant studder. Oddly, I had two segfaults when trying to play the video. Once it happened right when I started and another when I switched from TrueHD to 5.1 then back to TrueHD (the instant I selected the TrueHD audio track it segfaulted). Finally got it playing. I tried several times and a few times it played flawlessly. The rest was really bad. Switching to the 5.1 track fixed the issue.

Relevant info:

Code: Select all

myth@htpc ~ $ mythfrontend --version
Please attach all output as a file in bug reports.
MythTV Version : v31.0-10-gaa63cae341
MythTV Branch : fixes/31
Network Protocol : 91
Library API : 31.20200101-1
QT Version : 5.9.5
Options compiled in:
 linux profile use_hidesyms using_alsa using_pulse using_backend using_bdjava using_bindings_perl using_bindings_python using_bindings_php using_dvb using_frontend using_hdhomerun using_vbox using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_lirc using_mheg using_opengl using_egl using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_v4l2prime using_x11 using_libbluray_external using_xrandr using_profiletype using_systemd_notify using_systemd_journal using_drm using_bdjava using_bindings_perl using_bindings_python using_bindings_php using_fontconfig using_freetype2 using_mythtranscode using_opengl using_egl using_drm using_nvdec using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2 using_libmp3lame
Here's a log showing the studder. This was done with playback,audio logging:

https://pastebin.com/wpARD92c



A few highlights that jumped out..

Plenty of these:

Code: Select all

layer(0): AV Sync: Audio ahead by 88 ms
2020-04-01 11:55:24.001463 I  AOBase: Pause 0
2020-04-01 11:55:24.001551 I  Player(0): Dropping frame: Video is behind by 33ms
2020-04-01 11:55:24.001603 I  AOBase: Pause 0
2020-04-01 11:55:24.001620 I  Player(0): AV Sync: Audio ahead by 102 ms
2020-04-01 11:55:24.043468 I  AOBase: Pause 0
2020-04-01 11:55:24.043523 I  Player(0): AV Sync: Audio ahead by 113 ms
Noticed this:

Code: Select all

2020-04-01 11:55:29.061281 I  AOBase: OutputAudioLoop: Play Event
2020-04-01 11:55:29.083822 I  VDPAUInterop: VDPAU display preempted
2020-04-01 11:55:29.083890 E  VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:548 (#3, An invalid handle value was provided.)
2020-04-01 11:55:29.084378 I  OpenGLInterop: Deleted 1 textures in 1 groups
2020-04-01 11:55:29.084405 I  VDPAUInterop: Setup deinterlacer '2x VDPAU Basic'
2020-04-01 11:55:29.084416 E  VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:381 (#3, An invalid handle value was provided.)
2020-04-01 11:55:29.088624 E  AFD: video avcodec_send_packet error: Input/output error (-5) gotpicture:0
2020-04-01 11:55:29.088639 I  AFD: Decoder needs reset
2020-04-01 11:55:29.088656 I  AFD: SeekReset(0, 0, do flush, do discard)
Let me know if you need more info!
User avatar
mark_k
Developer
Posts: 61
Joined: Tue Jan 28, 2020 3:14 pm
Great Britain

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by mark_k »

Thanks for this.

I did switch my Onkyo receiver over to a different system with an NVidia Gt1050 and everything worked without issue again.
Lost Dog wrote:
Thu Apr 02, 2020 5:52 am
Sorry for the delay on this... Here's what I've got. I used a .mkv rip of the Wonder Woman bluray. It has a TrueHD track that usually causes significant studder. Oddly, I had two segfaults when trying to play the video. Once it happened right when I started and another when I switched from TrueHD to 5.1 then back to TrueHD (the instant I selected the TrueHD audio track it segfaulted). Finally got it playing. I tried several times and a few times it played flawlessly. The rest was really bad. Switching to the 5.1 track fixed the issue.

Relevant info:

Code: Select all

myth@htpc ~ $ mythfrontend --version
Please attach all output as a file in bug reports.
MythTV Version : v31.0-10-gaa63cae341
MythTV Branch : fixes/31
Network Protocol : 91
Library API : 31.20200101-1
QT Version : 5.9.5
Options compiled in:
 linux profile use_hidesyms using_alsa using_pulse using_backend using_bdjava using_bindings_perl using_bindings_python using_bindings_php using_dvb using_frontend using_hdhomerun using_vbox using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_lirc using_mheg using_opengl using_egl using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_v4l2prime using_x11 using_libbluray_external using_xrandr using_profiletype using_systemd_notify using_systemd_journal using_drm using_bdjava using_bindings_perl using_bindings_python using_bindings_php using_fontconfig using_freetype2 using_mythtranscode using_opengl using_egl using_drm using_nvdec using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2 using_libmp3lame
Here's a log showing the studder. This was done with playback,audio logging:

https://pastebin.com/wpARD92c



A few highlights that jumped out..

Plenty of these:

Code: Select all

layer(0): AV Sync: Audio ahead by 88 ms
2020-04-01 11:55:24.001463 I  AOBase: Pause 0
2020-04-01 11:55:24.001551 I  Player(0): Dropping frame: Video is behind by 33ms
2020-04-01 11:55:24.001603 I  AOBase: Pause 0
2020-04-01 11:55:24.001620 I  Player(0): AV Sync: Audio ahead by 102 ms
2020-04-01 11:55:24.043468 I  AOBase: Pause 0
2020-04-01 11:55:24.043523 I  Player(0): AV Sync: Audio ahead by 113 ms
Noticed this:

Code: Select all

2020-04-01 11:55:29.061281 I  AOBase: OutputAudioLoop: Play Event
2020-04-01 11:55:29.083822 I  VDPAUInterop: VDPAU display preempted
2020-04-01 11:55:29.083890 E  VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:548 (#3, An invalid handle value was provided.)
2020-04-01 11:55:29.084378 I  OpenGLInterop: Deleted 1 textures in 1 groups
2020-04-01 11:55:29.084405 I  VDPAUInterop: Setup deinterlacer '2x VDPAU Basic'
2020-04-01 11:55:29.084416 E  VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:381 (#3, An invalid handle value was provided.)
2020-04-01 11:55:29.088624 E  AFD: video avcodec_send_packet error: Input/output error (-5) gotpicture:0
2020-04-01 11:55:29.088639 I  AFD: Decoder needs reset
2020-04-01 11:55:29.088656 I  AFD: SeekReset(0, 0, do flush, do discard)
Let me know if you need more info!
User avatar
mark_k
Developer
Posts: 61
Joined: Tue Jan 28, 2020 3:14 pm
Great Britain

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by mark_k »

Sorry - hit the submit button a little early there:)

Looking at the logs, it appears as if playback is fine after the display is pre-empted. Does that match what you are seeing?

Once playback has settled down again, it looks like there are no subsequent frame drops. On the other hand, I see no reason why the St.Dev is that high for playback - you are using mode switching, so the display rate matches the video rate - and I would expect St.Dev to be pretty low.

Is there anything else running that could interact with the display driver to cause the pre-emption? Otherwise I'm wondering if it some sort of interaction between the audio and video side of the NVidia drivers. Maybe just coincidence, but the pre-emption happens just after 'AOBase: OutputAudioLoop: Play Event'.

Regards
Mark
pletchtd
Newcomer
Posts: 4
Joined: Sat Mar 28, 2020 7:47 pm
United States of America

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by pletchtd »

Lost Dog wrote:
Thu Apr 02, 2020 5:52 am
Sorry for the delay on this... Here's what I've got. I used a .mkv rip of the Wonder Woman bluray. It has a TrueHD track that usually causes significant studder. Oddly, I had two segfaults when trying to play the video. Once it happened right when I started and another when I switched from TrueHD to 5.1 then back to TrueHD (the instant I selected the TrueHD audio track it segfaulted). Finally got it playing. I tried several times and a few times it played flawlessly. The rest was really bad. Switching to the 5.1 track fixed the issue.
Hi Lost Dog,

I looked at your log and you definitely have alsa buffer size issues that should be addressed.

Code: Select all

2020-04-01 11:55:21.797629 I  AOBase: Opening audio device 'hdmi:CARD=NVidia,DEV=3' ch 8(8) sr 192000 sf signed 16 bit reenc 0
2020-04-01 11:55:21.797638 I  ALSA: OpenDevice hdmi:CARD=NVidia,DEV=3,AES0=6,AES1=0x82,AES2=0x00,AES3=0x01 for passthrough
2020-04-01 11:55:21.799917 I  ALSA: SetParameters(format=2, channels=8, rate=192000, buffer_time=500000, period_time=4)
2020-04-01 11:55:21.800028 I  ALSA: Buffer size range from 16 to 4096
2020-04-01 11:55:21.800035 I  ALSA: Period size range from 8 to 2048
2020-04-01 11:55:21.800055 W  ALSA: Requested 500000us got 21333 buffer time
2020-04-01 11:55:21.800166 I  ALSA: Hardware audio buffer cur: 64 need: 1536 max allowed: 32768
2020-04-01 11:55:21.800195 W  ALSA: Try to manually increase audio buffer with: echo 1536 | sudo tee /proc/asound/card1/pcm9p/sub0/prealloc
At the current setting of 64kB, the buffer only holds 20 milliseconds worth of playback data and the mythfrontend target is to hold 500 milliseconds. With 24fps content, the system is only processing an incoming video frame every 42 millisconds.

7.1 TrueHD (8ch, 192KHz, 16bit) audio is coming in at a nominal bitrate of 3000 KB/sec requiring 16 Bytes/alsa frame. In contrast, 5.1 audio flows in at 2300 KB/sec at 12 Bytes/alsa frame. More channels and higher audio sample rate simply exacerbate buffer issues because the buffer must be fed/drained more quickly.

In one of the playback sequences in your log, audio buffer underruns are occurring which are very destabilizing to playback:

Code: Select all

2020-04-01 11:55:25.095521 I  ALSA: WriteAudio: buffer underrun
2020-04-01 11:55:25.127696 I  AOBase: Pause 0
2020-04-01 11:55:25.127749 I  Player(0): AV Sync: Audio ahead by 550 ms
2020-04-01 11:55:25.127812 I  AOBase: Pause 1
2020-04-01 11:55:25.251043 I  AOBase: OutputAudioLoop: audio paused
2020-04-01 11:55:25.252077 I  AOBase: Pause 0
2020-04-01 11:55:25.252203 I  Player(0): Dropping frame: Video is behind by 110ms
2020-04-01 11:55:25.252264 I  AOBase: Pause 0
2020-04-01 11:55:25.252285 I  Player(0): Dropping frame: Video is behind by 70ms
2020-04-01 11:55:25.252334 I  AOBase: Pause 0
2020-04-01 11:55:25.252358 I  Player(0): AV Sync: Audio ahead by 647 ms
2020-04-01 11:55:25.252395 I  AOBase: Pause 1
2020-04-01 11:55:25.253956 I  AOBase: OutputAudioLoop: audio paused
2020-04-01 11:55:25.255353 I  Player(0): AV Sync: Audio ahead by 546 ms
2020-04-01 11:55:25.295289 I  AOBase: Pause 0
2020-04-01 11:55:25.295318 I  Player(0): Dropping frame: Video is behind by 56ms
2020-04-01 11:55:25.295365 I  AOBase: Pause 0
2020-04-01 11:55:25.295384 I  Player(0): AV Sync: Audio ahead by 464 ms
2020-04-01 11:55:25.295422 I  AOBase: Pause 1
You might try addressing the alsa buffer issue to help address at least one potential contributor.

I have tested some of the clips posted earlier in this thread using 7.1 TrueHD with my Denon x4400 receiver on a 60hz display and observed smooth playback with no issues. This is using NVDEC on a GT1030 card on an i5-8400 machine. As Mark noted in one of his other responses, there is some AV Sync jitter seen in the log associated with the playback of 24fps content on a 60hz display but for me this is not really noticeable in the playback on screen.
Vaska
Junior
Posts: 57
Joined: Fri Sep 01, 2017 11:09 pm
Canada

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by Vaska »

Thanks for investigating this everyone. I was able to get rid of the visual studder by deselecting "HBR passthrough support" in the audio section. My Yamaha AV receiver now shows PCM instead of lighting up with "TrueHD" as it did with the HBR check box & studder. My receiver's information it does show it's playing 3/4/.1 channels when watching the movie with the TrueHD audio track as opposed to only showing 3/2/.1 when I choose the AC3 5.1 track.

I'm a bit confused though. I thought I needed to chose the HBR box in order to bit-stream, but I also thought the AV receiver only shows PCM when I AM actually bit-streaming. So am I bit-streaming now or not? Any chance someone could help me better understand what I'm doing now please?

Thanks again,
Vaska.
Lost Dog
Junior
Posts: 36
Joined: Sat Feb 08, 2014 4:18 pm
United States of America

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by Lost Dog »

Hi all,

Finally got around to testing this again. I increased the also buffer to 3072:

Code: Select all

$ more /proc/asound/card1/pcm9p/sub0/prealloc
3072
Video playback is much better, at least on the one movie I have with TrueHD. I didn't notice any visual studder as I was testing but the playback log was still filled with sync messages:

Code: Select all

2020-04-20 10:08:16.675455 I  Player(0): AV Sync: Audio ahead by 64 ms
2020-04-20 10:08:16.714810 I  AOBase: Pause 0
2020-04-20 10:08:16.753356 I  AOBase: Pause 0
2020-04-20 10:08:16.753413 I  Player(0): AV Sync: Audio ahead by 74 ms
2020-04-20 10:08:16.754023 I  Player(0): FPS:   23.99 Mean: 41682 Std.Dev:  2208 CPUs: 4% 5% 4% 
2020-04-20 10:08:16.792435 I  AOBase: Pause 0
2020-04-20 10:08:16.792494 I  Player(0): AV Sync: Audio behind by 61 ms
2020-04-20 10:08:16.830624 I  AOBase: Pause 0
2020-04-20 10:08:16.830676 I  Player(0): AV Sync: Audio ahead by 56 ms
2020-04-20 10:08:16.873882 I  AOBase: Pause 0
2020-04-20 10:08:16.873937 I  Player(0): AV Sync: Audio behind by 78 ms
2020-04-20 10:08:16.912947 I  AOBase: Pause 0
Not sure if this is an issue or just a standard occurrence. Should the buffer be more than 3072?

Thanks!
Vaska
Junior
Posts: 57
Joined: Fri Sep 01, 2017 11:09 pm
Canada

Re: Slight Visual Studder with TrueHD 7.1 Audio Track

Post by Vaska »

I'm going to mark this as solved. I no longer experience the slight video studder after enabling "HBR Passthrough Support" in Setup/Audio/Advanced Audio Settings. I don't see the "Dolby TrueHD" lights on my Yamaha receiver anymore, but now just see PCM instead. When I show the Yamaha's "Info" about what it's playing I can clearly see that it is a full 7.1 audio track.

Image

Please correct me if I'm wrong, but I'm assuming that the heavy lifting of decoding the surround sound audio track is now being done by MythTV and the nVidia GeForce card that supports TrueHD and passing it to the Yamaha via HDMI as PCM rather than letting the Yamaha receiver process the decoding job.

Thanks again to everyone who took the extra time to investigate this issue for me, that ultimately was probably just a mis-configuration on my end.

Vaska.
Post Reply