[mythtv-users] Mythfilldatabase fails to reschedule for id -1

Chuck Filson mythtv at goodeid.com
Sat Sep 6 00:26:19 UTC 2008


 	I am running Mythtv with Schedules Direct as a program source. Recently I
 noticed that even when the "Listing Status" showed that Mythfilldatabase
 had run successfully and I had 14 days of data available, "Upcoming
 Recordings" showed nothing scheduled for the last day or two of the
 listings. Also there were a few recordings made for programs that I had
 never selected.

 	Since I was running the release version of 0.21, I pulled the latest
 version ( 18188 at the time ) from svn fixes, compiled and installed.

 chuck at skiffia ~]$ mythbackend --version
 Please include all output in bug reports.
 MythTV Version   : 18188
 MythTV Branch    : branches/release-0-21-fixes
 Library API      : 0.21.20080304-1
 Network Protocol : 40
 Options compiled in:
  linux release using_oss using_alsa using_arts using_jack using_backend
 using_frontend using_hdhomerun using_ivtv using_lirc using_v4l using_x11
 using_xrandr using_xv using_xvmc using_xvmcw using_xvmc_vld
 using_bindings_perl using_bindings_python using_opengl using_ffmpeg_threads

 	This update has not changed the situation at all.

	Both an automatic mfdb run and a manual run produce the following errors when 
an attempt is made to contact the backend for rescheduling.

===============================================================
| Attempting to contact the master backend for rescheduling.  |
| If the master is not running, rescheduling will happen when |
| the master backend is restarted.                            |
===============================================================
2008-09-03 15:49:59.998 MSqlQuery: SELECT data FROM settings WHERE value 
= 'MasterServerIP' AND hostname = 'skiffia.goodeid.com' ;
2008-09-03 15:49:59.998 MSqlQuery: SELECT data FROM settings WHERE value 
= 'MasterServerIP' AND hostname IS NULL;
2008-09-03 15:49:59.998 MSqlQuery: SELECT data FROM settings WHERE value 
= 'MasterServerPort' AND hostname = 'skiffia.goodeid.com' ;
2008-09-03 15:49:59.999 MSqlQuery: SELECT data FROM settings WHERE value 
= 'MasterServerPort' AND hostname IS NULL;
2008-09-03 15:49:59.999 MythSocket(818c3a8:15): new socket
2008-09-03 15:50:00.000 MSqlQuery: SELECT data FROM settings WHERE value 
= 'WOLbackendReconnectWaitTime' AND hostname = 'skiffia.goodeid.com' ;
2008-09-03 15:50:00.000 MSqlQuery: SELECT data FROM settings WHERE value 
= 'WOLbackendReconnectWaitTime' AND hostname IS NULL;
2008-09-03 15:50:00.000 MSqlQuery: SELECT data FROM settings WHERE value 
= 'WOLbackendConnectRetry' AND hostname = 'skiffia.goodeid.com' ;
2008-09-03 15:50:00.001 MSqlQuery: SELECT data FROM settings WHERE value 
= 'WOLbackendConnectRetry' AND hostname IS NULL;
2008-09-03 15:50:00.001 Connecting to backend server: 192.168.0.5:6543 (try 1 
of 5)
2008-09-03 15:50:00.001 MythSocket(820c2b0:16): new socket
2008-09-03 15:50:00.001 MythSocket(820c2b0:16): attempting connect() to 
(192.168.0.5:6543)
2008-09-03 15:50:00.001 MythSocket(820c2b0:16): state change Idle -> Connected
2008-09-03 15:50:00.002 write -> 16 21      MYTH_PROTO_VERSION 40
2008-09-03 15:50:00.002 read  <- 16 13      ACCEPT[]:[]40
2008-09-03 15:50:00.002 Using protocol version 40
2008-09-03 15:50:00.003 write -> 16 33      ANN Monitor skiffia.goodeid.com 0
2008-09-03 15:50:07.006 MythSocket(820c2b0:16): readStringList: Error, timeout 
(quick).
2008-09-03 15:50:07.006 MythSocket(820c2b0:16): state change Connected -> Idle
2008-09-03 15:50:07.006 MythSocket(818c3a8:15): attempting connect() to 
(192.168.0.5:6543)
2008-09-03 15:50:07.006 MythSocket(818c3a8:15): state change Idle -> Connected
2008-09-03 15:50:07.006 write -> 15 33      ANN Monitor skiffia.goodeid.com 1
2008-09-03 15:50:26.088 read  <- 15 2       OK
2008-09-03 15:50:26.089 MythSocket(818c3a8:15): UpRef: 1
2008-09-03 15:50:26.089 MythSocket(820c2b0:-1): writeStringList: Error, called 
with unconnected socket.
2008-09-03 15:50:26.089 MythSocket(820c2b0:-1): readStringList: Error, called 
with unconnected socket.
2008-09-03 15:50:26.089 Connection to backend server lost
2008-09-03 15:50:26.089 MythSocket(820c2b0:-1): DownRef: -1
2008-09-03 15:50:26.089 MythSocket(820c2b0:-1): delete socket
2008-09-03 15:50:26.089 MythSocket: readyread thread start
2008-09-03 15:50:26.089 Connecting to backend server: 192.168.0.5:6543 (try 1 
of 5)
2008-09-03 15:50:26.089 MythSocket(b4400520:18): new socket
2008-09-03 15:50:26.089 MythSocket(b4400520:18): attempting connect() to 
(192.168.0.5:6543)
2008-09-03 15:50:26.090 MythSocket(b4400520:18): state change Idle -> 
Connected
2008-09-03 15:50:26.090 write -> 18 21      MYTH_PROTO_VERSION 40
2008-09-03 15:50:26.090 read  <- 18 13      ACCEPT[]:[]40
2008-09-03 15:50:26.090 Using protocol version 40
2008-09-03 15:50:26.090 write -> 18 33      ANN Monitor skiffia.goodeid.com 0
2008-09-03 15:50:26.107 read  <- 18 2       OK
2008-09-03 15:50:26.107 MythSocket(b4400520:18): writeStringList: Error, 
invalid string list.
2008-09-03 15:50:56.113 MythSocket(b4400520:18): readStringList: Error, 
timeout.
2008-09-03 15:50:56.113 MythSocket(b4400520:18): state change Connected -> 
Idle
2008-09-03 15:50:56.113 MythSocket(b4400520:-1): DownRef: -1
2008-09-03 15:50:56.114 MythSocket(b4400520:-1): delete socket
2008-09-03 15:50:56.114 Reconnection to backend server failed
2008-09-03 15:50:56.114 Error rescheduling id -1 in 
ScheduledRecording::signalChange
2008-09-03 15:50:56.114 Connecting to backend server: 192.168.0.5:6543 (try 1 
of 5)
2008-09-03 15:50:56.114 MythSocket(b4400590:18): new socket
2008-09-03 15:50:56.114 MythSocket(b4400590:18): attempting connect() to 
(192.168.0.5:6543)
2008-09-03 15:50:56.114 MythSocket(b4400590:18): state change Idle -> 
Connected
2008-09-03 15:50:56.114 write -> 18 21      MYTH_PROTO_VERSION 40
2008-09-03 15:50:56.114 read  <- 18 13      ACCEPT[]:[]40
2008-09-03 15:50:56.115 Using protocol version 40
2008-09-03 15:50:56.115 write -> 18 33      ANN Monitor skiffia.goodeid.com 0
2008-09-03 15:50:56.117 read  <- 18 2       OK
2008-09-03 15:50:56.117 write -> 18 32      MESSAGE[]:[]CLEAR_SETTINGS_CACHE
2008-09-03 15:50:56.118 MythSocket(818c3a8:15): socket is readable
2008-09-03 15:50:56.118 read  <- 18 2       OK
2008-09-03 15:50:56.118 MythSocket(818c3a8:15): cb->readyRead()
2008-09-03 15:50:56.118 MythSocket(b4400590:18): DownRef: -1
2008-09-03 15:50:56.118 read  <- 15 50      BACKEND_MESSAGE[]:
[]CLEAR_SETTINGS_CACHE[]:[]empty
2008-09-03 15:50:56.118 MythSocket(b4400590:18): state change Connected -> 
Idle
2008-09-03 15:50:56.118 Received a remote 'Clear Cache' request
2008-09-03 15:50:56.118 Clearing Settings Cache.
2008-09-03 15:50:56.118 MythSocket(b4400590:-1): delete socket
2008-09-03 15:50:56.118 MythSocket(818c3a8:15): DownRef: 0
2008-09-03 15:50:56.118 MythSocket(818c3a8:15): DownRef: -1
2008-09-03 15:50:56.118 MythSocket(818c3a8:15): state change Connected -> Idle
2008-09-03 15:50:56.118 MythSocket(818c3a8:-1): delete socket
2008-09-03 15:50:56.119 mythfilldatabase run complete.
2008-09-03 15:50:56.119 DataDirect: Deleting temporary files
2008-09-03 15:50:56.141 MythSocket: readyread thread exit

	The backend and sql server are the same machine and it appears that the 
initial connection to determine protocol version succeeds, but the connection 
for rescheduling for id -1 fails. Until this reschedule is done manually the 
new data downloaded is not processed and available in the scheduled 
recordings.

	Any ideas of where the problem may be or where to start looking ?

Chuck Filson


More information about the mythtv-users mailing list