On Sat, 12 Feb 2005 21:24:30 -0500, Brad Benson <[EMAIL PROTECTED]> wrote: > ---------- Forwarded message ---------- > From: Brad Benson <[EMAIL PROTECTED]> > Date: Sat, 12 Feb 2005 20:49:37 -0500 > Subject: Re: [mythtv-users] 0.17 upgrade -> backend crashes > To: Chris Pinkham <[EMAIL PROTECTED]> > > On Sat, 12 Feb 2005 20:03:46 -0500 (EST), Chris Pinkham > <[EMAIL PROTECTED]> wrote: > > > I upgraded from 0.16 to 0.17 late Thursday night/early Friday morning. > > > Ever since then I've been seeing some strange behavior from the box. > > What's in your jobqueue table? You can also limit the number of jobs > > that myth will run at one time, the default is 1 I believe, so I'm > > not sure why it's running multiple jobs unless you bumped up the > > JobQueueMaxSimultaneousJobs setting. > > > > When I run setup it tells me that I already have the backend limited > to 1 simultaneous job, CPU usage is set to Medium, Job Queue check > frequency is set to 60 seconds, Run Jobs only on original recording > host is unchecked, and I have allowed this backend to run any jobs in > the queue (commflag, user 1, user 2, user 3 and user 4). > > > Can you do a "select * from jobqueue order by id;" and post the > > output? This should indicate if there are multiple entries in the > > table for a single show. The code should prevent that though. > > > > Here's the output from "select * from jobqueue order by id;": > +----+--------+---------------------+---------------------+------+------+-------+--------+---------------------+------------+------+-----------------------------+ > | id | chanid | starttime | inserttime | type | > cmds | flags | status | statustime | hostname | args | > comment | > +----+--------+---------------------+---------------------+------+------+-------+--------+---------------------+------------+------+-----------------------------+ > | 1 | 1030 | 2005-02-11 15:59:00 | 2005-02-11 17:03:00 | 2 | > 0 | 0 | 272 | 2005-02-11 18:43:47 | bivomaster | | > Finished, 0 break(s) found. | > | 3 | 1052 | 2005-02-11 22:58:00 | 2005-02-11 23:32:00 | 2 | > 0 | 0 | 1 | 2005-02-12 20:23:05 | bivomaster | | > | > | 4 | 1009 | 2005-02-11 20:53:00 | 2005-02-12 16:04:35 | 2 | > 4 | 0 | 272 | 2005-02-12 16:07:42 | bivomaster | | > Finished, 0 break(s) found. | > | 5 | 1024 | 2005-02-11 18:28:00 | 2005-02-12 16:06:16 | 2 | > 0 | 0 | 272 | 2005-02-12 20:40:23 | bivomaster | | 60% > Completed @ 60 fps. > | > | 6 | 1031 | 2005-02-11 19:30:00 | 2005-02-12 16:06:21 | 2 | > 0 | 0 | 4 | 2005-02-12 20:40:22 | bivomaster | | 80% > Completed @ 60 fps. | > +----+--------+---------------------+---------------------+------+------+-------+--------+---------------------+------------+------+-----------------------------+ > 5 rows in set (0.00 sec) > > Interestingly, here's a snippet from mythbackend.log from immediately > after the above select statement was run: > 2005-02-12 20:34:52.770 Starting Commercial Flagging for "Everybody > Loves Raymond" recorded from channel 1031 at Fri Feb 11 19:30:00 2005. > 2005-02-12 20:34:52.910 commflag: Commercial Flagging Starting > QTime::setHMS Invalid time 28:12:01.000 > QDate::setYMD: Invalid date 2935-93-02 > 2005-02-12 20:37:49.989 MainServer::HandleAnnounce Playback > 2005-02-12 20:37:50.055 adding: bivomaster as a client (events: 0) > 2005-02-12 20:37:50.249 Reloading backend settings > 2005-02-12 20:37:50.370 MainServer::HandleAnnounce Playback > 2005-02-12 20:37:50.380 adding: bivomaster as a client (events: 1) > QTime::setHMS Invalid time 28:12:02.000 > QDate::setYMD: Invalid date 2935-93-02 > 2005-02-12 20:38:53.065 Starting Commercial Flagging for "Everybody > Loves Raymond" recorded from channel 1031 at Fri Feb 11 19:30:00 2005. > QTime::setHMS Invalid time 28:12:02.000 > QDate::setYMD: Invalid date 2935-93-02 > 2005-02-12 20:42:12.339 Waited 2 seconds for data to become available, > waiting again... > 2005-02-12 20:42:16.380 commflag: Last message repeated 1 times > 2005-02-12 20:42:16.458 commflag: Commercial Flagging Finished > 2005-02-12 20:42:16.631 Finished, 1 break(s) found. > > There is definitely only a single jobqueue entry for the show with a > start time of 02/11/2004:19:30:00, but the log clearly shows two > separate instances of commercial flagging being run for that show. > Here's another sample taken from the same log file: > > 2005-02-12 20:42:53.525 Starting Commercial Flagging for "Best Week > Ever" recorded from channel 1052 at Fri Feb 11 22:58:00 2005. > 2005-02-12 20:42:53.596 commflag: Commercial Flagging Starting > QTime::setHMS Invalid time 28:12:01.000 > QDate::setYMD: Invalid date 2935-93-02 > QTime::setHMS Invalid time 28:12:02.000 > QDate::setYMD: Invalid date 2935-93-02 > 2005-02-12 20:43:53.735 Starting Commercial Flagging for "Best Week > Ever" recorded from channel 1052 at Fri Feb 11 22:58:00 2005. > QTime::setHMS Invalid time 28:12:02.000 > QDate::setYMD: Invalid date 2935-93-02 > > Again, you can see that there's only a single entry in the job queue, > but two instances of mythcommflag being run. > > > > This message is repeated several times in the log and the backend is > > > dead. When I try to restart the backend from the command line it > > > returns me to a prompt with no output to the console or the log file > > > and the backend never starts. I have to do a hard reboot of the box > > > in order to get the backend started again. > > > > Not sure about this, what is the result code? Type "echo $?" without > > the quotes after you try to run the backend, that will let you know if > > it is exiting with a certain error status but not printing anything > > verbose. You can also try running "mythbackend -v all" which will > > turn on all debugging output and might give a clue as to why it's > > dying. > > Well, I figured this part out. When the backend dies it's leaving > behind /var/lock/subsys/mythbackend. The startup file checks for this > and silently returns if the file already exists. Once I delete > /var/lock/subsys/mythbackend I can then restart the backend normally. > > > > > 0.17. I did set -march=athlon for mythtv and all modules when I > > > compiled since I'm running an Athlon 1600+ and I thought I could > > > squeeze a little extra speed out of the code. I'm going to try > > > recompiling with the default -march=pentiumpro just to see what > > > happens, but I doubt that's going to fix the problem. > > > > Anything but the default compile options are usually untested by > > the developers I believe, so you're best bet is to try pentiumpro and > > see if the problems are still occuring. Make sure you do a > > "make distclean". > > > > I haven't yet recompiled everything, but I think I'm going to leave > -march=athlon and turn on debugging first. That way I can run the > backend under gdb and see if we get any interesting data the next time > it crashes. > > Thanks for your help so far. I'll post back after recompiling and > running under gdb. > > Accidentally replied off-list so I'm forwarding this message to the > list this time. > > I've now recompiled with debug support and am running mythbackend > under gdb. It hasn't crashed yet, but I've currently got 14 instances > of mythcommflag running and the load average on the box is just under > 20! > > > Brad >
Okay, one more reply to myself with a little more info. Here's the ps output for all the currently running mythcommflags: root 14432 16.7 4.1 74548 19956 ? RN 20:42 7:12 mythcommflag -j --chanid 1052 --starttime 20050211225800 --force root 14468 16.3 4.1 75020 19876 ? RN 20:43 6:52 mythcommflag -j --chanid 1052 --starttime 20050211225800 --force root 14786 11.4 4.0 73580 19500 ? RN 20:51 3:57 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 14908 10.1 4.0 73464 19704 pts/1 RN 20:53 3:17 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 14926 10.1 4.0 72628 19688 pts/1 RN 20:53 3:16 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15195 8.6 4.0 72500 19648 pts/1 SN 20:58 2:20 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15246 8.2 4.0 73252 19620 pts/1 RN 21:00 2:06 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15410 6.9 4.0 72832 19336 pts/1 RN 21:05 1:26 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15482 6.3 4.0 72388 19676 pts/1 RN 21:07 1:10 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15536 5.8 4.0 72944 19708 pts/1 RN 21:08 0:59 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15554 5.8 4.0 72788 19692 pts/1 RN 21:09 0:58 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15599 5.4 4.1 72304 19988 pts/1 RN 21:10 0:50 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15680 4.9 4.2 73048 20400 pts/1 RN 21:12 0:38 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 15945 4.3 4.6 78824 22440 pts/1 RN 21:19 0:17 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force root 16130 3.6 9.9 79092 47944 pts/1 RN 21:25 0:01 mythcommflag -j --chanid 1024 --starttime 20050211182800 --force By comparing the --starttime flag you can see that there are two instances running for one episode and 13(!) running for another episode. Hopefully this thing will crash soon and I can get some meaningful info from gdb. Brad
_______________________________________________ mythtv-users mailing list [email protected] http://mythtv.org/cgi-bin/mailman/listinfo/mythtv-users
