9.04 users - check your mythbackend logs!

[Dewey_Oxberger]

Just a thought: There seems to be a loose screw in the booting of mysql.

Everyone with 9.04 - do me a favor and check your /var/log/mythtv/mythbackend.log.

Look for signs of a DB error. If you see any kind of text like:

DB Error (blah blah):
Query was:
SELECT blah blah
Database error was:
MySQL server has gone away

Post here. If you don't see any errors post here.

Boot several times and see if it's consistant.

Thanks

[andrewc6l]

I see that in my logs. In my case, it looks like it starts with:

2009-04-30 23:22:42.630 AutoExpire: CalcParams(): Max required Free Space: 1.0 G
B w/freq: 15 min
2009-04-30 23:22:45.584 Reschedule requested for id -1.
2009-04-30 23:22:45.798 Invalid rectype for manual recordid 498
2009-04-30 23:22:49.475 DB Error (AddNewRecords):
Query was:
SELECT DISTINCT channel.chanid, channel.sourceid, program.starttime, program.endtime, program.title, program.subtitle, program.description, channel.channum, channel.callsign, channel.name, oldrecduplicate, program.category, sched_temp_record.recpriority, sched_temp_record.dupin, recduplicate, findduplicate, sched_temp_record.type, sched_temp_record.recordid, program.starttime - INTERVAL sched_temp_record.startoffset minute AS recstartts, program.endtime + INTERVAL sched_temp_record.endoffset minute AS recendts, program.previouslyshown, sched_temp_record.recgroup, sched_temp_record.dupmethod, channel.commmethod, capturecard.cardid, cardinput.cardinputid, UPPER(cardinput.shareable) = 'Y' AS shareable, program.seriesid, program.programid, program.category_type, program.airdate, program.stars, program.originalairdate, sched_temp_record.inactive, sched_temp_record.parentid, (CASE sched_temp_record.type WHEN 6 THEN sched_temp_record.findid WHEN 9 THEN to_days(date_sub(program.starttime, interval time_format(sched_temp_record.findtime, '%H:%i') hour_minute)) WHEN 10 THEN floor((to_days(date_sub(program.starttime, interval time_format(sched_temp_record.findtime, '%H:%i') hour_minute)) - sched_temp_record.findday)/7) * 7 + sched_temp_record.findday WHEN 7 THEN sched_temp_record.find
id ELSE 0 END) , sched_temp_record.playgroup, oldrecstatus.recstatus, oldrecstatus.reactivate, program.videoprop+0, program.subtitletypes+0, program.audioprop+0, sched_temp_record.storagegroup, capturecard.hostname, recordmatch.oldrecstatus, channel.recpriority + cardinput.recpriority + (cardinput.cardinputid = sched_temp_record.prefinput) * 2 AS powerpriority FROM recordmatch INNER JOIN sched_temp_record ON (recordmatch.recordid = sched_temp_record.recordid) INNER JOIN program ON (recordmatch.chanid = program.chanid AND recordmatch.starttime = program.starttime AND recordmatch.manualid = program.manualid) INNER JOIN channel ON (channel.chanid = program.chanid) INNER JOIN cardinput ON (channel.sourceid = cardinput.sourceid) INNER JOIN capturecard ON (capturecard.cardid = cardinput.cardid) LEFT JOIN oldrecorded as oldrecstatus ON ( oldrecstatus.station = channel.callsign AND oldrecstatus.starttime = program.starttime AND oldrecstatus.title = program.title ) ORDER BY sched_temp_record.recordid DESC
Driver error was [2/2013]:
QMYSQL3: Unable to execute query
Database error was:
Lost connection to MySQL server during query

2009-04-30 23:22:49.502 DB Error (AddNotListed):
Query was:
SELECT record.recordid, record.type, record.chanid, record.starttime, record.startdate, record.endtime, record.enddate, record.startoffset, record.endoffset, record.title, record.subtitle, record.description, channel.channum, channel.callsign, channel.name FROM record INNER JOIN channel ON (channel.chanid = record.chanid) LEFT JOIN recordmatch on record.recordid = recordmatch.recordid WHERE (type = 1 OR type = 2 OR type = 5 OR type = 7) AND recordmatch.chanid IS NULL
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-04-30 23:22:49.506 Scheduled 0 items in 3.9 = 1.03 match + 2.89 place
2009-04-30 23:22:49.509 Seem to be woken up by USER
2009-04-30 23:22:51.472 DB Error (Error clearing channel locks):
Query was:
DELETE FROM eit_cache WHERE status = 1
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-04-30 23:22:51.605 DB Error (Housekeeper Creating Temporary Table):
Query was:
CREATE TEMPORARY TABLE IF NOT EXISTS temprecordedcleanup ( chanid int(10) unsign
ed NOT NULL default '0', starttime datetime NOT NULL default '0000-00-00 00:00:0
0' );
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away


2009-04-30 23:22:51.919 DB Error (Error in JobQueue::GetJobs(), Unable to query
list of Jobs in Queue.):
Query was:
SELECT j.id, j.chanid, j.starttime, j.inserttime, j.type, j.cmds, j.flags, j.sta
tus, j.statustime, j.hostname, j.args, j.comment, r.endtime, j.schedruntime FROM
jobqueue j, recorded r WHERE j.chanid = r.chanid AND j.starttime = r.starttime
ORDER BY j.schedruntime, j.id;
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

[phroman]

Yea, getting errors every time I boot up, however, other than 3 digit channel changing problems, things seem to be working ok.

2009-05-02 15:47:17.616 Using runtime prefix = /usr
2009-05-02 15:47:17.689 Empty LocalHostName.
2009-05-02 15:47:17.720 Using localhost value of mythtvserver
2009-05-02 15:47:17.846 New DB connection, total: 1
2009-05-02 15:47:17.893 Connected to database 'mythconverg' at host: localhost
2009-05-02 15:47:17.920 Closing DB connection named 'DBManager0'
2009-05-02 15:47:17.921 Connected to database 'mythconverg' at host: localhost
2009-05-02 15:47:17.924 New DB connection, total: 2
2009-05-02 15:47:17.925 Connected to database 'mythconverg' at host: localhost
2009-05-02 15:47:17.968 Current Schema Version: 1214
Starting up as the master server.
2009-05-02 15:47:18.152 New DB connection, total: 3
2009-05-02 15:47:18.154 Connected to database 'mythconverg' at host: localhost
2009-05-02 15:47:18.491 Channel(/dev/video0) Warning: You have not set an external channel changing
script for a composite or s-video input. Channel changing will do nothing.
2009-05-02 15:47:18.541 New DB scheduler connection
2009-05-02 15:47:18.561 Connected to database 'mythconverg' at host: localhost
2009-05-02 15:47:18.616 MediaServer:: Loopback address specified - 127.0.0.1. Disabling UPnP
2009-05-02 15:47:18.630 Main::Registering HttpStatus Extension
2009-05-02 15:47:18.631 mythbackend version: 0.21.20080304-1 www.mythtv.org
2009-05-02 15:47:18.632 Enabled verbose msgs: important general
2009-05-02 15:47:18.650 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2009-05-02 15:47:21.574 Reschedule requested for id -1.
2009-05-02 15:47:22.177 Scheduled 0 items in 0.6 = 0.60 match + 0.01 place
2009-05-02 15:47:22.454 Seem to be woken up by USER
2009-05-02 15:47:28.032 DB Error (Error clearing channel locks):
Query was:
DELETE FROM eit_cache WHERE status = 1
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:47:28.591 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
Query was:
SELECT j.id, j.chanid, j.starttime, j.inserttime, j.type, j.cmds, j.flags, j.status, j.statustime, j.hostname, j.args, j.comment, r.endtime, j.schedruntime FROM jobqueue j, recorded r WHERE j.chanid = r.chanid AND j.starttime = r.starttime ORDER BY j.schedruntime, j.id;
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:47:28.956 DB Error (JobQueue::CleanupOldJobsInQueue: Error deleting old finished jobs.):
Query was:
DELETE FROM jobqueue WHERE (status in (272, 288, 320) AND statustime < '2009-04-30T15:47:28') OR (status in (304) AND statustime < '2009-04-28T15:47:28')
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:47:29.880 DB Error (HouseKeeper Cleaning TVChain Table):
Query was:
SELECT DISTINCT chainid FROM tvchain WHERE endtime > '2009-05-02T11:47:29' ;
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:47:30.000 DB Error (Housekeeper Creating Temporary Table):
Query was:
CREATE TEMPORARY TABLE IF NOT EXISTS temprecordedcleanup ( chanid int(10) unsigned NOT NULL default '0', starttime datetime NOT NULL default '0000-00-00 00:00:00' );
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:47:30.197 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
Query was:
SELECT j.id, j.chanid, j.starttime, j.inserttime, j.type, j.cmds, j.flags, j.status, j.statustime, j.hostname, j.args, j.comment, r.endtime, j.schedruntime FROM jobqueue j, recorded r WHERE j.chanid = r.chanid AND j.starttime = r.starttime ORDER BY j.schedruntime, j.id;
Driver error was [2/2006]:
QMYSQL3: Unable to execute query
Database error was:
MySQL server has gone away

2009-05-02 15:48:38.575 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2009-05-02 15:52:07.296 MainServer::HandleAnnounce Monitor
2009-05-02 15:52:07.303 adding: mythtvserver as a client (events: 0)
2009-05-02 15:52:07.304 MainServer::HandleAnnounce Monitor
2009-05-02 15:52:07.304 adding: mythtvserver as a client (events: 1)
2009-05-02 15:52:07.308 MainServer::HandleAnnounce Playback
2009-05-02 15:52:07.327 adding: mythtvserver as a client (events: 0)
2009-05-02 15:52:07.340 TVRec(1): Changing from None to WatchingLiveTV
2009-05-02 15:52:07.348 TVRec(1): HW Tuner: 1->1
2009-05-02 15:52:07.619 Channel(/dev/video0) Warning: You have not set an external channel changing
script for a composite or s-video input. Channel changing will do nothing.
2009-05-02 15:52:09.051 AutoExpire: CalcParams(): Max required Free Space: 2.0 GB w/freq: 15 min
2009-05-02 15:52:09.078 MPEGRec(/dev/video0) Warning: Audio sample rate 32000 Hz
is not supported by ivtv driver, using 48000 Hz instead.
2009-05-02 15:52:12.759 TVRec(1): Changing from WatchingLiveTV to None
2009-05-02 15:52:13.011 Finished recording A Civil Action: channel 1005
2009-05-02 15:54:38.589 Expiring 1 MBytes for 1005 @ Sat May 2 14:30:00 2009 => A Civil Action
2009-05-02 16:03:38.600 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min

[AKADAP]

I get these errors about half the time I boot.
I also find this in my syslog

May 3 09:39:58 AComputer mysqld_safe[4576]: Number of processes running now: 1
May 3 09:39:58 AComputer mysqld_safe[4584]: mysqld process hanging, pid 3206 - killed
May 3 09:39:58 AComputer mysqld_safe[4587]: restarted

This corresponds with mythbackend starting.

See this thread for more details:
http://ubuntuforums.org/showthread.php?p=7205519#post7205519

[frugal]

I'd have to double check my logs but every time I reboot I lose all my recording schedules. What I mean is that the rules still show up if I check system status but it shows 0 matching shows. Running mythfilldatabase seems to clear this up without any additional intervention from me.

[Dewey_Oxberger]

Heads up. superm1 has a patch proposed for mysql that did the trick for me.

With a little luck it'll make it upstream.

In the mean time try moving /etc/rc2.d/Sxxmythback-end to S99zmythback-end.

[AKADAP]

Heads up. superm1 has a patch proposed for mysql that did the trick for me.

With a little luck it'll make it upstream.

In the mean time try moving /etc/rc2.d/Sxxmythback-end to S99zmythback-end.

That was insufficient for me. I currently have a 3 minute delay in the mythbackend startup script. It doesn't prevent the database restart, but after three minutes, nothing but the restart is happening, so it seems to happen fast enough that it does not affect the myth backend. Take this with a grain of salt though, since this is based on only one reboot since I made this change.

[Dewey_Oxberger]

superm1 has been working on a fix for mysql - quote


Regarding the mysql being hung thing, please activate jaunty-proposed, perform all updates (make sure mysql server gets updated) and add feedback to bug
326768

Note, this might actually help the problem with the hdhr too indirectly since mysql is "actually" ready sooner..


To activate "proposed" go to System, Software Sources, and the Updates tab (or something like that). There is a checkbox that says "jaunty-proposed." Check it, reload the package info, and run Update Manager.

Report your results (good or bad) in the bug.

[phroman]

Well, ran that update and things look ok. However, Dewey's post saying to try this:

In the mean time try moving /etc/rc2.d/Sxxmythback-end to S99zmythback-end.

Fixed it for me before this. Should this be un-done and update again to see the effect?

[Dewey_Oxberger]

It would be good to restore mythbackend to whatever Sxx level you had, verify the problem comes back, then update and verify the problem went away. No big deal though.

[ktmom]

I had these "MySQL server has gone away" errors on 9.04 consistently every boot. I then activated the "proposed" updates and cleared the log then rebooted.

The "MySQL server has gone away" errors went away, but now I am getting:
Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)

[pblarry49]

Here is my log greped fro DB Error. I am experiencing intermittent lack of connection backend -> database at boot time. Also I am experiencing intermittent inability of the front end to find or display the recorded video icons.

2009-10-03 20:40:47.113 DB Error (KickDatabase):
2009-10-03 20:40:47.164 DB Error (JobQueue::CleanupOldJobsInQueue: Error deleting old finished jobs.):
2009-10-03 20:40:47.218 DB Error (KickDatabase):
2009-10-03 20:40:47.268 DB Error (HouseKeeper Cleaning TVChain Table):
2009-10-03 20:40:47.321 DB Error (KickDatabase):
2009-10-03 20:40:47.372 DB Error (Housekeeper Creating Temporary Table):
2009-10-03 20:40:47.425 DB Error (KickDatabase):
2009-10-03 20:40:47.527 DB Error (KickDatabase):
2009-10-03 20:40:47.579 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-04 00:31:37.263 DB Error (LogEntry):
2009-10-04 00:31:37.266 DB Error (DelLogEntry#1):
2009-10-04 00:31:37.268 DB Error (JobQueue::CleanupOldJobsInQueue: Error deleting old finished jobs.):
2009-10-04 00:31:37.319 DB Error (KickDatabase):
2009-10-04 00:31:37.370 DB Error (HouseKeeper Cleaning TVChain Table):
2009-10-04 00:31:37.425 DB Error (KickDatabase):
2009-10-04 00:31:37.475 DB Error (Housekeeper Creating Temporary Table):
2009-10-04 00:31:37.534 DB Error (KickDatabase):
2009-10-04 00:31:37.636 DB Error (KickDatabase):
2009-10-04 00:31:37.697 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-04 16:14:55.123 DB Error (Error clearing channel locks):
2009-10-04 16:14:55.404 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-04 16:14:55.844 DB Error (LogEntry):
2009-10-04 16:14:55.855 DB Error (DelLogEntry#1):
2009-10-04 16:14:55.856 DB Error (JobQueue::CleanupOldJobsInQueue: Error deleting old finished jobs.):
2009-10-04 16:14:55.857 DB Error (HouseKeeper Cleaning TVChain Table):
2009-10-04 16:14:55.858 DB Error (Housekeeper Creating Temporary Table):
2009-10-04 16:14:55.860 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-04 18:03:40.025 DB Error (KickDatabase):
2009-10-04 19:17:30.647 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-05 23:01:21.541 DB Error (Error in JobQueue::GetJobs(), Unable to query list of Jobs in Queue.):
2009-10-09 19:43:19.140 DB Error (KickDatabase):
2009-10-10 15:18:03.500 DB Error (fetching chanid):
2009-10-10 15:18:03.505 DB Error (CardUtil::GetInputInfo()):
2009-10-10 15:18:03.506 DB Error (GetMplexID 4):
2009-10-10 15:18:04.507 DB Error (fetching chanid):
2009-10-10 15:18:04.507 DB Error (CardUtil::GetInputInfo()):
2009-10-10 15:18:04.508 DB Error (GetMplexID 4):
2009-10-10 15:18:05.509 DB Error (fetching chanid):
2009-10-10 15:18:05.511 DB Error (CardUtil::GetInputInfo()):
2009-10-10 15:18:05.512 DB Error (GetMplexID 4):
2009-10-10 15:18:06.512 DB Error (fetching chanid):
2009-10-10 15:18:06.515 DB Error (CardUtil::GetInputInfo()):
2009-10-10 15:18:06.516 DB Error (GetMplexID 4):