RossBoylan at stanfordalumni
Aug 9, 2012, 3:39 PM
Post #3 of 3
(203 views)
Permalink
|
Belated response at the bottom--I've been away. Also, I have an update
on the source of the problem.
Ater a lot of grepping and looking at the state of my tables, it seems
the only way things could have gotten in this state is for the
DoVideoDatabseSchemaUpgrade() code in dbcheck.cpp of mythvideo (in the
0.24.2 version) to have run part way and then failed.
I know some of my installs (and runs?) of myth failed because the file
system ran out space. I speculate that for the same reason my logs do
not show evidence of an install of mythvideo, but that I did try to
install it at some point. I thought I had cleared out the database too
when I reinstalled, but apparently not.
The tables (I checked videometadata in particular) are in a weird state
which seems to match this theory; they definitely lack many later
changes. videometadata is empty.
Still not sure how to dig out; I considered manually reseting the
mythvideo.DBSchemaVer to the current one, but since the tables are not
current that won't work.
See below for the logs.
On Mon, 2012-07-30 at 11:09 -0400, Michael T. Dean wrote:
> On 07/27/2012 04:48 PM, Ross Boylan wrote:
> > If anyone can confirm my diagnosis or offer suggestions for a way
> > forward, I'd appreciate it.
> >
> > Also, would this be better directed to the developer list?
> >
> > Short version: The automatic upgrade of my database from 0.24.2 to
> > 0.25.0 fails. The problem seems to be that my mythvideo.DBSchemaVer is
> > 1011, while the minimum acceptable for upgrade is 1016. Probably not
> > coincidentally I do not have the mythvideo package from Marillat's
> > repository installed (along with several others--I just got what I
> > needed for TV). 0.24.2 was the first version ever installed on the
> > machine, and so the version number could not be a hold-over from an
> > older install.
> >
> >
> > Thanks.
> > Ross
> >
> >
> > Details of the diagnosis:
> >
> > Since the log shows I'm at DBSchemaVer 1266 I looked at the code in
> > dbcheck.cpp
> > (http://code.mythtv.org/doxygen/mythtv_2libs_2libmythtv_2dbcheck_8cpp_source.html). It appears this code successively upgrade the database for each version. The fact that I'm at 1266 indicates the upgrade code from 1266 to 1267 failed; I believe that's lines 1244-1255 (that's on the web; I'm actually using slightly older source code). This calls doUpgradeVideoDatabaseSchema, which in turn does these checks:
> >
> > 00348 bool doUpgradeVideoDatabaseSchema(void)
> > 00349 {
> > 00350 QString dbver = gCoreContext->GetSetting("mythvideo.DBSchemaVer");
> > 00351 if (dbver == finalVideoDatabaseVersion)
> > 00352 {
> > 00353 return true;
> > 00354 }
> > 00355
> > 00356 QString olddbver = gCoreContext->GetSetting("VideoDBSchemaVer");
> > 00357 QString dvddbver = gCoreContext->GetSetting("DVDDBSchemaVer");
> > 00358 if (dbver.isEmpty()&& olddbver.isEmpty()&& dvddbver.isEmpty())
> > 00359 {
> > 00360 if (!InitializeVideoSchema())
> > 00361 return false;
> > 00362 dbver = gCoreContext->GetSetting("mythvideo.DBSchemaVer");
> > 00363 }
> > 00364
> > 00365 if (dbver.isEmpty() || dbver.toInt()< minimumVideoDatabaseVersion.toInt())
> > 00366 {
> > 00367 LOG(VB_GENERAL, LOG_ERR,
> > 00368 "Unrecognized video database schema version. "
> > 00369 "Unable to upgrade database.");
> > 00370 LOG(VB_GENERAL, LOG_ERR, QString("mythvideo.DBSchemaVer: '%1', "
> > 00371 "VideoDBSchemaVer: '%2', DVDDBSchemaVer: '%3'").arg(dbver)
> > 00372 .arg(olddbver).arg(dvddbver));
> > 00373 return false;
> > 00374 }
> > and my log shows
> > CoreContext videodbcheck.cpp:375 (doUpgradeVideoDatabaseSchema) - mythvideo.DBSchemaVer: '1011', VideoDBSchemaVer: '', DVDDBSchemaVer: ''.
> >
> > Manual inspection of the tables confirms the version of
> > mythvideo.DBSchemaVer and the absence of the other keys in the settings
> > table. Unfortunately minimalVideoDatabaseVersion is 1016.
> >
> > BTW, my logs indicate 0.24.2 was on MythTV Schema 1264. Note this is a
> > distinct sequence from mythvideo.DBSchemaVer.
>
> Can you please provide the logs showing the failed DB upgrade. If you
> never installed MythVideo from MythTV version 0.13 or whatever the
> oldest supported version was (somewhere around 0.13), then the "old
> MythVideo schema version" isn't the problem.
>
> Mike
When I run the 0.25 version the time-stamped mythbackend logs show (I
think only the last few lines are interesting)
2012-05-13 21:31:40.262783 C [342/342] thread_unknown mythcommandlineparser.cpp:2534 (ConfigureLogging) - mythbackend version: [v0.25pre] www.mythtv.org
2012-05-13 21:31:40.262873 N [342/342] thread_unknown mythcommandlineparser.cpp:2536 (ConfigureLogging) - Enabled verbose msgs: general
2012-05-13 21:31:40.263316 N [342/342] thread_unknown logging.cpp:1176 (logStart) - Setting Log Level to LOG_INFO
2012-05-13 21:31:40.263472 I [342/342] thread_unknown logging.cpp:229 (FileLogger) - Added logging to the console
2012-05-13 21:31:40.276940 I [342/342] thread_unknown logging.cpp:238 (FileLogger) - Added logging to /var/log/mythtv/mythbackend.20120513213140.342.log
2012-05-13 21:31:40.276975 I [342/342] thread_unknown logging.cpp:425 (DatabaseLogger) - Added database logging to table logging
2012-05-13 21:31:40.277331 N [342/342] thread_unknown logging.cpp:1215 (logStart) - Setting up SIGHUP handler
2012-05-13 21:31:40.338971 N [342/342] thread_unknown mythdirs.cpp:51 (InitializeMythDirs) - Using runtime prefix = /usr
2012-05-13 21:31:40.339039 N [342/342] thread_unknown mythdirs.cpp:64 (InitializeMythDirs) - Using configuration directory = /var/lib/mythtv/.mythtv
2012-05-13 21:31:40.390779 I [342/342] CoreContext mythcorecontext.cpp:227 (Init) - Assumed character encoding: en_US.UTF-8
2012-05-13 21:31:40.437278 E [342/342] CoreContext configuration.cpp:64 (Load) - Error parsing: /var/lib/mythtv/.mythtv/config.xml at line: 1 column: 1
2012-05-13 21:31:40.437301 E [342/342] CoreContext configuration.cpp:66 (Load) - Error Msg: unexpected end of file
2012-05-13 21:31:40.490617 N [342/342] CoreContext mythcontext.cpp:477 (LoadDatabaseSettings) - Empty LocalHostName.
2012-05-13 21:31:40.490645 I [342/342] CoreContext mythcontext.cpp:481 (LoadDatabaseSettings) - Using localhost value of corn
2012-05-13 21:31:40.490823 E [342/342] CoreContext configuration.cpp:64 (Load) - Error parsing: /var/lib/mythtv/.mythtv/config.xml at line: 1 column: 1
2012-05-13 21:31:40.490835 E [342/342] CoreContext configuration.cpp:66 (Load) - Error Msg: unexpected end of file
2012-05-13 21:31:42.474211 N [342/342] CoreContext mythcorecontext.cpp:1270 (InitLocale) - Setting QT default locale to en_US
2012-05-13 21:31:42.474539 I [342/342] CoreContext mythcorecontext.cpp:1303 (SaveLocaleDefaults) - Current locale en_US
2012-05-13 21:31:42.514424 N [342/342] CoreContext mythlocale.cpp:121 (LoadDefaultsFromXML) - Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
2012-05-13 21:31:42.941783 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:42.941837 C [342/342] CoreContext schemawizard.cpp:135 (CompareAndWait) - MythTV database schema is old. Waiting to see if DB is being upgraded.
2012-05-13 21:31:44.021755 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:45.024322 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:46.026637 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:47.028983 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:48.031182 I [342/342] CoreContext schemawizard.cpp:117 (Compare) - Current MythTV Schema Version (DBSchemaVer): 1266
2012-05-13 21:31:48.031282 C [342/342] CoreContext schemawizard.cpp:179 (CompareAndWait) - Timed out waiting.
2012-05-13 21:31:48.041371 C [342/342] CoreContext dbutil.cpp:217 (BackupDB) - Database backups disabled. Skipping backup.
2012-05-13 21:31:48.111326 I [342/342] CoreContext schemawizard.cpp:316 (PromptForUpgrade) - Console is non-interactive, can't prompt user...
2012-05-13 21:31:48.111346 C [342/342] CoreContext schemawizard.cpp:341 (PromptForUpgrade) - Upgrading.
2012-05-13 21:31:48.129495 C [342/342] CoreContext dbcheck.cpp:495 (UpgradeTVDatabaseSchema) - Newest MythTV Schema Version : 1299
2012-05-13 21:31:48.209034 E [342/342] CoreContext videodbcheck.cpp:369 (doUpgradeVideoDatabaseSchema) - Unrecognized video database schema version. Unable to upgrade database.
2012-05-13 21:31:48.209051 E [342/342] CoreContext videodbcheck.cpp:372 (doUpgradeVideoDatabaseSchema) - Please see mythplugins/mythvideo/README.database for more information.
2012-05-13 21:31:48.209064 E [342/342] CoreContext videodbcheck.cpp:375 (doUpgradeVideoDatabaseSchema) - mythvideo.DBSchemaVer: '1011', VideoDBSchemaVer: '', DVDDBSchemaVer: ''
2012-05-13 21:31:48.209074 E [342/342] CoreContext dbcheck.cpp:509 (UpgradeTVDatabaseSchema) - Database Schema upgrade FAILED, unlocking.
2012-05-13 21:31:48.209245 E [342/342] CoreContext main_helpers.cpp:529 (run_backend) - Couldn't upgrade database to new schema
The last entries in mythbackend.log (0.24.2) are
2012-05-12 08:00:50.043 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2012-05-12 08:08:29.953 UPnpMedia: BuildMediaMap - no VideoStartupDir set, skipping scan.
2012-05-12 08:15:50.395 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2012-05-12 08:23:29.957 UPnpMedia: BuildMediaMap - no VideoStartupDir set, skipping scan.
2012-05-12 08:29:19.828 MainServer::ANN Monitor
2012-05-12 08:29:20.239 adding: corn as a client (events: 0)
2012-05-12 08:29:20.652 MainServer::ANN Monitor
2012-05-12 08:29:20.750 adding: corn as a client (events: 1)
>From my notes, there were a number of issues with the package upgrade itself (from Marillat's Debian repo's):
<terminal>
Installing new version of config file /etc/init.d/mythtv-backend ...
Starting MythTV server: mythbackend Unable to load library icui18n "Cannot load library icui18n: (libicui18n.so.48: cannot open shared object file: No such file or directory)"
Cannot login to database?
Would you like to configure the database connection now? [no]
[console is not interactive, using default 'no']
</terminal>
After installing libicu the first error went away, but the second did
not. I fiddled with the stored passwords in some configuration files (I
had some troubles getting DB access working initially and so things were
in an inconsistent state), and got the 0.25 version running enough to
give the errors shown above.
Before the upgrade the mythbackend log sometimes showed errors like this
one, about recordmatch marked as crash. Perhaps it is a clue to some of
the other problems; on its face, it's a different issue:
2012-05-10 09:37:53.777 New DB scheduler connection
2012-05-10 09:37:53.789 Connected to database 'mythconverg' at host: localhost
2012-05-10 09:37:53.792 Scheduler, Warning: Listings source 'OTA' is defined, but is not attached to a card input.
2012-05-10 09:37:53.858 Main::Registering HttpStatus Extension
2012-05-10 09:37:53.876 Enabled verbose msgs: important general
2012-05-10 09:37:53.894 AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
2012-05-10 09:37:55.180 MainServer::ANN Monitor
2012-05-10 09:37:55.184 adding: corn as a client (events: 0)
2012-05-10 09:37:55.189 MainServer::ANN Monitor
2012-05-10 09:37:55.200 adding: corn as a client (events: 1)
2012-05-10 09:37:56.837 Reschedule requested for id -1.
2012-05-10 09:37:56.841 Error preparing query: DELETE FROM recordmatch
2012-05-10 09:37:56.842 Driver error was [2/144]:
QMYSQL3: Unable to prepare statement
Database error was:
Table './mythconverg/recordmatch' is marked as crashed and last (automatic?) repair failed
2012-05-10 09:37:56.843 DB Error (UpdateMatches):
Query was:
DELETE FROM recordmatch
Driver error was [2/144]:
QMYSQL: Unable to execute query
Database error was:
Table './mythconverg/recordmatch' is marked as crashed and last (automatic?) repair failed
2012-05-10 09:37:56.914 Error preparing query: UPDATE 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) LEFT JOIN oldrecorded ON ( sched_temp_record.dupmethod > 1 AND oldrecorded.duplicate <> 0 AND program.title = oldrecorded.title AND ( (program.programid <> '' AND program.generic = 0 AND program.programid = oldrecorded.programid) OR (oldrecorded.findid <> 0 AND oldrecorded.findid = (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 ti
me_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.findid ELSE 0 END) ) OR ( program.generic = 0 AND (program.programid = '' OR oldrecorded.programid = '') AND (((sched_temp_record.dupmethod & 0x02) = 0) OR (program.subtitle <> '' AND program.subtitle = oldrecorded.subtitle)) AND (((sched_temp_record.dupmethod & 0x04) = 0) OR (program.description <> '' AND program.description = oldrecorded.description)) AND (((sched_temp_record.dupmethod & 0x08) = 0) OR (program.subtitle <> '' AND program.subtitle = oldrecorded.subtitle) OR (program.subtitle = '' AND oldrecorded.subtitle = '' AND program.description <> '' AND program.description = oldrecorded.description)) ) ) ) LEFT JOIN sched_temp_recorded recorded ON ( s
ched_temp_record.dupmethod > 1 AND recorded.duplicate <> 0 AND program.title = recorded.title AND recorded.recgroup NOT IN ('LiveTV','Deleted') AND ( (program.programid <> '' AND program.generic = 0 AND program.programid = recorded.programid) OR (recorded.findid <> 0 AND recorded.findid = (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.findid ELSE 0 END) ) OR ( program.generic = 0 AND (program.programid = '' OR recorded.programid = '') AND (((sched_temp_
record.dupmethod & 0x02) = 0) OR (program.subtitle <> '' AND program.subtitle = recorded.subtitle)) AND (((sched_temp_record.dupmethod & 0x04) = 0) OR (program.description <> '' AND program.description = recorded.description)) AND (((sched_temp_record.dupmethod & 0x08) = 0) OR (program.subtitle <> '' AND program.subtitle = recorded.subtitle) OR (program.subtitle = '' AND recorded.subtitle = '' AND program.description <> '' AND program.description = recorded.description)) ) ) ) LEFT JOIN oldfind ON (oldfind.recordid = recordmatch.recordid AND oldfind.findid = (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.findid ELSE 0 END) ) SET oldrecduplicate = (oldrecorded.endtime IS NOT NULL), recduplicate = (recorded.endtime IS NOT NULL), findduplicate = (oldfind.findid IS NOT NULL), oldrecstatus = oldrecorded.recstatus WHERE program.endtime >= NOW() - INTERVAL 1 DAY
2012-05-10 09:37:56.919 Driver error was [2/144]:
QMYSQL3: Unable to prepare statement
Database error was:
Table './mythconverg/recordmatch' is marked as crashed and last (automatic?) repair failed
2012-05-10 09:37:56.919 DB Error (AddNewRecords recordmatch):
Query was:
UPDATE 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) LEFT JOIN oldrecorded ON ( sched_temp_record.dupmethod > 1 AND oldrecorded.duplicate <> 0 AND program.title = oldrecorded.title AND ( (program.programid <> '' AND program.generic = 0 AND program.programid = oldrecorded.programid) OR (oldrecorded.findid <> 0 AND oldrecorded.findid = (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.findid ELSE 0 END) ) OR ( program.generic = 0 AND (program.programid = '' OR oldrecorded.programid = '') AND (((sched_temp_record.dupmethod & 0x02) = 0) OR (program.subtitle <> '' AND program.subtitle = oldrecorded.subtitle)) AND (((sched_temp_record.dupmethod & 0x04) = 0) OR (program.description <> '' AND program.description = oldrecorded.description)) AND (((sched_temp_record.dupmethod & 0x08) = 0) OR (program.subtitle <> '' AND program.subtitle = oldrecorded.subtitle) OR (program.subtitle = '' AND oldrecorded.subtitle = '' AND program.description <> '' AND program.description = oldrecorded.description)) ) ) ) LEFT JOIN sched_temp_recorded recorded ON ( sched_temp_record.dupmethod > 1 AND recorded
.duplicate <> 0 AND program.title = recorded.title AND recorded.recgroup NOT IN ('LiveTV','Deleted') AND ( (program.programid <> '' AND program.generic = 0 AND program.programid = recorded.programid) OR (recorded.findid <> 0 AND recorded.findid = (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.findid ELSE 0 END) ) OR ( program.generic = 0 AND (program.programid = '' OR recorded.programid = '') AND (((sched_temp_record.dupmethod & 0x02) = 0) OR (program.subti
tle <> '' AND program.subtitle = recorded.subtitle)) AND (((sched_temp_record.dupmethod & 0x04) = 0) OR (program.description <> '' AND program.description = recorded.description)) AND (((sched_temp_record.dupmethod & 0x08) = 0) OR (program.subtitle <> '' AND program.subtitle = recorded.subtitle) OR (program.subtitle = '' AND recorded.subtitle = '' AND program.description <> '' AND program.description = recorded.description)) ) ) ) LEFT JOIN oldfind ON (oldfind.recordid = recordmatch.recordid AND oldfind.findid = (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.findid ELSE 0 END) ) SET oldrecduplicate = (oldrecorded.endtime IS NOT NULL), recduplicate = (recorded.endtime IS NOT NULL), findduplicate = (oldfind.findid IS NOT NULL), oldrecstatus = oldrecorded.recstatus WHERE program.endtime >= NOW() - INTERVAL 1 DAY
No error type from QSqlError? Strange...
2012-05-10 09:37:56.922 Error preparing query: SELECT record.title, record.subtitle, record.description, record.category, record.chanid, channel.channum, record.station, channel.name, record.recgroup, record.playgroup, record.seriesid, record.programid, record.recpriority, record.startdate, record.starttime, record.enddate, record.endtime, record.recordid, record.type, record.dupin, record.dupmethod, record.findid, record.startoffset, record.endoffset, channel.commmethod 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
2012-05-10 09:37:56.922 Driver error was [2/144]:
QMYSQL3: Unable to prepare statement
Database error was:
Table './mythconverg/recordmatch' is marked as crashed and last (automatic?) repair failed
2012-05-10 09:37:56.923 DB Error (AddNotListed):
Query was:
SELECT record.title,
_______________________________________________
mythtv-users mailing list
mythtv-users [at] mythtv
http://www.mythtv.org/mailman/listinfo/mythtv-users
|
