Some FLAC files stop playing part way through
Posted: 08 Mar 2009 16:51
I am a new user of VLC, and I am very impressed by the sound quality that it produces from FLAC files.
So far I have only been able to try playing a small number of FLAC files. One of these files stops playing part way through on VLC, though it plays correctly on other players.. The problem occurs on both vlc-0.9.8a-win32 and vlc-1.0.0-git-20090306-2305-win32. The file was compressed using the latest level of FLAC (1.2.1b) with compression level 6. The same file plays correctly on foobar2000, Winamp and WMP. If I reduce the compression level to 3, the file plays correctly on VLC.
I set the VLC verbosity level to 2 and captured the output from the same track with FLAC compression levels 6, 4 and 3. (Compression level 5 produced a .flac file that was identical to compression level 6.) With compression level 6, some warning messages are logged. Here are the log extracts from just before the start to just after the end of playing the file.
Compression level 6 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_resampler"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: found a filter for the whole conversion
main debug: End of audio preroll
main debug: Decoder buffering done in 8 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: New Event: type 1107
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
qt4 debug: New Event: type 1108
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1111
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
main warning: received buffer in the future
main warning: received buffer in the future
flac warning: the decoder was aborted by the read callback.
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m10.356000s, kernel 0m0.015600s, user 0m1.606810s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m10.379000s, kernel 0m0.343202s, user 0m0.343202s
Compression level 4 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_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
qt4 debug: Updating the geometry
main debug: End of audio preroll
qt4 debug: size: 109 - 349
main debug: Decoder buffering done in 10 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: sizeHint: 109 - 349
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m9.938000s, kernel 0m0.078000s, user 0m1.716011s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m10.056000s, kernel 0m0.296401s, user 0m0.374402s
Compression level 3 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_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 35 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: New Event: type 1111
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m25.839000s, kernel 0m0.015600s, user 0m1.887612s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m25.815000s, kernel 0m0.358802s, user 0m0.421202s
From the level 3 (successful) log you can see that the track is about 2m 25s long. The level 4 and level 6 logs both show the player ending prematurely after about 2m 10s. The level 6 log has warnings "received buffer in the future" and "the decoder was aborted by the read callback". These messages don't appear in the level 4 log, even though the playback ended at the same point.
I am happy to post the FLAC file so that someone can reproduce and debug the problem. It is about 11MB. Please indicate where I should put it.
This problem seems similar to http://trac.videolan.org/vlc/ticket/2349 (reported in viewtopic.php?p=176428#p176428)
except that in my case the file was compressed with the latest level of FLAC, not an older level.
So far I have only been able to try playing a small number of FLAC files. One of these files stops playing part way through on VLC, though it plays correctly on other players.. The problem occurs on both vlc-0.9.8a-win32 and vlc-1.0.0-git-20090306-2305-win32. The file was compressed using the latest level of FLAC (1.2.1b) with compression level 6. The same file plays correctly on foobar2000, Winamp and WMP. If I reduce the compression level to 3, the file plays correctly on VLC.
I set the VLC verbosity level to 2 and captured the output from the same track with FLAC compression levels 6, 4 and 3. (Compression level 5 produced a .flac file that was identical to compression level 6.) With compression level 6, some warning messages are logged. Here are the log extracts from just before the start to just after the end of playing the file.
Compression level 6 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_resampler"
main debug: TIMER module_need() : 1.000 ms - Total 1.000 ms / 1 intvls (Avg 1.000 ms)
main debug: found a filter for the whole conversion
main debug: End of audio preroll
main debug: Decoder buffering done in 8 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: New Event: type 1107
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
qt4 debug: New Event: type 1108
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1116
qt4 debug: New Event: type 1111
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
main warning: received buffer in the future
main warning: received buffer in the future
flac warning: the decoder was aborted by the read callback.
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m10.356000s, kernel 0m0.015600s, user 0m1.606810s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m10.379000s, kernel 0m0.343202s, user 0m0.343202s
Compression level 4 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_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
qt4 debug: Updating the geometry
main debug: End of audio preroll
qt4 debug: size: 109 - 349
main debug: Decoder buffering done in 10 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: sizeHint: 109 - 349
qt4 debug: Updating the geometry
qt4 debug: size: 109 - 349
qt4 debug: sizeHint: 109 - 349
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m9.938000s, kernel 0m0.078000s, user 0m1.716011s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m10.056000s, kernel 0m0.296401s, user 0m0.374402s
Compression level 3 log extract:
main debug: found a filter for the whole conversion
main debug: filter(s) 'fl32'->'fl32' 48510 Hz->44100 Hz Stereo->Stereo
main debug: looking for audio filter module: 24 candidates
main debug: using audio filter module "bandlimited_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 35 ms
main warning: PTS is out of range (-10000), dropping buffer
qt4 debug: New Event: type 1111
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
qt4 debug: New Event: type 1114
main debug: EOF reached
main debug: finished input
main debug: thread times: real 2m25.839000s, kernel 0m0.015600s, user 0m1.887612s
main debug: removing module "flac"
main debug: killing decoder fourcc `flac', 0 PES in FIFO
main debug: removing module "converter_float"
main debug: removing module "scaletempo"
main debug: removing module "bandlimited_resampler"
aout_directx debug: closing audio device
aout_directx debug: DirectSoundThread exiting
main debug: thread ended
main debug: thread times: real 2m25.815000s, kernel 0m0.358802s, user 0m0.421202s
From the level 3 (successful) log you can see that the track is about 2m 25s long. The level 4 and level 6 logs both show the player ending prematurely after about 2m 10s. The level 6 log has warnings "received buffer in the future" and "the decoder was aborted by the read callback". These messages don't appear in the level 4 log, even though the playback ended at the same point.
I am happy to post the FLAC file so that someone can reproduce and debug the problem. It is about 11MB. Please indicate where I should put it.
This problem seems similar to http://trac.videolan.org/vlc/ticket/2349 (reported in viewtopic.php?p=176428#p176428)
except that in my case the file was compressed with the latest level of FLAC, not an older level.