Kodi Community Forum

Full Version: Slow channel opening after Restart or Suspend
You're currently viewing a stripped down version of our content. View the full version with proper formatting.
Hi,

I have a problem with LiveTV.
Mostly it takes up to 10 seconds (ore more), after I press LiveTV to open a channel. The problem affects only after reboot or suspend.
In very few cases the channel opens nearly instant.
Zapping after that is very fast. So it's only effects the first tuning.

I'm using VDR as Frontend and Backend. But already thried tvheadend Server/Client and had the same problem.

Log Output fast Channel opening:
Code:
18:19:25 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: OnDisconnect - connection lost !!!
18:19:26 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: failed to read greeting from server
18:19:37 T:140697522730752   ERROR: CAESinkALSA - snd_pcm_writei(-86) Streams pipe error - trying to recover
18:19:37 T:140696325441280  NOTICE: ES: Client  from 127.0.0.1 timed out
18:19:37 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: Open - Can't connect to XVDR Server
18:19:38 T:140697535493952   ERROR: Previous line repeats 2 times.
18:19:38 T:140697535493952  NOTICE: OnWake: Running resume jobs
18:19:38 T:140697535493952  NOTICE: OnWake: Restarting lirc
18:19:38 T:140697531123456 WARNING: CActiveAE::StateMachine - signal: 0 from port: OutputControlPort not handled for state: 6
18:19:39 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: Open - Can't connect to XVDR Server
18:19:44 T:140696325441280   ERROR: Previous line repeats 1 times.
18:19:44 T:140696325441280  NOTICE: ES: Client  from 127.0.0.1 timed out
18:19:44 T:140697535493952   ERROR: ActiveAE::Resume - failed to init
18:19:44 T:140697535493952  NOTICE: PVRManager - ContinueLastChannel - continue playback on channel 'RTL HD'
18:19:44 T:140697535493952  NOTICE: DVDPlayer: Opening: pvr://channels/tv/Alle TV-Kanäle/8.pvr
18:19:44 T:140697535493952 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:19:44 T:140696122988288  NOTICE: Thread DVDPlayer start, auto delete: false
18:19:44 T:140696122988288  NOTICE: Creating InputStream
18:19:44 T:140696122988288  NOTICE: AddOnLog: VDR XVDR Client: doing timeshift on hdd at '/tmp/xvdr-timeshift.dat' using 1024.000000 Mb
18:19:44 T:140696122988288  NOTICE: Creating Demuxer
18:19:44 T:140696122988288   ERROR: Get - failed to get stream
18:19:44 T:140696122988288 WARNING: CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
18:19:44 T:140696122988288 WARNING: CDVDMessageQueue(video)::Put MSGQ_NOT_INITIALIZED
18:19:44 T:140697535493952  NOTICE: PVRManager - StartPlayback - started playback on channel 'RTL HD'
18:19:45 T:140696122988288  NOTICE: Opening video stream: 0 source: 256
18:19:45 T:140696122988288  NOTICE: Creating video codec with codec id: 28
18:19:45 T:140696122988288  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:19:45 T:140696122988288  NOTICE: Creating video thread
18:19:45 T:140696156563200  NOTICE: Thread VideoReferenceClock start, auto delete: false
18:19:45 T:140696148170496  NOTICE: Thread DVDPlayerVideo start, auto delete: false
18:19:45 T:140696122988288  NOTICE: Opening audio stream: 1 source: 256
18:19:45 T:140696122988288  NOTICE: Finding audio codec for: 86019
18:19:45 T:140696122988288  NOTICE: Creating audio thread
18:19:45 T:140696148170496  NOTICE: running thread: video_thread
18:19:45 T:140696114595584  NOTICE: Thread DVDPlayerAudio start, auto delete: false
18:19:45 T:140696122988288  NOTICE: Opening Subtitle stream: 2 source: 256
18:19:45 T:140696122988288  NOTICE: Opening teletext stream: 3 source: 256
18:19:45 T:140696122988288  NOTICE: Creating teletext data thread
18:19:45 T:140696114595584  NOTICE: running thread: CDVDPlayerAudio::Process()
18:19:45 T:140696046393088  NOTICE: Thread DVDTeletextData start, auto delete: false
18:19:45 T:140696046393088  NOTICE: running thread: CDVDTeletextData
18:19:47 T:140696122988288  NOTICE: Opening video stream: 0 source: 256
18:19:47 T:140696122988288  NOTICE: Opening audio stream: 1 source: 256
18:19:47 T:140696122988288  NOTICE: Opening Subtitle stream: 2 source: 256
18:19:47 T:140696122988288  NOTICE: Opening teletext stream: 3 source: 256
18:19:47 T:140696148170496   ERROR: Decode - avcodec_decode_video returned failure
18:19:47 T:140696114595584   ERROR: Previous line repeats 3 times.
18:19:47 T:140696114595584  NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, pass-through)
18:19:47 T:140696122988288  NOTICE: Opening video stream: 0 source: 256
18:19:47 T:140696122988288  NOTICE: Creating video codec with codec id: 28
18:19:47 T:140696122988288  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:19:47 T:140696148170496 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:19:47 T:140696114595584 WARNING: CActiveAEStream::AddData - timeout waiting for buffer, paused: 0, cache time: 0.000000, free buffers: 0
18:19:47 T:140696148170496 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:19:47 T:140696148170496  NOTICE:  fps: 25.000000, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
18:19:47 T:140696148170496  NOTICE: Display resolution ADJUST : HDMI1: 1920x1080 @ 50.00Hz (18) (weight: 0.000)
18:19:47 T:140697535493952  NOTICE: Using GL_TEXTURE_2D
18:19:47 T:140697535493952  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:19:47 T:140697535493952  NOTICE: GL: NPOT texture support detected
18:19:47 T:140697535493952  NOTICE: GL: Using GL_ARB_pixel_buffer_object
18:19:47 T:140697535493952  NOTICE: CWinSystemX11::SetFullScreen - calling xrandr
18:19:48 T:140696114595584 WARNING: CActiveAEStream::AddData - timeout waiting for buffer, paused: 0, cache time: 0.400000, free buffers: 0
18:19:48 T:140697535493952 WARNING: Previous line repeats 3 times.
18:19:48 T:140697535493952  NOTICE: Using GL_TEXTURE_2D
18:19:48 T:140697535493952  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:19:48 T:140697535493952  NOTICE: GL: NPOT texture support detected
18:19:48 T:140697535493952  NOTICE: GL: Using GL_ARB_pixel_buffer_object

Log Output slow Channel opening:
Code:
18:23:26 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: OnDisconnect - connection lost !!!
18:23:26 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: failed to read greeting from server
18:23:37 T:140697522730752   ERROR: CAESinkALSA - snd_pcm_writei(-86) Streams pipe error - trying to recover
18:23:37 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: Open - Can't connect to XVDR Server
18:23:38 T:140697535493952   ERROR: Previous line repeats 2 times.
18:23:38 T:140697535493952  NOTICE: OnWake: Running resume jobs
18:23:38 T:140697535493952  NOTICE: OnWake: Restarting lirc
18:23:38 T:140697531123456 WARNING: CActiveAE::StateMachine - signal: 0 from port: OutputControlPort not handled for state: 6
18:23:39 T:140696208008960   ERROR: AddOnLog: VDR XVDR Client: Open - Can't connect to XVDR Server
18:23:44 T:140697535493952   ERROR: Previous line repeats 1 times.
18:23:44 T:140697535493952   ERROR: ActiveAE::Resume - failed to init
18:23:44 T:140697535493952  NOTICE: PVRManager - ContinueLastChannel - continue playback on channel 'RTL HD'
18:23:44 T:140697535493952  NOTICE: DVDPlayer: Opening: pvr://channels/tv/Alle TV-Kanäle/8.pvr
18:23:44 T:140697535493952 WARNING: CDVDMessageQueue(player)::Put MSGQ_NOT_INITIALIZED
18:23:44 T:140696164955904  NOTICE: Thread DVDPlayer start, auto delete: false
18:23:44 T:140696164955904  NOTICE: Creating InputStream
18:23:44 T:140696164955904  NOTICE: AddOnLog: VDR XVDR Client: doing timeshift on hdd at '/tmp/xvdr-timeshift.dat' using 1024.000000 Mb
18:23:44 T:140696164955904  NOTICE: Creating Demuxer
18:23:44 T:140696164955904   ERROR: Get - failed to get stream
18:23:44 T:140696164955904 WARNING: CDVDMessageQueue(audio)::Put MSGQ_NOT_INITIALIZED
18:23:44 T:140696164955904 WARNING: CDVDMessageQueue(video)::Put MSGQ_NOT_INITIALIZED
18:23:44 T:140697535493952  NOTICE: PVRManager - StartPlayback - started playback on channel 'RTL HD'
18:23:44 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:23:44 T:140696164955904  NOTICE: Creating video codec with codec id: 28
18:23:44 T:140696164955904  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:23:44 T:140696164955904  NOTICE: Creating video thread
18:23:44 T:140696148170496  NOTICE: Thread VideoReferenceClock start, auto delete: false
18:23:44 T:140696114595584  NOTICE: Thread DVDPlayerVideo start, auto delete: false
18:23:44 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:23:44 T:140696164955904  NOTICE: Finding audio codec for: 86019
18:23:44 T:140696164955904  NOTICE: Creating audio thread
18:23:44 T:140696114595584  NOTICE: running thread: video_thread
18:23:44 T:140696046393088  NOTICE: Thread DVDPlayerAudio start, auto delete: false
18:23:44 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:23:44 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:23:44 T:140696164955904  NOTICE: Creating teletext data thread
18:23:44 T:140696046393088  NOTICE: running thread: CDVDPlayerAudio::Process()
18:23:44 T:140695819351808  NOTICE: Thread DVDTeletextData start, auto delete: false
18:23:44 T:140695819351808  NOTICE: running thread: CDVDTeletextData
18:23:46 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:23:46 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:23:46 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:23:46 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:23:50 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:23:50 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:23:50 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:23:50 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:23:54 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:23:54 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:23:54 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:23:54 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:23:58 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:23:58 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:23:58 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:23:58 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:24:00 T:140697534760704  NOTICE: Thread RSSReader start, auto delete: false
18:24:02 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:24:02 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:24:02 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:24:02 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:24:06 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:24:06 T:140696164955904  NOTICE: Opening audio stream: 1 source: 256
18:24:06 T:140696164955904  NOTICE: Opening Subtitle stream: 2 source: 256
18:24:06 T:140696164955904  NOTICE: Opening teletext stream: 3 source: 256
18:24:09 T:140696114595584   ERROR: Decode - avcodec_decode_video returned failure
18:24:09 T:140696114595584   ERROR: Previous line repeats 3 times.
18:24:09 T:140696114595584 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:24:09 T:140696046393088  NOTICE: Creating audio stream (codec id: 86019, channels: 2, sample rate: 48000, pass-through)
18:24:09 T:140696114595584   ERROR: Decode - avcodec_decode_video returned failure
18:24:09 T:140696164955904  NOTICE: Opening video stream: 0 source: 256
18:24:09 T:140696164955904  NOTICE: Creating video codec with codec id: 28
18:24:09 T:140696164955904  NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
18:24:10 T:140696046393088 WARNING: CActiveAEStream::AddData - timeout waiting for buffer, paused: 0, cache time: 0.000000, free buffers: 0
18:24:10 T:140696114595584 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
18:24:10 T:140696114595584  NOTICE:  fps: 25.000000, pwidth: 1920, pheight: 1080, dwidth: 1920, dheight: 1080
18:24:10 T:140696114595584  NOTICE: Display resolution ADJUST : HDMI1: 1920x1080 @ 50.00Hz (18) (weight: 0.000)
18:24:10 T:140697535493952  NOTICE: Using GL_TEXTURE_2D
18:24:10 T:140697535493952  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:24:10 T:140697535493952  NOTICE: GL: NPOT texture support detected
18:24:10 T:140697535493952  NOTICE: GL: Using GL_ARB_pixel_buffer_object
18:24:10 T:140697535493952  NOTICE: CWinSystemX11::SetFullScreen - calling xrandr
18:24:10 T:140696046393088 WARNING: CActiveAEStream::AddData - timeout waiting for buffer, paused: 0, cache time: 0.400000, free buffers: 0
18:24:11 T:140697535493952 WARNING: Previous line repeats 2 times.
18:24:11 T:140697535493952  NOTICE: Using GL_TEXTURE_2D
18:24:11 T:140697535493952  NOTICE: GL: Selecting Single Pass YUV 2 RGB shader
18:24:11 T:140697535493952  NOTICE: GL: NPOT texture support detected
18:24:11 T:140697535493952  NOTICE: GL: Using GL_ARB_pixel_buffer_object
18:24:25 T:140696325441280  NOTICE: ES: Client  from 127.0.0.1 timed out

Does anyone know, what I can do, to fix this?
Looks like VDR hasn't finished starting up yet when you resume playback. You'll need to enable debug logging and post full logs of both situations.