Buggy playback of 44100/ 44.1 kHz WAV audio on Linux 2.6

[nanomir]

I think I just discovered a buggy behavior - not necessarily a bug in VLC, though; but I think it's better for it to be documented.

These are my specs:

Code: Select all

$ echo $(cat /etc/issue ; uname -a) Ubuntu 11.04 \n \l Linux mypc 2.6.38-16-generic #67-Ubuntu SMP Thu Sep 6 18:00:43 UTC 2012 i686 i686 i386 GNU/Linux $ pulseaudio --version pulseaudio 0.9.22-24-g67d18 $ alsactl --version alsactl version 1.0.24.2 $ vlc --version VLC media player 1.1.9 The Luggage (revision exported) VLC version 1.1.9 The Luggage (exported) Compiled by buildd on vernadsky.buildd (Jul 21 2011 11:32:22) Compiler: gcc version 4.5.2 (Ubuntu/Linaro 4.5.2-8ubuntu4)

To make sure the test doesn't depend on any files, I'll generate files with `sox` synth. First a 8 kHz file - not a problem with wav there (but flac is silent):

Code: Select all

$ sox -n -r 8000 test.wav synth 1.0 sine 300:500 $ aplay test.wav Playing WAVE 'test.wav' : Signed 32 bit Little Endian, Rate 8000 Hz, Mono $ cvlc --play-and-exit -v ./test.wav # plays fine VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590212) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x899930c] dummy interface: using the dummy interface module... [0x899b834] main audio output warning: PTS is out of range (-9962), dropping buffer [0x8975db4] main playlist: end of playlist, exiting $ sox -n -r 8000 test.flac synth 1.0 sine 300:500 $ cvlc --play-and-exit -v ./test.flac # does not play at all VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590350) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0xb72007bc] dummy interface: using the dummy interface module... [0x9f30db4] main playlist: end of playlist, exiting

Then 22050 kHz - same situation:

Code: Select all

$ sox -n -r 22050 test.wav synth 1.0 sine 300:500 $ aplay ./test.wav Playing WAVE './test.wav' : Signed 32 bit Little Endian, Rate 22050 Hz, Mono $ cvlc --play-and-exit -v ./test.wav # plays fine VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590555) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0xa04b65c] dummy interface: using the dummy interface module... [0xa031834] main audio output warning: PTS is out of range (-9582), dropping buffer [0xa02edb4] main playlist: end of playlist, exiting $ sox -n -r 22050 test.flac synth 1.0 sine 300:500 $ cvlc --play-and-exit -v ./test.flac # does not play at all VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590623) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0xb750456c] dummy interface: using the dummy interface module... [0x96d881c] main audio output warning: PTS is out of range (-9330), dropping buffer [0x9684db4] main playlist: end of playlist, exiting

... and finally, 44100 Hz: here the .wav doesn't play - but instead, there is a click at start, and then silence (and dropping buffer/audio drift messages); the .flac now for the first time, also gives a click - but then again silence:

Code: Select all

$ sox -n -r 44100 test.wav synth 1.0 sine 300:500 $ aplay ./test.wav Playing WAVE './test.wav' : Signed 32 bit Little Endian, Rate 44100 Hz, Mono $ cvlc --play-and-exit -v ./test.wav VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590781) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x99d972c] dummy interface: using the dummy interface module... [0x99e12b4] main audio output warning: PTS is out of range (-9960), dropping buffer [0x99e12b4] main audio output warning: PTS is out of range (-33103), dropping buffer [0x99e12b4] main audio output warning: output date isn't PTS date, requesting resampling (44620) [0x99e12b4] main audio output warning: buffer is 44619 late, triggering upsampling [0x99e12b4] main audio output warning: output date isn't PTS date, requesting resampling (95267) [0x99e12b4] main audio output warning: audio drift is too big (139749), dropping buffer [0x99e12b4] main audio output warning: timing screwed, stopping resampling [0x99e12b4] main audio output warning: buffer is 116530 late, triggering upsampling [0x99e12b4] main audio output warning: output date isn't PTS date, requesting resampling (48014) [0x99e12b4] main audio output warning: audio drift is too big (164521), dropping buffer [0x99e12b4] main audio output warning: audio drift is too big (141302), dropping buffer [0x99e12b4] main audio output warning: output date isn't PTS date, requesting resampling (94441) [0x99e12b4] main audio output warning: audio drift is too big (212431), dropping buffer [0x99e12b4] main audio output warning: audio drift is too big (189212), dropping buffer [0x99e12b4] main audio output warning: audio drift is too big (165992), dropping buffer [0x99e12b4] main audio output warning: audio drift is too big (162431), dropping buffer [0x99e12b4] main audio output warning: audio drift is too big (139212), dropping buffer [0x99e12b4] main audio output warning: output date isn't PTS date, requesting resampling (155021) [0x99bcdb4] main playlist: end of playlist, exiting $ sox -n -r 44100 test.flac synth 1.0 sine 300:500 $ cvlc --play-and-exit -v ./test.flac VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369590817) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x8cd9fbc] dummy interface: using the dummy interface module... [0x8d0bfc4] main audio output warning: PTS is out of range (-9335), dropping buffer [0x8d0bfc4] main audio output warning: output date isn't PTS date, requesting resampling (145531) [0x8cbddb4] main playlist: end of playlist, exiting

Eh now, by accident I played around, and it turns out, this is the same behavior as the default `alsa` module:

Code: Select all

$ cvlc --play-and-exit -v --aout alsa ./test.wav VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369591006) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x922af04] dummy interface: using the dummy interface module... [0x923582c] main audio output warning: PTS is out of range (-9959), dropping buffer [0x923582c] main audio output warning: PTS is out of range (-33091), dropping buffer [0x923582c] main audio output warning: output date isn't PTS date, requesting resampling (84012) [0x923582c] main audio output warning: buffer is 84011 late, triggering upsampling [0x923582c] main audio output warning: output date isn't PTS date, requesting resampling (47992) [0x923582c] main audio output warning: audio drift is too big (131934), dropping buffer [0x923582c] main audio output warning: output date isn't PTS date, requesting resampling (49941) [0x923582c] main audio output warning: audio drift is too big (158610), dropping buffer [0x923582c] main audio output warning: audio drift is too big (135391), dropping buffer [0x923582c] main audio output warning: output date isn't PTS date, requesting resampling (106453) [0x923582c] main audio output warning: audio drift is too big (218533), dropping buffer [0x923582c] main audio output warning: audio drift is too big (195314), dropping buffer [0x923582c] main audio output warning: audio drift is too big (172094), dropping buffer [0x923582c] main audio output warning: audio drift is too big (168533), dropping buffer [0x923582c] main audio output warning: audio drift is too big (145314), dropping buffer [0x923582c] main audio output warning: audio drift is too big (122094), dropping buffer [0x923582c] main audio output warning: output date isn't PTS date, requesting resampling (141885) [0x9212e3c] main playlist: end of playlist, exiting

... however, if I change it to `pulse` - then suddenly 44.1 kHz starts playing - and then even the `flac` starts playing!

Code: Select all

$ cvlc --play-and-exit -v --aout pulse ./test.wav VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369591059) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x8bddec4] dummy interface: using the dummy interface module... [0x8be05cc] main audio output warning: PTS is out of range (-9954), dropping buffer [0x8be05cc] main audio output warning: PTS is out of range (-33095), dropping buffer [0x8bc5e3c] main playlist: end of playlist, exiting $ cvlc --play-and-exit -v --aout pulse ./test.flac VLC media player 1.1.9 The Luggage (revision exported) Warning: call to srand(1369591074) Warning: call to rand() Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x8cec03c] dummy interface: using the dummy interface module... [0x8cefe94] main audio output warning: PTS is out of range (-9424), dropping buffer [0x8ccfe3c] main playlist: end of playlist, exiting

Not sure if I just have the wrong settings in VLC (though I don't see any problems playing other stuff); but here is the last .wav output, with increased verbosity level, maybe it helps someone:

Code: Select all

$ cvlc --play-and-exit -vv --aout alsa ./test.wav VLC media player 1.1.9 The Luggage (revision exported) [0x8ccc914] main libvlc debug: VLC media player - 1.1.9 The Luggage [0x8ccc914] main libvlc debug: Copyright © 1996-2011 the VideoLAN team [0x8ccc914] main libvlc debug: revision exported [0x8ccc914] main libvlc debug: configured with ./configure '--enable-static' '--build=i686-linux-gnu' '--config-cache' '--disable-maintainer-mode' '--disable-silent-rules' '--disable-update-check' '--enable-fast-install' '--prefix=/usr' '--docdir=/usr/share/doc/vlc-nox' '--sysconfdir=/etc' '--with-binary-version=1ubuntu1.3' '--enable-a52' '--enable-aa' '--enable-bonjour' '--enable-caca' '--enable-dca' '--enable-dirac' '--enable-dvb' '--enable-dvbpsi' '--enable-dvdnav' '--enable-faad' '--enable-flac' '--enable-fluidsynth' '--enable-freetype' '--enable-fribidi' '--enable-ggi' '--enable-gnutls' '--enable-jack' '--enable-kate' '--enable-libass' '--enable-libmpeg2' '--enable-libproxy' '--enable-libxml2' '--enable-lirc' '--enable-live555' '--enable-mad' '--enable-mkv' '--enable-mod' '--enable-mozilla' '--enable-mpc' '--enable-mtp' '--enable-mux_ogg' '--enable-ncurses' '--enable-notify' '--enable-ogg' '--enable-pulse' '--enable-qt4' '--enable-realrtsp' '--enable-schroedinger' '--enable-sdl' '--enable-shout' '--enable-skins2' '--enable-smb' '--enable-speex' '--enable-svg' '--enable-taglib' '--enable-theora' '--enable-twolame' '--enable-upnp' '--enable-vcd' '--enable-vcdx' '--enable-vorbis' '--enable-x264' '--enable-zvbi' '--with-kde-solid=/usr/share/kde4/apps/solid/actions/' '--with-mozilla-pkg=libxul' '--disable-dxva2' '--disable-gnomevfs' '--disable-goom' '--disable-osso_screensaver' '--disable-portaudio' '--disable-projectm' '--disable-sqlite' '--disable-telx' '--enable-alsa' '--enable-atmo' '--enable-dc1394' '--enable-dv' '--enable-libva' '--enable-pvr' '--enable-udev' '--enable-v4l2' '--enable-svgalib' 'build_alias=i686-linux-gnu' 'CFLAGS=-g -O2' 'LDFLAGS=-Wl,--as-needed' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' [0x8ccc914] main libvlc debug: translation test: code is "C" [0x8ccc914] main libvlc debug: checking plugin modules [0x8ccc914] main libvlc debug: loading plugins cache file /usr/lib/vlc/plugins/plugins-04041e-3e8.dat [0x8ccc914] main libvlc debug: recursively browsing `/usr/lib/vlc/plugins' [0x8ccc914] main libvlc debug: saving plugins cache /usr/lib/vlc/plugins/plugins-04041e-3e8.dat [0x8ccc914] main libvlc debug: module bank initialized (394 modules) [0x8ccc914] main libvlc debug: opening config file (~/.config/vlc/vlcrc) [0x8ccc914] main libvlc debug: CPU has capabilities MMX MMXEXT SSE SSE2 SSE3 SSSE3 FPU [0x8ccc914] main libvlc debug: looking for memcpy module: 3 candidates [0x8ccc914] main libvlc debug: using memcpy module "memcpymmxext" [0x8d65274] main input debug: Creating an input for 'Media Library' [0x8d65274] main input debug: Input is a meta file: disabling unneeded options [0x8d65274] main input debug: using timeshift granularity of 50 MiB [0x8d65274] main input debug: using timeshift path '/tmp' [0x8d65274] main input debug: `file/xspf-open://~/.local/share/vlc/ml.xspf' gives access `file' demux `xspf-open' path `~/.local/share/vlc/ml.xspf' [0x8d65274] main input debug: creating demux: access='file' demux='xspf-open' path='~/.local/share/vlc/ml.xspf' [0x8d690fc] main demux debug: looking for access_demux module: 2 candidates [0x8d690fc] main demux debug: no access_demux module matching "file" could be loaded [0x8d690fc] main demux debug: TIMER module_need() : 1.730 ms - Total 1.730 ms / 1 intvls (Avg 1.730 ms) [0x8d65274] main input debug: creating access 'file' path='~/.local/share/vlc/ml.xspf' [0x8d7356c] main access debug: looking for access module: 2 candidates [0x8d7356c] filesystem access debug: opening file `~/.local/share/vlc/ml.xspf' [0x8d7356c] main access debug: using access module "filesystem" [0x8d7356c] main access debug: TIMER module_need() : 0.980 ms - Total 0.980 ms / 1 intvls (Avg 0.980 ms) [0x8d736b4] main stream debug: Using AStream*Stream [0x8d736b4] main stream debug: pre buffering [0x8d736b4] main stream debug: received first data after 0 ms [0x8d736b4] main stream debug: pre-buffering done 296 bytes in 0s - 4014 KiB/s [0x8d72ae4] main stream debug: looking for stream_filter module: 5 candidates [0x8d72ae4] main stream debug: no stream_filter module matching "any" could be loaded [0x8d72ae4] main stream debug: TIMER module_need() : 1.237 ms - Total 1.237 ms / 1 intvls (Avg 1.237 ms) [0x8d72ae4] main stream debug: looking for stream_filter module: 1 candidate [0x8d72ae4] main stream debug: using stream_filter module "stream_filter_record" [0x8d72ae4] main stream debug: TIMER module_need() : 0.477 ms - Total 0.477 ms / 1 intvls (Avg 0.477 ms) [0x8d65274] main input debug: creating demux: access='file' demux='xspf-open' path='~/.local/share/vlc/ml.xspf' [0x8d73f3c] main demux debug: looking for demux module: 1 candidate [0x8d73f3c] playlist demux debug: using XSPF playlist reader [0x8d73f3c] main demux debug: using demux module "playlist" [0x8d73f3c] main demux debug: TIMER module_need() : 0.625 ms - Total 0.625 ms / 1 intvls (Avg 0.625 ms) [0x8d768d4] main demux meta debug: looking for meta reader module: 2 candidates [0x8d768d4] lua demux meta debug: Trying Lua scripts in ~/.local/share/vlc/lua/meta/reader [0x8d768d4] lua demux meta debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader [0x8d768d4] lua demux meta debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac [0x8d768d4] lua demux meta debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader [0x8d768d4] main demux meta debug: no meta reader module matching "any" could be loaded [0x8d768d4] main demux meta debug: TIMER module_need() : 11.254 ms - Total 11.254 ms / 1 intvls (Avg 11.254 ms) [0x8d65274] main input debug: `file/xspf-open://~/.local/share/vlc/ml.xspf' successfully opened [0x8d768d4] main xml debug: looking for xml module: 2 candidates [0x8d768d4] main xml debug: using xml module "xml" [0x8d768d4] main xml debug: TIMER module_need() : 1.887 ms - Total 1.887 ms / 1 intvls (Avg 1.887 ms) Warning: call to srand(1369591178) Warning: call to rand() [0x8d73f3c] playlist demux debug: parsed 0 tracks successfully [0x8d768d4] main xml debug: removing module "xml" [0x8d65274] main input debug: EOF reached [0x8d73f3c] main demux debug: removing module "playlist" [0x8d72ae4] main stream debug: removing module "stream_filter_record" [0x8d7356c] main access debug: removing module "filesystem" [0x8d65274] main input debug: TIMER input launching for 'Media Library' : 17.821 ms - Total 17.821 ms / 1 intvls (Avg 17.821 ms) [0x8d72ae4] main interface debug: looking for interface module: 1 candidate [0x8d72ae4] main interface debug: using interface module "hotkeys" [0x8d72ae4] main interface debug: TIMER module_need() : 0.939 ms - Total 0.939 ms / 1 intvls (Avg 0.939 ms) [0x8d768d4] main interface debug: looking for interface module: 1 candidate Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x8d63e3c] main playlist debug: Activated [0x8d768d4] main interface debug: using interface module "inhibit" [0x8d768d4] main interface debug: TIMER module_need() : 7.227 ms - Total 7.227 ms / 1 intvls (Avg 7.227 ms) [0x8d63e3c] main playlist debug: adding item `test.wav' ( file:///path/to/./test.wav ) [0x8d7b26c] main interface debug: looking for interface module: 1 candidate [0x8d7b26c] main interface debug: using interface module "signals" [0x8d7b26c] main interface debug: TIMER module_need() : 0.944 ms - Total 0.944 ms / 1 intvls (Avg 0.944 ms) [0x8d66f8c] main interface debug: looking for interface module: 1 candidate [0x8d7bbf4] main input debug: Creating an input for 'test.wav' [0x8d63e3c] main playlist debug: rebuilding array of current - root Playlist [0x8d63e3c] main playlist debug: rebuild done - 1 items, index -1 [0x8d66f8c] main interface debug: using interface module "globalhotkeys" [0x8d66f8c] main interface debug: TIMER module_need() : 14.909 ms - Total 14.909 ms / 1 intvls (Avg 14.909 ms) [0x8d9e09c] main interface debug: looking for interface module: 1 candidate [0x8d9e09c] dummy interface: using the dummy interface module... [0x8d9e09c] main interface debug: using interface module "dummy" [0x8d9e09c] main interface debug: TIMER module_need() : 0.993 ms - Total 0.993 ms / 1 intvls (Avg 0.993 ms) [0x8d63e3c] main playlist debug: processing request item null node Playlist skip 0 [0x8d63e3c] main playlist debug: starting new item [0x8d63e3c] main playlist debug: creating new input thread [0x8d9ef44] main input debug: Creating an input for 'test.wav' [0x8d9ef44] main input debug: thread (input) created at priority 10 (input/input.c:220) [0x8d63e3c] main playlist debug: no fetch required for (null) (art currently (null)) [0x8d9ef44] main input debug: thread started [0x8d9ef44] main input debug: using timeshift granularity of 50 MiB [0x8d9ef44] main input debug: using timeshift path '/tmp' [0x8d9ef44] main input debug: `file:///path/to/./test.wav' gives access `file' demux `' path `/path/to/./test.wav' [0x8d9ef44] main input debug: creating demux: access='file' demux='' path='/path/to/./test.wav' [0x8d86024] main demux debug: looking for access_demux module: 2 candidates [0x8d86024] main demux debug: no access_demux module matching "file" could be loaded [0x8d86024] main demux debug: TIMER module_need() : 0.685 ms - Total 0.685 ms / 1 intvls (Avg 0.685 ms) [0x8d9ef44] main input debug: creating access 'file' path='/path/to/./test.wav' [0x8da5f84] main access debug: looking for access module: 2 candidates [0x8da5f84] filesystem access debug: opening file `/path/to/./test.wav' [0x8da5f84] main access debug: using access module "filesystem" [0x8da5f84] main access debug: TIMER module_need() : 0.519 ms - Total 0.519 ms / 1 intvls (Avg 0.519 ms) [0x8d86004] main stream debug: Using AStream*Stream [0x8d86004] main stream debug: pre buffering [0x8d86004] main stream debug: received first data after 0 ms [0x8d86004] main stream debug: pre-buffering done 1024 bytes in 0s - 17857 KiB/s [0x8d893ec] main stream debug: looking for stream_filter module: 5 candidates [0x8d893ec] main stream debug: no stream_filter module matching "any" could be loaded [0x8d893ec] main stream debug: TIMER module_need() : 0.418 ms - Total 0.418 ms / 1 intvls (Avg 0.418 ms) [0x8d893ec] main stream debug: looking for stream_filter module: 1 candidate [0x8d893ec] main stream debug: using stream_filter module "stream_filter_record" [0x8d893ec] main stream debug: TIMER module_need() : 1.476 ms - Total 1.476 ms / 1 intvls (Avg 1.476 ms) [0x8d9ef44] main input debug: creating demux: access='file' demux='' path='/path/to/./test.wav' [0x8da76bc] main demux debug: looking for demux module: 52 candidates [0x8da76bc] wav demux debug: chunk: fcc=`fmt ` size=40 [0x8da76bc] wav demux debug: format: 0xfffe, fourcc: pcm , channels: 1, freq: 44100 Hz, bitrate: 172Ko/s, blockalign: 4, bits/samples: 32, extra size: 0 [0x8da76bc] wav demux debug: found PCM audio format [0x8da76bc] wav demux debug: chunk: fcc=`fact` size=4 [0x8da76bc] wav demux debug: chunk: fcc=`data` size=176400 [0x8d9ef44] main input debug: selecting program id=0 [0x8da76bc] main demux debug: using demux module "wav" [0x8da76bc] main demux debug: TIMER module_need() : 1.038 ms - Total 1.038 ms / 1 intvls (Avg 1.038 ms) [0x8d9ef44] main input debug: looking for a subtitle file in /path/to/./ [0x8d86e7c] main decoder debug: looking for decoder module: 30 candidates [0x8d86e7c] araw decoder debug: samplerate:44100Hz channels:1 bits/sample:32 [0x8d86e7c] main decoder debug: using decoder module "araw" [0x8d86e7c] main decoder debug: TIMER module_need() : 12.572 ms - Total 12.572 ms / 1 intvls (Avg 12.572 ms) [0x8d86e7c] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301) [0x8d86e7c] main decoder debug: thread started [0x8d8732c] main demux meta debug: looking for meta reader module: 2 candidates [0x8d8732c] lua demux meta debug: Trying Lua scripts in ~/.local/share/vlc/lua/meta/reader [0x8d8732c] lua demux meta debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader [0x8d8732c] lua demux meta debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac [0x8d8732c] lua demux meta debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader [0x8d8732c] main demux meta debug: no meta reader module matching "any" could be loaded [0x8d8732c] main demux meta debug: TIMER module_need() : 2.412 ms - Total 2.412 ms / 1 intvls (Avg 2.412 ms) [0x8d9ef44] main input debug: `file:///path/to/./test.wav' successfully opened [0x8d9ef44] main input debug: Buffering 0% [0x8d9ef44] main input debug: Buffering 16% [0x8d9ef44] main input debug: Buffering 33% [0x8d9ef44] main input debug: Buffering 50% [0x8d9ef44] main input debug: Buffering 66% [0x8d9ef44] main input debug: Buffering 83% [0x8d9ef44] main input debug: Buffering 100% [0x8d9ef44] main input debug: Stream buffering done (350 ms in 1 ms) [0x8d9ef44] main input debug: creating aout [0x8da99f4] main audio output debug: looking for audio output module: 4 candidates [0x8da99f4] alsa audio output debug: opening ALSA device `default' [0x8da99f4] main audio output debug: using audio output module "alsa" [0x8da99f4] main audio output debug: TIMER module_need() : 62.460 ms - Total 62.460 ms / 1 intvls (Avg 62.460 ms) [0x8da99f4] main audio output debug: output 'f32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8da99f4] main audio output debug: mixer 'f32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8da99f4] main audio output debug: no need for any filter [0x8da439c] main generic debug: looking for audio mixer module: 3 candidates [0x8da439c] main generic debug: using audio mixer module "float32_mixer" [0x8da439c] main generic debug: TIMER module_need() : 0.943 ms - Total 0.943 ms / 1 intvls (Avg 0.943 ms) [0x8da99f4] main audio output debug: input 's32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8da99f4] main audio output debug: filter(s) 's32l'->'f32l' 44100 Hz->44100 Hz Mono->Mono [0x8dc874c] main audio filter debug: looking for audio filter module: 13 candidates [0x8dc874c] audio_format audio filter debug: s32l->f32l, bits per sample: 32->32 [0x8dc874c] main audio filter debug: using audio filter module "audio_format" [0x8dc874c] main audio filter debug: TIMER module_need() : 8.346 ms - Total 8.346 ms / 1 intvls (Avg 8.346 ms) [0x8da99f4] main audio output debug: found a filter for the whole conversion [0x8da99f4] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Mono->Mono [0x8dcc9fc] main audio filter debug: looking for audio filter module: 13 candidates [0x8dcc9fc] main audio filter debug: using audio filter module "ugly_resampler" [0x8dcc9fc] main audio filter debug: TIMER module_need() : 0.259 ms - Total 0.259 ms / 1 intvls (Avg 0.259 ms) [0x8da99f4] main audio output debug: found a filter for the whole conversion [0x8d86e7c] main decoder debug: End of audio preroll [0x8d9ef44] main input debug: Decoder buffering done in 77 ms [0x8da99f4] main audio output warning: PTS is out of range (-9959), dropping buffer [0x8da99f4] main audio output warning: PTS is out of range (-33067), dropping buffer [0x8da99f4] main audio output warning: output date isn't PTS date, requesting resampling (58454) [0x8da99f4] main audio output warning: buffer is 58453 late, triggering upsampling [0x8da99f4] main audio output warning: output date isn't PTS date, requesting resampling (47952) [0x8da99f4] main audio output warning: timing screwed, stopping resampling [0x8da99f4] main audio output warning: buffer is 106337 late, triggering upsampling [0x8da99f4] main audio output warning: output date isn't PTS date, requesting resampling (47865) [0x8da99f4] main audio output warning: audio drift is too big (154156), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (130937), dropping buffer [0x8da99f4] main audio output warning: output date isn't PTS date, requesting resampling (107619) [0x8da99f4] main audio output warning: audio drift is too big (215245), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (192026), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (168806), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (165245), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (142026), dropping buffer [0x8da99f4] main audio output warning: output date isn't PTS date, requesting resampling (142068) [0x8da99f4] main audio output warning: audio drift is too big (260782), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (237563), dropping buffer [0x8da99f4] main audio output warning: audio drift is too big (214343), dropping buffer [0x8d9ef44] main input debug: EOF reached [0x8d63e3c] main playlist debug: finished input [0x8d86e7c] main decoder debug: removing module "araw" [0x8d86e7c] main decoder debug: killing decoder fourcc `s32l', 0 PES in FIFO [0x8dc874c] main audio filter debug: removing module "audio_format" [0x8dcc9fc] main audio filter debug: removing module "ugly_resampler" [0x8da99f4] main audio output debug: removing module "alsa" [0x8da439c] main generic debug: removing module "float32_mixer" [0x8d9ef44] main input debug: releasing aout [0x8da76bc] main demux debug: removing module "wav" [0x8d893ec] main stream debug: removing module "stream_filter_record" [0x8da5f84] main access debug: removing module "filesystem" [0x8d9ef44] main input debug: Program doesn't contain anymore ES [0x8d63e3c] main playlist debug: dead input [0x8d9ef44] main input debug: thread ended [0x8d63e3c] main playlist debug: changing item without a request (current 0/1) [0x8d63e3c] main playlist debug: nothing to play [0x8d63e3c] main playlist: end of playlist, exiting [0x8ccc914] main libvlc debug: deactivating the playlist [0x8d63e3c] main playlist debug: Deactivate [0x8dc563c] main playlist export debug: saving Media Library to file ~/.local/share/vlc/ml.xspf [0x8dc563c] main playlist export debug: looking for playlist export module: 1 candidate [0x8dc563c] main playlist export debug: using playlist export module "export" [0x8dc563c] main playlist export debug: TIMER module_need() : 1.566 ms - Total 1.566 ms / 1 intvls (Avg 1.566 ms) [0x8dc563c] main playlist export debug: removing module "export" [0x8d63e3c] main playlist debug: Deactivated [0x8ccc914] main libvlc debug: removing all services discovery tasks [0x8ccc914] main libvlc debug: removing all interfaces [0x8d9e09c] main interface debug: removing module "dummy" [0x8d66f8c] main interface debug: removing module "globalhotkeys" [0x8d7b26c] main interface debug: removing module "signals" [0x8d9ef44] main input debug: TIMER input launching for 'test.wav' : 25.504 ms - Total 25.504 ms / 1 intvls (Avg 25.504 ms) [0x8d768d4] main interface debug: removing module "inhibit" [0x8d72ae4] main interface debug: removing module "hotkeys" [0x8d63e3c] main playlist debug: destroying [0x8ccc914] main libvlc debug: TIMER ML Load : Total 20.914 ms / 1 intvls (Avg 20.914 ms) [0x8ccc914] main libvlc debug: TIMER Preparse run : Total 22.943 ms / 1 intvls (Avg 22.943 ms) [0x8ccc914] main libvlc debug: TIMER Items array build : Total 0.138 ms / 1 intvls (Avg 0.138 ms) [0x8ccc914] main libvlc debug: TIMER ML Dump : Total 2.455 ms / 1 intvls (Avg 2.455 ms) [0x8ccc914] main libvlc debug: removing stats [0x8ccc914] main libvlc debug: removing module "memcpymmxext" $ cvlc --play-and-exit -vv --aout pulse ./test.wav VLC media player 1.1.9 The Luggage (revision exported) [0x8a8e914] main libvlc debug: VLC media player - 1.1.9 The Luggage [0x8a8e914] main libvlc debug: Copyright © 1996-2011 the VideoLAN team [0x8a8e914] main libvlc debug: revision exported [0x8a8e914] main libvlc debug: configured with ./configure '--enable-static' '--build=i686-linux-gnu' '--config-cache' '--disable-maintainer-mode' '--disable-silent-rules' '--disable-update-check' '--enable-fast-install' '--prefix=/usr' '--docdir=/usr/share/doc/vlc-nox' '--sysconfdir=/etc' '--with-binary-version=1ubuntu1.3' '--enable-a52' '--enable-aa' '--enable-bonjour' '--enable-caca' '--enable-dca' '--enable-dirac' '--enable-dvb' '--enable-dvbpsi' '--enable-dvdnav' '--enable-faad' '--enable-flac' '--enable-fluidsynth' '--enable-freetype' '--enable-fribidi' '--enable-ggi' '--enable-gnutls' '--enable-jack' '--enable-kate' '--enable-libass' '--enable-libmpeg2' '--enable-libproxy' '--enable-libxml2' '--enable-lirc' '--enable-live555' '--enable-mad' '--enable-mkv' '--enable-mod' '--enable-mozilla' '--enable-mpc' '--enable-mtp' '--enable-mux_ogg' '--enable-ncurses' '--enable-notify' '--enable-ogg' '--enable-pulse' '--enable-qt4' '--enable-realrtsp' '--enable-schroedinger' '--enable-sdl' '--enable-shout' '--enable-skins2' '--enable-smb' '--enable-speex' '--enable-svg' '--enable-taglib' '--enable-theora' '--enable-twolame' '--enable-upnp' '--enable-vcd' '--enable-vcdx' '--enable-vorbis' '--enable-x264' '--enable-zvbi' '--with-kde-solid=/usr/share/kde4/apps/solid/actions/' '--with-mozilla-pkg=libxul' '--disable-dxva2' '--disable-gnomevfs' '--disable-goom' '--disable-osso_screensaver' '--disable-portaudio' '--disable-projectm' '--disable-sqlite' '--disable-telx' '--enable-alsa' '--enable-atmo' '--enable-dc1394' '--enable-dv' '--enable-libva' '--enable-pvr' '--enable-udev' '--enable-v4l2' '--enable-svgalib' 'build_alias=i686-linux-gnu' 'CFLAGS=-g -O2' 'LDFLAGS=-Wl,--as-needed' 'CPPFLAGS=' 'CXXFLAGS=-g -O2' [0x8a8e914] main libvlc debug: translation test: code is "C" [0x8a8e914] main libvlc debug: checking plugin modules [0x8a8e914] main libvlc debug: loading plugins cache file /usr/lib/vlc/plugins/plugins-04041e-3e8.dat [0x8a8e914] main libvlc debug: recursively browsing `/usr/lib/vlc/plugins' [0x8a8e914] main libvlc debug: saving plugins cache /usr/lib/vlc/plugins/plugins-04041e-3e8.dat [0x8a8e914] main libvlc debug: module bank initialized (394 modules) [0x8a8e914] main libvlc debug: opening config file (~/.config/vlc/vlcrc) [0x8a8e914] main libvlc debug: CPU has capabilities MMX MMXEXT SSE SSE2 SSE3 SSSE3 FPU [0x8a8e914] main libvlc debug: looking for memcpy module: 3 candidates [0x8a8e914] main libvlc debug: using memcpy module "memcpymmxext" [0x8b27274] main input debug: Creating an input for 'Media Library' [0x8b27274] main input debug: Input is a meta file: disabling unneeded options [0x8b27274] main input debug: using timeshift granularity of 50 MiB [0x8b27274] main input debug: using timeshift path '/tmp' [0x8b27274] main input debug: `file/xspf-open://~/.local/share/vlc/ml.xspf' gives access `file' demux `xspf-open' path `~/.local/share/vlc/ml.xspf' [0x8b27274] main input debug: creating demux: access='file' demux='xspf-open' path='~/.local/share/vlc/ml.xspf' [0x8b2b0fc] main demux debug: looking for access_demux module: 2 candidates [0x8b2b0fc] main demux debug: no access_demux module matching "file" could be loaded [0x8b2b0fc] main demux debug: TIMER module_need() : 1.499 ms - Total 1.499 ms / 1 intvls (Avg 1.499 ms) [0x8b27274] main input debug: creating access 'file' path='~/.local/share/vlc/ml.xspf' [0x8b3556c] main access debug: looking for access module: 2 candidates [0x8b3556c] filesystem access debug: opening file `~/.local/share/vlc/ml.xspf' [0x8b3556c] main access debug: using access module "filesystem" [0x8b3556c] main access debug: TIMER module_need() : 1.024 ms - Total 1.024 ms / 1 intvls (Avg 1.024 ms) [0x8b356b4] main stream debug: Using AStream*Stream [0x8b356b4] main stream debug: pre buffering [0x8b356b4] main stream debug: received first data after 0 ms [0x8b356b4] main stream debug: pre-buffering done 296 bytes in 0s - 5899 KiB/s [0x8b34ae4] main stream debug: looking for stream_filter module: 5 candidates [0x8b34ae4] main stream debug: no stream_filter module matching "any" could be loaded [0x8b34ae4] main stream debug: TIMER module_need() : 1.572 ms - Total 1.572 ms / 1 intvls (Avg 1.572 ms) [0x8b34ae4] main stream debug: looking for stream_filter module: 1 candidate [0x8b34ae4] main stream debug: using stream_filter module "stream_filter_record" [0x8b34ae4] main stream debug: TIMER module_need() : 0.642 ms - Total 0.642 ms / 1 intvls (Avg 0.642 ms) [0x8b27274] main input debug: creating demux: access='file' demux='xspf-open' path='~/.local/share/vlc/ml.xspf' [0x8b35f3c] main demux debug: looking for demux module: 1 candidate [0x8b35f3c] playlist demux debug: using XSPF playlist reader [0x8b35f3c] main demux debug: using demux module "playlist" [0x8b35f3c] main demux debug: TIMER module_need() : 0.965 ms - Total 0.965 ms / 1 intvls (Avg 0.965 ms) [0x8b388d4] main demux meta debug: looking for meta reader module: 2 candidates [0x8b388d4] lua demux meta debug: Trying Lua scripts in ~/.local/share/vlc/lua/meta/reader [0x8b388d4] lua demux meta debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader [0x8b388d4] lua demux meta debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac [0x8b388d4] lua demux meta debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader [0x8b388d4] main demux meta debug: no meta reader module matching "any" could be loaded [0x8b388d4] main demux meta debug: TIMER module_need() : 11.401 ms - Total 11.401 ms / 1 intvls (Avg 11.401 ms) [0x8b27274] main input debug: `file/xspf-open://~/.local/share/vlc/ml.xspf' successfully opened [0x8b388d4] main xml debug: looking for xml module: 2 candidates [0x8b388d4] main xml debug: using xml module "xml" [0x8b388d4] main xml debug: TIMER module_need() : 1.770 ms - Total 1.770 ms / 1 intvls (Avg 1.770 ms) Warning: call to srand(1369591308) Warning: call to rand() [0x8b35f3c] playlist demux debug: parsed 0 tracks successfully [0x8b388d4] main xml debug: removing module "xml" [0x8b27274] main input debug: EOF reached [0x8b35f3c] main demux debug: removing module "playlist" [0x8b34ae4] main stream debug: removing module "stream_filter_record" [0x8b3556c] main access debug: removing module "filesystem" [0x8b27274] main input debug: TIMER input launching for 'Media Library' : 18.599 ms - Total 18.599 ms / 1 intvls (Avg 18.599 ms) [0x8b34ae4] main interface debug: looking for interface module: 1 candidate [0x8b34ae4] main interface debug: using interface module "hotkeys" [0x8b34ae4] main interface debug: TIMER module_need() : 1.383 ms - Total 1.383 ms / 1 intvls (Avg 1.383 ms) [0x8b388d4] main interface debug: looking for interface module: 1 candidate Blocked: call to unsetenv("DBUS_ACTIVATION_ADDRESS") Blocked: call to unsetenv("DBUS_ACTIVATION_BUS_TYPE") [0x8b25e3c] main playlist debug: Activated [0x8b388d4] main interface debug: using interface module "inhibit" [0x8b388d4] main interface debug: TIMER module_need() : 6.719 ms - Total 6.719 ms / 1 intvls (Avg 6.719 ms) [0x8b25e3c] main playlist debug: adding item `test.wav' ( file:///path/to/./test.wav ) [0x8b3d26c] main interface debug: looking for interface module: 1 candidate [0x8b3d26c] main interface debug: using interface module "signals" [0x8b3d26c] main interface debug: TIMER module_need() : 0.932 ms - Total 0.932 ms / 1 intvls (Avg 0.932 ms) [0x8b28f8c] main interface debug: looking for interface module: 1 candidate [0x8b3dbf4] main input debug: Creating an input for 'test.wav' [0x8b25e3c] main playlist debug: rebuilding array of current - root Playlist [0x8b25e3c] main playlist debug: rebuild done - 1 items, index -1 [0x8b28f8c] main interface debug: using interface module "globalhotkeys" [0x8b28f8c] main interface debug: TIMER module_need() : 17.108 ms - Total 17.108 ms / 1 intvls (Avg 17.108 ms) [0x8b652e4] main interface debug: looking for interface module: 1 candidate [0x8b652e4] dummy interface: using the dummy interface module... [0x8b652e4] main interface debug: using interface module "dummy" [0x8b652e4] main interface debug: TIMER module_need() : 0.922 ms - Total 0.922 ms / 1 intvls (Avg 0.922 ms) [0x8b25e3c] main playlist debug: processing request item null node Playlist skip 0 [0x8b25e3c] main playlist debug: starting new item [0x8b25e3c] main playlist debug: creating new input thread [0x8b43764] main input debug: Creating an input for 'test.wav' [0x8b43764] main input debug: thread (input) created at priority 10 (input/input.c:220) [0x8b25e3c] main playlist debug: no fetch required for (null) (art currently (null)) [0x8b43764] main input debug: thread started [0x8b43764] main input debug: using timeshift granularity of 50 MiB [0x8b43764] main input debug: using timeshift path '/tmp' [0x8b43764] main input debug: `file:///path/to/./test.wav' gives access `file' demux `' path `/path/to/./test.wav' [0x8b43764] main input debug: creating demux: access='file' demux='' path='/path/to/./test.wav' [0x8b48024] main demux debug: looking for access_demux module: 2 candidates [0x8b48024] main demux debug: no access_demux module matching "file" could be loaded [0x8b48024] main demux debug: TIMER module_need() : 0.534 ms - Total 0.534 ms / 1 intvls (Avg 0.534 ms) [0x8b43764] main input debug: creating access 'file' path='/path/to/./test.wav' [0x8b67b0c] main access debug: looking for access module: 2 candidates [0x8b67b0c] filesystem access debug: opening file `/path/to/./test.wav' [0x8b67b0c] main access debug: using access module "filesystem" [0x8b67b0c] main access debug: TIMER module_need() : 0.533 ms - Total 0.533 ms / 1 intvls (Avg 0.533 ms) [0x8b4119c] main stream debug: Using AStream*Stream [0x8b4119c] main stream debug: pre buffering [0x8b4119c] main stream debug: received first data after 0 ms [0x8b4119c] main stream debug: pre-buffering done 1024 bytes in 0s - 16666 KiB/s [0x8b4878c] main stream debug: looking for stream_filter module: 5 candidates [0x8b4878c] main stream debug: no stream_filter module matching "any" could be loaded [0x8b4878c] main stream debug: TIMER module_need() : 0.509 ms - Total 0.509 ms / 1 intvls (Avg 0.509 ms) [0x8b4878c] main stream debug: looking for stream_filter module: 1 candidate [0x8b4878c] main stream debug: using stream_filter module "stream_filter_record" [0x8b4878c] main stream debug: TIMER module_need() : 0.393 ms - Total 0.393 ms / 1 intvls (Avg 0.393 ms) [0x8b43764] main input debug: creating demux: access='file' demux='' path='/path/to/./test.wav' [0x8b6a6b4] main demux debug: looking for demux module: 52 candidates [0x8b6a6b4] wav demux debug: chunk: fcc=`fmt ` size=40 [0x8b6a6b4] wav demux debug: format: 0xfffe, fourcc: pcm , channels: 1, freq: 44100 Hz, bitrate: 172Ko/s, blockalign: 4, bits/samples: 32, extra size: 0 [0x8b6a6b4] wav demux debug: found PCM audio format [0x8b6a6b4] wav demux debug: chunk: fcc=`fact` size=4 [0x8b6a6b4] wav demux debug: chunk: fcc=`data` size=176400 [0x8b43764] main input debug: selecting program id=0 [0x8b6a6b4] main demux debug: using demux module "wav" [0x8b6a6b4] main demux debug: TIMER module_need() : 1.034 ms - Total 1.034 ms / 1 intvls (Avg 1.034 ms) [0x8b43764] main input debug: looking for a subtitle file in /path/to/./ [0x8b4b464] main decoder debug: looking for decoder module: 30 candidates [0x8b4b464] araw decoder debug: samplerate:44100Hz channels:1 bits/sample:32 [0x8b4b464] main decoder debug: using decoder module "araw" [0x8b4b464] main decoder debug: TIMER module_need() : 9.164 ms - Total 9.164 ms / 1 intvls (Avg 9.164 ms) [0x8b4b464] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301) [0x8b4b464] main decoder debug: thread started [0x8b4211c] main demux meta debug: looking for meta reader module: 2 candidates [0x8b4211c] lua demux meta debug: Trying Lua scripts in ~/.local/share/vlc/lua/meta/reader [0x8b4211c] lua demux meta debug: Trying Lua scripts in /usr/lib/vlc/lua/meta/reader [0x8b4211c] lua demux meta debug: Trying Lua playlist script /usr/lib/vlc/lua/meta/reader/filename.luac [0x8b4211c] lua demux meta debug: Trying Lua scripts in /usr/share/vlc/lua/meta/reader [0x8b4211c] main demux meta debug: no meta reader module matching "any" could be loaded [0x8b4211c] main demux meta debug: TIMER module_need() : 2.517 ms - Total 2.517 ms / 1 intvls (Avg 2.517 ms) [0x8b43764] main input debug: `file:///path/to/./test.wav' successfully opened [0x8b43764] main input debug: Buffering 0% [0x8b43764] main input debug: Buffering 16% [0x8b43764] main input debug: Buffering 33% [0x8b43764] main input debug: Buffering 50% [0x8b43764] main input debug: Buffering 66% [0x8b43764] main input debug: Buffering 83% [0x8b43764] main input debug: Buffering 100% [0x8b43764] main input debug: Stream buffering done (350 ms in 1 ms) [0x8b43764] main input debug: creating aout [0x8b405d4] main audio output debug: looking for audio output module: 4 candidates [0x8b405d4] pulse audio output debug: using Mono channel map [0x8b405d4] pulse audio output debug: connected to device alsa_output.pci-0000_00_1b.0.analog-stereo (0) [0x8b405d4] pulse audio output debug: using buffer metrics: maxlength=4194304, tlength=135828, prebuf=88200, minreq=3528 [0x8b405d4] main audio output debug: using audio output module "pulse" [0x8b405d4] main audio output debug: TIMER module_need() : 35.140 ms - Total 35.140 ms / 1 intvls (Avg 35.140 ms) [0x8b405d4] main audio output debug: output 's32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8b405d4] main audio output debug: mixer 'f32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8b405d4] main audio output debug: filter(s) 'f32l'->'s32l' 44100 Hz->44100 Hz Mono->Mono [0x8b694dc] main audio filter debug: looking for audio filter module: 13 candidates [0x8b694dc] audio_format audio filter debug: f32l->s32l, bits per sample: 32->32 [0x8b694dc] main audio filter debug: using audio filter module "audio_format" [0x8b694dc] main audio filter debug: TIMER module_need() : 5.899 ms - Total 5.899 ms / 1 intvls (Avg 5.899 ms) [0x8b405d4] main audio output debug: found a filter for the whole conversion [0x8b847ec] main generic debug: looking for audio mixer module: 3 candidates [0x8b847ec] main generic debug: using audio mixer module "float32_mixer" [0x8b847ec] main generic debug: TIMER module_need() : 0.820 ms - Total 0.820 ms / 1 intvls (Avg 0.820 ms) [0x8b405d4] main audio output debug: input 's32l' 44100 Hz Mono frame=1 samples/4 bytes [0x8b405d4] main audio output debug: filter(s) 's32l'->'f32l' 44100 Hz->44100 Hz Mono->Mono [0x8b84c2c] main audio filter debug: looking for audio filter module: 13 candidates [0x8b84c2c] audio_format audio filter debug: s32l->f32l, bits per sample: 32->32 [0x8b84c2c] main audio filter debug: using audio filter module "audio_format" [0x8b84c2c] main audio filter debug: TIMER module_need() : 0.404 ms - Total 0.404 ms / 1 intvls (Avg 0.404 ms) [0x8b405d4] main audio output debug: found a filter for the whole conversion [0x8b405d4] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Mono->Mono [0x8b84f5c] main audio filter debug: looking for audio filter module: 13 candidates [0x8b84f5c] main audio filter debug: using audio filter module "ugly_resampler" [0x8b84f5c] main audio filter debug: TIMER module_need() : 0.297 ms - Total 0.297 ms / 1 intvls (Avg 0.297 ms) [0x8b405d4] main audio output debug: found a filter for the whole conversion [0x8b4b464] main decoder debug: End of audio preroll [0x8b43764] main input debug: Decoder buffering done in 44 ms [0x8b405d4] main audio output warning: PTS is out of range (-9611), dropping buffer [0x8b405d4] main audio output warning: PTS is out of range (-32755), dropping buffer [0x8b405d4] pulse audio output debug: uncorking [0x8b405d4] pulse audio output debug: started [0x8b405d4] pulse audio output debug: underflow [0x8b43764] main input debug: EOF reached [0x8b25e3c] main playlist debug: finished input [0x8b4b464] main decoder debug: removing module "araw" [0x8b4b464] main decoder debug: killing decoder fourcc `s32l', 0 PES in FIFO [0x8b84c2c] main audio filter debug: removing module "audio_format" [0x8b84f5c] main audio filter debug: removing module "ugly_resampler" [0x8b405d4] main audio output debug: removing module "pulse" [0x8b694dc] main audio filter debug: removing module "audio_format" [0x8b847ec] main generic debug: removing module "float32_mixer" [0x8b43764] main input debug: releasing aout [0x8b6a6b4] main demux debug: removing module "wav" [0x8b4878c] main stream debug: removing module "stream_filter_record" [0x8b67b0c] main access debug: removing module "filesystem" [0x8b43764] main input debug: Program doesn't contain anymore ES [0x8b43764] main input debug: thread ended [0x8b25e3c] main playlist debug: dead input [0x8b25e3c] main playlist debug: changing item without a request (current 0/1) [0x8b25e3c] main playlist debug: nothing to play [0x8b25e3c] main playlist: end of playlist, exiting [0x8a8e914] main libvlc debug: deactivating the playlist [0x8b25e3c] main playlist debug: Deactivate [0x8b6a7ac] main playlist export debug: saving Media Library to file ~/.local/share/vlc/ml.xspf [0x8b6a7ac] main playlist export debug: looking for playlist export module: 1 candidate [0x8b6a7ac] main playlist export debug: using playlist export module "export" [0x8b6a7ac] main playlist export debug: TIMER module_need() : 1.346 ms - Total 1.346 ms / 1 intvls (Avg 1.346 ms) [0x8b6a7ac] main playlist export debug: removing module "export" [0x8b25e3c] main playlist debug: Deactivated [0x8a8e914] main libvlc debug: removing all services discovery tasks [0x8a8e914] main libvlc debug: removing all interfaces [0x8b652e4] main interface debug: removing module "dummy" [0x8b28f8c] main interface debug: removing module "globalhotkeys" [0x8b3d26c] main interface debug: removing module "signals" [0x8b43764] main input debug: TIMER input launching for 'test.wav' : 20.786 ms - Total 20.786 ms / 1 intvls (Avg 20.786 ms) [0x8b388d4] main interface debug: removing module "inhibit" [0x8b34ae4] main interface debug: removing module "hotkeys" [0x8b25e3c] main playlist debug: destroying [0x8a8e914] main libvlc debug: TIMER ML Load : Total 21.752 ms / 1 intvls (Avg 21.752 ms) [0x8a8e914] main libvlc debug: TIMER Preparse run : Total 21.198 ms / 1 intvls (Avg 21.198 ms) [0x8a8e914] main libvlc debug: TIMER Items array build : Total 0.135 ms / 1 intvls (Avg 0.135 ms) [0x8a8e914] main libvlc debug: TIMER ML Dump : Total 2.148 ms / 1 intvls (Avg 2.148 ms) [0x8a8e914] main libvlc debug: removing stats [0x8a8e914] main libvlc debug: removing module "memcpymmxext"

[Rémi Denis-Courmont]

This is already fixed with more recent VLC and PulseAudio versions.