2010-09-17, 01:55
davilla,
i just finally managed to get build over on to my appletv of the tip of the Dharma branch.
http://trac.xbmc.org/ticket/10177 is fixed and that video plays back now. thanks for that.
I still see a large delay on the startup of the next 1080p. What is delay i should expect after i click on start to when i see the picture?
I have 1080p sample that will take close to 1-2 minutes to start playing correctly, is this expected? 720p plays flawlessly. I am uploading this video now will send you a PM when its done.
also i have annotated the following logs with times where i I am not sure what xbmc is doing? this is reading files off a nfs share. Dharma smb seems very flaky on hardy!
i just finally managed to get build over on to my appletv of the tip of the Dharma branch.
http://trac.xbmc.org/ticket/10177 is fixed and that video plays back now. thanks for that.
I still see a large delay on the startup of the next 1080p. What is delay i should expect after i click on start to when i see the picture?
I have 1080p sample that will take close to 1-2 minutes to start playing correctly, is this expected? 720p plays flawlessly. I am uploading this video now will send you a PM when its done.
also i have annotated the following logs with times where i I am not sure what xbmc is doing? this is reading files off a nfs share. Dharma smb seems very flaky on hardy!
Code:
21:26:27 T:2839260048 M: 56999936 DEBUG: Open - av_find_stream_info finished
21:26:27 T:2839260048 M: 57040896 INFO: ffmpeg[A93BAB90]: Input #0, matroska, from '/net/kalahari/Video/English/Movies/HD/A Passage to India.mkv':
21:26:27 T:2839260048 M: 57040896 INFO: ffmpeg[A93BAB90]: Duration: 02:43:57.85, start: 0.000000, bitrate: 1606 kb/s
21:26:27 T:2839260048 M: 57040896 INFO: ffmpeg[A93BAB90]: Stream #0.0(eng): Video: h264, yuv420p, 1792x1080 [PAR 1:1 DAR 224:135], 23.98 fps, 24 tbr, 1k tbn, 47.95 tbc
21:26:27 T:2839260048 M: 57040896 INFO: ffmpeg[A93BAB90]: Stream #0.1(eng): Audio: ac3, 48000 Hz, 5.1, s16, 448 kb/s
21:26:27 T:2839260048 M: 57040896 NOTICE: Opening video stream: 0 source: 256
21:26:27 T:2839260048 M: 57040896 NOTICE: Creating video codec with codec id: 28
21:26:27 T:2839260048 M: 57040896 DEBUG: CDVDFactoryCodec: compiled in hardware support: CrystalHD:yes OpenMax:no VDPAU:yes VAAPI:no
21:26:27 T:2839260048 M: 57040896 INFO: Trying Broadcom Crystal HD Decoder...
21:26:27 T:2839260048 M: 57040896 DEBUG: FactoryCodec - Video: - Opening
21:26:27 T:2839260048 M: 57040896 DEBUG: CrystalHD: profile 640029
21:26:27 T:2839260048 M: 57040896 DEBUG: CrystalHD: nal size 4
21:26:27 T:2839260048 M: 57040896 DEBUG: CrystalHD: num sps 1
21:26:27 T:2839260048 M: 57040896 DEBUG: CrystalHD: data size at end = 0
21:26:28 T:2797591440 M: 57131008 DEBUG: thread start, auto delete: 0
21:26:28 T:2797591440 M: 57131008 DEBUG: CrystalHD: Output Thread Started...
21:26:28 T:2839260048 M: 57131008 INFO: DVDVideoCodecCrystalHD: Opened Broadcom Crystal HD Codec
21:26:28 T:2839260048 M: 57131008 DEBUG: FactoryCodec - Video: chd-h264 - Opened
21:26:28 T:2839260048 M: 57131008 NOTICE: Creating video thread
21:26:28 T:2789198736 M: 57106432 DEBUG: thread start, auto delete: 0
21:26:28 T:2839260048 M: 57106432 NOTICE: Opening audio stream: 1 source: 256
21:26:28 T:2839260048 M: 57106432 NOTICE: Finding audio codec for: 86020
21:26:28 T:2839260048 M: 57106432 DEBUG: FactoryCodec - Audio: PassthroughFFmpeg - Opening
21:26:28 T:2839260048 M: 57106432 INFO: CDVDAudioCodecPassthroughFFmpeg::Open - Won't transcode for HDMI
21:26:28 T:2839260048 M: 57106432 DEBUG: FactoryCodec - Audio: PassthroughFFmpeg - Failed
21:26:28 T:2839260048 M: 57106432 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
21:26:28 T:2789198736 M: 57106432 DEBUG: LinuxRendererGL: Cleaning up GL resources
21:26:28 T:2789198736 M: 57106432 NOTICE: running thread: video_thread
21:26:28 T:2839260048 M: 57106432 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
21:26:28 T:2839260048 M: 57106432 NOTICE: Creating audio thread
21:26:28 T:2771385232 M: 57106432 DEBUG: thread start, auto delete: 0
21:26:28 T:2771385232 M: 57106432 NOTICE: running thread: CDVDPlayerAudio::Process()
21:26:28 T:2839260048 M: 57106432 DEBUG: ReadEditDecisionLists - Adjusting detected frame rate by half assuming 1080i (interlaced): 24.000
21:26:28 T:2839260048 M: 57106432 DEBUG: ReadEditDecisionLists - Checking for edit decision lists (EDL) on local drive or remote share for: /net/kalahari/Video/English/Movies/HD/A Passage to India.mkv
21:26:28 T:2839260048 M: 57106432 DEBUG: Process - Start position set
to last stopped position: 596000
What is it doing here??? for about 20 seconds
21:26:41 T:2856299408 M: 59068416 DEBUG: Thread 2856299408 terminating (autodelete)
21:26:45 T:2900536208 M: 59375616 DEBUG: Thread 2900536208 terminating (autodelete)
21:26:45 T:2814376848 M: 59375616 DEBUG: Thread 2814376848 terminating (autodelete)
21:26:46 T:2885294992 M: 59260928 DEBUG: Thread 2885294992 terminating (autodelete)
Again whats the delay for?
21:27:26 T:2839260048 M: 59654144 DEBUG: SeekTime - seek ended up on time 599641
21:27:26 T:2839260048 M: 59654144 DEBUG: Process - starting demuxer from: 596000
21:27:26 T:2839260048 M: 59654144 DEBUG: CDVDPlayer::SetCaching - caching state 2
21:27:26 T:2789198736 M: 59645952 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
21:27:26 T:2789198736 M: 59645952 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(599641000.000000, 1)
21:27:26 T:2789198736 M: 59645952 INFO: CDVDPlayerVideo - Stillframe left, switching to normal playback
21:27:26 T:2771385232 M: 59645952 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(599808000.000000, 0)
21:27:26 T:2771385232 M: 59645952 NOTICE: Creating audio device with codec id: 86020, channels: 6, sample rate: 48000, no pass-through
21:27:26 T:2771385232 M: 59645952 INFO: AudioRendererFactory: not a explicit device, trying to autodetect.
21:27:26 T:2789198736 M: 59613184 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:27:26 T:3043235680 M: 59613184 DEBUG: CGUIAudioManager::DeInitialize
21:27:26 T:2789198736 M: 59527168 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
21:27:26 T:2771385232 M: 59547648 WARNING: Previous line repeats 1 times.
21:27:26 T:2771385232 M: 59547648 INFO: CPCMRemap: Configured speaker layout: 2.0
21:27:26 T:2771385232 M: 59547648 INFO: CPCMRemap: I channel map: FL,FR,CE,LFE,SL,SR
21:27:26 T:2771385232 M: 59547648 DEBUG: CPCMRemap: Forcing side channel map to back channels
21:27:26 T:2771385232 M: 59547648 INFO: CPCMRemap: O channel map: FL,FR
21:27:26 T:2771385232 M: 59547648 DEBUG: CPCMRemap: Downmix normalization is disabled
21:27:26 T:2771385232 M: 59547648 DEBUG: CPCMRemap: FL = FL(1.000000) CE(0.707107) LFE(0.707107) BL(1.000000)
21:27:26 T:2771385232 M: 59547648 DEBUG: CPCMRemap: FR = FR(1.000000) CE(0.707107) LFE(0.707107) BR(1.000000)
21:27:26 T:2771385232 M: 59547648 DEBUG: CPulseAudioDirectSound::CPulseAudioDirectSound - Requested channels changed from 6 to 2
21:27:26 T:2771385232 M: 59547648 DEBUG: RemoveActiveDevice - Removing device 1
21:27:27 T:3043235680 M: 58494976 DEBUG: CAnnouncementManager - Announcement: PlaybackStarted from xbmc
21:27:27 T:2771385232 M: 58507264 DEBUG: SetActiveDevice - SetActiveDevice from 0 to 2
21:27:27 T:2771385232 M: 58507264 DEBUG: RemoveActiveDevice - Removing device 0
21:27:27 T:3043235680 M: 57982976 DEBUG: CGUIInfoManager::SetCurrentMovie(/net/kalahari/Video/English/Movies/HD/A Passage to India.mkv)
21:27:27 T:3043235680 M: 57835520 DEBUG: SECTION:UnloadDelayed(SECTION: LCODE)
21:27:27 T:3043235680 M: 57835520 DEBUG: SECTION:UnloadDelayed(DLL: special://xbmcbin/system/ImageLib-i486-linux.so)
21:27:27 T:3043235680 M: 57835520 DEBUG: Unloading: ImageLib-i486-linux.so
21:27:27 T:2797591440 M: 57843712 DEBUG: CrystalHD: Format Change Detected. Flags: 0x00030000
21:27:27 T:2797591440 M: 57843712 DEBUG: ----------------------------------
21:27:27 T:2797591440 M: 57843712 DEBUG: TimeStamp: 0
21:27:27 T:2797591440 M: 57843712 DEBUG: Picture Number: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: Width: 1792
21:27:27 T:2797591440 M: 57815040 DEBUG: Height: 1080
21:27:27 T:2797591440 M: 57815040 DEBUG: Chroma: 0x001
21:27:27 T:2797591440 M: 57815040 DEBUG: Pulldown: 9
21:27:27 T:2797591440 M: 57815040 DEBUG: Flags: 0x00000000
21:27:27 T:2797591440 M: 57815040 DEBUG: Frame Rate/Res: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: Aspect Ratio: 1
21:27:27 T:2797591440 M: 57815040 DEBUG: Color Primaries: 33686016
21:27:27 T:2797591440 M: 57815040 DEBUG: MetaData: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: Session Number: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: TimeStamp: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: Custom Aspect: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: Frames to Drop: 0
21:27:27 T:2797591440 M: 57815040 DEBUG: H264 Valid Fields: 0x00000000
21:27:27 T:2797591440 M: 57815040 DEBUG: CrystalHD: dec_par x = 1, dec_par y = 1
21:27:27 T:2797591440 M: 57815040 DEBUG: CrystalHD: resolution = 0 interlace = 0
21:27:27 T:2797591440 M: 57815040 DEBUG: CrystalHD: No timestamp detected: 0
21:27:27 T:2789198736 M: 46026752 NOTICE: fps: 24.000000, pwidth: 1792, pheight: 1080, dwidth: 1791, dheight: 1080
21:27:27 T:2789198736 M: 46026752 DEBUG: OutputPicture - change configuration. 1792x1080. framerate: 24.00. format: YUY2
21:27:27 T:3043235680 M: 46026752 DEBUG: ------ Window Deinit (DialogBusy.xml) ------
21:27:27 T:2789198736 M: 40136704 WARNING: CRenderManager::Configure - timeout waiting for previous frame
21:27:27 T:2789198736 M: 38289408 NOTICE: Display resolution DESKTOP : 1024x768 @ 60.00 - Full Screen (12)
21:27:27 T:3043235680 M: 38289408 DEBUG: Activating window ID: 12005
21:27:27 T:3043235680 M: 38289408 DEBUG: Checking if window ID 12005 is locked.
21:27:27 T:3043235680 M: 38289408 DEBUG: ------ Window Deinit (MyVideoNav.xml) ------
21:27:27 T:2839260048 M: 38289408 DEBUG: CDVDPlayer::HandleMessages - player started 2