[vlc-devel] audio output bug report

[Sébastien Escudier]

Hi,

While trying to play this file http://www.w6rz.net/newmobcal1280_12mbps.ts (may
not be specific to this file but I rarely test files with sound), I had a crash
in audio output.
Here is vlc full log, and gdb backtrace :

(gdb) bt
#0  0xb7f18430 in __kernel_vsyscall ()
#1  0xb7c618a0 in raise () from /lib/tls/i686/cmov/libc.so.6
#2  0xb7c63268 in abort () from /lib/tls/i686/cmov/libc.so.6
#3  0xb7c9f16d in ?? () from /lib/tls/i686/cmov/libc.so.6
#4  0xb7ca5454 in ?? () from /lib/tls/i686/cmov/libc.so.6
#5  0xb7ca74b6 in free () from /lib/tls/i686/cmov/libc.so.6
#6  0xb76a424e in Play (p_aout=0xa1f7af4) at aout.c:78
#7  0xb7e767bf in aout_OutputPlay (p_aout=0xa1f7af4, p_buffer=0xa2f0648) at
audio_output/output.c:259
#8  0xb7e75be7 in MixBuffer (p_aout=0xa1f7af4) at audio_output/mixer.c:363
#9  0xb7e75cb9 in aout_MixerRun (p_aout=0xa1f7af4) at audio_output/mixer.c:375
#10 0xb7e70cf6 in aout_DecPlay (p_aout=0xa1f7af4, p_input=0xa1e7c58,
p_buffer=0xa1f6cb8, i_input_rate=1000) at audio_output/dec.c:349
#11 0xb7e31922 in DecoderPlayAudio (p_dec=0xb5204dec, p_audio=0xa1f6cb8,
pi_played_sum=0xb43fa2c8, pi_lost_sum=0xb43fa2cc) at input/decoder.c:1190
#12 0xb7e31bdf in DecoderDecodeAudio (p_dec=0xb5204dec, p_block=0xb5209518) at
input/decoder.c:1257
#13 0xb7e333df in DecoderProcessAudio (p_dec=0xb5204dec, p_block=0xb5209518,
b_flush=false) at input/decoder.c:1863
#14 0xb7e338f5 in DecoderProcess (p_dec=0xb5204dec, p_block=0xb5209518) at
input/decoder.c:1983
#15 0xb7e30db9 in DecoderThread (p_this=0xb5204dec) at input/decoder.c:881
#16 0xb7e91392 in thread_entry (data=0xa1a1598) at misc/threads.c:57
#17 0xb7dc450f in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#18 0xb7d17a0e in clone () from /lib/tls/i686/cmov/libc.so.6




[0xa0361f4] main libvlc debug: module bank initialized (323 modules)
[0xa0361f4] main libvlc debug: opening config file
(/home/sebastien/.config/vlc/vlcrc)
[0xa0361f4] main libvlc debug: CPU has capabilities 486 586 MMX MMXEXT SSE SSE2
FPU
[0xa0361f4] main libvlc debug: looking for memcpy module: 3 candidates
[0xa0361f4] main libvlc debug: using memcpy module "memcpymmxext"
[0xa188394] main input debug: Creating an input for 'Media Library'
[0xa188394] main input debug: Input is a meta file: disabling unneeded options
[0xa188394] main input debug: using timeshift granularity of 50 MBytes
[0xa188394] main input debug: using timeshift path '/tmp'
[0xa188394] main input debug:
`file/xspf-open:///home/sebastien/.local/share/vlc/ml.xspf' gives access `file'
demux `xspf-open' path `/home/sebastien/.local/share/vlc/ml.xspf'
[0xa188394] main input debug: creating demux: access='file' demux='xspf-open'
path='/home/sebastien/.local/share/vlc/ml.xspf'
[0xa0aee64] main demux debug: looking for access_demux module: 0 candidates
[0xa0aee64] main demux debug: no access_demux module matched "file"
[0xa0aee64] main demux debug: TIMER module_need() : 0.071 ms - Total 0.071 ms /
1 intvls (Avg 0.071 ms)
[0xa188394] main input debug: creating access 'file'
path='/home/sebastien/.local/share/vlc/ml.xspf'
[0xa195774] main access debug: looking for access module: 3 candidates
[0xa195774] access_file access debug: opening file
`/home/sebastien/.local/share/vlc/ml.xspf'
[0xa195774] main access debug: using access module "access_file"
[0xa195774] main access debug: TIMER module_need() : 0.201 ms - Total 0.201 ms /
1 intvls (Avg 0.201 ms)
[0xa195e64] main stream debug: Using AStream*Stream
[0xa195e64] main stream debug: pre buffering
[0xa195e64] main stream debug: received first data after 0 ms
[0xa195e64] main stream debug: pre-buffering done 296 bytes in 0s - 17003
kbytes/s
[0xa1966bc] main stream debug: looking for stream_filter module: 4 candidates
[0xa1966bc] main stream debug: TIMER module_need() : 0.066 ms - Total 0.066 ms /
1 intvls (Avg 0.066 ms)
[0xa1966bc] main stream debug: looking for stream_filter module: 1 candidate
[0xa1966bc] main stream debug: using stream_filter module "stream_filter_record"
[0xa1966bc] main stream debug: TIMER module_need() : 0.061 ms - Total 0.061 ms /
1 intvls (Avg 0.061 ms)
[0xa188394] main input debug: creating demux: access='file' demux='xspf-open'
path='/home/sebastien/.local/share/vlc/ml.xspf'
[0xa196e94] main demux debug: looking for demux module: 1 candidate
[0xa196e94] playlist demux debug: using XSPF playlist reader
[0xa196e94] main demux debug: using demux module "playlist"
[0xa196e94] main demux debug: TIMER module_need() : 0.081 ms - Total 0.081 ms /
1 intvls (Avg 0.081 ms)
[0xa188394] main input debug:
`file/xspf-open:///home/sebastien/.local/share/vlc/ml.xspf' successfully opened
[0xa193a04] main xml debug: looking for xml module: 1 candidate
[0xa193a04] main xml debug: using xml module "xtag"
[0xa193a04] main xml debug: TIMER module_need() : 0.062 ms - Total 0.062 ms / 1
intvls (Avg 0.062 ms)
[0xa196e94] playlist demux debug: parsed 0 tracks successfully
[0xa193a04] main xml debug: removing module "xtag"
[0xa188394] main input debug: EOF reached
[0xa196e94] main demux debug: removing module "playlist"
[0xa1966bc] main stream debug: removing module "stream_filter_record"
[0xa195774] main access debug: removing module "access_file"
[0xa188394] main input debug: Destroying the input for 'Media Library'
[0xa188394] main input debug: TIMER input launching for 'Media Library' : 3.632
ms - Total 3.632 ms / 1 intvls (Avg 3.632 ms)
[New Thread 0xb545ab90 (LWP 29610)]
[0xa18c514] main playlist debug: Activated
[0xa18c514] main playlist debug: rebuilding array of current - root Playlist
[0xa18c514] main playlist debug: rebuild done - 0 items, index -1
[0xa18855c] main interface debug: looking for interface module: 1 candidate
[0xa18855c] main interface debug: using interface module "hotkeys"
[0xa18855c] main interface debug: TIMER module_need() : 0.144 ms - Total 0.144
ms / 1 intvls (Avg 0.144 ms)
[0xa19401c] main interface debug: looking for interface module: 1 candidate
[New Thread 0xb53d9b90 (LWP 29611)]
[0xa19401c] main interface debug: using interface module "screensaver"
[0xa19401c] main interface debug: TIMER module_need() : 0.641 ms - Total 0.641
ms / 1 intvls (Avg 0.641 ms)
input_item_SetURI() was likely called with a path. FIXME
[0xa18c514] main playlist debug: adding item `mobcal.ts' (
/home/sebastien/videos_tests/mobcal.ts )
[0xa0aea1c] main interface debug: looking for interface module: 1 candidate
[New Thread 0xb51ffb90 (LWP 29612)]
[0xa0aea1c] main interface debug: using interface module "signals"
[0xa0aea1c] main interface debug: TIMER module_need() : 0.684 ms - Total 0.684
ms / 1 intvls (Avg 0.684 ms)
[0xa0aee94] main interface debug: looking for interface module: 1 candidate
[New Thread 0xb517eb90 (LWP 29613)]
[0xa0aee94] main interface debug: using interface module "globalhotkeys"
[0xa0aee94] main interface debug: TIMER module_need() : 7.921 ms - Total 7.921
ms / 1 intvls (Avg 7.921 ms)
[0xa195504] main interface debug: looking for interface module: 1 candidate
[0xa195504] dummy interface: using the dummy interface module...
[0xa195504] main interface debug: using interface module "dummy"
[0xa195504] main interface debug: TIMER module_need() : 0.085 ms - Total 0.085
ms / 1 intvls (Avg 0.085 ms)
[0xa18c514] main playlist debug: processing request item null node Playlist skip
0
[0xa18c514] main playlist debug: rebuilding array of current - root Playlist
[0xa18c514] main playlist debug: rebuild done - 1 items, index -1
[0xa18c514] main playlist debug: starting new item
[0xa18c514] main playlist debug: creating new input thread
[0xb5200584] main input debug: Creating an input for 'mobcal.ts'
[New Thread 0xb50fdb90 (LWP 29614)]
[0xb5200584] main input debug: thread (input) created at priority 10
(input/input.c:230)
[0xb5200584] main input debug: thread started
[0xb5200584] main input debug: using timeshift granularity of 50 MBytes
[0xb5200584] main input debug: using timeshift path '/tmp'
[0xb5200584] main input debug: `/home/sebastien/videos_tests/mobcal.ts' gives
access `' demux `' path `/home/sebastien/videos_tests/mobcal.ts'
[0xb5200584] main input debug: creating demux: access='' demux=''
path='/home/sebastien/videos_tests/mobcal.ts'
[0xa196b04] main demux debug: looking for access_demux module: 4 candidates
[0xa196b04] main demux debug: TIMER module_need() : 0.088 ms - Total 0.088 ms /
1 intvls (Avg 0.088 ms)
[0xb5200584] main input debug: creating access ''
path='/home/sebastien/videos_tests/mobcal.ts'
[0xa196d04] main access debug: looking for access module: 3 candidates
[0xa196d04] access_file access debug: opening file
`/home/sebastien/videos_tests/mobcal.ts'
[0xa196d04] main access debug: using access module "access_file"
[0xa196d04] main access debug: TIMER module_need() : 0.294 ms - Total 0.294 ms /
1 intvls (Avg 0.294 ms)
[0xa19b914] main stream debug: Using AStream*Stream
[0xa19b914] main stream debug: pre buffering
[0xa19b914] main stream debug: received first data after 0 ms
[0xa19b914] main stream debug: pre-buffering done 1024 bytes in 0s - 62500
kbytes/s
[0xa19c134] main stream debug: looking for stream_filter module: 4 candidates
[0xa19c134] main stream debug: TIMER module_need() : 0.069 ms - Total 0.069 ms /
1 intvls (Avg 0.069 ms)
[0xa19c134] main stream debug: looking for stream_filter module: 1 candidate
[0xa19c134] main stream debug: using stream_filter module "stream_filter_record"
[0xa19c134] main stream debug: TIMER module_need() : 0.066 ms - Total 0.066 ms /
1 intvls (Avg 0.066 ms)
[0xb5200584] main input debug: creating demux: access='' demux=''
path='/home/sebastien/videos_tests/mobcal.ts'
[0xa19c8ac] main demux debug: looking for demux module: 47 candidates
[0xa19c8ac] main demux debug: using demux module "ts"
[0xa19c8ac] main demux debug: TIMER module_need() : 0.945 ms - Total 0.945 ms /
1 intvls (Avg 0.945 ms)
[0xb5200584] main input debug: looking for a subtitle file in
/home/sebastien/videos_tests/
[0xa19c8ac] ts demux debug: DEMUX_SET_GROUP 0 (nil)
[0xb5200584] main input debug: `/home/sebastien/videos_tests/mobcal.ts'
successfully opened
[0xa19c8ac] ts demux debug: PATCallBack called
[0xa19c8ac] ts demux debug: new PAT ts_id=0 version=0 current_next=1
[0xa19c8ac] ts demux debug:   * number=1 pid=32
[0xa19c8ac] ts demux debug: PMTCallBack called
[0xa19c8ac] ts demux debug: new PMT program number=1 version=0 pid_pcr=48
[0xa19c8ac] ts demux debug:   * es pid=49 type=2 dr->i_tag=0x52
[0xa19c8ac] ts demux debug:   * es pid=49 type=2 fcc=mpgv
[0xb5200584] main input debug: selecting program id=1
[0xb5203efc] main decoder debug: looking for decoder module: 22 candidates
[0xb5203efc] avcodec decoder debug: libavcodec initialized (interface 0x341d01)
[0xb5203efc] avcodec decoder debug: using direct rendering
[0xb5203efc] avcodec decoder debug: ffmpeg codec (MPEG-1/2 Video) started
[0xb5203efc] main decoder debug: using decoder module "avcodec"
[0xb5203efc] main decoder debug: TIMER module_need() : 1.486 ms - Total 1.486 ms
/ 1 intvls (Avg 1.486 ms)
[0xa19df6c] main decoder debug: looking for packetizer module: 20 candidates
[0xa19df6c] main decoder debug: using packetizer module "packetizer_mpegvideo"
[0xa19df6c] main decoder debug: TIMER module_need() : 0.224 ms - Total 0.224 ms
/ 1 intvls (Avg 0.224 ms)
[New Thread 0xb447bb90 (LWP 29615)]
[0xb5203efc] main decoder debug: thread started
[0xb5203efc] main decoder debug: thread (decoder) created at priority 0
(input/decoder.c:302)
[0xa19c8ac] ts demux debug:   * es pid=50 type=129 dr->i_tag=0x52
[0xa19c8ac] ts demux debug:   * es pid=50 type=129 fcc=a52
[0xb5204dec] main decoder debug: looking for decoder module: 22 candidates
[0xb5204dec] main decoder debug: using decoder module "a52"
[0xb5204dec] main decoder debug: TIMER module_need() : 0.417 ms - Total 0.417 ms
/ 1 intvls (Avg 0.417 ms)
[New Thread 0xb43fab90 (LWP 29616)]
[0xb5204dec] main decoder debug: thread (decoder) created at priority 5
(input/decoder.c:302)
[0xb5204dec] main decoder debug: thread started
[0xa19c8ac] ts demux debug: pid[48] unknown
[0xb5200584] main input debug: Buffering 0%
[0xb5200584] main input debug: Buffering 16%
[0xb5200584] main input debug: Buffering 32%
[0xb5200584] main input debug: Buffering 49%
[0xb5200584] main input debug: Buffering 65%
[0xb5200584] main input debug: Buffering 81%
[0xb5200584] main input debug: Buffering 98%
[0xb5200584] main input debug: Stream buffering done (343 ms in 2 ms)
[0xb5200584] main input debug: Decoder buffering done in 0 ms
[0xa19df6c] packetizer_mpegvideo decoder debug: size 1280x1080 fps=29.970
[0xb5200584] main input debug: no usable vout present, spawning one
[0xa1ce8ac] main spu text debug: looking for text renderer module: 1 candidate
[0xa1ce8ac] main spu text debug: using text renderer module "dummy"
[0xa1ce8ac] main spu text debug: TIMER module_need() : 0.100 ms - Total 0.100 ms
/ 1 intvls (Avg 0.100 ms)
[0xa21be84] main scale debug: looking for video filter2 module: 20 candidates
[0xa21be84] swscale scale debug: 32x32 chroma: YUVA -> 16x16 chroma: YUVA with
scaling using Bicubic (good quality)
[0xa21be84] main scale debug: using video filter2 module "swscale"
[0xa21be84] main scale debug: TIMER module_need() : 1.122 ms - Total 1.122 ms /
1 intvls (Avg 1.122 ms)
[0xa21cccc] main scale debug: looking for video filter2 module: 20 candidates
[0xa21cccc] yuvp scale debug: YUVP to YUVA converter
[0xa21cccc] main scale debug: using video filter2 module "yuvp"
[0xa21cccc] main scale debug: TIMER module_need() : 0.101 ms - Total 0.101 ms /
1 intvls (Avg 0.101 ms)
[0xa218f14] main video output debug: window size: 1920x1080
[0xa218f14] main video output debug: Deinterlacing available
[New Thread 0xb3f4cb90 (LWP 29617)]
[0xa218f14] main video output debug: looking for video output module: 8
candidates
[0xa218f14] vout_wrapper video output warning: Opening vout display wrapper
[0xa2b88d4] main generic debug: looking for vout display module: 0 candidates
[0xa2b88d4] main generic error: no vout display module matched "xcb_xv"
[0xa2b88d4] main generic debug: TIMER module_need() : 0.079 ms - Total 0.079 ms
/ 1 intvls (Avg 0.079 ms)
[0xa218f14] vout_wrapper video output warning: Opening vout display wrapper
[0xa2b87a4] main generic debug: looking for vout display module: 1 candidate
[0xa2b8934] main generic debug: looking for vout window xid module: 3 candidates
[0xa2b8934] qt4 generic debug: Qt4 interface not found
[New Thread 0xb3ecbb90 (LWP 29618)]
[0xa2b8934] main generic debug: using vout window xid module "xcb_window"
[0xa2b8934] main generic debug: TIMER module_need() : 9.636 ms - Total 9.636 ms
/ 1 intvls (Avg 9.636 ms)
[0xa2b87a4] xcb_x11 generic debug: using screen 0x1a6
[0xa2b87a4] xcb_x11 generic debug: using X11 visual ID 0x21
[0xa2b87a4] xcb_x11 generic debug:  32 bits per pixels, 32 bits line pad
[0xa2b87a4] xcb_x11 generic debug: using X11 window 08000000
[0xa2b87a4] xcb_x11 generic debug: using X11 graphic context 08000001
[0xa2b87a4] main generic debug: VoutDisplayEvent 'resize' 1280x949
[0xa2b87a4] main generic debug: VoutDisplayEvent 'fullscreen' 0
[0xa2b87a4] main generic debug: using vout display module "xcb_x11"
[0xa2b87a4] main generic debug: TIMER module_need() : 35.785 ms - Total 35.785
ms / 1 intvls (Avg 35.785 ms)
[0xa2b87a4] main generic error: A filter to adapt decoder to display is needed
[0xa2ba224] main filter debug: looking for video filter2 module: 20 candidates
[0xa2ba224] swscale filter debug: 1280x1080 chroma: I420 -> 1280x1080 chroma:
RV32 with scaling using Bicubic (good quality)
[0xa2ba224] main filter debug: using video filter2 module "swscale"
[0xa2ba224] main filter debug: TIMER module_need() : 0.571 ms - Total 0.571 ms /
1 intvls (Avg 0.571 ms)
[0xa2b87a4] main generic debug: Filter 'Swscale' (0xa2ba224) appended to chain
[0xa218f14] main video output debug: using video output module "vout_wrapper"
[0xa218f14] main video output debug: TIMER module_need() : 36.904 ms - Total
36.904 ms / 1 intvls (Avg 36.904 ms)
[0xa218f14] main video output debug: got 1 direct buffer(s)
[0xa218f14] main video output debug: pic render sz 1280x1080, of (0,0), vsz
1280x1080, 4cc I420, ar 16:9, sar 3:2, msk r0x0 g0x0 b0x0
[0xa218f14] main video output debug: pic in sz 1280x1080, of (0,0), vsz
1280x1080, 4cc I420, ar 16:9, sar 3:2, msk r0x0 g0x0 b0x0
[0xa218f14] main video output debug: pic out sz 1280x1080, of (0,0), vsz
1280x1080, 4cc I420, ar 16:9, sar 3:2, msk r0x0 g0x0 b0x0
[0xa218f14] main video output debug: direct render, mapping render pictures 0-14
to system pictures 1-15
[0xb5203efc] main decoder debug: End of video preroll
[0xa2b87a4] main generic warning: VoutDisplayEvent 'pictures invalid'
[0xa2b87a4] main generic debug: Filter 0xa2ba224 removed from chain
[0xa2ba224] main filter debug: removing module "swscale"
[0xa2b87a4] main generic error: A filter to adapt decoder to display is needed
[0xa2ba224] main filter debug: looking for video filter2 module: 20 candidates
[0xa2ba224] swscale filter debug: 1280x1080 chroma: I420 -> 1280x720 chroma:
RV32 with scaling using Bicubic (good quality)
[0xa2ba224] main filter debug: using video filter2 module "swscale"
[0xa2ba224] main filter debug: TIMER module_need() : 2.653 ms - Total 2.653 ms /
1 intvls (Avg 2.653 ms)
[0xa2b87a4] main generic debug: Filter 'Swscale' (0xa2ba224) appended to chain
[0xa218f14] main video output debug: Post-processing available
[0xa218f14] main video output warning: vlc_object_find_name(postproc) is not
safe!
[0xa2b87a4] main generic debug: VoutDisplayEvent 'mouse button' 4 t=7
[0xa2b87a4] main generic debug: VoutDisplayEvent 'mouse button' 4 t=8
[0xb5204dec] a52 decoder: A/52 channels:2 samplerate:48000 bitrate:384000
[0xb5200584] main input debug: creating aout
[0xa1f7af4] main audio output debug: looking for audio output module: 1
candidate
[0xa1f7af4] main audio output debug: using audio output module "dummy"
[0xa1f7af4] main audio output debug: TIMER module_need() : 0.233 ms - Total
0.233 ms / 1 intvls (Avg 0.233 ms)
[0xa1f7af4] main audio output debug: output 'a52 ' 48000 Hz Stereo frame=1536
samples/1536 bytes
[0xa1f7af4] main audio output debug: mixer 'a52 ' 48000 Hz Stereo frame=1536
samples/1536 bytes
[0xa1f7af4] main audio output debug: no need for any filter
[0xa2cd244] main generic debug: looking for audio mixer module: 3 candidates
[0xa2cd244] main generic debug: using audio mixer module "spdif_mixer"
[0xa2cd244] main generic debug: TIMER module_need() : 0.076 ms - Total 0.076 ms
/ 1 intvls (Avg 0.076 ms)
[0xa1f7af4] main audio output debug: input 'a52 ' 48000 Hz Stereo frame=1536
samples/1536 bytes
[0xb5204dec] main decoder debug: End of audio preroll
[0xa2b87a4] main generic debug: VoutDisplayEvent 'mouse button' 4 t=7
[0xa2b87a4] main generic debug: VoutDisplayEvent 'mouse button' 4 t=8
*** glibc detected *** /home/sebastien/git/vlc/vlc: double free or corruption
(!prev): 0x0a2f0648 ***