Here's a further fragment from where the channel does open for 1-2 seconds before freezing up (seems that I can reliable get this to happen if I am switching from a channel already open, if I try to do it cold it just won't open):
Code:
18:38:54 T:139700191037376 DEBUG: CGUIInfoManager::SetCurrentMovie(pvr://channels/tv/All channels/0.pvr)
18:38:54 T:139700191037376 INFO: GL: Enabling VSYNC
18:38:54 T:139700191037376 INFO: GL: Selected vsync mode 2
18:38:54 T:139700191037376 DEBUG: GL: Vertex Shader compilation log:
18:38:54 T:139700191037376 DEBUG: GL: Vertex Shader compiled successfully
18:38:54 T:139700191037376 DEBUG: GL: Pixel Shader compilation log:
18:38:54 T:139700191037376 DEBUG: GL: Fragment Shader compiled successfully
18:38:54 T:139697311606528 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
18:38:54 T:139698670552832 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
18:38:54 T:139697950922496 DEBUG: CDVDPlayer::SetCaching - caching state 3
18:38:54 T:139697950922496 DEBUG: PVRManager - PerformChannelSwitch - switching to channel 'BBC One HD'
18:38:54 T:139697950922496 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux open
18:38:54 T:139697950922496 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux unsubcribe from 8
18:38:54 T:139697950922496 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux successfully unsubscribed 8
18:38:54 T:139697950922496 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux subscribe to 30
18:38:54 T:139697950922496 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux successfully subscribed to 30
18:38:54 T:139696736786176 DEBUG: DoWork - Saving file state for video item pvr://channels/tv/All channels/27.pvr
18:38:54 T:139697950922496 DEBUG: Loading settings for pvr://channels/tv/All channels/0.pvr
18:38:54 T:139697950922496 DEBUG: CPVRChannelGroup - Persist - persisting channel group 'All channels' with 69 channels
18:38:54 T:139697950922496 NOTICE: PVRManager - PerformChannelSwitch - switched to channel 'BBC One HD'
18:38:54 T:139697950922496 NOTICE: Creating Demuxer
18:38:54 T:139698661897984 DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
18:38:54 T:139697950922496 DEBUG: CDVDPlayer::SetCaching - caching state 2
18:38:54 T:139698661897984 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
18:38:54 T:139698661897984 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - Announce(flag=Player, sender=xbmc, message=OnStop)
18:38:54 T:139698661897984 DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
18:38:54 T:139698661897984 DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
18:38:54 T:139698661897984 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - Announce(flag=Player, sender=xbmc, message=OnPlay)
18:38:54 T:139698661897984 DEBUG: UPnP: Building didl for object 'pvr://channels/tv/All channels/0.pvr'
18:38:54 T:139700191037376 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
18:38:54 T:139699280656128 DEBUG: PushCecKeypress - received key b duration 228
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux subscription start
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - id: 1, type H264, codec: 28
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux subscription start
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - id: 2, type AAC, codec: 86018
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux subscription start
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - id: 3, type AAC, codec: 86018
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux subscription start
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - id: 4, type DVBSUB, codec: 94209
18:38:58 T:139698288412416 DEBUG: AddOnLog: Tvheadend Client: pvr.tvh - demux stream change
18:38:58 T:139697950922496 DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 0:1 with codec_id 28
18:38:58 T:139697950922496 DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 1:2 with codec_id 86018
18:38:58 T:139697950922496 DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 2:3 with codec_id 86018
18:38:58 T:139697950922496 DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 3:4 with codec_id 94209
18:38:58 T:139697950922496 NOTICE: Opening stream: 0 source: 256
18:38:58 T:139697950922496 NOTICE: Creating video codec with codec id: 28
18:38:58 T:139697950922496 DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:yes VAAPI:yes iMXVPU:no
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Video: - Opening
18:38:58 T:139697950922496 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:38:58 T:139697950922496 DEBUG: CDVDVideoCodecFFmpeg::Open() Keeping default threading 3
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Video: ff-h264 - Opened
18:38:58 T:139697950922496 NOTICE: Opening stream: 1 source: 256
18:38:58 T:139697950922496 NOTICE: Finding audio codec for: 86018
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Audio: passthrough - Opening
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Audio: passthrough - Failed
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Audio: FFmpeg - Opening
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Audio: FFmpeg - Opened
18:38:58 T:139697950922496 NOTICE: Opening stream: 3 source: 256
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Overlay: FFmpeg Subtitle Decoder - Opening
18:38:58 T:139697950922496 DEBUG: FactoryCodec - Overlay: FFmpeg Subtitle Decoder - Opened
18:39:02 T:139697950922496 ERROR: ffmpeg[7F0DF6BD9700]: [NULL] illegal POC type 12
18:39:02 T:139697950922496 DEBUG: ParsePacket - {0} profile changed from -99 to 100
18:39:02 T:139697950922496 DEBUG: ParsePacket - {0} level changed from -99 to 40
18:39:02 T:139697950922496 NOTICE: Opening stream: 0 source: 256
18:39:02 T:139697950922496 NOTICE: Creating video codec with codec id: 28
18:39:02 T:139697950922496 DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:no MediaCodec:no OpenMax:no libstagefright:no VDPAU:yes VAAPI:yes iMXVPU:no
18:39:02 T:139697950922496 DEBUG: FactoryCodec - Video: - Opening
18:39:02 T:139697950922496 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:39:02 T:139697950922496 DEBUG: CDVDVideoCodecFFmpeg::Open() Keeping default threading 3
18:39:02 T:139697950922496 ERROR: ffmpeg[7F0DF6BD9700]: [h264] illegal POC type 12
18:39:02 T:139697950922496 ERROR: Previous line repeats 1 times.
18:39:02 T:139697950922496 DEBUG: FactoryCodec - Video: ff-h264 - Opened
18:39:02 T:139698670552832 DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(0.000000, 1)
18:39:02 T:139696817555200 ERROR: ffmpeg[7F0DB32FC700]: [h264] illegal POC type 12
18:39:02 T:139696817555200 ERROR: Previous line repeats 1 times.
18:39:02 T:139696817555200 ERROR: ffmpeg[7F0DB32FC700]: [h264] top block unavailable for requested intra4x4 mode -1 at 23 0
18:39:02 T:139696817555200 ERROR: ffmpeg[7F0DB32FC700]: [h264] error while decoding MB 23 0, bytestream 108855
18:39:02 T:139696817555200 INFO: ffmpeg[7F0DB32FC700]: [h264] concealing 8160 DC, 8160 AC, 8160 MV errors in I frame
18:39:02 T:139698670552832 ERROR: ffmpeg[7F0E21A24700]: [h264] mmco: unref short failure
18:39:02 T:139696806278912 DEBUG: ffmpeg[7F0DB283B700]: [h264] Increasing reorder buffer to 1
18:39:02 T:139696806278912 INFO: ffmpeg[7F0DB283B700]: [h264] concealing 6807 DC, 6807 AC, 6807 MV errors in B frame
18:39:02 T:139696778749696 INFO: ffmpeg[7F0DB0DFA700]: [h264] concealing 7173 DC, 7173 AC, 7173 MV errors in B frame
18:39:02 T:139697311606528 DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(13277.000000, 1)
18:39:02 T:139697311606528 ERROR: ffmpeg[7F0DD0A26700]: [aac] channel element 0.9 is not allocated
18:39:02 T:139697311606528 ERROR: CDVDPlayerAudio::DecodeFrame - Decode Error. Skipping audio packet (-1094995529)
18:39:02 T:139697311606528 DEBUG: CDVDPlayerAudio::Process - Decode Error
18:39:02 T:139696761964288 ERROR: ffmpeg[7F0DAFDF8700]: [h264] reference picture missing during reorder
18:39:02 T:139696761964288 ERROR: Previous line repeats 1 times.
18:39:02 T:139696761964288 ERROR: ffmpeg[7F0DAFDF8700]: [h264] Missing reference picture, default is 65647
18:39:02 T:139698670552832 ERROR: Previous line repeats 1 times.
18:39:02 T:139698670552832 DEBUG: ffmpeg[7F0E21A24700]: [src] w:1920 h:1080 pixfmt:yuv420p tb:1/50 fr:0/1 sar:1/1 sws_param:
18:39:02 T:139696761964288 INFO: ffmpeg[7F0DAFDF8700]: [h264] concealing 7767 DC, 7767 AC, 7767 MV errors in P frame
18:39:02 T:139697311606528 ERROR: ffmpeg[7F0DD0A26700]: [aac] channel element 1.8 is not allocated
18:39:02 T:139697311606528 ERROR: CDVDPlayerAudio::DecodeFrame - Decode Error. Skipping audio packet (-1094995529)
18:39:02 T:139697311606528 DEBUG: CDVDPlayerAudio::Process - Decode Error
18:39:02 T:139697311606528 NOTICE: Creating audio stream (codec id: 86018, channels: 6, sample rate: 48000, no pass-through)
18:39:02 T:139699706132224 DEBUG: CActiveAE::DiscardStream - audio stream deleted
18:39:02 T:139699706132224 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:39:02 T:139697311606528 DEBUG: CDVDPlayerAudio:: synctype set to 1: skip/duplicate
18:39:02 T:139699694819072 INFO: CActiveAESink::OpenSink - initialize sink
18:39:03 T:139699694819072 DEBUG: CActiveAESink::OpenSink - trying to open device ALSA:hdmi:CARD=PCH,DEV=0
18:39:03 T:139699694819072 INFO: CAESinkALSA::Initialize - Attempting to open device "hdmi:CARD=PCH,DEV=0"
18:39:03 T:139699694819072 INFO: CAESinkALSA::Initialize - Opened device "hdmi:CARD=PCH,DEV=0,AES0=0x04,AES1=0x82,AES2=0x00,AES3=0x02"
18:39:03 T:139699694819072 INFO: CAESinkALSA::InitializeHW - Your hardware does not support AE_FMT_FLOAT, trying other formats
18:39:03 T:139699694819072 INFO: CAESinkALSA::InitializeHW - Using data format AE_FMT_S32NE
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::InitializeHW - Request: periodSize 682, bufferSize 2730
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::InitializeHW - Got: periodSize 910, bufferSize 2730
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::InitializeHW - Setting timeout to 57 ms
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::GetChannelLayout - Input Channel Count: 6 Output Channel Count: 6
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::GetChannelLayout - Requested Layout: FL,FR,FC,LFE,BL,BR
18:39:03 T:139699694819072 DEBUG: CAESinkALSA::GetChannelLayout - Got Layout: FL,FR,BL,BR,FC,LFE (ALSA: FL FR RL RR FC LFE)
18:39:03 T:139699694819072 DEBUG: CActiveAESink::OpenSink - ALSA Initialized:
18:39:03 T:139699694819072 DEBUG: Output Device : HDA Intel PCH
18:39:03 T:139699694819072 DEBUG: Sample Rate : 48000
18:39:03 T:139699694819072 DEBUG: Sample Format : AE_FMT_S32NE
18:39:03 T:139699694819072 DEBUG: Channel Count : 6
18:39:03 T:139699694819072 DEBUG: Channel Layout: FL,FR,BL,BR,FC,LFE
18:39:03 T:139699694819072 DEBUG: Frames : 910
18:39:03 T:139699694819072 DEBUG: Frame Samples : 5460
18:39:03 T:139699694819072 DEBUG: Frame Size : 24
18:39:03 T:139699706132224 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:39:03 T:139697950922496 DEBUG: Previous line repeats 1 times.
18:39:03 T:139697950922496 DEBUG: CDVDPlayer::HandleMessages - player started 1
18:39:03 T:139698670552832 ERROR: ffmpeg[7F0E21A24700]: [h264] mmco: unref short failure
18:39:03 T:139696817555200 ERROR: ffmpeg[7F0DB32FC700]: [h264] top block unavailable for requested intra4x4 mode -1 at 40 0
18:39:03 T:139696817555200 ERROR: ffmpeg[7F0DB32FC700]: [h264] error while decoding MB 40 0, bytestream 165178
18:39:03 T:139696817555200 INFO: ffmpeg[7F0DB32FC700]: [h264] concealing 8160 DC, 8160 AC, 8160 MV errors in I frame
18:39:03 T:139696806278912 INFO: ffmpeg[7F0DB283B700]: [h264] concealing 7946 DC, 7946 AC, 7946 MV errors in B frame
18:39:03 T:139698670552832 NOTICE: fps: 25.000000, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
18:39:03 T:139698670552832 DEBUG: OutputPicture - change configuration. 1920x1080. framerate: 25.00. format: YV12
18:39:03 T:139698670552832 NOTICE: Display resolution ADJUST : HDMI1: 1920x1080 @ 50.00Hz (21) (weight: 0.000)
18:39:03 T:139698670552832 DEBUG: CXBMCRenderManager::Configure - 3
18:39:03 T:139700191037376 NOTICE: Using GL_TEXTURE_2D
18:39:03 T:139700191037376 DEBUG: GL: Requested render method: 2
18:39:03 T:139700191037376 DEBUG: GL: BaseYUV2RGBGLSLShader: defines:
#define XBMC_texture_rectangle 0
#define XBMC_texture_rectangle_hack 0
#define XBMC_STRETCH 0
#define XBMC_YV12
18:39:03 T:139700191037376 NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:39:03 T:139700191037376 DEBUG: GL: Vertex Shader compilation log:
18:39:03 T:139700191037376 DEBUG: GL: Vertex Shader compiled successfully
18:39:03 T:139700191037376 DEBUG: GL: Pixel Shader compilation log:
18:39:03 T:139700191037376 DEBUG: GL: Fragment Shader compiled successfully
18:39:03 T:139700191037376 DEBUG: GL: Vertex Shader compilation log:
18:39:03 T:139700191037376 DEBUG: GL: Vertex Shader compiled successfully
18:39:03 T:139700191037376 DEBUG: GL: Pixel Shader compilation log:
18:39:03 T:139700191037376 DEBUG: GL: Fragment Shader compiled successfully
18:39:03 T:139700191037376 NOTICE: GL: NPOT texture support detected
18:39:03 T:139700191037376 NOTICE: GL: Using GL_ARB_pixel_buffer_object
18:39:03 T:139697950922496 DEBUG: CDVDPlayer::HandleMessages - player started 2
18:39:03 T:139697950922496 DEBUG: set caching from pvr to done. audio (1) = 11. video (1) = 13
18:39:03 T:139697950922496 DEBUG: CDVDPlayer::SetCaching - caching state 0
18:39:03 T:139697311606528 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError1 - was:-154651.226000, should be:95566.876807, error:250218.102808
18:39:03 T:139697311606528 ERROR: ffmpeg[7F0DD0A26700]: [aac] Reserved bit set.
18:39:03 T:139697311606528 ERROR: CDVDPlayerAudio::DecodeFrame - Decode Error. Skipping audio packet (-1094995529)
18:39:03 T:139697311606528 DEBUG: CDVDPlayerAudio::Process - Decode Error
18:39:03 T:139696778749696 INFO: ffmpeg[7F0DB0DFA700]: [h264] concealing 7658 DC, 7658 AC, 7658 MV errors in B frame
18:39:03 T:139696806278912 DEBUG: ffmpeg[7F0DB283B700]: [h264] Increasing reorder buffer to 2
18:39:03 T:139696761964288 INFO: ffmpeg[7F0DAFDF8700]: [h264] concealing 1876 DC, 1876 AC, 1876 MV errors in B frame
18:39:03 T:139697311606528 DEBUG: CDVDClock::Discontinuity - CDVDPlayerAudio::HandleSyncError1 - was:196313.574808, should be:494980.757828, error:298667.183020
18:39:04 T:139700191037376 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
18:39:04 T:139696778749696 ERROR: ffmpeg[7F0DB0DFA700]: [h264] reference picture missing during reorder
18:39:04 T:139696778749696 ERROR: Previous line repeats 1 times.
18:39:04 T:139696778749696 ERROR: ffmpeg[7F0DB0DFA700]: [h264] Missing reference picture, default is 65551
18:39:04 T:139696806278912 ERROR: Previous line repeats 1 times.
18:39:04 T:139696806278912 DEBUG: ffmpeg[7F0DB283B700]: [h264] Increasing reorder buffer to 3
18:39:04 T:139698670552832 ERROR: ffmpeg[7F0E21A24700]: [h264] mmco: unref short failure
18:39:05 T:139697311606528 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available
18:39:06 T:139698670552832 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:39:06 T:139698670552832 INFO: CDVDPlayerVideo - Stillframe detected, switching to forced 25.000000 fps
18:39:11 T:139698670552832 DEBUG: CPullupCorrection: detected pattern of length 1: 40000.00, frameduration: 40000.000000
18:39:18 T:139699280656128 DEBUG: PushCecKeypress - received key b duration 0
18:39:18 T:139700191037376 DEBUG: OnKey: 11 (0x0b) pressed, action is Info
18:39:18 T:139700191037376 DEBUG: ------ Window Init (DialogFullScreenInfo.xml) ------
18:39:18 T:139700191037376 INFO: Loading skin file: DialogFullScreenInfo.xml, load type: KEEP_IN_MEMORY
18:39:18 T:139700191037376 DEBUG: ------ Window Init (DialogSeekBar.xml) ------
18:39:19 T:139699280656128 DEBUG: PushCecKeypress - received key b duration 115
18:39:19 T:139699280656128 DEBUG: PushCecKeypress - received key b duration 0
18:39:19 T:139700191037376 DEBUG: OnKey: 11 (0x0b) pressed, action is Info
18:39:19 T:139699280656128 DEBUG: PushCecKeypress - received key b duration 119
18:39:19 T:139700191037376 DEBUG: ------ Window Deinit (DialogFullScreenInfo.xml) ------
18:39:20 T:139700191037376 DEBUG: ------ Window Deinit (DialogSeekBar.xml) ------
18:39:24 T:139696736786176 DEBUG: Thread JobWorker 139696736786176 terminating (autodelete)
18:40:00 T:139697342891776 DEBUG: EPG - UpdateFromScraper - updating EPG for channel 'Drama' from client '2'
18:40:00 T:139697342891776 DEBUG: EPG - UpdateFromScraper - updating EPG for channel 'CBBC HD' from client '2'
18:40:00 T:139697342891776 DEBUG: EPG - UpdateFromScraper - updating EPG for channel 'CBBC Channel' from client '2'
18:40:00 T:139698661897984 DEBUG: CPVRTimers - Update - updating timers
18:40:55 T:139699280656128 DEBUG: PushCecKeypress - received key e0 duration 500
18:40:55 T:139700191037376 DEBUG: OnKey: 224 (0xe0) pressed, action is Stop
18:40:55 T:139700191037376 NOTICE: CDVDPlayer::CloseFile()
18:40:55 T:139700191037376 NOTICE: DVDPlayer: waiting for threads to exit
18:40:55 T:139697950922496 NOTICE: CDVDPlayer::OnExit()
18:40:55 T:139697950922496 NOTICE: Closing stream player 1
18:40:55 T:139697950922496 NOTICE: Waiting for audio thread to exit
18:40:55 T:139697311606528 DEBUG: CDVDPlayerAudio::Process - Abort received, exiting thread
18:40:55 T:139697311606528 NOTICE: thread end: CDVDPlayerAudio::OnExit()
18:40:55 T:139697950922496 NOTICE: Closing audio device
18:40:55 T:139697311606528 DEBUG: Thread DVDPlayerAudio 139697311606528 terminating
18:40:55 T:139697950922496 NOTICE: Deleting audio codec
18:40:55 T:139699706132224 DEBUG: CActiveAE::DiscardStream - audio stream deleted
18:40:55 T:139697950922496 NOTICE: Closing stream player 2
18:40:55 T:139697950922496 NOTICE: waiting for video thread to exit
18:40:55 T:139699706132224 DEBUG: CActiveAE::ClearDiscardedBuffers - buffer pool deleted
18:40:55 T:139698670552832 DEBUG: Previous line repeats 1 times.
18:40:55 T:139698670552832 NOTICE: thread end: video_thread
18:40:55 T:139698670552832 DEBUG: Thread DVDPlayerVideo 139698670552832 terminating
18:40:55 T:139697950922496 NOTICE: deleting video codec
18:40:55 T:139699694819072 INFO: CActiveAESink::OpenSink - initialize sink
18:40:55 T:139697950922496 NOTICE: Closing stream player 3