Linux infinite loop when switching channels
#1
Hi,

I have a problem when switching channels. Audio is running, video is black and Kodi is running with 120%CPU and 4 fps in an infinite loop.

- Odroid C1 with ubuntu 14.04, unwindowed (kodi-standalone)
- kodi 15 alpha (but the same is with kodi 14.01)
- TVHeadend backend version 3.9.2505~g051412d
- pwr.hts Kodi addon 2.1.1
- Grundig GSS.box as a satelite -> iptv converter

If I start Kodi and select the first channel everything is fine.
If I switch to another channel, sometimes (25% chance) video is black screen, audio is running and the console output gets filled with:

Code:
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=9
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=9
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=9
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=9
send control failed,handle=0,cmd=4004530e,paramter=226b3, t=ffffffff errno=9
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=9
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=4004530e,paramter=257eb, t=ffffffff errno=25
send control failed,handle=0,cmd=4004530e,paramter=234c3, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25
send control failed,handle=0,cmd=4004530e,paramter=23bcb, t=ffffffff errno=25
send control failed,handle=0,cmd=80045308,paramter=a34dbc8c, t=ffffffff errno=25

messages.

Sorry, here is no file - upload button so I post the sequence of the kodi log beginning with an failed channel switch here:

Code:
06:01:03 T:2702570528   DEBUG: add three byte NAL 264 header in stream before header len=147
06:01:03 T:2702570528   DEBUG: CAMLCodec::SetSpeed, speed(1000)
06:01:03 T:2702570528   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_SYNCHRONIZE
06:01:03 T:2744841248   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_SYNCHRONIZE
06:01:03 T:2730218528   DEBUG: CDVDPlayer::SetCaching - caching state 3
06:01:03 T:2702570528   DEBUG: CAMLCodec::SetSpeed, speed(0)
06:01:03 T:2730218528   DEBUG: PVRManager - PerformChannelSwitch - switching to channel 'tagesschau24 HD'
06:01:03 T:2730218528   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux open
06:01:03 T:2730218528   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux unsubscribe from 2059952527
06:01:03 T:2730218528   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux successfully unsubscribed 2059952527
06:01:03 T:2730218528   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux subscribe to 1550252983
06:01:03 T:2730218528   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux successfully subscribed to 1550252983
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux unhandled subscription message [subscriptionGrace]
06:01:03 T:3037245440    INFO: LIRC Initialize: using: /run/lirc/lircd
06:01:03 T:3037245440   DEBUG: Failed to connect to LIRC. Retry in 10s.
06:01:03 T:2730218528   DEBUG: Loading settings for pvr://channels/tv/Alle Kanäle/2.pvr
06:01:03 T:2730218528  NOTICE: PVRManager - PerformChannelSwitch - switched to channel 'tagesschau24 HD'
06:01:03 T:2879476768   DEBUG: CAnnouncementManager - Announcement: OnStop from xbmc
06:01:03 T:2879476768   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnStop
06:01:03 T:2879476768   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Announce(flag=Player, sender=xbmc, message=OnStop)
06:01:03 T:2879476768   DEBUG: CAnnouncementManager - Announcement: OnPlay from xbmc
06:01:03 T:2730218528  NOTICE: Creating Demuxer
06:01:03 T:2879476768   DEBUG: GOT ANNOUNCEMENT, type: 1, from xbmc, message OnPlay
06:01:03 T:2879476768   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - Announce(flag=Player, sender=xbmc, message=OnPlay)
06:01:03 T:2730218528   DEBUG: CDVDPlayer::SetCaching - caching state 2
06:01:03 T:2702570528   DEBUG: CAMLCodec::SetSpeed, speed(0)
06:01:03 T:3037245440   DEBUG: ------ Window Init (DialogSeekBar.xml) ------
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux subscription start
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts -   id: 1, type H264, codec: 28
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux subscription start
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts -   id: 2, type MPEG2AUDIO, codec: 86016
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux subscription start
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts -   id: 4, type AC3, codec: 86019
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux subscription start
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts -   id: 3, type TELETEXT, codec: 94215
06:01:03 T:2837439520   DEBUG: AddOnLog: Tvheadend HTSP Client: pvr.hts - demux stream change
06:01:03 T:2730218528   DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 0:1 with codec_id 28
06:01:03 T:2730218528   DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 1:2 with codec_id 86016
06:01:03 T:2730218528   DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 2:3 with codec_id 94215
06:01:03 T:2730218528   DEBUG: CDVDDemuxPVRClient::RequestStreams(): added/updated stream 3:4 with codec_id 86019
06:01:03 T:2730218528  NOTICE: Opening stream: 0 source: 256
06:01:03 T:2730218528  NOTICE: Creating video codec with codec id: 28
06:01:03 T:2730218528   DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:yes MediaCodec:no OpenMax:yes libstagefright:no VDPAU:no VAAPI:no iMXVPU:no MMAL:no
06:01:03 T:2730218528   DEBUG: FactoryCodec - Video: amcodec - Opening
06:01:03 T:2730218528    INFO: DVDVideoCodecAmlogic: Opened Amlogic Codec
06:01:03 T:2730218528   DEBUG: FactoryCodec - Video: am-h264 - Opened
06:01:03 T:2667160608  NOTICE: Thread RefClock start, auto delete: false
06:01:03 T:2667160608   DEBUG: CVideoReferenceClock: Setup failed, falling back to CurrentHostCounter()
06:01:03 T:2667160608   DEBUG: Thread RefClock 2667160608 terminating
06:01:03 T:2702570528   DEBUG: CAMLCodec::CloseDecoder
06:01:03 T:2658772000   DEBUG: CAMLCodec::Process Stopped
06:01:03 T:2658772000   DEBUG: Thread CAMLCodec 2658772000 terminating
06:01:03 T:2730218528  NOTICE: Opening stream: 3 source: 256
06:01:03 T:2730218528  NOTICE: Finding audio codec for: 86019
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: passthrough - Opening
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: passthrough - Failed
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: FFmpeg - Opening
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: FFmpeg - Opened
06:01:03 T:2730218528  NOTICE: Closing stream player 3
06:01:03 T:2730218528  NOTICE: Opening stream: 2 source: 256
06:01:03 T:2730218528   DEBUG: ParsePacket - {1} iSampleRate changed from 3 to 48000
06:01:03 T:2730218528   DEBUG: ParsePacket - {0} profile changed from -99 to 100
06:01:03 T:2730218528   DEBUG: ParsePacket - {0} level changed from -99 to 40
06:01:03 T:2730218528  NOTICE: Opening stream: 0 source: 256
06:01:03 T:2730218528  NOTICE: Creating video codec with codec id: 28
06:01:03 T:2730218528   DEBUG: CDVDFactoryCodec: compiled in hardware support: AMCodec:yes MediaCodec:no OpenMax:yes libstagefright:no VDPAU:no VAAPI:no iMXVPU:no MMAL:no
06:01:03 T:2730218528   DEBUG: FactoryCodec - Video: amcodec - Opening
06:01:03 T:2730218528    INFO: DVDVideoCodecAmlogic: Opened Amlogic Codec
06:01:03 T:2730218528   DEBUG: FactoryCodec - Video: am-h264 - Opened
06:01:03 T:2658772000  NOTICE: Thread RefClock start, auto delete: false
06:01:03 T:2658772000   DEBUG: CVideoReferenceClock: Setup failed, falling back to CurrentHostCounter()
06:01:03 T:2702570528   DEBUG: CAMLCodec::CloseDecoder
06:01:03 T:2702570528   DEBUG: CDVDPlayerVideo - CDVDMsg::GENERAL_RESYNC(1226266.000000, 1)
06:01:03 T:2702570528   DEBUG: codecid_to_vformat, id(28) -> vformat(2)
06:01:03 T:2702570528   DEBUG: codec_tag_to_vdec_type, codec_tag(28) -> vdec_type(4)
06:01:03 T:2730218528   DEBUG: ParsePacket - {3} iSampleRate changed from 3 to 48000
06:01:03 T:2702570528   DEBUG: CAMLCodec::OpenDecoder hints.width(1280), hints.height(720), hints.codec(28), hints.codec_tag(0), hints.pid(1)
06:01:03 T:2702570528   DEBUG: CAMLCodec::OpenDecoder hints.fpsrate(1000000), hints.fpsscale(20000), video_rate(1920)
06:01:03 T:2702570528   DEBUG: CAMLCodec::OpenDecoder hints.aspect(0.000000), video_ratio.num(1), video_ratio.den(1)
06:01:03 T:2702570528   DEBUG: CAMLCodec::OpenDecoder hints.orientation(0), hints.forced_aspect(0), hints.extrasize(147)
06:01:03 T:2658772000   DEBUG: Thread RefClock 2658772000 terminating
06:01:03 T:2730218528  NOTICE: Opening stream: 3 source: 256
06:01:03 T:2730218528  NOTICE: Finding audio codec for: 86019
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: passthrough - Opening
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: passthrough - Failed
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: FFmpeg - Opening
06:01:03 T:2730218528   DEBUG: FactoryCodec - Audio: FFmpeg - Opened
06:01:03 T:2744841248   DEBUG: CDVDPlayerAudio - CDVDMsg::GENERAL_RESYNC(40800.000000, 1)
06:01:03 T:2744841248   DEBUG: CDVDPlayerAudio:: synctype set to 0: clock feedback
06:01:03 T:2730218528   DEBUG: CDVDPlayer::HandleMessages - player started 1
06:01:03 T:2702570528   DEBUG: add three byte NAL 264 header in stream before header len=147
06:01:03 T:2658772000  NOTICE: Thread CAMLCodec start, auto delete: false
06:01:03 T:2658772000   DEBUG: CAMLCodec::Process Started
06:01:03 T:2702570528   DEBUG: CAMLCodec::SetSpeed, speed(1000)
06:01:03 T:2702570528 WARNING: CDVDMessageQueue(video)::Get - asked for new data packet, with nothing available
06:01:03 T:3037245440   DEBUG: CAMLCodec::SetVideo3dMode:mode3d(0x0)
06:01:03 T:3037245440   ERROR: SetInt: error writing /sys/class/ppmgr/ppmgr_3d_mode
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed
06:01:03 T:2702570528   DEBUG: ERROR check in pts error!
06:01:03 T:2702570528   DEBUG: check in pts failed

The last two lines are repeated about 100times/sec.

Is this problem already known? Is there already an solution for this?
I hope that the Information are sufficient...

Thank you!

Edit: I forgot to say: I'm impressed about both software components Kodi and TVHeadend. It's so much fun!
Reply
#2
Looks like a bug in AML regarding 3D modes. Can you file a bug report on trac.kodi.tv and CC koying?
Reply
#3
http://trac.kodi.tv/ticket/15881
Reply

Logout Mark Read Team Forum Stats Members Help
infinite loop when switching channels0