[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