[mythtv] backend dying while mythweb is creating previews for
recorded programs
Jim Westfall
jwestfall at surrealistic.net
Thu Feb 24 02:46:19 UTC 2005
I found some additional information on my test x86 backend box. It
appears that connectionClosed() signal is not always getting triggered
when a client disconnects. There ends up being dead sockets in
playbackList and fileTransferList.
attached is a patch that adds additional logging to the backend that shows
the issue along with a sample log.
jim
Risto Treksler <risto at elkhornbanff.ca> wrote [02.23.05]:
> For what it's worth
>
> http://www.gossamer-threads.com/lists/mythtv/users/92985?search_string=waiting%20for%20a%20thread;#92985
> http://www.gossamer-threads.com/lists/mythtv/users/53694?search_string=waiting%20for%20a%20thread;#53694
> http://www.gossamer-threads.com/lists/mythtv/users/88540?search_string=0%20retries%20remaining.;#88540
>
> seem to be related but
> don't point to a solution
>
> it's weird though since i never saw this b4 0.17
>
> rt
>
> On Tuesday 22 February 2005 09:55 am, Risto Treksler wrote:
> > Hi,
> >
> > Has the code for static preview generation changed since .16
> > to make it happen in the background?
> >
> > I see '(0 retries remaining)' in the logs for remote filetransfers
> > How can I change that, so that it tries again?
> >
> >
> > Here's what's happening:
> >
> > i start by clearing out the png files
> > #rm -f /mnt/store/*.png /var/www/html/mythweb/image_cache/*.png
> >
> > then i go to the recorded_programs.php page in firefox and
> > when the backend is busy with commflagging or recording,
> > only a few preview images are shown
> >
> > sometimes the backend seems to crash,
> > but upon further investigation it doesn't really segfault
> > but just exits gracefully right after a
> > 2005-02-22 00:00:16.986 Unknown file transfer socket: 18
> > or similar, in the log
> >
> > other times it gets stuck with tons of
> > "waiting for a thread" messages
> > see preview-2.log
> > i <ctrl-c>-ed the backend and got preview-4.bt
> >
> > most of the time the files are actually created in /mnt/store
> > but they just don't get copied over to image_cache
> > so hitting reload copies them over
> >
> > i have toyed with the idea of adding a timeout to let the file creation
> > complete before trying to copy the png over but no luck so far
> >
> > i have added some debug statements to see what's going on
> > preview-4.diff produces preview-4.html.txt
> > and
> > preview-7.diff produces preview-7.html.txt
> > (with the backend running inside a while loop)
> >
> > i am stumped
> >
> > :(
> >
> > --
> > Risto Treksler
> > Elkhorn Lodge
> > Banff, Alberta, Canada
>
> --
> Risto Treksler
> Elkhorn Lodge
> Banff, Alberta, Canada
> _______________________________________________
> mythtv-dev mailing list
> mythtv-dev at mythtv.org
> http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-dev
-------------- next part --------------
Index: programs/mythbackend/mainserver.cpp
===================================================================
RCS file: /var/lib/mythcvs/mythtv/programs/mythbackend/mainserver.cpp,v
retrieving revision 1.179
diff -u -r1.179 mainserver.cpp
--- programs/mythbackend/mainserver.cpp 23 Feb 2005 05:04:36 -0000 1.179
+++ programs/mythbackend/mainserver.cpp 24 Feb 2005 02:39:08 -0000
@@ -146,6 +146,7 @@
void MainServer::newConnection(RefSocket *socket)
{
+ VERBOSE(VB_ALL,"newConnection was called");
connect(socket, SIGNAL(readyRead()), this, SLOT(readSocket()));
}
@@ -196,6 +197,9 @@
line = line.simplifyWhiteSpace();
QStringList tokens = QStringList::split(" ", line);
QString command = tokens[0];
+
+ VERBOSE(VB_ALL,QString("playbackList size: %1").arg(playbackList.size()));
+ VERBOSE(VB_ALL,QString("fileTransferList size: %1").arg(fileTransferList.size()));
//cerr << "command='" << command << "'\n";
if (command == "MYTH_PROTO_VERSION")
{
@@ -561,6 +565,7 @@
VERBOSE(VB_ALL, QString("adding: %1 as a client (events: %2)")
.arg(commands[2]).arg(wantevents));
PlaybackSock *pbs = new PlaybackSock(socket, commands[2], wantevents);
+ VERBOSE(VB_ALL,"Added new playbackList item");
playbackList.push_back(pbs);
}
else if (commands[1] == "SlaveBackend")
@@ -679,6 +684,7 @@
FileTransfer *ft = new FileTransfer(filename, socket);
fileTransferList.push_back(ft);
+ VERBOSE(VB_ALL,"Added new fileTransferList item");
retlist << QString::number(socket->socket());
encodeLongLong(retlist, ft->GetFileSize());
@@ -2748,6 +2754,7 @@
void MainServer::endConnection(RefSocket *socket)
{
+ VERBOSE(VB_ALL,"endConnection was called");
vector<PlaybackSock *>::iterator it = playbackList.begin();
for (; it != playbackList.end(); ++it)
{
@@ -2776,6 +2783,7 @@
}
delete (*it);
playbackList.erase(it);
+ VERBOSE(VB_ALL,"removed item from playbackList");
return;
}
}
@@ -2789,6 +2797,7 @@
socket->DownRef();
delete (*ft);
fileTransferList.erase(ft);
+ VERBOSE(VB_ALL,"removed item from fileTransferList");
return;
}
}
-------------- next part --------------
2005-02-23 18:34:40.760 New DB connection, total: 1
Starting up as the master server.
2005-02-23 18:34:41.015 New DB connection, total: 2
rom1394_1 warning: read failed: 0x0000fffff0000414
rom1394_1 error: invalid root directory length
2005-02-23 18:34:42.116 ret_pid(0) child(18453) status(0x0)
2005-02-23 18:34:42.882 ret_pid(18453) child(18453) status(0x0)
2005-02-23 18:34:42.886 External Tuning program exited with no error
2005-02-23 18:34:42.923 New DB scheduler connection
2005-02-23 18:34:42.973 New DB connection, total: 3
2005-02-23 18:34:42.991 mythbackend version: 0.17.20050223-1 www.mythtv.org
2005-02-23 18:34:42.998 Enabled verbose msgs : important general
2005-02-23 18:34:43.012 New DB connection, total: 4
2005-02-23 18:34:45.040 Reschedule requested for id -1.
2005-02-23 18:34:45.421 Scheduled 0 items in 0.4 = 0.30 match + 0.07 place
2005-02-23 18:34:45.449 Seem to be woken up by USER
2005-02-23 18:34:48.639 newConnection was called
2005-02-23 18:34:48.673 playbackList size: 0
2005-02-23 18:34:48.680 fileTransferList size: 0
2005-02-23 18:34:48.710 playbackList size: 0
2005-02-23 18:34:48.716 fileTransferList size: 0
2005-02-23 18:34:48.723 MainServer::HandleAnnounce Playback
2005-02-23 18:34:48.731 adding: mini as a client (events: 0)
2005-02-23 18:34:48.738 Added new playbackList item
2005-02-23 18:34:48.776 playbackList size: 1
2005-02-23 18:34:48.782 fileTransferList size: 0
2005-02-23 18:34:48.810 playbackList size: 1
2005-02-23 18:34:48.816 fileTransferList size: 0
2005-02-23 18:34:48.950 playbackList size: 1
2005-02-23 18:34:48.956 fileTransferList size: 0
2005-02-23 18:34:49.073 endConnection was called
2005-02-23 18:34:49.081 removed item from playbackList
2005-02-23 18:35:00.302 newConnection was called
2005-02-23 18:35:00.314 playbackList size: 0
2005-02-23 18:35:00.320 fileTransferList size: 0
2005-02-23 18:35:00.341 playbackList size: 0
2005-02-23 18:35:00.347 fileTransferList size: 0
2005-02-23 18:35:00.353 MainServer::HandleAnnounce Playback
2005-02-23 18:35:00.360 adding: mini as a client (events: 0)
2005-02-23 18:35:00.367 Added new playbackList item
2005-02-23 18:35:00.405 playbackList size: 1
2005-02-23 18:35:00.411 fileTransferList size: 0
2005-02-23 18:35:00.437 playbackList size: 1
2005-02-23 18:35:00.443 fileTransferList size: 0
2005-02-23 18:35:00.537 newConnection was called
2005-02-23 18:35:00.548 playbackList size: 1
2005-02-23 18:35:00.557 fileTransferList size: 0
2005-02-23 18:35:00.564 MainServer::HandleAnnounce FileTransfer
2005-02-23 18:35:00.571 adding: mini as a remote file transfer
2005-02-23 18:35:00.605 Added new fileTransferList item
2005-02-23 18:35:00.631 playbackList size: 1
2005-02-23 18:35:00.637 fileTransferList size: 1
2005-02-23 18:35:00.643 MainServer::HandleAnnounce Playback
2005-02-23 18:35:00.650 adding: mini as a client (events: 0)
2005-02-23 18:35:00.697 Added new playbackList item
2005-02-23 18:35:00.718 playbackList size: 2
2005-02-23 18:35:00.724 fileTransferList size: 1
2005-02-23 18:35:00.758 playbackList size: 2
2005-02-23 18:35:00.764 fileTransferList size: 1
2005-02-23 18:35:04.800 newConnection was called
2005-02-23 18:35:04.812 playbackList size: 2
2005-02-23 18:35:04.817 fileTransferList size: 1
2005-02-23 18:35:04.823 MainServer::HandleAnnounce FileTransfer
2005-02-23 18:35:04.830 adding: mini as a remote file transfer
2005-02-23 18:35:04.844 Invalid file handle when opening /mnt/store//1004_20050222185800_20050222191000.nuv.png. 0 retries remaining.
2005-02-23 18:35:05.357 Added new fileTransferList item
2005-02-23 18:35:05.382 playbackList size: 2
2005-02-23 18:35:05.388 fileTransferList size: 2
2005-02-23 18:35:05.394 MainServer::HandleAnnounce Playback
2005-02-23 18:35:05.401 adding: mini as a client (events: 0)
2005-02-23 18:35:05.407 Added new playbackList item
2005-02-23 18:35:05.428 playbackList size: 3
2005-02-23 18:35:05.434 fileTransferList size: 2
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
2005-02-23 18:35:09.598 playbackList size: 3
2005-02-23 18:35:09.603 fileTransferList size: 2
2005-02-23 18:35:13.630 playbackList size: 3
2005-02-23 18:35:13.635 fileTransferList size: 2
2005-02-23 18:35:13.744 endConnection was called
2005-02-23 18:35:13.748 removed item from playbackList
2005-02-23 18:35:19.864 newConnection was called
2005-02-23 18:35:19.877 playbackList size: 2
2005-02-23 18:35:19.883 fileTransferList size: 2
2005-02-23 18:35:19.903 playbackList size: 2
2005-02-23 18:35:19.909 fileTransferList size: 2
2005-02-23 18:35:19.915 MainServer::HandleAnnounce Playback
2005-02-23 18:35:19.921 adding: mini as a client (events: 0)
2005-02-23 18:35:19.926 Added new playbackList item
2005-02-23 18:35:19.965 playbackList size: 3
2005-02-23 18:35:19.971 fileTransferList size: 2
2005-02-23 18:35:19.997 playbackList size: 3
2005-02-23 18:35:20.002 fileTransferList size: 2
2005-02-23 18:35:20.103 newConnection was called
2005-02-23 18:35:20.115 playbackList size: 3
2005-02-23 18:35:20.121 fileTransferList size: 2
2005-02-23 18:35:20.127 MainServer::HandleAnnounce FileTransfer
2005-02-23 18:35:20.133 adding: mini as a remote file transfer
2005-02-23 18:35:20.146 Added new fileTransferList item
2005-02-23 18:35:20.167 playbackList size: 3
2005-02-23 18:35:20.173 fileTransferList size: 3
2005-02-23 18:35:20.179 MainServer::HandleAnnounce Playback
2005-02-23 18:35:20.185 adding: mini as a client (events: 0)
2005-02-23 18:35:20.191 Added new playbackList item
2005-02-23 18:35:20.211 playbackList size: 4
2005-02-23 18:35:20.217 fileTransferList size: 3
2005-02-23 18:35:20.244 playbackList size: 4
2005-02-23 18:35:20.250 fileTransferList size: 3
2005-02-23 18:35:24.287 newConnection was called
2005-02-23 18:35:24.298 playbackList size: 4
2005-02-23 18:35:24.304 fileTransferList size: 3
2005-02-23 18:35:24.309 MainServer::HandleAnnounce FileTransfer
2005-02-23 18:35:24.315 adding: mini as a remote file transfer
2005-02-23 18:35:24.328 Invalid file handle when opening /mnt/store//1004_20050222185800_20050222191000.nuv.png. 0 retries remaining.
2005-02-23 18:35:24.839 Added new fileTransferList item
2005-02-23 18:35:24.860 playbackList size: 4
2005-02-23 18:35:24.866 fileTransferList size: 4
2005-02-23 18:35:24.872 MainServer::HandleAnnounce Playback
2005-02-23 18:35:24.878 adding: mini as a client (events: 0)
2005-02-23 18:35:24.884 Added new playbackList item
2005-02-23 18:35:24.905 playbackList size: 5
2005-02-23 18:35:24.910 fileTransferList size: 4
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
ERROR: file I/O problem in 'safe_read()': Bad file descriptor
2005-02-23 18:35:29.071 playbackList size: 5
2005-02-23 18:35:29.076 fileTransferList size: 4
2005-02-23 18:35:33.105 playbackList size: 5
2005-02-23 18:35:33.110 fileTransferList size: 4
2005-02-23 18:35:33.220 endConnection was called
2005-02-23 18:35:33.225 removed item from playbackList
More information about the mythtv-dev
mailing list