Opened 13 years ago

Closed 12 years ago

#5126 closed defect (fixed)

timestretch: garbled auidio after skipping commerical

Reported by: jppoet@… Owned by: JYA
Priority: minor Milestone: 0.23
Component: MythTV - Audio Output Version: head
Severity: medium Keywords:
Cc: Ticket locked: no

Description

After an (automatic) commercial skip, if timestretch is enabled the audio can become garbled:

2008-04-02 20:38:28.094 VideoOutputXv?: UpdatePauseFrame?() UUUUUUUUUUUuUULUUUUUUUUUUUUUUUA 2008-04-02 20:38:28.095 AFD: DoFastForward?(69397 (57538), do discard frames) 2008-04-02 20:38:28.095 Dec: DoFastForward?(69397 (57538), do discard frames) 2008-04-02 20:38:28.095 AFD: SeekReset?(69390, 7, do flush, do discard) 2008-04-02 20:38:28.096 AFD: SeekReset?() flushing 2008-04-02 20:38:28.096 VideoOutputXv?: DiscardFrames?(1) 2008-04-02 20:38:28.096 VideoBuffers::DiscardFrames?(1): UUUUUUUUUUUUUUAUUUUUUUUUUUUUUUA 2008-04-02 20:38:28.096 VideoBuffers::DiscardFrames?(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2008-04-02 20:38:28.096 VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done 2008-04-02 20:38:28.096 VideoOutputXv?: DiscardFrames?() 3: AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2008-04-02 20:38:28.158 audio stream changed 2008-04-02 20:38:28.158 AFD: Selected track 1: Undetermined AC3 2ch (A/V Stream #1) 2008-04-02 20:38:28.158 AFD: Initializing audio parms from audio track #1 2008-04-02 20:38:28.158 AFD: Audio format changed digital passthrough id( AC3) 48000Hz 2ch 16bps

from id( AC3) 48000Hz 6ch 16bps ; id( AC3) 48000Hz 6ch 16bps to id( AC3) 48000Hz 2ch 16bps ; id( AC3) 48000Hz 2ch 16bps

2008-04-02 20:38:28.158 AO: SetEffDsp?: 4800000 2008-04-02 20:38:28.158 AO: no change exiting 2008-04-02 20:38:28.161 NVP: ClearAfterSeek?(0) 2008-04-02 20:38:28.162 AO: Pause 1 2008-04-02 20:38:28.163 AO: OutputAudioLoop?: audio paused 2008-04-02 20:38:28.165 NVP: Waiting for prebuffer.. 0 AAAaAALAAAAAAAAAAAAAAAAAAAAAAAA 2008-04-02 20:38:28.212 NVP: Waiting for prebuffer.. 1 AAAAAALAALAAAAAAAAAAAAAUAAAAUAA 2008-04-02 20:38:28.235 AO: Pause 0 2008-04-02 20:38:28.235 NVP: Video is 3.24899 frames behind audio (too slow), dropping frame to catch up. 2008-04-02 20:38:28.236 AO: OutputAudioLoop?: Play Event 'video_output' mean = '13362.01', std. dev. = '16040.71', fps = '74.84' 2008-04-02 20:38:28.258 NVP: Video is 14.4554 frames ahead of audio,

doubling video frame interval to slow down.

2008-04-02 20:38:28.282 NVP: Video is 25.2968 frames ahead of audio,

doubling video frame interval to slow down.

2008-04-02 20:38:28.306 NVP: Video is 30 frames ahead of audio,

doubling video frame interval to slow down.

full log attached.

Attachments (1)

timestretch-garbled-audio.log.bz2​ (8.7 KB) - added by jppoet@… 13 years ago.

Download all attachments as: .zip

Change History (9)

Changed 13 years ago by jppoet@…

Attachment: timestretch-garbled-audio.log.bz2​ added

comment:1 Changed 13 years ago by Matt S <skd5aner@…>

Does the audio sound as though it is extremely fast and garbled? I get that sometimes as well, almost randomly. Not sure if this relates to #5113, as I think it's definitely a different symptom but may be caused by the same areas of code?

comment:2 Changed 13 years ago by jppoet@…

Yes, in this particular example it does sound like the audio is greatly sped up.

comment:3 Changed 12 years ago by jppoet@…

When watching a show with Dolby Digital 5.1, the commercials may just be Dolby Digital stereo.

When this happens at 1.0x speed, the audio stream is just passed through to my pre-amp, and it automatically switches from DD5.1 to DD stereo as needed without any problems.

When this happens and timestretch is enabled, the switch from DD5.1 to DD stereo confuses it, and the result is very garbled audio.

In the following log, timestretch is enabled at 2009-06-14 17:00:08.270, and properly handles the DD5.1. A commercial is encountered at 2009-06-14 17:00:32.577 and the audio becomes garbled. It will stay garbled until I quit the show, and re-start playback. 

2009-06-14 17:00:00.746 TV: Attempting to change from None to Watching WatchingPreRecorded
2009-06-14 17:00:04.001 RemoteFile(myth://192.168.0.60:6543/2276_20090613160000.mpg)
2009-06-14 17:00:04.001 TV: StartPlayer(0, Watching WatchingPreRecorded, main) -- begin
2009-06-14 17:00:04.647 AFD: Opened codec 0x44de190, id(H264) type(Video)
2009-06-14 17:00:04.647 AFD: codec AC3 has 6 channels
2009-06-14 17:00:04.647 AFD: Opened codec 0x44de890, id(AC3) type(Audio)
2009-06-14 17:00:04.648 AFD: Audio Track #1 is A/V stream #1 and has 6 channels in the Undetermined language(7695972).
2009-06-14 17:00:04.648 AFD: Selected track 1: Undetermined AC3 5.1ch (A/V Stream #1)
2009-06-14 17:00:04.648 AFD: Initializing audio parms from audio track #1
2009-06-14 17:00:04.648 AFD: Audio format changed digital passthrough id( AC3) 48000Hz  2ch  16bps pt
			from id(NONE)    -1Hz -1ch   0bps    ; id(NONE)    -1Hz -1ch   0bps   
			to   id( AC3) 48000Hz  6ch  16bps pt ; id( AC3) 48000Hz  6ch  16bps pt
2009-06-14 17:00:04.650 AO: Needs upmix
2009-06-14 17:00:04.650 AO: Killing AudioOutputDSP
2009-06-14 17:00:04.650 Opening audio device 'spdif'. ch 6(2) sr 48000
2009-06-14 17:00:04.650 Opening ALSA audio device 'spdif'.
2009-06-14 17:00:04.654 in SetParameters(format=2, channels=6, rate=48000, buffer_time=400000, period_time=25000)
2009-06-14 17:00:04.654 get_buffer_size returned 6553
2009-06-14 17:00:04.654 set_period_time_near returned 25000
2009-06-14 17:00:04.654 get_period_size returned 1200
2009-06-14 17:00:04.657 AO: Audio fragment size: 18432
2009-06-14 17:00:04.658 AO: create upmixer
2009-06-14 17:00:04.661 AO: create upmixer done with surround mode 0
2009-06-14 17:00:04.661 AO: Audio Stretch Factor: 1
2009-06-14 17:00:04.661 Audio Codec Used: not set
2009-06-14 17:00:04.661 AO: Ending reconfigure
2009-06-14 17:00:04.661 AO: Killing AudioOutputDSP
2009-06-14 17:00:04.661 AO: kickoffOutputAudioLoop: pid = 32133
2009-06-14 17:00:04.661 AO: OutputAudioLoop: Stop Event
2009-06-14 17:00:04.661 AO: kickoffOutputAudioLoop exiting
2009-06-14 17:00:04.664 Opening audio device 'spdif'. ch 2(2) sr 48000
2009-06-14 17:00:04.664 Opening ALSA audio device 'spdif'.
2009-06-14 17:00:04.664 in SetParameters(format=2, channels=2, rate=48000, buffer_time=400000, period_time=25000)
2009-06-14 17:00:04.665 get_buffer_size returned 6553
2009-06-14 17:00:04.665 set_period_time_near returned 25000
2009-06-14 17:00:04.665 get_period_size returned 1200
2009-06-14 17:00:04.667 AO: Audio fragment size: 6144
2009-06-14 17:00:04.667 AO: Audio Stretch Factor: 1
2009-06-14 17:00:04.667 Audio Codec Used: AC3
2009-06-14 17:00:04.668 AO: Ending reconfigure
2009-06-14 17:00:04.668 AO: kickoffOutputAudioLoop: pid = 32133
2009-06-14 17:00:04.668 AO: OutputAudioLoop: Play Event
2009-06-14 17:00:04.726 AO: no change exiting
2009-06-14 17:00:04.726 AO: Pause 1
2009-06-14 17:00:04.728 AO: OutputAudioLoop: audio paused
2009-06-14 17:00:04.789 VideoOutputXv: XVideo Adaptor Name: 'NV17 Video Texture'
2009-06-14 17:00:04.898 OSD Theme Dimensions W: 1280 H: 720
2009-06-14 17:00:05.238 TV: StartPlayer(0, Watching WatchingPreRecorded, main) -- end ok
2009-06-14 17:00:05.240 TV: Changing from None to Watching WatchingPreRecorded
2009-06-14 17:00:05.240 AO: Pause 1
2009-06-14 17:00:05.240 New DB connection, total: 3
2009-06-14 17:00:05.241 The realtime priority setting is not enabled.
2009-06-14 17:00:05.241 AO: OutputAudioLoop: audio paused
2009-06-14 17:00:05.256 Connected to database 'mythconverg' at host: 192.168.0.60
2009-06-14 17:00:05.259 Couldn't load deinterlace filter none
2009-06-14 17:00:05.260 OpenGLVideoSync()
2009-06-14 17:00:05.268 Setting  volume to 0
2009-06-14 17:00:05.268 Setting  volume to 0
2009-06-14 17:00:05.268 muting sound 1
2009-06-14 17:00:05.301 Video timing method: SGI OpenGL
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]mmco: unref short failure
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.342 AFD Error: Unknown decoding error
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.342 AFD Error: Unknown decoding error
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.342 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.342 AFD Error: Unknown decoding error
2009-06-14 17:00:05.349 [h264 @ 0x7f99953d2840]mmco: unref short failure
2009-06-14 17:00:05.483 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.484 AFD Error: Unknown decoding error
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.484 AFD Error: Unknown decoding error
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:05.484 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:05.484 AFD Error: Unknown decoding error
2009-06-14 17:00:05.686 AO: Pause 0
2009-06-14 17:00:06.101 Setting  volume to 100
2009-06-14 17:00:06.101 Setting  volume to 100
2009-06-14 17:00:06.101 unmuting sound 0
2009-06-14 17:00:08.262 AFD: Disabling pass through
2009-06-14 17:00:08.262 AFD: Initializing audio parms from audio track #1
2009-06-14 17:00:08.262 AFD: Audio format changed digital passthrough id( AC3) 48000Hz  6ch  16bps   
			from id( AC3) 48000Hz  6ch  16bps pt ; id( AC3) 48000Hz  6ch  16bps pt
			to   id( AC3) 48000Hz  6ch  16bps    ; id( AC3) 48000Hz  6ch  16bps   
2009-06-14 17:00:08.262 AO: SetEffDsp: 4800000
2009-06-14 17:00:08.262 AO: Killing AudioOutputDSP
2009-06-14 17:00:08.263 AO: OutputAudioLoop: Stop Event
2009-06-14 17:00:08.263 AO: kickoffOutputAudioLoop exiting
2009-06-14 17:00:08.266 Opening audio device 'spdif'. ch 2(2) sr 48000
2009-06-14 17:00:08.266 Opening ALSA audio device 'spdif'.
2009-06-14 17:00:08.267 in SetParameters(format=2, channels=2, rate=48000, buffer_time=400000, period_time=25000)
2009-06-14 17:00:08.267 get_buffer_size returned 6553
2009-06-14 17:00:08.267 set_period_time_near returned 25000
2009-06-14 17:00:08.267 get_period_size returned 1200
2009-06-14 17:00:08.270 AO: Audio fragment size: 6144
2009-06-14 17:00:08.270 AO: Audio Stretch Factor: 1
2009-06-14 17:00:08.270 Audio Codec Used: AC3
2009-06-14 17:00:08.270 AO: Ending reconfigure
2009-06-14 17:00:08.270 AO: Using time stretch 1.5
2009-06-14 17:00:08.270 AO: kickoffOutputAudioLoop: pid = 32133
2009-06-14 17:00:08.270 AO: OutputAudioLoop: Play Event
2009-06-14 17:00:08.270 AO: Creating Encoder for codec 86020 origfs 1536
2009-06-14 17:00:08.270 DEnc: Init codecid=AC3, br=384000, sr=48000, ch=6
2009-06-14 17:00:08.270 DigitalEncoder::Init fs=1536, bpf=12 ofb=18432
2009-06-14 17:00:08.366 NVP(0): prebuffering pause
2009-06-14 17:00:08.366 AO: Pause 1
2009-06-14 17:00:08.367 AO: OutputAudioLoop: audio paused
2009-06-14 17:00:08.468 AO: Pause 0
2009-06-14 17:00:08.470 AO: OutputAudioLoop: Play Event
2009-06-14 17:00:12.987 Setting  volume to 0
2009-06-14 17:00:12.987 Setting  volume to 0
2009-06-14 17:00:12.987 muting sound 1
2009-06-14 17:00:13.020 AO: Pause 1
2009-06-14 17:00:13.021 AO: OutputAudioLoop: audio paused
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]mmco: unref short failure
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:13.074 AFD Error: Unknown decoding error
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:13.074 AFD Error: Unknown decoding error
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]B picture before any references, skipping
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]decode_slice_header error
2009-06-14 17:00:13.074 [h264 @ 0x7f99953d2840]no frame!
2009-06-14 17:00:13.074 AFD Error: Unknown decoding error
2009-06-14 17:00:13.086 [h264 @ 0x7f99953d2840]mmco: unref short failure
2009-06-14 17:00:13.252 AO: Pause 0
2009-06-14 17:00:13.253 AO: OutputAudioLoop: Play Event
2009-06-14 17:00:13.815 Setting  volume to 100
2009-06-14 17:00:13.815 Setting  volume to 100
2009-06-14 17:00:13.815 unmuting sound 0
2009-06-14 17:00:30.022 MythSocket(11df060:40): readStringList: Error, timeout.
2009-06-14 17:00:30.023 Preview Error: Remote Preview failed due to communications error.
2009-06-14 17:00:32.577 audio stream changed
2009-06-14 17:00:32.577 AFD: Selected track 1: Undetermined AC3 2ch (A/V Stream #1)
2009-06-14 17:00:32.577 AFD: Initializing audio parms from audio track #1
2009-06-14 17:00:32.577 AFD: Audio format changed digital passthrough id( AC3) 48000Hz  2ch  16bps   
			from id( AC3) 48000Hz  6ch  16bps    ; id( AC3) 48000Hz  6ch  16bps   
			to   id( AC3) 48000Hz  2ch  16bps    ; id( AC3) 48000Hz  2ch  16bps   
2009-06-14 17:00:32.577 AO: SetEffDsp: 4800000
2009-06-14 17:00:32.577 AO: no change exiting
2009-06-14 17:00:37.998 AO: Pause 1
2009-06-14 17:00:38.002 AO: OutputAudioLoop: audio paused
2009-06-14 17:00:39.430 TV: Attempting to change from Watching WatchingPreRecorded to None
2009-06-14 17:00:39.430 TV: Changing from Watching WatchingPreRecorded to None
2009-06-14 17:00:39.434 ~OpenGLVideoSync() -- closing opengl vsync
2009-06-14 17:00:39.458 AO: Killing AudioOutputDSP
2009-06-14 17:00:39.459 AO: OutputAudioLoop: Stop Event
2009-06-14 17:00:39.459 AO: kickoffOutputAudioLoop exiting

comment:4 Changed 12 years ago by jppoet@…

It looks like audioencoding-trunk-jya15.patch from ​http://svn.mythtv.org/trac/ticket/5900 works around this problem. So, whenever that patch (or equivalent) is applied, this ticket can be closed.

comment:5 Changed 12 years ago by stuartm

Component: mythtv → MythTV - Audio Output
Milestone: unknown → 0.23
Owner: changed from Isaac Richards to JYA
Status: new → assigned
Version: unknown → head

comment:6 Changed 12 years ago by JYA

Status: assigned → infoneeded

Can you please check if the issue still occurs with trunk >= 22432.

Thanks

comment:7 Changed 12 years ago by jppoet@…

I have been unable to reproduce this problem lately. Feel free to close the ticket.

comment:8 Changed 12 years ago by JYA

Resolution: → fixed
Status: infoneeded → closed

Obviously fixed with the new audio code ... Closing at author's request

Note: See TracTickets for help on using tickets.