[mythtv-users] Mythfrontend QUERY_RECORDINGS timeout - hangs frontend

Wed Sep 19 03:49:33 UTC 2007

I need some help here...

My backend is running KnoppMyth R5F27 and my XBOX frontend is running
0.20.20070821-1.  The problem started as soon as I upgraded everything from
0.19 due to the SD changes.

When I'm viewing my list of recorded programs and the program list is
updated by the backend, the frontend makes a 'QUERY_RECORDINGS Play' request
which times out, disconnects, generates errors, and ultimately hangs the
frontend.

I attached some verbose logging to demonstrate the problem.  Any advice on
how to proceed would be greatly appreciated - I'm kind of stuck at this
point.

2007-09-18 22:59:52.535 write -> 14 17      QUERY_ISRECORDING
2007-09-18 22:59:52.536 read  <- 14 1       1
2007-09-18 22:59:57.535 write -> 14 17      QUERY_ISRECORDING
2007-09-18 22:59:57.542 read  <- 14 1       1
2007-09-18 23:00:00.545 MythSocket(8268798:13): socket is readable
2007-09-18 23:00:00.545 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:00:00.546 read  <- 13 51
BACKEND_MESSAGE[]:[]DONE_RECORDING 1 3594[]:[]empty
2007-09-18 23:00:00.874 MythSocket(8268798:13): socket is readable
2007-09-18 23:00:00.875 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:00:00.875 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:00:01.911 MSqlQuery: SELECT recgroup, password FROM
recgrouppassword WHERE password is not null AND password <> '' ;
2007-09-18 23:00:01.912 write -> 14 21      QUERY_RECORDINGS Play
2007-09-18 23:00:02.790 MythSocket(8268798:13): socket is readable
2007-09-18 23:00:02.791 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:00:02.791 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:00:03.561 read  <- 14 90750   164[]:[]Family Guy[]:[]Mind Over
Murder[]:[]Peter is under house arrest after punching a pregnant woman he
thought was a ...
2007-09-18 23:00:03.733 write -> 14 17      QUERY_ISRECORDING
2007-09-18 23:00:03.741 read  <- 14 1       0
2007-09-18 23:00:03.836 MSqlQuery: SELECT icon FROM channel WHERE chanid =
'1004' ;
2007-09-18 23:00:03.860 write -> 14 601
QUERY_PIXMAP_LASTMODIFIED[]:[]Law & Order: Special Victims
Unit[]:[]Screwed[]:[]A man (Chris "Ludacris" Bridges) connected to ...
2007-09-18 23:00:03.892 read  <- 14 24      Tue Sep 18 22:07:49 2007
2007-09-18 23:00:04.780 MSqlQuery: SELECT recgroup, password FROM
recgrouppassword WHERE password is not null AND password <> '' ;
2007-09-18 23:00:04.781 write -> 14 21      QUERY_RECORDINGS Play
2007-09-18 23:00:05.019 MythSocket(8268798:13): socket is readable
2007-09-18 23:00:05.019 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:00:05.020 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:00:05.587 MythSocket(8268798:13): socket is readable
2007-09-18 23:00:05.588 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:00:05.588 read  <- 13 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2007-09-18 23:00:06.761 read  <- 14 91764   166[]:[]Family Guy[]:[]Mind Over
Murder[]:[]Peter is under house arrest after punching a pregnant woman he
thought was a ...
2007-09-18 23:00:07.023 MSqlQuery: SELECT icon FROM channel WHERE chanid =
'1004' ;
2007-09-18 23:00:07.047 write -> 14 601
QUERY_PIXMAP_LASTMODIFIED[]:[]Law & Order: Special Victims
Unit[]:[]Screwed[]:[]A man (Chris "Ludacris" Bridges) connected to ...
2007-09-18 23:00:07.064 read  <- 14 24      Tue Sep 18 22:07:49 2007
2007-09-18 23:00:07.535 write -> 14 17      QUERY_ISRECORDING
2007-09-18 23:00:07.548 read  <- 14 1       2
2007-09-18 23:00:07.962 MSqlQuery: SELECT recgroup, password FROM
recgrouppassword WHERE password is not null AND password <> '' ;
2007-09-18 23:00:07.962 write -> 14 21      QUERY_RECORDINGS Play
2007-09-18 23:00:37.965 MythSocket(8255ad0:14): readStringList: Error,
timeout.
2007-09-18 23:00:37.965 MythSocket(8255ad0:14): state change Connected ->
Idle
2007-09-18 23:00:37.966 Connection to backend server lost
2007-09-18 23:00:37.966 MythSocket(8255ad0:-1): DownRef: -1
2007-09-18 23:00:37.966 MythSocket(8255ad0:-1): delete socket
2007-09-18 23:00:37.966 Connecting to backend server: 10.10.10.18:6543 (try
1 of 5)
2007-09-18 23:00:37.967 MythSocket(856dac8:14): new socket
2007-09-18 23:00:37.967 MythSocket(856dac8:14): attempting connect() to (
10.10.10.18:6543)
2007-09-18 23:00:37.968 MythSocket(856dac8:14): state change Idle ->
Connected
2007-09-18 23:00:37.968 write -> 14 21      MYTH_PROTO_VERSION 31
2007-09-18 23:00:37.974 read  <- 14 13      ACCEPT[]:[]31
2007-09-18 23:00:37.974 Using protocol version 31
2007-09-18 23:00:37.974 write -> 14 31      ANN Monitor myth2.jjoshua.com 0
2007-09-18 23:00:37.980 read  <- 14 2       OK
2007-09-18 23:00:37.980 MythSocket(856dac8:14): writeStringList: Error,
invalid string list.
2007-09-18 23:01:03.624 MythSocket(8268798:13): socket is readable
2007-09-18 23:01:03.624 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:01:03.625 read  <- 13 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
2007-09-18 23:01:07.985 MythSocket(856dac8:14): readStringList: Error,
timeout.
2007-09-18 23:01:07.985 MythSocket(856dac8:14): state change Connected ->
Idle
2007-09-18 23:01:07.986 MythSocket(856dac8:-1): DownRef: -1
2007-09-18 23:01:07.986 MythSocket(856dac8:-1): delete socket
2007-09-18 23:01:07.986 Reconnection to backend server failed
2007-09-18 23:01:08.081 MSqlQuery: SELECT data FROM settings WHERE value =
'PopupHeightPadding' AND hostname = 'myth2.jjoshua.com' ;
2007-09-18 23:01:08.084 MSqlQuery: SELECT data FROM settings WHERE value =
'PopupHeightPadding' AND hostname IS NULL;
2007-09-18 23:01:08.086 MSqlQuery: SELECT data FROM settings WHERE value =
'PopupWidthPadding' AND hostname = 'myth2.jjoshua.com' ;
2007-09-18 23:01:08.089 MSqlQuery: SELECT data FROM settings WHERE value =
'PopupWidthPadding' AND hostname IS NULL;
2007-09-18 23:04:51.358 MythSocket(8268798:13): socket is readable
2007-09-18 23:04:51.358 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:04:51.359 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:04:51.903 MythSocket(8268798:13): socket is readable
2007-09-18 23:04:51.904 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:04:51.904 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:05:24.048 MythSocket(8268798:13): socket is readable
2007-09-18 23:05:24.049 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:05:24.049 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:05:24.084 MythSocket(8268798:13): socket is readable
2007-09-18 23:05:24.084 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:05:24.085 read  <- 13 69
BACKEND_MESSAGE[]:[]COMMFLAG_START 1044 2007-09-18T21:00:00[]:[]empty
2007-09-18 23:30:00.901 MythSocket(8268798:13): socket is readable
2007-09-18 23:30:00.902 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:30:00.902 read  <- 13 51
BACKEND_MESSAGE[]:[]DONE_RECORDING 2 1795[]:[]empty
2007-09-18 23:30:01.231 MythSocket(8268798:13): socket is readable
2007-09-18 23:30:01.232 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:30:01.232 read  <- 13 51
BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2007-09-18 23:30:53.474 MythSocket(8268798:13): socket is readable
2007-09-18 23:30:53.474 MythSocket(8268798:13): cb->readyRead()
2007-09-18 23:30:53.475 read  <- 13 45
BACKEND_MESSAGE[]:[]SCHEDULE_CHANGE[]:[]empty
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mythtv.org/pipermail/mythtv-users/attachments/20070918/11775702/attachment.htm 