DVD playback stalls with commercially produced videos

[ineuw]

I am using VLC 1.1.1 on Windows XP SP3 with 2GB RAM. and playing a commercially released DVD of the British ITV series "Prime Suspect" with closed captions (there are no other subtitles). The DVD surface is clean and not scratched.

It plays for some time, which I assume it to be a chapter and then it stalls. At times it restarts after a few minutes and at times it doesn't. VLC controls are not frozen when this happens, but they don't do anything. When playing without close captions, the play is longer, perhaps 2 chapters, and then it stall as well. I guess they are chapters because I see the image flickers at some point. What can I do to correct this annoyance?

[VLC_help]

Have you tried dvdsimple option? What does Tools -> Messages (set Verbosity to 2) complain when stalling happens?

[ineuw]

Thanks for your reply. I reset the Preferences and after some 5 minutes, (and a lot messages omitted), when the video stopped, these were the last lines of the messages.

main warning: early picture skipped
main warning: computed PTS is out of range (2834912), clearing out
main warning: output PTS is out of range (2862912), clearing out
main debug: audio output is starving (394951), playing silence
main warning: output date isn't PTS date, requesting resampling (-44951)
main debug: auto hidding mouse
main debug: auto hidding mouse

[VLC_help]

No errors before those messages?

[ineuw]

No errors.

[ineuw]

Sorry for this 1,500 post but I don't know if you accept uploads:

This is the log dump for five minutes of viewing when it froze up:

qt4 warning: Input option: dvdnav-caching=300
main debug: adding item `dvd://G' ( dvd://G:\ )
main debug: rebuilding array of current - root Playlist
main debug: rebuild done - 1 items, index -1
main debug: processing request item dvd://G node Playlist skip 0
main debug: resyncing on dvd://G
main debug: dvd://G is at 0
main debug: starting new item
main debug: creating new input thread
main debug: Creating an input for 'dvd://G'
main debug: thread (input) created at priority 1 (../.././src/input/input.c:220)
main debug: thread started
main debug: using timeshift granularity of 50 MiB
main debug: using timeshift path 'C:\DOCUME~1\Imre\LOCALS~1\Temp'
main debug: `dvd://G:\' gives access `dvd' demux `' path `G:\'
main debug: creating demux: access='dvd' demux='' path='G:\'
main debug: looking for access_demux module: 2 candidates
qt4 debug: IM: Setting an input
dvdnav debug: trying to go to dvd menu
main debug: using access_demux module "dvdnav"
main debug: TIMER module_need() : 1213.000 ms - Total 1213.000 ms / 1 intvls (Avg 1213.000 ms)
main debug: looking for meta reader module: 2 candidates
lua debug: Trying Lua scripts in C:\Documents and Settings\Imre\Application Data\vlc\lua\meta\reader
lua debug: Trying Lua scripts in C:\Program Files\VideoLAN\VLC\lua\meta\reader
qt4 debug: Title 6
qt4 debug: Chapter: 7
lua debug: Trying Lua playlist script C:\Program Files\VideoLAN\VLC\lua\meta\reader\filename.lua
main debug: no meta reader module matching "any" could be loaded
main debug: TIMER module_need() : 2.000 ms - Total 2.000 ms / 1 intvls (Avg 2.000 ms)
main debug: `dvd://G:\' successfully opened
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_VTS_CHANGE
dvdnav debug: - vtsN=5
dvdnav debug: - domain=8
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=1
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=45000
dvdnav debug: - pg_length=45000
dvdnav debug: - pgc_length=45000
dvdnav debug: - cell_start=0
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=0
dvdnav debug: - physical_letterbox=0
dvdnav debug: - physical_pan_scan=0
dvdnav debug: buttonUpdate not done b=1 t=0
main debug: selecting program id=0
main debug: looking for decoder module: 34 candidates
avcodec debug: libavcodec initialized (interface 0x350500)
avcodec warning: refusing to decode non validated subtitle codec
main debug: using decoder module "spudec"
main debug: TIMER module_need() : 25.000 ms - Total 25.000 ms / 1 intvls (Avg 25.000 ms)
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "spudec"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: thread (decoder) created at priority 0 (../.././src/input/decoder.c:301)
main debug: thread started
spudec debug: invalid starting packet (size < 4 or pts <=0)
spudec debug: spu size: 0, i_pts: 0 i_buffer: 128
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main debug: Buffering 0%
dvdnav debug: buttonUpdate 1
main debug: Buffering 0%
main debug: looking for decoder module: 34 candidates
avcodec debug: libavcodec already initialized
avcodec debug: trying to use direct rendering
avcodec debug: ffmpeg codec (MPEG-1/2 Video) started
main debug: using decoder module "avcodec"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "packetizer_mpegvideo"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: thread (decoder) created at priority 0 (../.././src/input/decoder.c:301)
main debug: thread started
dvdnav debug: buttonUpdate 1
packetizer_mpegvideo debug: size 720x480 fps=29.970
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 15%
main debug: Buffering 15%
main debug: Buffering 16%
main debug: Buffering 16%
main debug: Buffering 17%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 20%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: Buffering 22%
main debug: Buffering 23%
main debug: Buffering 23%
main debug: Buffering 24%
main debug: Buffering 24%
main debug: Buffering 25%
main debug: Buffering 26%
main debug: Buffering 26%
main debug: Buffering 27%
main debug: Buffering 27%
main debug: Buffering 28%
main debug: Buffering 28%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 47%
main debug: Buffering 47%
main debug: Buffering 48%
main debug: Buffering 48%
main debug: Buffering 49%
main debug: Buffering 49%
main debug: Buffering 50%
main debug: Buffering 50%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 53%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 56%
main debug: Buffering 57%
main debug: Buffering 57%
main debug: Buffering 58%
main debug: Buffering 59%
main debug: Stream buffering done (177 ms in 79 ms)
main debug: no usable vout present, spawning one
main debug: looking for text renderer module: 2 candidates
freetype debug: Using Arial as font from file C:\WINDOWS\Fonts\ARIAL.TTF
freetype debug: using fontsize: 2
main debug: using text renderer module "freetype"
main debug: TIMER module_need() : 2.000 ms - Total 2.000 ms / 1 intvls (Avg 2.000 ms)
main debug: looking for video filter2 module: 18 candidates
swscale debug: 32x32 chroma: YUVA -> 16x16 chroma: YUVA with scaling using Bicubic (good quality)
main debug: using video filter2 module "swscale"
main debug: TIMER module_need() : 2.000 ms - Total 2.000 ms / 1 intvls (Avg 2.000 ms)
main debug: looking for video filter2 module: 18 candidates
yuvp debug: YUVP to YUVA converter
main debug: using video filter2 module "yuvp"
main debug: TIMER module_need() : 16.000 ms - Total 16.000 ms / 1 intvls (Avg 16.000 ms)
main debug: crop: 277,269,250,50, palette forced: 1
main debug: window size: 720x540
main debug: Deinterlacing available
main debug: deinterlace 0, mode blend, is_needed 0
main debug: looking for video output module: 1 candidate
vout_wrapper debug: Opening vout display wrapper
main debug: looking for vout display module: 8 candidates
directx debug: creating Vout EventThread
directx debug: DirectXCreateWindow
main debug: looking for vout window hwnd module: 3 candidates
qt4 debug: requesting video...
qt4 debug: Video was requested 0, 0
main debug: using vout window hwnd module "qt4"
main debug: TIMER module_need() : 72.000 ms - Total 72.000 ms / 1 intvls (Avg 72.000 ms)
directx debug: created video sub-window
directx debug: Vout EventThread running
directx debug: disabling screen saver
directx debug: directx-device:
directx debug: DirectXEnumCallback: Radeon X1300/X1550 Series , \\.\DISPLAY1
directx debug: selecting Radeon X1300/X1550 Series , \\.\DISPLAY1
directx debug: screen dimensions (0x0,1024x768)
directx debug: DirectDraw Capabilities: overlay=1 yuvoverlay=1 can_deinterlace_overlay=1 colorkey=1 stretch=1 bltfourcc=1
main debug: VoutDisplayEvent 'resize' 728x567 window
directx debug: YUV plain surface created successfully
main debug: using vout display module "directx"
main debug: TIMER module_need() : 81.000 ms - Total 81.000 ms / 1 intvls (Avg 81.000 ms)
main debug: using video output module "vout_wrapper"
main debug: TIMER module_need() : 82.000 ms - Total 82.000 ms / 1 intvls (Avg 82.000 ms)
main debug: got 1 direct buffer(s)
main debug: pic render sz 720x480, of (0,0), vsz 720x480, 4cc I420, sar 8:9, msk r0x0 g0x0 b0x0
main debug: pic in sz 720x480, of (0,0), vsz 720x480, 4cc I420, sar 8:9, msk r0x0 g0x0 b0x0
main debug: pic out sz 720x480, of (0,0), vsz 720x480, 4cc I420, sar 8:9, msk r0x0 g0x0 b0x0
main debug: direct render, mapping render pictures 0-23 to system pictures 1-24
avcodec debug: using direct rendering
main debug: End of video preroll
main debug: Received first picture
main debug: Decoder buffering done in 109 ms
dvdnav debug: DVDNAV_NOP
dvdnav debug: DVDNAV_WAIT
dvdnav debug: DVDNAV_STILL_FRAME
dvdnav debug: - length=0xff
main debug: VoutDisplayEvent 'resize' 1024x620 window
main debug: Post-processing available
main warning: vlc_object_find_name(postproc) is not safe!
main debug: looking for video blending module: 1 candidate
blend debug: chroma: YUVA -> I420
main debug: using video blending module "blend"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
freetype debug: using fontsize: 30
main debug: VoutDisplayEvent 'mouse button' 0 t=8
main debug: crop: 277,269,250,50, palette forced: 1
dvdnav debug: buttonUpdate 1
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
spudec debug: invalid starting packet (size < 4 or pts <=0)
spudec debug: spu size: 0, i_pts: 0 i_buffer: 128
dvdnav debug: DVDNAV_VTS_CHANGE
dvdnav debug: - vtsN=5
dvdnav debug: - domain=2
main debug: ES_OUT_RESET_PCR called
spudec debug: invalid starting packet (size < 4 or pts <=0)
spudec debug: spu size: 0, i_pts: 0 i_buffer: 128
main debug: thread times: real 0m2.578125s, kernel 0m0.000000s, user 0m0.046875s
avcodec debug: ffmpeg codec (MPEG-1/2 Video) stopped
main debug: removing module "avcodec"
main debug: killing decoder fourcc `mpgv', 0 PES in FIFO
main debug: [0] 0 0
main debug: [1] 0 0
main debug: [2] 0 0
main debug: [3] 0 0
main debug: [4] 0 0
main debug: [5] 0 0
main debug: [6] 0 0
main debug: [7] 0 0
main debug: [8] 0 0
main debug: [9] 0 0
main debug: [10] 0 0
main debug: [11] 2 0
main debug: [12] 0 0
main debug: [13] 0 0
main debug: [14] 0 0
main debug: [15] 0 0
main debug: [16] 0 0
main debug: [17] 0 0
main debug: [18] 0 0
main debug: [19] 0 0
main debug: [20] 0 0
main debug: [21] 0 0
main debug: [22] 0 0
main debug: [23] 0 0
main debug: saving a free vout
main debug: removing module "packetizer_mpegvideo"
main debug: thread times: real 0m2.625000s, kernel 0m0.000000s, user 0m0.000000s
main debug: removing module "spudec"
main debug: killing decoder fourcc `spu ', 0 PES in FIFO
main debug: removing module "spudec"
main debug: Program doesn't contain anymore ES
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=1
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=38283000
dvdnav debug: - pg_length=101835000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=0
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: looking for decoder module: 34 candidates
avcodec debug: libavcodec already initialized
avcodec debug: trying to use direct rendering
avcodec debug: ffmpeg codec (MPEG-1/2 Video) started
main debug: using decoder module "avcodec"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: looking for packetizer module: 21 candidates
main debug: using packetizer module "packetizer_mpegvideo"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: thread (decoder) created at priority 0 (../.././src/input/decoder.c:301)
main debug: thread started
dvdnav debug: buttonUpdate not done b=1 t=1
packetizer_mpegvideo debug: size 720x480 fps=29.970
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
qt4 debug: Title 6
qt4 debug: Chapter: 7
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Adding CC track 1 for es[2]
main debug: Adding CC track 2 for es[2]
main debug: Adding CC track 3 for es[2]
main debug: Adding CC track 4 for es[2]
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 15%
main debug: Buffering 15%
main debug: Buffering 16%
main debug: Buffering 16%
main debug: Buffering 17%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 20%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: trying to reuse free vout
main debug: reusing provided vout
avcodec debug: using direct rendering
main debug: Buffering 22%
main debug: Buffering 23%
main debug: Buffering 23%
main debug: Buffering 24%
main debug: Buffering 24%
main debug: Buffering 25%
main debug: Buffering 26%
main debug: Buffering 26%
main debug: Buffering 27%
main debug: Buffering 27%
main debug: Buffering 28%
main debug: Buffering 28%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 47%
main debug: Buffering 47%
main debug: Buffering 48%
main debug: Buffering 48%
main debug: Buffering 49%
main debug: End of video preroll
main debug: Received first picture
main debug: Detected interlaced video
main debug: deinterlace 0, mode blend, is_needed 1
main debug: Buffering 49%
main debug: Buffering 50%
main debug: looking for decoder module: 34 candidates
main debug: using decoder module "a52"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: thread started
main debug: thread (decoder) created at priority 2 (../.././src/input/decoder.c:301)
a52 debug: A/52 channels:2 samplerate:48000 bitrate:192000
main debug: Buffering 50%
main debug: creating aout
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 53%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: looking for audio output module: 4 candidates
aout_directx debug: Opening DirectSound Audio Output
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 56%
main debug: Buffering 57%
main debug: Buffering 57%
main debug: Buffering 58%
main debug: Buffering 59%
main debug: Buffering 59%
main debug: Buffering 61%
main debug: Buffering 61%
main debug: Buffering 62%
main debug: Buffering 62%
main debug: Buffering 63%
main debug: Buffering 63%
main debug: Buffering 64%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 74%
main debug: Buffering 75%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering 77%
main debug: Buffering 78%
main debug: Buffering 79%
main debug: Buffering 89%
main debug: Buffering 89%
main debug: Buffering 90%
main debug: Stream buffering done (300 ms in 113 ms)
main debug: VoutDisplayEvent 'mouse button' 0 t=9
aout_directx debug: found device: Primary Sound Driver
aout_directx debug: found device: SoundMAX HD Audio
aout_directx debug: device supports 2 channels (DEFAULT!)
aout_directx debug: device supports 1 channel
aout_directx debug: Windows says your SpeakerConfig is stereo
aout_directx debug: device supports A/52 over S/PDIF
aout_directx debug: creating DirectSoundThread
main debug: thread started
aout_directx debug: DirectSoundThread ready
main debug: thread (DirectSound Notification Thread) created at priority 15 (../../.././modules/audio_output/directx.c:321)
main debug: using audio output module "aout_directx"
main debug: TIMER module_need() : 56.000 ms - Total 56.000 ms / 1 intvls (Avg 56.000 ms)
main debug: output 's16l' 48000 Hz Dolby frame=1 samples/4 bytes
main debug: mixer 'f32l' 48000 Hz Dolby frame=1 samples/8 bytes
main debug: filter(s) 'f32l'->'s16l' 48000 Hz->48000 Hz Dolby->Dolby
main debug: looking for audio filter module: 13 candidates
audio_format debug: f32l->s16l, bits per sample: 32->16
main debug: using audio filter module "audio_format"
main debug: TIMER module_need() : 5.000 ms - Total 5.000 ms / 1 intvls (Avg 5.000 ms)
main debug: found a filter for the whole conversion
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: input 'a52 ' 48000 Hz Dolby frame=1536 samples/768 bytes
main debug: looking for audio filter module: 1 candidate
scaletempo debug: format: 48000 rate, 2 nch, 4 bps, fl32
scaletempo debug: params: 30 stride, 0.200 overlap, 14 search
scaletempo debug: 1.000 scale, 1440.000 stride_in, 1440 stride_out, 1152 standing, 288 overlap, 672 search, 2400 queue, fl32 mode
main debug: using audio filter module "scaletempo"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: filter(s) 'a52 '->'f32l' 48000 Hz->48000 Hz Dolby->Dolby
main debug: looking for audio filter module: 13 candidates
main debug: using audio filter module "a52tofloat32"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: found a filter for the whole conversion
main debug: filter(s) 'f32l'->'f32l' 52800 Hz->48000 Hz Dolby->Dolby
main debug: looking for audio filter module: 13 candidates
main debug: using audio filter module "ugly_resampler"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: found a filter for the whole conversion
main debug: End of audio preroll
main debug: Decoder buffering done in 62 ms
freetype debug: using fontsize: 30
main debug: auto hidding mouse
main debug: control type=10
main warning: early picture skipped
main warning: early picture skipped
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=4
dvdnav debug: - pgN=2
dvdnav debug: - cell_length=9627000
dvdnav debug: - pg_length=95616000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=101835000
dvdnav debug: - pg_start=101835000
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
qt4 debug: Title 6
qt4 debug: Chapter: 7
qt4 debug: Title 6
qt4 debug: Chapter: 7
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 17%
main debug: Buffering 45%
main debug: End of audio preroll
main debug: Buffering 55%
main debug: Buffering 73%
main debug: Stream buffering done (304 ms in 9 ms)
main debug: End of video preroll
main debug: Received first picture
main debug: Decoder buffering done in 4 ms
main warning: the mixer got a packet in the past (187423)
main warning: the mixer got a packet in the past (155423)
main warning: the mixer got a packet in the past (123423)
main warning: the mixer got a packet in the past (91423)
main warning: the mixer got a packet in the past (59423)
main warning: the mixer got a packet in the past (27423)
main warning: mixer start isn't output start (10530)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: removing module "float32_mixer"
main debug: looking for audio mixer module: 3 candidates
main debug: using audio mixer module "float32_mixer"
main debug: TIMER module_need() : 0.000 ms - Total 0.000 ms / 1 intvls (Avg 0.000 ms)
main debug: control type=3
main warning: early picture skipped
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=3
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=25938000
dvdnav debug: - pg_length=101835000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=75897000
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
qt4 debug: Title 6
qt4 debug: Chapter: 7
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: End of audio preroll
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 15%
main debug: Buffering 15%
main debug: Buffering 20%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: Buffering 22%
main debug: Buffering 23%
main debug: Buffering 23%
main debug: Buffering 24%
main debug: Buffering 24%
main debug: Buffering 25%
main debug: Buffering 26%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 47%
main debug: Buffering 47%
main debug: Buffering 48%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 56%
main debug: Buffering 57%
main debug: Buffering 57%
main debug: Buffering 58%
main debug: Buffering 58%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering 77%
main debug: Buffering 78%
main debug: Buffering 78%
main debug: Buffering 79%
main debug: Buffering 80%
main debug: Buffering 80%
main debug: Buffering 81%
main debug: Buffering 87%
main debug: Buffering 87%
main debug: Buffering 88%
main debug: Buffering 88%
main debug: Buffering 89%
main debug: Buffering 90%
main debug: Buffering 90%
main debug: Buffering 91%
main debug: Buffering 91%
main debug: Buffering 92%
main debug: Buffering 94%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (300 ms in 88 ms)
main debug: End of video preroll
main debug: Received first picture
main debug: Decoder buffering done in 15 ms
main warning: the mixer got a packet in the past (124634)
main warning: the mixer got a packet in the past (92634)
main warning: the mixer got a packet in the past (60634)
main warning: the mixer got a packet in the past (28634)
main warning: mixer start isn't output start (10995)
main debug: control type=3
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
main warning: late picture skipped (48708203999 > -249)
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=3
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=25938000
dvdnav debug: - pg_length=101835000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=75897000
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: End of audio preroll
main debug: Buffering 4%
main debug: Buffering 6%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 17%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 20%
main debug: Buffering 28%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 50%
main debug: Buffering 51%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 53%
main debug: Buffering 53%
main debug: Buffering 60%
main debug: Buffering 61%
main debug: Buffering 62%
main debug: Buffering 62%
main debug: Buffering 63%
main debug: Buffering 64%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 74%
main debug: Buffering 75%
main debug: Buffering 75%
main debug: Buffering 76%
main debug: Buffering 84%
main debug: Buffering 84%
main debug: Buffering 85%
main debug: Buffering 85%
main debug: Buffering 86%
main debug: Buffering 86%
main debug: Buffering 87%
main debug: Buffering 87%
main debug: Buffering 88%
main debug: Buffering 95%
main debug: Buffering 95%
main debug: Buffering 96%
main debug: Buffering 96%
main debug: Buffering 97%
main debug: Buffering 97%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (300 ms in 103 ms)
main debug: Decoder buffering done in 0 ms
main debug: control type=3
main warning: the mixer got a packet in the past (161189)
main warning: the mixer got a packet in the past (129189)
main warning: the mixer got a packet in the past (97189)
main warning: the mixer got a packet in the past (65189)
main warning: the mixer got a packet in the past (33189)
main warning: the mixer got a packet in the past (1189)
main warning: mixer start isn't output start (456)
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=3
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=25938000
dvdnav debug: - pg_length=101835000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=75897000
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 20%
main debug: End of audio preroll
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: Buffering 22%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 45%
main debug: Buffering 47%
main debug: Buffering 51%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 53%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 62%
main debug: Buffering 62%
main debug: Buffering 63%
main debug: Buffering 64%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 74%
main debug: Buffering 75%
main debug: Buffering 75%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering 77%
main debug: Buffering 78%
main debug: Buffering 78%
main debug: Buffering 84%
main debug: Buffering 85%
main debug: Buffering 85%
main debug: Buffering 86%
main debug: Buffering 86%
main debug: Buffering 87%
main debug: Buffering 87%
main debug: Buffering 88%
main debug: Buffering 88%
main debug: Buffering 89%
main debug: Buffering 95%
main debug: Buffering 96%
main debug: Buffering 96%
main debug: Buffering 97%
main debug: Buffering 97%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (300 ms in 226 ms)
main debug: End of video preroll
main debug: Received first picture
main debug: Decoder buffering done in 11 ms
main warning: mixer start isn't output start (-41271)
main debug: audio output is starving (64850), playing silence
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: control type=13
main debug: looking for decoder module: 34 candidates
main debug: using decoder module "cc"
main debug: TIMER module_need() : 2.000 ms - Total 2.000 ms / 1 intvls (Avg 2.000 ms)
main debug: auto hidding mouse
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
main debug: auto hidding mouse
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
main debug: control type=3
main warning: early picture skipped
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=3
dvdnav debug: - pgN=1
dvdnav debug: - cell_length=25938000
dvdnav debug: - pg_length=101835000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=75897000
dvdnav debug: - pg_start=0
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 5%
main debug: Buffering 5%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: End of audio preroll
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 15%
main debug: Buffering 15%
main debug: Buffering 20%
main debug: Buffering 21%
main debug: Buffering 21%
main debug: Buffering 22%
main debug: Buffering 22%
main debug: Buffering 23%
main debug: Buffering 23%
main debug: Buffering 24%
main debug: Buffering 24%
main debug: Buffering 25%
main debug: Buffering 26%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 35%
main debug: Buffering 36%
main debug: Buffering 36%
main debug: Buffering 37%
main debug: Buffering 37%
main debug: Buffering 38%
main debug: Buffering 38%
main debug: Buffering 39%
main debug: Buffering 39%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 43%
main debug: Buffering 43%
main debug: Buffering 44%
main debug: Buffering 45%
main debug: Buffering 45%
main debug: Buffering 46%
main debug: Buffering 46%
main debug: Buffering 47%
main debug: Buffering 47%
main debug: Buffering 48%
main debug: Buffering 53%
main debug: Buffering 54%
main debug: Buffering 55%
main debug: Buffering 55%
main debug: Buffering 56%
main debug: Buffering 56%
main debug: Buffering 57%
main debug: Buffering 57%
main debug: Buffering 58%
main debug: Buffering 58%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 69%
main debug: Buffering 69%
main debug: Buffering 70%
main debug: Buffering 71%
main debug: Buffering 71%
main debug: Buffering 72%
main debug: Buffering 72%
main debug: Buffering 73%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 76%
main debug: Buffering 76%
main debug: Buffering 77%
main debug: Buffering 77%
main debug: Buffering 78%
main debug: Buffering 78%
main debug: Buffering 79%
main debug: Buffering 80%
main debug: Buffering 80%
main debug: Buffering 81%
main debug: Buffering 87%
main debug: Buffering 87%
main debug: Buffering 88%
main debug: Buffering 88%
main debug: Buffering 89%
main debug: Buffering 90%
main debug: Buffering 90%
main debug: Buffering 91%
main debug: Buffering 91%
main debug: Buffering 92%
main debug: Buffering 94%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (300 ms in 87 ms)
main debug: End of video preroll
main debug: Received first picture
main debug: Decoder buffering done in 15 ms
main warning: the mixer got a packet in the past (109111)
main warning: the mixer got a packet in the past (77111)
main warning: the mixer got a packet in the past (45111)
main warning: the mixer got a packet in the past (13111)
main warning: mixer start isn't output start (5034)
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
main debug: control type=3
main warning: early picture skipped
dvdnav debug: DVDNAV_HOP_CHANNEL
main debug: ES_OUT_RESET_PCR called
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=4
dvdnav debug: - pgN=2
dvdnav debug: - cell_length=9627000
dvdnav debug: - pg_length=95616000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=101835000
dvdnav debug: - pg_start=101835000
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
qt4 debug: Title 6
qt4 debug: Chapter: 7
main debug: Buffering 0%
dvdnav debug: buttonUpdate not done b=1 t=1
main debug: Buffering 0%
main debug: Buffering 1%
main debug: Buffering 1%
main debug: Buffering 2%
main debug: Buffering 2%
main debug: Buffering 3%
main debug: Buffering 3%
main debug: Buffering 4%
main debug: Buffering 4%
main debug: Buffering 6%
main debug: Buffering 7%
main debug: Buffering 7%
main debug: Buffering 8%
main debug: Buffering 8%
main debug: Buffering 9%
main debug: Buffering 10%
main debug: Buffering 10%
main debug: Buffering 11%
main debug: Buffering 11%
main debug: Buffering 12%
main debug: Buffering 12%
main debug: End of audio preroll
main debug: Buffering 13%
main debug: Buffering 13%
main debug: Buffering 14%
main debug: Buffering 14%
main debug: Buffering 17%
main debug: Buffering 18%
main debug: Buffering 18%
main debug: Buffering 19%
main debug: Buffering 20%
main debug: Buffering 29%
main debug: Buffering 29%
main debug: Buffering 30%
main debug: Buffering 30%
main debug: Buffering 31%
main debug: Buffering 31%
main debug: Buffering 32%
main debug: Buffering 32%
main debug: Buffering 33%
main debug: Buffering 33%
main debug: Buffering 34%
main debug: Buffering 34%
main debug: Buffering 40%
main debug: Buffering 40%
main debug: Buffering 41%
main debug: Buffering 41%
main debug: Buffering 42%
main debug: Buffering 42%
main debug: Buffering 51%
main debug: Buffering 51%
main debug: Buffering 52%
main debug: Buffering 52%
main debug: Buffering 62%
main debug: Buffering 62%
main debug: Buffering 63%
main debug: End of video preroll
main debug: Received first picture
main debug: Buffering 64%
main debug: Buffering 64%
main debug: Buffering 65%
main debug: Buffering 65%
main debug: Buffering 66%
main debug: Buffering 66%
main debug: Buffering 67%
main debug: Buffering 67%
main debug: Buffering 68%
main debug: Buffering 68%
main debug: Buffering 73%
main debug: Buffering 74%
main debug: Buffering 74%
main debug: Buffering 75%
main debug: Buffering 75%
main debug: Buffering 84%
main debug: Buffering 85%
main debug: Buffering 85%
main debug: Buffering 86%
main debug: Buffering 86%
main debug: Buffering 95%
main debug: Buffering 96%
main debug: Buffering 96%
main debug: Buffering 97%
main debug: Buffering 97%
main debug: Buffering 98%
main debug: Buffering 99%
main debug: Buffering 99%
main debug: Stream buffering done (300 ms in 80 ms)
main debug: Decoder buffering done in 0 ms
main warning: the mixer got a packet in the past (172100)
main warning: the mixer got a packet in the past (140100)
main warning: the mixer got a packet in the past (108100)
main warning: the mixer got a packet in the past (76100)
main warning: the mixer got a packet in the past (44100)
main warning: the mixer got a packet in the past (12100)
main warning: mixer start isn't output start (4646)
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
main debug: auto hidding mouse
main debug: auto hidding mouse
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
freetype debug: using fontsize: 30
dvdnav debug: DVDNAV_NOP
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=5
dvdnav debug: - pgN=2
dvdnav debug: - cell_length=29127000
dvdnav debug: - pg_length=95616000
dvdnav debug: - pgc_length=547674000
dvdnav debug: - cell_start=111462000
dvdnav debug: - pg_start=101835000
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=1 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main warning: clock gap, unexpected stream discontinuity
main warning: feeding synchro with a new reference point trying to recover from clock gap
dvdnav debug: buttonUpdate not done b=1 t=1
main warning: received buffer in the future
main warning: audio drift is too big (182211), dropping buffer
main warning: audio drift is too big (150211), dropping buffer
main warning: early picture skipped
main warning: buffer is 118211 late, triggering upsampling
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse

[ineuw]

This problem seems to relate to the closed captions. The video has no other sub title options, so I can't tell. I've been watching it for the past 20 minutes without closed captions and it hasn't stopped. There are also no messages. Can someone please advise what settings I should modify so that I can see the closed captions as well? Thank you.

[VLC_help]

Closed captions shouldn't stall DVD playback. There have been some changes to CC support in VLC 1.2.0, so you can test out nightly builds, but I don't know if they work any better.

[rogerdpack]

Maybe we need a gprof enabled build of VLC for windows so people can see what's using up the time?

[ineuw]

This is the message dump without closed captions. I removed the intervening buffering messages. The film runs fine but there is an image jump between the chapters. I paused the film to post this:

main error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 715 ms)
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 1154 ms)
main debug: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 0%
main debug: Buffering 0%

main debug: Buffering 98%
main debug: Stream buffering done (1158 ms in 163 ms)
main debug: Decoder buffering done in 0 ms
main warning: output PTS is out of range (586011), clearing out
main error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 1773 ms)
main debug: ES_OUT_RESET_PCR called
main debug: Buffering 0%

main debug: Buffering 99%
main debug: Stream buffering done (1775 ms in 284 ms)
main debug: Decoder buffering done in 0 ms
main warning: output PTS is out of range (1142389), clearing out
main error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 2077 ms)
main debug: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: End of audio preroll
main debug: Buffering 0%
main debug: Buffering 0%

main debug: Buffering 99%
main debug: Stream buffering done (2077 ms in 547 ms)
main debug: Decoder buffering done in 0 ms
main warning: output PTS is out of range (3551278), clearing out
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
dvdnav debug: DVDNAV_NOP
dvdnav debug: DVDNAV_CELL_CHANGE
dvdnav debug: - cellN=6
dvdnav debug: - pgN=2
dvdnav debug: - cell_length=38643000
dvdnav debug: - pg_length=126135000
dvdnav debug: - pgc_length=563328000
dvdnav debug: - cell_start=136023000
dvdnav debug: - pg_start=50781000
dvdnav debug: DVDNAV_SPU_CLUT_CHANGE
dvdnav debug: DVDNAV_SPU_STREAM_CHANGE
dvdnav debug: - physical_wide=-1
dvdnav debug: - physical_letterbox=-1
dvdnav debug: - physical_pan_scan=-1
dvdnav debug: buttonUpdate not done b=2 t=1
dvdnav debug: DVDNAV_AUDIO_STREAM_CHANGE
dvdnav debug: - physical=0
main warning: clock gap, unexpected stream discontinuity
main warning: feeding synchro with a new reference point trying to recover from clock gap
dvdnav debug: buttonUpdate not done b=2 t=1
main warning: received buffer in the future
main warning: received buffer in the future
main warning: received buffer in the future

main warning: early picture skipped
main warning: early picture skipped
main warning: computed PTS is out of range (1079833), clearing out
main warning: output PTS is out of range (1101833), clearing out
main debug: audio output is starving (370106), playing silence
main error: ES_OUT_SET_(GROUP_)PCR is called too late (pts_delay increased to 2287 ms)
main debug: ES_OUT_RESET_PCR called
main debug: Buffering 0%
main debug: Buffering 0%

main debug: Buffering 99%
main debug: Stream buffering done (2287 ms in 287 ms)
main debug: Decoder buffering done in 0 ms
main warning: output PTS is out of range (430311), clearing out
main debug: audio output is starving (67950), playing silence
main debug: auto hidding mouse
main debug: control type=1
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse
main debug: auto hidding mouse

[rogerdpack]

My guess is maybe it is jumping to an "uncached" segment of the DVD, then having to rebuffer before it plays again (CC shouldn't matter though). Maybe try it with a decreased cache size somehow?

[ineuw]

Thanks. That's the one logical solution I didn't try. (Increasing the cache didn't help) Will try tomorrow and let you know. Interestingly, this only happens with English programs on DVD. The DVD was released in the early 2000's it has the HBO logo. So, I don't know if it's the foreign compilation/production is the problem. I watch many DVD's of TV programs from different sources and don't have this problems.

[ineuw]

Hi rogerdpack. Sorry for not getting back sooner but couldn't get the next video in the series, so I couldn't test the problem with the disc which was a BBC/HBO release. I've looked at other US made videos since and they worked seamlessly. But, now, I am watching another commercial US film, a Paramount release and it stalls for about 5 secs each time it reaches a new chapter. The video was made in 2000, just like the BBC/HBO release. This makes me wonder about older production methods with newer computer hardware & OS? I have an Intel dual core CPU, 2GB or RAM and running Windows XP SP3. Also, can you please tell me which cache setting should I adjust? Thanks in advance.

[rogerdpack]

when you go to open the DVD choose "advanced options" or whatever it is. Also if you play it in mplayer does the timestamp shown in the console "reset" when you go from chapter to chapter? (which would indicate that you're going to a new VOB with each chapter, which I think you are).
It may be related to this:
viewtopic.php?f=2&t=95532
but my problem is only that it skips maybe...2s or 5s then keeps playing, it doesn't pause for like 5s...

Anyway are you using 1.1.1 or 1.1.11? I did try a title with 1.0.6 that seemed to have the "pause 5 seconds" between VOB's...
With 1.1.12 I just get the "skipping a few seconds" now.

I see a lot of these messages around the time of the skip:
main warning: PTS is out of range (191668), dropping buffer
full output: https://gist.github.com/1378623

I think what is happening is that the MPEG stream seems to do some funky stuff around that time (see second part of that gist), and VLC just kind of drops it on the floor. I don't see 5s pauses though...even with CC turned on. I assume that disc plays fine in commercial players?

-r

[rogerdpack]

https://forum.videolan.org/viewtopic.php?f=14&t=78010 may be related as well (possible fix?)

[rogerdpack]

I think the problem here is that VLC "skips" when it hit a "break" (PGC boundary typically) in the DVD. I'm willing to provide a sample DVD (cars 2 in this case) and a $200 bounty if anybody can fix this annoyance.

The skip is probably caused by the fact that sometimes MPEG TS timestamps reset back to zero when it hits those boundaries. So it probably confuses VLC. It then skips the (offending) sequences before resyncing and continuing merrily on its way.
Thank you.
-rogerdpack-

[Jean-Baptiste Kempf]

Just tell me what DVD to buy.

[rogerdpack]

Just tell me what DVD to buy.

OK to the best of my knowledge this is the DVD I have:

http://www.amazon.com/gp/product/B001HN ... UTF8&psc=1

I tried to repro the problem and it seems...slightly different now (2.2.0 nightly behaves better than 2.1.3 seemingly, but still something is barely not quite right in the audio--with 2.1.3 something is also wrong with the video, but that seems better in 2.2.0).

Basically, around minute 2 (1:45-2:10), the audio starts breaking up slightly still every so often. Rest of the movie seems ok [?]

oddly, clearing preferences can sometimes make the problem occur less frequently. I hope it's not related overall.

the "skip" with 2.1.3 can sometimes occur at about (vlc's) 2:30 mark (here's the message tools: https://gist.github.com/rdp/11272472 ) Unable to reproduce it with 2.2.0

with 2.2.0, at the same spot I get these messages:

core warning: feeding synchro with a new reference point trying to recover from clock gap
dvdnav debug: buttonUpdate not done b=1 t=18
core error: Could not convert timestamp 108088993066
core warning: early picture skipped
core error: Could not convert timestamp 108089059800
core warning: early picture skipped
core error: Could not convert timestamp 108089109849
core warning: early picture skipped
core error: Could not convert timestamp 108089159898
core warning: early picture skipped
core error: Could not convert timestamp 108089063967
core debug: discarded audio buffer
core debug: auto hiding mouse cursor
core warning: original picture size is undefined

but it appears to not skip enough video frames to be noticeable so...possibly this problem is fixed already [?]

(also try to be on the look out for "very long load time" for some reason sometimes VLC takes ages to load this DVD, as in it takes a full 40 seconds before any video appears, and it feels as if VLC is "frozen" or "broken" or something during that time frame [mplayer can start the dvd right up though, FWIW, if run like mplayer dvdnav:// though mplayer -identify dvdnav:// does take forever to load as well--powerdvd can seemingly load it right up though, perhaps chapters in a title could be queried only when the title starts playing or something, maybe that's what powerdvd does [?]--or possibly showing some busy cursor or dialog while it's querying for chapter/title lengths or so? dunno...]. So this DVD may still be useful to you. Or should I report that one on trac? [will do so in about a week if no response)
Thanks.
-roger-