[mythtv-commits] Ticket #10574: Error, timed out after 7000 ms. Unable to change channels in 0.25

MythTV noreply at mythtv.org
Tue Apr 10 17:59:17 UTC 2012


#10574: Error, timed out after 7000 ms. Unable to change channels in 0.25
----------------------------+--------------------------------------------
 Reporter:  iwelcomespam@…  |           Type:  Bug Report - Hang/Deadlock
   Status:  new             |       Priority:  major
Milestone:  0.25.1          |      Component:  MythTV - General
  Version:  0.25-fixes      |       Severity:  high
 Keywords:                  |  Ticket locked:  0
----------------------------+--------------------------------------------
 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 at 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

-- 
Ticket URL: <http://code.mythtv.org/trac/ticket/10574>
MythTV <http://code.mythtv.org/trac>
MythTV Media Center


More information about the mythtv-commits mailing list