[mythtv-users] mythfilldatabase loses connection to database
rjmorris.list at zoho.com
Sun Sep 9 03:30:44 UTC 2018
A couple weeks ago, I migrated my backend to new hardware by following the
database backup and restore instructions on the wiki. Everything seemed to be
working fine, but then today I realized that I don't have guide listings for
Digging into it, I saw that mythfilldatabase sits for 5 minutes on "Updating
programs" before losing its connection to the database, which then leads to
several errors because the temp tables don't exist anymore. This same step took
9 seconds on my old system. I checked the database tuning parameters, and
everything looked the same between the old and new system.
I have 2 video sources, and the error happens while processing the first one, so
the listings from the second video source never get populated. My guide *does*
show updated listings for channels on the first video source.
I enabled MariaDB's slow query logging, and it showed that the following query
took 733 seconds (about 12 minutes):
INSERT IGNORE INTO people (name) SELECT fullname FROM dd_productioncrew LEFT OUTER JOIN people ON people.name = dd_productioncrew.fullname WHERE people.name IS NULL;
The query plan and explain output are below:
/usr/sbin/mysqld, Version: 10.1.35-MariaDB-1 (Debian unstable). started with:
Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock
Time Id Command Argument
# Time: 180908 10:58:54
# User at Host: mythtv[mythtv] @ localhost 
# Thread_id: 138 Schema: mythconverg QC_hit: No
# Query_time: 733.357978 Lock_time: 0.000112 Rows_sent: 0 Rows_examined: 82468
# Rows_affected: 0
# Full_scan: Yes Full_join: Yes Tmp_table: Yes Tmp_table_on_disk: No
# Filesort: No Filesort_on_disk: No Merge_passes: 0 Priority_queue: No
# explain: id select_type table type possible_keys key key_len ref rows r_rows filtered r_filtered Extra
# explain: 1 SIMPLE dd_productioncrew index NULL nameidx 165 NULL 82439 82439.00 100.00 100.00 Using index; Using temporary
# explain: 1 SIMPLE people ALL NULL NULL NULL NULL 136345 136345.00 100.00 0.00 Using where; Not exists; Using join buffer (flat, BNL join)
I'm not familiar with how to interpret these results, but inserting the
production crew details into the people table doesn't seem like it should take
The log up to the first error from a `mythfilldatabase --dd-grab-all` run:
2018-09-08 18:49:51.780219 C mythfilldatabase version: joey/fixes/29 [v29.1-49-ga546136424] www.mythtv.org
2018-09-08 18:49:51.780239 C Qt version: compile: 5.10.1, runtime: 5.11.1
2018-09-08 18:49:51.780241 N Enabled verbose msgs: general
2018-09-08 18:49:51.780252 N Setting Log Level to LOG_INFO
2018-09-08 18:49:51.791214 I Added logging to the console
2018-09-08 18:49:51.791570 I Setup Interrupt handler
2018-09-08 18:49:51.791577 I Setup Terminated handler
2018-09-08 18:49:51.791583 I Setup Segmentation fault handler
2018-09-08 18:49:51.791588 I Setup Aborted handler
2018-09-08 18:49:51.791592 I Setup Bus error handler
2018-09-08 18:49:51.791597 I Setup Floating point exception handler
2018-09-08 18:49:51.791601 I Setup Illegal instruction handler
2018-09-08 18:49:51.791608 I Setup Real-time signal 0 handler
2018-09-08 18:49:51.791615 I Setup Hangup handler
2018-09-08 18:49:51.791655 N Read conf dir = /etc/mythtv
2018-09-08 18:49:51.791751 N Using runtime prefix = /usr/local/stow/mythtv-0.29-20180802
2018-09-08 18:49:51.791754 N Using configuration directory = /etc/mythtv
2018-09-08 18:49:51.791817 I Assumed character encoding: en_US.UTF-8
2018-09-08 18:49:51.792174 I Using localhost value of otto
2018-09-08 18:49:51.792245 I Start up testing connections. DB localhost, BE , attempt 0, status dbAwake
2018-09-08 18:49:52.819866 N Setting QT default locale to EN_US
2018-09-08 18:49:52.819889 I Current locale EN_US
2018-09-08 18:49:52.819964 N Reading locale defaults from /usr/local/stow/mythtv-0.29-20180802/share/mythtv//locales/en_us.xml
2018-09-08 18:49:52.827608 I Loading en_us translation for module mythfrontend
2018-09-08 18:49:52.829748 I Current MythTV Schema Version (DBSchemaVer): 1348
2018-09-08 18:49:52.833993 I MythCoreContext::ConnectCommandSocket(): Connecting to backend server: 192.168.1.14:6543 (try 1 of 1)
2018-09-08 18:49:52.837002 I MythCoreContext::CheckProtoVersion(): Using protocol version 91 BuzzOff
2018-09-08 18:49:52.837315 I Opening blocking connection to master backend
2018-09-08 18:49:52.926683 I Updating source #1 (Schedules Direct 27519) with grabber schedulesdirect1
2018-09-08 18:49:52.926877 I Found 23 channels for source 1 which use grabber
2018-09-08 18:49:52.926907 I This DataDirect listings source is shared by 2 MythTV lineups
2018-09-08 18:49:52.926911 N We should keep data around after this one
2018-09-08 18:49:52.928251 I Retrieving datadirect data.
2018-09-08 18:49:52.928257 I Grabbing ALL available data.
2018-09-08 18:49:52.928304 I DataDirect: Grabbing listing data
2018-09-08 18:49:52.928483 I Downloading DataDirect feed
2018-09-08 18:50:10.617123 I Downloaded 1676767 bytes
2018-09-08 18:50:10.617133 I Uncompressing DataDirect feed
2018-09-08 18:50:10.676207 I Uncompressed to 20198067 bytes
2018-09-08 18:50:10.676217 I Writing to temporary file: [/tmp/mythtv_ddp_CR9VXO/mythtv_dd_cache_1_UTC_20180906224952_to_20180923224952]
2018-09-08 18:50:10.706762 I New static DB connectionDataDirectCon
2018-09-08 18:50:10.717901 I DataDirect: Your subscription expires on Sat Sep 21 2019 6:24 PM
2018-09-08 18:50:10.737285 I DataDirect: sourceid 5 has lineup type: LocalBroadcast
2018-09-08 18:50:10.746951 I DataDirect: sourceid 1 has lineup type: LocalBroadcast
2018-09-08 18:50:34.654689 I Grab complete. Actual data from 2018-09-06T22:49:52Z to 2018-09-23T22:49:52Z (UTC)
2018-09-08 18:50:34.655500 I Main temp tables populated.
2018-09-08 18:50:34.655503 I Updating MythTV channels.
2018-09-08 18:50:34.770936 I Channels updated.
2018-09-08 18:50:35.090056 I Clearing data for source.
2018-09-08 18:50:35.090110 I Clearing from 2018-09-06T18:49:52 to 2018-09-23T18:49:52 (localtime)
2018-09-08 18:50:36.185826 I Data for source cleared.
2018-09-08 18:50:36.185834 I Updating programs.
2018-09-08 18:55:37.396270 E DB Error (Inserting into people table):
INSERT IGNORE INTO program ( chanid, starttime, endtime, title, subtitle, description, showtype, category, category_type, airdate, stars, previouslyshown, stereo, subtitled, subtitletypes, videoprop, audioprop, hdtv, closecaptioned, partnumber, parttotal, seriesid, originalairdate, colorcode, syndicatedepisodenumber, programid, listingsource) SELECT dd_v_program.chanid, DATE_ADD(starttime, INTERVAL channel.tmoffset MINUTE), DATE_ADD(endtime, INTERVAL channel.tmoffset MINUTE), title, subtitle, description, showtype, dd_genre.class, category_type, airdate, stars, previouslyshown, stereo, subtitled, (subtitled << 1 ) | closecaptioned, hdtv, (dolby << 3) | stereo, hdtv, closecaptioned, partnumber, parttotal, seriesid, originalairdate, colorcode, syndicatedepisodenumber, dd_v_program.programid, ? FROM (dd_v_program, channel) LEFT JOIN dd_genre ON ( dd_v_program.programid = dd_genre.programid AND dd_genre.relevance = '0' ) WHERE dd_v_program.chanid = channel.chanid
Driver error was [2/2013]:
QMYSQL: Unable to execute query
Database error was:
Lost connection to MySQL server during query
One thing that seems really strange is that the slow query log and the DB error
message in the mythfilldatabase log both point to query that inserts into people
table as the slow one, but the actual query printed in the mythfilldatabase log
is the one that inserts into the program table.
A few notes that might be pertinent:
- I use the Schedules Direct / Data Direct grabber.
- I'm in the US receiving OTA channels.
- I build from source.
- I was using MySQL on the old hardware but MariaDB on the new hardware.
I can try switching to the XMLTV grabber (which I was planning to do at some
point anyway) to see if that helps, but I wonder if whatever is causing the
current problem may still be a problem later.
Any ideas for what might be wrong or suggestions for troubleshooting would be
More information about the mythtv-users