Error, timed out after 7000 ms. Unable to change channels in 0.25

[iwelcomespam@…]

I just upgraded to the new 0.25/fixes release and I'm unable to change channels. The front-end always crashes when changing channels with a socket timeout error.

When I downgrade to 0.24/fixes I don't see this problem.

Here's my FE log

2012-04-10 10:50:53.499667 C  mythfrontend version: master [v0.25-rc-182-gcffed2b] www.mythtv.org
2012-04-10 10:50:53.499697 N  Enabled verbose msgs:  general
2012-04-10 10:50:53.499732 N  Setting Log Level to LOG_INFO
2012-04-10 10:50:53.499808 I  Added logging to the console
2012-04-10 10:50:53.499848 I  Added syslogging to facility local7
2012-04-10 10:50:53.499859 I  Added database logging to table logging
2012-04-10 10:50:53.499965 N  Setting up SIGHUP handler
2012-04-10 10:50:53.500113 N  Using runtime prefix = /usr
2012-04-10 10:50:53.500135 N  Using configuration directory = /home/w/.mythtv
2012-04-10 10:50:53.500328 I  Assumed character encoding: en_US.UTF-8
2012-04-10 10:50:53.501244 N  Empty LocalHostName.
2012-04-10 10:50:53.501254 I  Using localhost value of w
2012-04-10 10:50:53.501499 I  Testing network connectivity to '192.168.2.24'
2012-04-10 10:50:53.503041 I  Starting IO manager (write)
2012-04-10 10:50:53.503272 I  Starting process signal handler
2012-04-10 10:50:53.503285 I  Starting IO manager (read)
2012-04-10 10:50:53.503684 I  Starting process manager
2012-04-10 10:50:53.703086 E  Could not open settings file /home/w/.mythtv/config.xml for writing
2012-04-10 10:50:53.707074 N  Setting QT default locale to en_US
2012-04-10 10:50:53.707093 I  Current locale en_US
2012-04-10 10:50:53.707161 N  Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
2012-04-10 10:50:53.853963 I  ScreenSaverX11Private: XScreenSaver support enabled
2012-04-10 10:50:53.854820 I  ScreenSaverX11Private: DPMS is disabled.
2012-04-10 10:50:53.875078 N  Desktop video mode: 1920x1080 60.000 Hz
2012-04-10 10:50:55.269402 I  Listening on TCP 127.0.0.1:6547
2012-04-10 10:50:55.269557 I  Listening on TCP 192.168.2.77:6547
2012-04-10 10:50:55.269713 I  Listening on TCP [0:0:0:0:0:0:0:1]:6547
2012-04-10 10:50:55.269877 I  Listening on TCP [2002:453e:9325:1234:201:80ff:fe76:f453]:6547
2012-04-10 10:50:55.271408 E  Could not open settings file /home/w/.mythtv/config.xml for writing
2012-04-10 10:50:55.898961 E  RAOP Conn: Failed to read key from: /home/w/.mythtv/RAOPKey.rsa
2012-04-10 10:50:55.898986 E  RAOP Device: Aborting startup - no key found.
2012-04-10 10:50:55.906287 I  Loading en_us translation for module mythfrontend
2012-04-10 10:50:55.929352 I  LIRC: Successfully initialized '/dev/lircd' using '/home/w/.mythtv/lircrc' config
2012-04-10 10:50:55.929477 E  JoystickMenuThread: Joystick disabled - Failed to read /home/w/.mythtv/joystickmenurc
2012-04-10 10:50:55.931072 I  Binding to UDP 127.0.0.1:6948
2012-04-10 10:50:55.931175 I  Binding to UDP 192.168.2.77:6948
2012-04-10 10:50:55.931306 I  Binding to UDP [0:0:0:0:0:0:0:1]:6948
2012-04-10 10:50:55.931434 I  Binding to UDP [2002:453e:9325:1234:201:80ff:fe76:f453]:6948
2012-04-10 10:50:55.931525 I  Binding to UDP 192.168.2.255:6948
2012-04-10 10:50:56.011639 I  Using Frameless Window
2012-04-10 10:50:56.011777 I  Using Full Screen Window
2012-04-10 10:50:56.247626 I  Using the Qt painter
2012-04-10 10:50:56.382642 I  Current MythTV Schema Version (DBSchemaVer): 1299
2012-04-10 10:50:56.556891 W  ThemeInfo: Unable to open themeinfo.xml for /usr/share/mythtv/themes/BlackCurves-OSD/themeinfo.xml
2012-04-10 10:50:56.556915 E  ThemeInfo: The theme (/usr/share/mythtv/themes/BlackCurves-OSD) is missing a themeinfo.xml file.
2012-04-10 10:50:56.558173 W  ThemeInfo: Unable to open themeinfo.xml for /usr/share/mythtv/themes/Gray-OSD/themeinfo.xml
2012-04-10 10:50:56.558191 E  ThemeInfo: The theme (/usr/share/mythtv/themes/Gray-OSD) is missing a themeinfo.xml file.
2012-04-10 10:50:56.951636 N  Registering Internal as a media playback plugin.
2012-04-10 10:50:57.002876 W  No plugins directory /usr/lib/mythtv/plugins
2012-04-10 10:50:57.095759 N  Found mainmenu.xml for theme 'MythCenter-wide'
2012-04-10 10:50:57.184577 I  MythCoreContext: Connecting to backend server: 192.168.2.24:6543 (try 1 of 1)
2012-04-10 10:50:57.192503 I  Using protocol version 72
2012-04-10 10:50:57.354155 I  Bonjour: Service registration complete: name 'Mythfrontend on w' type '_mythfrontend._tcp.' domain: 'local.'
2012-04-10 10:51:02.672008 I  TV: Creating TV object
2012-04-10 10:51:02.703303 N  Suspending idle timer
2012-04-10 10:51:02.711733 I  TV: Created TvPlayWindow.
2012-04-10 10:51:02.797712 I  TV: Attempting to change from None to WatchingLiveTV
2012-04-10 10:51:02.797768 I  MythCoreContext: Connecting to backend server: 192.168.2.24:6543 (try 1 of 1)
2012-04-10 10:51:02.799057 I  Using protocol version 72
2012-04-10 10:51:02.811800 N  TV: Spawning LiveTV Recorder -- begin
2012-04-10 10:51:03.013844 N  TV: Spawning LiveTV Recorder -- end
2012-04-10 10:51:03.027035 E  SG(Default): Unable to find any Storage Group Directories.  Using hardcoded default value of '/mnt/store'
2012-04-10 10:51:03.033629 I  TV: playbackURL(myth://192.168.2.24:6543/1632_20120410105102.mpg) cardtype(DUMMY)
2012-04-10 10:51:03.354744 I  Pulse: PulseAudio suspend OK
2012-04-10 10:51:03.377323 N  AudioPlayer: Enabling Audio
2012-04-10 10:51:03.416525 I  VideoOutputXv: XVideo Adaptor Name: 'Intel(R) Textured Video'
2012-04-10 10:51:03.466197 I  OSD: Base theme size: 1280x720
2012-04-10 10:51:03.466232 I  OSD: Scaling factors: 0.5625x0.8
2012-04-10 10:51:03.513545 I  OSD: Base theme size: 1280x720
2012-04-10 10:51:03.513568 I  OSD: Scaling factors: 0.5625x0.8
2012-04-10 10:51:03.543305 I  Player(0): Video timing method: DRM
2012-04-10 10:51:03.559769 I  TV: Created player.
2012-04-10 10:51:03.559829 I  TV: Changing from None to WatchingLiveTV
2012-04-10 10:51:03.559853 I  TV: State is LiveTV & mctx == ctx
2012-04-10 10:51:03.562138 I  TV: UpdateOSDInput done
2012-04-10 10:51:03.562163 I  TV: UpdateLCD done
2012-04-10 10:51:03.563086 I  TV: ITVRestart done
2012-04-10 10:51:03.577761 I  TV: Main UI disabled.
2012-04-10 10:51:03.578327 I  TV: Entering main playback loop.
2012-04-10 10:51:03.619748 E  SG(Default): Unable to find any Storage Group Directories.  Using hardcoded default value of '/mnt/store'
2012-04-10 10:51:03.625924 I  Using protocol version 72
2012-04-10 10:51:03.627204 I  Using protocol version 72
Running DIL (3.22.0) Version
DtsDeviceOpen: Opening HW in mode 0
Scaling command param 0x0,ctx_scal:0x0
2012-04-10 10:51:05.488169 I  CrystalHD: Device: BCM70015
2012-04-10 10:51:05.488201 I  CrystalHD: Library : 22.0.5635
2012-04-10 10:51:05.488215 I  CrystalHD: Driver  : 10.0.3204448419
2012-04-10 10:51:05.488227 I  CrystalHD: Firmware: 60.39.3036836803
2012-04-10 10:51:05.780992 I  VideoOutputXv: XVideo Adaptor Name: 'Intel(R) Textured Video'
2012-04-10 10:51:05.864864 I  OSD: Base theme size: 1280x720
2012-04-10 10:51:05.864893 I  OSD: Scaling factors: 1x1
2012-04-10 10:51:05.913782 I  AFD: Opened codec 0xffffffffaf469e50, id(H264) type(Video)
2012-04-10 10:51:05.913800 I  AFD: codec AC3 has 6 channels
2012-04-10 10:51:05.914280 I  AFD: Opened codec 0xffffffffa8168550, id(AC3) type(Audio)
2012-04-10 10:51:05.976530 I  AO: Opening audio device 'hw:CARD=Intel,DEV=0' ch 2(6) sr 48000 sf signed 32 bit reenc 0
2012-04-10 10:51:05.991815 E  ALSA: no playback control PCM found on mixer device default
2012-04-10 10:51:05.991831 E  ALSA: Unable to open audio mixer. Volume control disabled
2012-04-10 10:51:06.045470 N  AFD: Resetting byte context eof (livetv 1 was eof 0)
2012-04-10 10:51:06.372198 N  Player(0): Waited 105ms for video buffers AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAP
2012-04-10 10:51:06.419689 I  CrystalHD: Decoder reported format change.
2012-04-10 10:51:06.488721 N  Player(0): Waited 221ms for video buffers UUUAAAAAAAAAAAAAAAAAAAAAAAAAAAAP
2012-04-10 10:51:06.587365 I  OSD: Base theme size: 1280x720
2012-04-10 10:51:06.587412 I  OSD: Scaling factors: 1x1
2012-04-10 10:51:06.662554 I  VideoOutput: Created YV12 OSD.

(TV plays fine at this point in HD)
...
..
(switching to any other channel)
...
2012-04-10 10:51:44.903092 E  MythSocket(8d16cd0:49): readStringList: Error, timed out after 7000 ms.
2012-04-10 10:51:44.903147 E  RemoteEncoder::SendReceiveStringList(): No response.
2012-04-10 10:51:44.911317 E  LiveTVChain(live-w-2012-04-10T10:51:02): SwitchTo() not switching to current
2012-04-10 10:51:44.920468 E  Player(0): Unknown recorder error, exiting decoder
2012-04-10 10:51:44.951521 I  TV: Attempting to change from WatchingLiveTV to None
2012-04-10 10:51:45.206999 I  Pulse: PulseAudio resume OK
2012-04-10 10:51:45.207757 I  MythCoreContext: Connecting to backend server: 192.168.2.24:6543 (try 1 of 1)
2012-04-10 10:51:45.209075 I  Using protocol version 72
2012-04-10 10:51:52.210917 E  MythSocket(92e42a8:49): readStringList: Error, timed out after 7000 ms.
2012-04-10 10:51:52.210976 E  RemoteEncoder::SendReceiveStringList(): No response.
2012-04-10 10:51:52.211031 I  TV: Changing from WatchingLiveTV to None
2012-04-10 10:51:52.211094 I  MythCoreContext: Connecting to backend server: 192.168.2.24:6543 (try 1 of 1)
2012-04-10 10:51:52.212366 I  Using protocol version 72
2012-04-10 10:51:52.213213 I  TV: Exiting main playback loop.
2012-04-10 10:51:52.229322 I  TV: Attempting to change from None to WatchingLiveTV
2012-04-10 10:51:52.229356 I  MythCoreContext: Connecting to backend server: 192.168.2.24:6543 (try 1 of 1)
2012-04-10 10:51:52.230331 I  Using protocol version 72
2012-04-10 10:51:52.240500 N  TV: Spawning LiveTV Recorder -- begin
2012-04-10 10:51:59.242367 E  MythSocket(ffffffffa5354e08:49): readStringList: Error, timed out after 7000 ms.
2012-04-10 10:51:59.242447 E  RemoteEncoder::SendReceiveStringList(): No response.
2012-04-10 10:51:59.242484 N  TV: Spawning LiveTV Recorder -- end
2012-04-10 10:51:59.243712 E  GetEntryAt(-1) failed.
2012-04-10 10:51:59.243742 E  It appears that your backend may be misconfigured.  Check your backend logs to determine whether your capture cards, lineups, channels, or storage configuration are reporting errors.  This issue is commonly caused by failing to complete all setup steps properly.  You may wish to review the documentation for mythtv-setup.
2012-04-10 10:51:59.243854 E  EntryToProgram(0@Wed Dec 31 16:00:00 1969) failed to get pginfo
2012-04-10 10:51:59.243877 E  TV: HandleStateChange(): LiveTV not successfully started
2012-04-10 10:51:59.243941 E  TV: Invalid Remote Encoder
2012-04-10 10:51:59.243954 E  TV: LiveTV not successfully started
2012-04-10 10:51:59.244034 I  TV: Main UI disabled.
2012-04-10 10:51:59.244048 I  TV: Entering main playback loop.
2012-04-10 10:51:59.247061 I  TV: Exiting main playback loop.
DtsAllocIoctlData Error
2012-04-10 10:51:59.432875 N  Suspending idle timer

I'm running Ubuntu 11.10 for both front-end and backend systems connected via gigabit network.

uname -a Linux w 3.0.0-17-generic-pae #30-Ubuntu SMP Thu Mar 8 17:53:35 UTC 2012 i686 i686 i386 GNU/Linux

[danielk]

For the crash we need a backtrace. For the underlying problem we will need three things matching frontend and backend logs, and a backtrace of the backend. The frontend at "-v playback" and the backend at "-v record,channel" to grab the backtrace for the backend you need to attach to the running process "sudo gdb which mythbackend pidof mythbackend" and then grab the backtrace normally.

[iwelcomespam@…]

frontend with playback option

[iwelcomespam@…]

backend with record and channel options

[iwelcomespam@…]

backtrace of backend

[iwelcomespam@…]

There is no crash of the backend rather a loss of connection from the FE to the BE. HD playback at 720 or 1080 is fine with crystaldhd decoder, but when I change channels that's when the connection is lost between the two.

Even if I disable crystalhd and use just use 'Standard' decoder with xv-bit player I still have same issues when changing channels.

On the same FE and BE if I revert back to 0.24/fixes channel changing is no problem.

[iwelcomespam@…]

I am using IPTV tuners. I did a test and used another system that doesn't use crystalhd but the basic ffmpeg decoder and similar issue. Unable to change channels.

I'm wondering if IPTV Network tuner Is completely broken in 0.25. I saw this unresolved bug that shows many of the symptoms I'm experiencing

​http://code.mythtv.org/trac/ticket/9670

[chemobejk@…]

According to #10493 IPTV is completely busted in 0.25. IMHO this bug should be closed as dup of #10493.

[iwelcomespam@…]

Wow!! Myth 0.25 went final with IPTV completely broken? Are not that many users on IPTV? How do I pull in that UDP/RTP branch that bug #10493 talks about?

[Kenni Lund [kenni a kelu dot dk]]

Please seek help on the mythtv-users mailing list, this is a bug tracker, not a discussion forum.

[sphery]

Seems to be a duplicate of #10493 and/or #9670