2011-05-18, 04:55
I'm trying to watch some HD movies in MP4 format. These are standard AVC files in the container. If I watch from the beginning, everything is great, however if I try and Seek, FF, or Rewind, I get either no video, or super jerky video that is well behind the audio. The audio seems to skip ahead properly, although I guess there's no way to tell for sure. This also happens if I resume from a previous stopped point (because it must seek to get there).
Here's some of the debug log. I started playing the video, and then skipped ahead 30 seconds and started getting the following errors:
I get tons of these: "21:42:44 T:2208 M:1863946240 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:42:44 T:7136 M:1863913472 WARNING: CProcessor::Render - requested time 64d is before first sample 64d" errors, whenever this happens. MKV files play perfectly fine.
I have a quad core AMD, and the processor never goes above 20%. I've tried enabling/disabling video acceleration and every other setting, and nothing seems to work. This is on an x64 Windows 7 machine with 4GB Ram and a Radeon HD card with updated drivers.
If you guys want the full debug log, I can give that to you too.
Here's some of the debug log. I started playing the video, and then skipped ahead 30 seconds and started getting the following errors:
Code:
21:42:38 T:7136 M:1869713408 DEBUG: ------ Window Deinit (VideoOSD.xml) ------
21:42:40 T:6312 M:1869336576 DEBUG: CDVDPlayerAudio:: Discontinuity - was:9232080.564382, should be:9221997.362887, error:-10083.201495
21:42:42 T:7136 M:1868705792 DEBUG: SDLKeyboard: scancode: 0, sym: 275, unicode: 0, modifier: 0
21:42:42 T:7136 M:1868701696 DEBUG: CApplication::OnKey: 61479 pressed, action is StepForward
21:42:42 T:2916 M:1868701696 DEBUG: CDVDPlayer::SetCaching - caching state 2
21:42:42 T:2916 M:1868701696 DEBUG: demuxer seek to: 40398
21:42:42 T:2916 M:1868701696 DEBUG: CDVDDemuxFFmpeg::SeekTime - unknown position after seek
21:42:42 T:2916 M:1868701696 DEBUG: demuxer seek to: 40398, success
21:42:42 T:7136 M:1871892480 DEBUG: CAnnouncementManager - Announcement: PlaybackSeek from xbmc
21:42:42 T:7136 M:1871892480 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
21:42:42 T:7136 M:1871892480 INFO: Loading skin file: DialogSeekBar.xml
21:42:42 T:2208 M:1878052864 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:42:42 T:6312 M:1878073344 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
21:42:42 T:6312 M:1878016000 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(40576000.000000, 1)
21:42:42 T:2208 M:1877938176 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(40574000.000000, 0)
21:42:42 T:2208 M:1877925888 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
21:42:42 T:2916 M:1877925888 DEBUG: CDVDPlayer::HandleMessages - player started 1
21:42:42 T:2916 M:1876725760 DEBUG: CDVDPlayer::HandleMessages - player started 2
21:42:42 T:2916 M:1876725760 DEBUG: CDVDPlayer::SetCaching - caching state 3
21:42:42 T:6312 M:1876742144 DEBUG: CDVDPlayerAudio:: Discontinuity - was:40458820.134642, should be:40575537.453894, error:116717.319253
21:42:42 T:2916 M:1876643840 DEBUG: CDVDPlayer::SetCaching - caching state 0
21:42:42 T:6312 M:1876578304 DEBUG: CWin32DirectSound::CheckPlayStatus: Resuming Playback
21:42:42 T:7136 M:1871253504 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:42 T:2208 M:1867833344 DEBUG: CPullupCorrection: detected pattern of length 30: 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00
21:42:42 T:7136 M:1867784192 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:44 T:2208 M:1863946240 WARNING: Previous line repeats 10 times.
21:42:44 T:2208 M:1863946240 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:42:44 T:7136 M:1863913472 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:44 T:6312 M:1863913472 DEBUG: CDVDPlayerAudio:: Discontinuity - was:42672802.068634, should be:42638084.785966, error:-34717.282668
21:42:44 T:7136 M:1863815168 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:44 T:7136 M:1863417856 WARNING: Previous line repeats 4 times.
21:42:44 T:7136 M:1863417856 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
21:42:45 T:7136 M:1863348224 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:46 T:7136 M:1862823936 WARNING: Previous line repeats 10 times.
21:42:46 T:7136 M:1862823936 DEBUG: SDLKeyboard: scancode: 0, sym: 273, unicode: 0, modifier: 0
21:42:46 T:7136 M:1862823936 DEBUG: CApplication::OnKey: 61478 pressed, action is BigStepForward
21:42:46 T:2916 M:1862823936 DEBUG: CDVDPlayer::SetCaching - caching state 2
21:42:46 T:2916 M:1862823936 DEBUG: demuxer seek to: 644307
21:42:46 T:2916 M:1862823936 DEBUG: CDVDDemuxFFmpeg::SeekTime - unknown position after seek
21:42:46 T:2916 M:1862823936 DEBUG: demuxer seek to: 644307, success
21:42:46 T:6312 M:1866788864 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
21:42:46 T:2208 M:1866788864 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:42:46 T:7136 M:1866788864 DEBUG: CAnnouncementManager - Announcement: PlaybackSeek from xbmc
21:42:46 T:6312 M:1866805248 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(644330666.666667, 1)
21:42:46 T:2916 M:1866805248 DEBUG: CDVDPlayer::HandleMessages - player started 1
21:42:46 T:2208 M:1866805248 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(644311000.000000, 0)
21:42:46 T:2208 M:1866805248 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
21:42:46 T:2916 M:1866805248 DEBUG: CDVDPlayer::HandleMessages - player started 2
21:42:46 T:2916 M:1866805248 DEBUG: CDVDPlayer::SetCaching - caching state 3
21:42:46 T:6312 M:1866805248 DEBUG: CDVDPlayerAudio:: Discontinuity - was:644267554.492774, should be:644326860.613024, error:59306.120250
21:42:46 T:6312 M:1866805248 DEBUG: CWin32DirectSound::CheckPlayStatus: Resuming Playback
21:42:46 T:6312 M:1866805248 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
21:42:46 T:2916 M:1866805248 DEBUG: CDVDPlayer::SetCaching - caching state 0
21:42:46 T:6312 M:1866903552 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
21:42:46 T:2208 M:1866387456 WARNING: Previous line repeats 1 times.
21:42:46 T:2208 M:1866387456 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:42:46 T:7136 M:1864691712 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
21:42:46 T:7136 M:1863630848 WARNING: CProcessor::Render - requested time 64d is before first sample 64d
21:42:46 T:2208 M:1862987776 DEBUG: CPullupCorrection: detected pattern of length 30: 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 33000.00 34000.00 33000.00 34000.00 33000.00 33000.00 34000.00
I get tons of these: "21:42:44 T:2208 M:1863946240 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:42:44 T:7136 M:1863913472 WARNING: CProcessor::Render - requested time 64d is before first sample 64d" errors, whenever this happens. MKV files play perfectly fine.
I have a quad core AMD, and the processor never goes above 20%. I've tried enabling/disabling video acceleration and every other setting, and nothing seems to work. This is on an x64 Windows 7 machine with 4GB Ram and a Radeon HD card with updated drivers.
If you guys want the full debug log, I can give that to you too.