[mythtv-users] mythfilldatabase loses connection to database

Joey Morris 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
some channels.

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
12 minutes.

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: (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):
    Query was:
    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
greatly appreciated.


More information about the mythtv-users mailing list