2009-11-28, 22:21
Hello there everyone. I am having a problem with transcoded video in XBMC.
First, here is the top of the XBMC log file so you can see what I am running:
The video is nothing special. It is an episode of Dexter transcoded with Nero Recode 4 set to Nero Digital standard. When I check its properties it describes itself as a MPEG-4 Level 5 with MP3 audio.
The problem is that XBMC seems to take minutes to try to start play back and then immediately has issues with losing sync with the file server.
It seems like XBMC does not seem to understand what to do with the file. Another section from the log file:
I have other transcoded files that play perfectly from the same source. The major difference is that files has properties of MPEG-4 Level 3 with AAC audio.
I have seen this same behavior on The Mac version of XBMC and the Xbox version as well. If it is useful I can generate and post those log files as well.
I am hoping there is an easy fix for this before I have recode a lot of media library to compensate for this.
Thanks!
First, here is the top of the XBMC log file so you can see what I am running:
Code:
14:40:23 T:5308 M:2563264512 NOTICE: -----------------------------------------------------------------------
14:40:23 T:5308 M:2563264512 NOTICE: Starting XBMC, Platform: Windows build 7600. Built on Nov 22 2009 (SVN:24883, compiler 1500)
14:40:23 T:5308 M:2563264512 NOTICE: Intel(R) Core(TM)2 Duo CPU T9400 @ 2.53GHz
14:40:23 T:5308 M:2563264512 NOTICE: Desktop Resolution: 1680x1050 32Bit at 50Hz
14:40:23 T:5308 M:2563264512 NOTICE: Running with restricted rights
-----------------------------------------------------------------------The problem is that XBMC seems to take minutes to try to start play back and then immediately has issues with losing sync with the file server.
It seems like XBMC does not seem to understand what to do with the file. Another section from the log file:
Code:
14:41:54 T:5308 M:2515824640 NOTICE: DVDPlayer: Opening: smb://nas-app-prod-series.homenetwork/Dexter/Season_03/Dexter.s03.e01.mp4
14:41:54 T:5680 M:2515656704 NOTICE: Creating Demuxer
14:41:54 T:5680 M:2515615744 DEBUG: Win32DllLoader::Load(special://xbmc/system/players/dvdplayer/avutil-50.dll)
14:41:54 T:5680 M:2515582976 DEBUG: Win32DllLoader::Load(special://xbmc/system/players/dvdplayer/avcodec-52.dll)
14:41:54 T:5680 M:2515472384 DEBUG: LoadLibrary('libfaad.dll') returning: 076599C8
14:41:54 T:5680 M:2515456000 DEBUG: Win32DllLoader::Load(special://xbmc/system/players/dvdplayer/avformat-52.dll)
14:41:54 T:5680 M:2515415040 DEBUG: LoadLibraryA('avcodec-52.dll')
14:41:54 T:5680 M:2515415040 DEBUG: LoadLibrary('avcodec-52.dll') returning: 07656FE8
14:41:54 T:5680 M:2515415040 DEBUG: LoadLibraryA('avutil-50.dll')
14:41:54 T:5680 M:2515415040 DEBUG: LoadLibrary('avutil-50.dll') returning: 07658DE8
14:41:54 T:5680 M:2515148800 DEBUG: CDVDDemuxFFmpeg::Open - probing detected format [mov,mp4,m4a,3gp,3g2,mj2]
14:41:56 T:5680 M:2496352256 DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info starting
14:41:57 T:4268 M:2504667136 INFO: Loading skin file: DialogProgress.xml
14:41:57 T:4268 M:2503692288 DEBUG: Load DialogProgress.xml: 2.37ms
14:41:57 T:4268 M:2503663616 DEBUG: ------ Window Init (DialogProgress.xml) ------
14:41:57 T:4268 M:2503643136 DEBUG: Alloc resources: 0.05ms (0.00 ms skin load)
14:44:14 T:5680 M:2454192128 DEBUG: ffmpeg[1630]: [mov,mp4,m4a,3gp,3g2,mj2] max_analyze_duration reached
14:44:14 T:5680 M:2454155264 DEBUG: CDVDDemuxFFmpeg::Open - av_find_stream_info finished
14:44:14 T:5680 M:2454155264 INFO: ffmpeg[1630]: Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'smb://nas-app-prod-series.homenetwork/Dexter/Season_03/Dexter.s03.e01.mp4':
14:44:14 T:5680 M:2454155264 INFO: ffmpeg[1630]: Duration: 00:58:05.06, start: 0.000000, bitrate: 1364 kb/s
14:44:14 T:5680 M:2454044672 INFO: ffmpeg[1630]: Stream #0.0(und): Data: mp4s / 0x7334706D
14:44:14 T:5680 M:2454032384 INFO: ffmpeg[1630]: Stream #0.1(eng): Video: mpeg4, yuv420p, 576x384 [PAR 40:33 DAR 20:11], 29.97 tbr, 30k tbn, 29.97 tbc
14:44:14 T:5680 M:2454028288 INFO: ffmpeg[1630]: Stream #0.2(eng): Audio: mp3, 48000 Hz, 2 channels, s16
14:44:14 T:5680 M:2454028288 INFO: ffmpeg[1630]: Metadata
14:44:14 T:5680 M:2454028288 INFO: ffmpeg[1630]: major_brand : mp42
14:44:14 T:5680 M:2454028288 INFO: ffmpeg[1630]: minor_version : 0
14:44:14 T:5680 M:2454028288 INFO: ffmpeg[1630]: compatible_brands: mp42isomndsd
14:44:14 T:5680 M:2453917696 NOTICE: Opening video stream: 1 source: 256
14:44:14 T:5680 M:2453897216 NOTICE: Creating video codec with codec id: 13
14:44:14 T:5680 M:2453856256 DEBUG: FactoryCodec - Video: - Opening
14:44:14 T:5680 M:2453770240 DEBUG: Win32DllLoader::Load(special://xbmc/system/players/dvdplayer/swscale-0.6.1.dll)
14:44:14 T:5680 M:2453688320 DEBUG: LoadLibraryA('avutil-50.dll')
14:44:14 T:5680 M:2453684224 DEBUG: LoadLibrary('avutil-50.dll') returning: 07658DE8
14:44:14 T:5680 M:2453610496 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-4 part 2
14:44:14 T:5680 M:2453602304 INFO: ffmpeg[1630]: [w32thread] thread count = 2
14:44:14 T:5680 M:2453602304 INFO: ffmpeg[1630]: [w32thread] init semaphors 1
14:44:14 T:5680 M:2453602304 INFO: ffmpeg[1630]: [w32thread] create thread 1
14:44:14 T:5680 M:2453581824 INFO: ffmpeg[1630]: [w32thread] init semaphors 2
14:44:14 T:5680 M:2453581824 INFO: ffmpeg[1630]: [w32thread] create thread 2
14:44:14 T:5680 M:2453528576 INFO: ffmpeg[1630]: [w32thread] init done
14:44:14 T:5680 M:2453516288 DEBUG: FactoryCodec - Video: ff-mpeg4 - Opened
14:44:14 T:5680 M:2453512192 NOTICE: Creating video thread
14:44:14 T:5680 M:2453467136 NOTICE: Opening audio stream: 2 source: 256
14:44:14 T:5680 M:2453450752 NOTICE: Finding audio codec for: 86017
14:44:14 T:5680 M:2453442560 DEBUG: FactoryCodec - Audio: passthrough - Opening
14:44:14 T:5680 M:2453434368 DEBUG: FactoryCodec - Audio: passthrough - Failed
14:44:14 T:5680 M:2453430272 DEBUG: FactoryCodec - Audio: libmad - Opening
14:44:14 T:3440 M:2453430272 DEBUG: thread start, auto delete: 0
14:44:14 T:5680 M:2453409792 DEBUG: Win32DllLoader::Load(special://xbmc/system/players/dvdplayer/libmad.dll)
14:44:14 T:3440 M:2453315584 NOTICE: running thread: video_thread
14:44:14 T:5680 M:2453245952 DEBUG: LoadLibraryA('MSVCR71.dll')
14:44:14 T:5680 M:2453245952 DEBUG: LoadLibrary('MSVCR71.dll') returning: 02C58E30
14:44:14 T:5680 M:2453241856 DEBUG: FactoryCodec - Audio: libmad - Opened
14:44:14 T:5680 M:2453233664 NOTICE: Creating audio thread
14:44:14 T:5612 M:2453200896 DEBUG: thread start, auto delete: 0
14:44:14 T:5612 M:2453151744 NOTICE: running thread: CDVDPlayerAudio::Process()
14:44:14 T:5612 M:2452385792 NOTICE: Creating audio device with codec id: 86017, channels: 2, sample rate: 48000, no pass-through
14:44:14 T:5612 M:2452381696 INFO: AudioRendererFactory: not a explicit device, trying to autodetect.
14:44:14 T:5612 M:2452357120 DEBUG: CWin32DirectSound::Initialize: Packet Size = 12384. Avg Bytes Per Second = 192000.
14:44:14 T:5612 M:2452316160 DEBUG: CWin32DirectSound::Initialize: Couldn't create secondary buffer (DSERR_UNSUPPORTED). Trying without LOCHARDWARE.
14:44:14 T:5612 M:2452025344 DEBUG: CWin32DirectSound::Initialize: secondary buffer created
14:44:14 T:5612 M:2452017152 DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
14:44:14 T:5612 M:2452013056 DEBUG: CDVDPlayerAudio:: Discontinuty - was:24934.033338, should be:24000.000000, error:-934.033338
14:44:14 T:3440 M:2452369408 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
14:44:14 T:3440 M:2452369408 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_DELAY(9366.666667)
14:44:14 T:5612 M:2456395776 DEBUG: CWin32DirectSound::CheckPlayStatus: Resuming Playback
14:44:14 T:3440 M:2459103232 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(33366.666667, 0)
14:44:14 T:5612 M:2458726400 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
14:44:14 T:3440 M:2458673152 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
14:44:14 T:3440 M:2458353664 NOTICE: fps: 29.970030, pwidth: 576, pheight: 384, dwidth: 576, dheight: 317
14:44:14 T:3440 M:2458353664 DEBUG: CDVDPlayerVideo::OutputPicture - change configuration. 576x384. framerate: 29.97
14:44:14 T:3440 M:2458349568 NOTICE: Display resolution DESKTOP : 1680x1050 @ 50.00 - Full Screen (12)
14:44:15 T:5612 M:2463092736 DEBUG: CDVDPlayerAudio:: Discontinuty - was:1026410.251755, should be:1002599.534812, error:-23810.716944
14:44:16 T:5612 M:2463129600 DEBUG: CDVDPlayerAudio:: Discontinuty - was:2028654.810135, should be:1990907.942150, error:-37746.867984
14:44:17 T:5612 M:2463592448 WARNING: CDVDMessageQueue(audio)::Get - retrieved last data packet of queue
14:44:17 T:3440 M:2465189888 WARNING: CDVDMessageQueue(video)::Get - retrieved last data packet of queue
14:44:17 T:3440 M:2466230272 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 29.970030 fps
14:44:17 T:5680 M:2482655232 DEBUG: CDVDPlayer::SetCaching - started cachingI have seen this same behavior on The Mac version of XBMC and the Xbox version as well. If it is useful I can generate and post those log files as well.
I am hoping there is an easy fix for this before I have recode a lot of media library to compensate for this.
Thanks!
