Mythbackend crashes when attempt to run LiveTV [Arch installation with MariaDB errors]

[bill6502]

Anyone else playing along:

https://aur.archlinux.org/libhdhomerun.git

for example returns a 404 error, but if you do the git clone there and
then makepkg && makepkg --install it works. Similar with the mythtv
package.

[chrismate]

After reading bill6502's comments after my last post I decided to change the OS of my MythTV server to Debian (10 - Buster).
MythTV is only available from git in Buster but it all built without any problem.
The standard mariadb was downloaded from apt and I now have a working MythTV server again.
This, obviously, doesn't solve the Arch mariadb issue but it confirms that's where the problem lies.
Thanks for your comments/suggestions.

[bill6502]

Arch users should probably upgrade, note the new version of mariadb three posts above.
I can't tie the four crashes fixed to mythfrontend's use of the DB, but it's worth a shot.

[bill6502]

Got v31-Pre running and watching LiveTV OK. The AUR version is missing a fix,
discussed earlier that will cause LiveTV to fail immediately. I don't know how Arch
updates packages from AUR (or know much about AUR itself.) The following should
be added to the .patch files that come with the package:

Code: Select all

commit ccf39fad9213c80ce8b7b4fd79dfa0ff63c090ca
Date:   Wed Jan 16 23:36:51 2019 -0600

    Fix issues with recent live TV channels commit.

diff --git a/mythtv/libs/libmythtv/channelutil.cpp b/mythtv/libs/libmythtv/channelutil.cpp
index 1c35d7ca4f..dc2e412e7d 100644
--- a/mythtv/libs/libmythtv/channelutil.cpp
+++ b/mythtv/libs/libmythtv/channelutil.cpp
@@ -2409,7 +2409,7 @@ ChannelInfoList ChannelUtil::LoadChannels(uint startIndex, uint count,
         cond << "channel.sourceid = :SOURCEID ";
 
     if (liveTVOnly)
-        cond << "channel.livetvorder > 0 ";
+        cond << "capturecard.livetvorder > 0 ";
 
     if (!cond.isEmpty())
         sql += QString("WHERE %1").arg(cond.join("AND "));
@@ -2429,7 +2429,7 @@ ChannelInfoList ChannelUtil::LoadChannels(uint startIndex, uint count,
     }
     else // kChanOrderByLiveTV
     {
-        sql += "ORDER BY callsign = :CALLSIGN1 AND channum = :CHANNUM, "
+        sql += "ORDER BY callsign = :CALLSIGN1 AND channum = :CHANNUM DESC, "
                "         callsign = :CALLSIGN2 DESC, "
                "         livetvorder, "
                "         channel.recpriority DESC, "

Why MariaDB drops core is for another forum. But I clearly had the issue
when running v30 without the patch. In any case, the DB server shouldn't fail on any queries
from MythTV, or anything else. I didn't try v30 with the patch, rather moved on to v31-Pre.

When v31 is released, the following AUR packages may need to be built:

Code: Select all

libhdhomerun (if users have HDHRs) perl-datetime-format-sqlite    perl-net-upnp        perl-xml-dom     tv_grab_zz_sdjson_sqlite  xmltv
help2man  lirc   perl-lwp-useragent-determined  perl-unicode-string  perl-xml-treepp  urlgrabber

Signing off.

[gustaf]

I have got the same problem on Ubuntu 18.04, running MariaDB 10.4.7-MariaDB-1:10.4.7+maria~bionic and mythtv 2:29.1+fixes.20180414.329c235-0ubuntu3. For some reason, I decided to switch from mysql to MariaDB....

The offending query is:

Code: Select all

Aug 19 23:00:31 x mysqld[18225]: Query (0x7fddc801aee8): SELECT recordid, category,        (category = ?) AS catmatch,        (category = ?) AS typematch FROM record WHERE type = ? AND       (category = ? OR category = ?        OR category = 'Default') ORDER BY catmatch DESC, typematch DESC

It's amazing that this crashes MariaDB. I guess there is little hope of your fix making its way into the Ubuntu 18.04 multiverse sources?

[bill6502]

I see the text above in earlier posts, but that wasn't where the fix being discussed was. Or I'm
missing something from the log snippet above.

That code is here: https://code.mythtv.org/cgit/mythtv/tre ... e.cpp#n283
and had no references to livetvorder in it.

The version from mythbackend --version would show what you're running on, as would a complete backend log.

*buntu users can add the ppa, see Mike's instructions here, for example:
viewtopic.php?f=36&t=3049&p=14816&hilit ... ntu#p14816
That will get fixes.

I certainly agree that no query should cause a DB to fail.

[gustaf]

Yes, I should have read more carefully above. My error is similar to @matrix432's, but different to @chrismate.

I can tune some channels, but on others MariaDB dies:

Code: Select all

22:58:21 mythbackend: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[1]: Changing from WatchingLiveTV to None
22:58:21 mythbackend: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (720x576 A/R: 3 25fps) Audio Codec: mp2
22:58:21 mythbackend: I TVRecEvent tv_rec.cpp:863 (FinishedRecording) TVRec[1]: FinishedRecording(7336_2019-08-19T21:55:30Z) damaged recq:<RecordingQuality overall_score="0" key="7336_2019-08-19T21:55:30Z" countinuity_error_count="0" packet_count="983784">#012    <Gap start="2019-08-19T21:00:00Z" end="2019-08-19T21:55:30Z" duration="3330" />#012    <Gap start="2019-08-19T21:58:20Z" end="2019-08-19T22:00:00Z" duration="99" />#012</RecordingQuality>
22:58:21 mythbackend: I MythSocketThread(136) mainserver.cpp:7681 (connectionClosed) FileTransfer sock(56168e3d86a0) disconnected
22:58:21 mythbackend: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
22:58:21 mythbackend: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: JDjunior(56168e39b700) as a client (events: 0)
22:58:21 mythbackend: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[1]: Changing from None to WatchingLiveTV
22:58:21 mythbackend: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
22:58:23 mythbackend: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
22:58:23 mythbackend: W TVRecEvent programinfo.cpp:5613 (LoadFromProgram) LoadFromProgram(): SQL contains LIMIT clause, caller should be updated to use limit parameter instead
22:58:24 mythbackend: E TVRecEvent mythdb.cpp:183 (DBError) DB Error (LoadByTemplate):#012Query was:#012SELECT recordid, category,        (category = ?) AS catmatch,        (category = ?) AS typematch FROM record WHERE type = ? AND       (category = ? OR category = ?        OR category = 'Default') ORDER BY catmatch DESC, typematch DESC#012Bindings were:#012:CAT1="", :CAT2="", :CATTYPE1="", :CATTYPE2="", :TEMPLATE=11#012Driver error was [2/2013]:#012QMYSQL3: Unable to reset statement#012Database error was:#012Lost connection to MySQL server during query
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:877 (prepare) Error preparing query: SELECT name FROM playgroup WHERE name = :TITLE1 OR       name = :CATEGORY OR       (titlematch <> '' AND        :TITLE2 REGEXP titlematch)
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:879 (prepare) Driver error was [2/2006]:#012QMYSQL3: Unable to prepare statement#012Database error was:#012MySQL server has gone away
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:651 (exec) MySQL server disconnected
22:58:24 mythbackend: E TVRecEvent mythdb.cpp:183 (DBError) DB Error (GetInitialName):#012Query was:#012SELECT name FROM playgroup WHERE name = ? OR       name = ? OR       (titlematch <> '' AND        ? REGEXP titlematch) #012Bindings were:#012:CATEGORY=NULL, :TITLE1="", :TITLE2=""#012Driver error was [2/2006]:#012QMYSQL3: Unable to prepare statement#012Database error was:#012MySQL server has gone away
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:242 (OpenDatabase) [DBManager2] Unable to connect to database!
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:243 (OpenDatabase) Driver error was [1/2002]:#012QMYSQL: Unable to connect#012Database error was:#012Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:855 (prepare) MySQL server disconnected
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:651 (exec) MySQL server disconnected
22:58:24 mythbackend: E TVRecEvent mythdb.cpp:183 (DBError) DB Error (RecGroup update):#012Query was:#012#012No error type from QSqlError?  Strange...
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:242 (OpenDatabase) [DBManager2] Unable to connect to database!
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:243 (OpenDatabase) Driver error was [1/2002]:#012QMYSQL: Unable to connect#012Database error was:#012Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:741 (exec) MySQL server disconnected
22:58:24 mythbackend: E TVRecEvent mythdb.cpp:183 (DBError) DB Error (InsertProgram -- lock):#012Query was:#012#012No error type from QSqlError?  Strange...
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:242 (OpenDatabase) [DBManager2] Unable to connect to database!
22:58:24 mythbackend: E TVRecEvent mythdbcon.cpp:243 (OpenDatabase) Driver error was [1/2002]:#012QMYSQL: Unable to connect#012Database error was:#012Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:855 (prepare) MySQL server disconnected
22:58:24 mythbackend: I TVRecEvent mythdbcon.cpp:651 (exec) MySQL server disconnected
## The last 8 lines repeat many times as presumably mythbackend retries the sql queries.

The mariaDB log/stack trace is:

Code: Select all

22:29:53 mysqld: 190819 22:29:53 [ERROR] mysqld got signal 11 ;
22:29:53 mysqld: This could be because you hit a bug. It is also possible that this binary
22:29:53 mysqld: or one of the libraries it was linked against is corrupt, improperly built,
22:29:53 mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
22:29:53 mysqld: To report this bug, see mariadb
22:29:53 mysqld: We will try our best to scrape up some info that will hopefully help
22:29:53 mysqld: diagnose the problem, but since we have already crashed,
22:29:53 mysqld: something is definitely wrong and this may fail.
22:29:53 mysqld: Server version: 10.4.7-MariaDB-1:10.4.7+maria~bionic
22:29:53 mysqld: key_buffer_size=134217728
22:29:53 mysqld: read_buffer_size=131072
22:29:53 mysqld: max_used_connections=38
22:29:53 mysqld: max_threads=102
22:29:53 mysqld: thread_count=44
22:29:53 mysqld: It is possible that mysqld could use up to
22:29:53 mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 355507 K  bytes of memory
22:29:53 mysqld: Hope that's ok; if not, decrease some variables in the equation.
22:29:53 mysqld: Thread pointer: 0x7f9b98000c08
22:29:53 mysqld: Attempting backtrace. You can use the following information to find out
22:29:53 mysqld: where mysqld died. If you see no messages after this, something went
22:29:53 mysqld: terribly wrong...
22:29:53 mysqld: stack_bottom = 0x7f9c00b9edd8 thread_stack 0x49000
22:29:53 mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x558729cb8cee]
22:29:53 mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x515)[0x558729730085]
22:29:53 mysqld: /lib/x86_64-linux-gnu/libpt hread. so.0(+0x12890)[0x7f9c059c9890]
22:29:53 mysqld: /usr/sbin/mysqld(_Z7sortcmpPK6StringS1_PK15charset_info_st+0xb)[0x5587295a3d8b]
22:29:53 mysqld: /usr/sbin/mysqld(_ZNK26Type_handler_string_result13Item_const_eqEPK10Item_constS2_b+0x100)[0x558729662390]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN4Item15eq_by_collationEPS_bPK15charset_info_st+0x61)[0x558729752bb1]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN9Item_cond14add_key_fieldsEP4JOINPP9KEY_FIELDPjyPP14SARGABLE_PARAM+0x266)[0x558729550866]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN13Item_cond_and14add_key_fieldsEP4JOINPP9KEY_FIELDPjyPP14SARGABLE_PARAM+0x5b)[0x5587295505cb]
22:29:53 mysqld: /usr/sbin/mysqld(+0x67883f)[0x55872955183f]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x18a1)[0x558729577ff1]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0x9b)[0x558729579e2b]
22:29:53 mysqld: /usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0xe0)[0x55872957a910]
22:29:53 mysqld: /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x141)[0x55872957b311]
22:29:53 mysqld: /usr/sbin/mysqld(+0x63f291)[0x558729518291]
22:29:53 mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x12ab)[0x55872952053b]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN18Prepared_statement7executeEP6Stringb+0x4fe)[0x55872953cafe]
22:29:53 mysqld: /usr/sbin/mysqld(_ZN18Prepared_statement12execute_loopEP6StringbPhS2_+0x82)[0x55872953cc12]
22:29:53 mysqld: /usr/sbin/mysqld(+0x664972)[0x55872953d972]
22:29:53 mysqld: /usr/sbin/mysqld(_Z19mysqld_stmt_executeP3THDPcj+0x25)[0x55872953da15]
22:29:53 mysqld: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0xd55)[0x558729529c25]
22:29:53 mysqld: /usr/sbin/mysqld(_Z10do_commandP3THD+0x148)[0x55872952bb48]
22:29:53 mysqld: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x2c6)[0x558729606ca6]
22:29:53 mysqld: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x558729606d9d]
22:29:53 mysqld: nptl/pthread_create.c:463(start_thread)[0x7f9c059be6db]
22:29:53 mysqld: x86_64/clone.S:97(clone)[0x7f9c04dbc88f]
22:29:53 mysqld: Trying to get some variables.
22:29:53 mysqld: Some pointers may be invalid and cause the dump to abort.
22:29:53 mysqld: Query (0x7f9b982e70c8): SELECT recordid, category,        (category = ?) AS catmatch,        (category = ?) AS typematch FROM record WHERE type = ? AND       (category = ? OR category = ?        OR category = 'Default') ORDER BY catmatch DESC, typematch DESC
22:29:53 mysqld: Connection ID (thread ID): 127
22:29:53 mysqld: Status: NOT_KILLED
22:29:53 mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=
22:29:53 mysqld: The manual page at  mysql . com contains
22:29:53 mysqld: information that should help you find out what is causing the crash.
22:29:53 mysqld: Writing a core file...
22:29:53 mysqld: Working directory at /var/lib/mysql
22:29:53 mysqld: Resource Limits:
22:29:53 mysqld: Limit                     Soft Limit           Hard Limit           Units
22:29:53 mysqld: Max cpu time              unlimited            unlimited            seconds
22:29:53 mysqld: Max file size             unlimited            unlimited            bytes
22:29:53 mysqld: Max data size             unlimited            unlimited            bytes
22:29:53 mysqld: Max stack size            8388608              unlimited            bytes
22:29:53 mysqld: Max core file size        0                    unlimited            bytes
22:29:53 mysqld: Max resident set          unlimited            unlimited            bytes
22:29:53 mysqld: Max processes             61930                61930                processes
22:29:53 mysqld: Max open files            16364                16364                files
22:29:53 mysqld: Max locked memory         16777216             16777216             bytes
22:29:53 mysqld: Max address space         unlimited            unlimited            bytes
22:29:53 mysqld: Max file locks            unlimited            unlimited            locks
22:29:53 mysqld: Max pending signals       61930                61930                signals
22:29:53 mysqld: Max msgqueue size         819200               819200               bytes
22:29:53 mysqld: Max nice priority         0                    0
22:29:53 mysqld: Max realtime priority     0                    0
22:29:53 mysqld: Max realtime timeout      unlimited            unlimited            us
22:29:53 mysqld: Core pattern: |/usr/share/apport/apport %p %s %c %d %P
22:29:53 systemd: mariadb.service: Main process exited, code=killed, status=11/SEGV
22:29:53 systemd: mariadb.service: Failed with result 'signal'.

This did not happen when I was still running mysql.

mythbackend --version

Code: Select all

MythTV Version : v29.1-13-g329c235
MythTV Branch : fixes/29
Network Protocol : 91
Library API : 29.20180316-1
QT Version : 5.9.4
Options compiled in:
 linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_crystalhd using_dvb using_firewire using_frontend using_hdhomerun using_vbox using_ceton using_hdpvr using_ivtv using_joystick_menu using_libcec using_libcrypto using_libdns_sd using_libfftw3 using_libxml2 using_lirc using_mheg using_opengl using_opengl_video using_opengl_themepainter using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_x11 using_xrandr using_xv using_profiletype using_systemd_notify using_systemd_journal using_bindings_perl using_bindings_python using_bindings_php using_freetype2 using_mythtranscode using_opengl using_vaapi using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2 using_libmp3lame

[bill6502]

Note that when I went through the following, I didn't get the failure you're
seeing. But I'm on Ubuntu 19.04 LTS, MythTV v31-Pre and mysqld Ver 10.3.17.
I've had MariaDB on my host under test for years though.

I only tested a single program and don't know what's unique about yours.
Something we don't have here in the States??? Maybe some special characters
in your categories? I did run the query below with the word Univisión in place of
Default.

You're about 50 commits behind, but I don't see any fixes that apply to
this. From the users that opt-in to smolt (https://smolt.mythtv.org/static/stats/stats.html),
looks like only about 4% are running SQL versions v10.x

I'd decouple the issue from MythTV by getting the actual bindings from
the failing query by doing the following:

Code: Select all

mythbackend --quiet --quiet --setverbose database:debug

Then use LiveTV to watch a failing program and look in mythbackend.log
for the actual query. You'll see the bindings in play there. There's copy of
mine at the very end of this.

Do the next step AFTER watching LiveTV, NOT in the script below:

Code: Select all

mythbackend --setverbose database:warn

But don't forget, or your logs will get very noisy!

Then put the following in a file (so you can run it more than once if
changes are required.) Replace all of the category = 'Default' below
with the data from the log and run it. You also may need to submit it
to the folks at MariaDB, more on that below.

Code: Select all

mysql --host localhost --user mythtv --password=<yourPassword> mythconverg -e \
    "SELECT recordid, category, (category = 'Default') AS catmatch,
          (category = 'Default') AS typematch
              FROM record
              WHERE type = 11 AND
                  (category = 'Default' OR category = 'Default'
                   OR category = 'Default')
                      ORDER BY catmatch DESC, typematch DESC"

Following all of that, and assuming it duplicates the failure, I'd take
the advice in the MariaDB logs and report it to them.

Please let us know if the query above fails though.

# Ignore this and below , it's just so I don't have to look things up again
#libs/libmyth/recordingtypes.h:
#typedef enum RecordingTypes
#{
# kTemplateRecord = 11
#} RecordingType;
#2019-08-20 11:20:57.453733 I [4303/4313] TVRecEvent mythdbcon.cpp:704 (exec) - MSqlQuery::exec(DBManager10) SELECT recordid, category, (category = 'News') AS catmatch, (category = 'series') AS typematch FROM record WHERE type = '11' AND (category = 'News' OR category = 'series' OR category = 'Default') ORDER BY catmatch DESC, typematch DESC <<<< Took 0ms, Returned 1 row(s)

[gustaf]

Thank you for the detailed instructions, I have been away and only had time now to continue the debugging.

I tried the above, and I can't reproduce the error by querying . The detailed database log is (hopefully I haven't trimmed too much):

Code: Select all

Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:722 (exec) MSqlQuery::exec(DBManager2) SELECT chanid, channum, callsign, name, commmethod, outputfilters FROM channel WHERE chanid = '53296' <<<< Took 0ms, Returned 1 row(s)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: D TVRecEvent mythdbcon.cpp:792 (seekDebug) MSqlQuery::next(DBManager2) Result: "chanid = 53296, channum = 120, callsign = S4C HD, name = S4C HD, commmethod = -1, outputfilters = "
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:722 (exec) MSqlQuery::exec(DBManager2) SELECT data FROM settings WHERE value = 'unknowntitle' AND hostname = 'hn' <<<< Took 0ms, Returned 0 row(s)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:722 (exec) MSqlQuery::exec(DBManager2) SELECT data FROM settings WHERE value = 'unknowntitle' AND hostname IS NULL <<<< Took 0ms, Returned 0 row(s)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: W TVRecEvent programinfo.cpp:5613 (LoadFromProgram) LoadFromProgram(): SQL contains LIMIT clause, caller should be updated to use limit parameter instead
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:722 (exec) MSqlQuery::exec(DBManager2) SELECT program.chanid, program.starttime, program.endtime, program.title, program.subtitle, program.description, program.category, channel.channum, channel.callsign, channel.name, program.previouslyshown, channel.commmethod, channel.outputfilters, program.seriesid, program.programid, program.airdate, program.stars, program.originalairdate, program.category_type, oldrecstatus.recordid, oldrecstatus.rectype, oldrecstatus.recstatus, oldrecstatus.findid, program.videoprop+0, program.audioprop+0, program.subtitletypes+0, program.syndicatedepisodenumber, program.partnumber, program.parttotal, program.season, program.episode, program.totalepisodes  FROM program LEFT JOIN channel ON program.chanid = channel.chanid LEFT JOIN oldrecorded AS oldrecstatus ON     oldrecstatus.future = 0 AND     program.title = oldrecstatus.title AND     channel.callsign = oldrecstatus.station AND     program.starttime = oldrecstatus.starttime WHERE program.chanid    = '53296'  AND       program.starttime > '2019-09-08T17:01:50Z' GROUP BY program.starttime ORDER BY program.starttime LIMIT 1  <<<< Took 0ms, Returned 0 row(s)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:722 (exec) MSqlQuery::exec(DBManager2) SELECT recordid, category,        (category = '') AS catmatch,        (category = '') AS typematch FROM record WHERE type = '11' AND       (category = '' OR category = ''        OR category = 'Default') ORDER BY catmatch DESC, typematch DESC <<<< Took 0ms, Returned -1 row(s)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: E TVRecEvent mythdb.cpp:183 (DBError) DB Error (LoadByTemplate):#012Query was:#012SELECT recordid, category,        (category = ?) AS catmatch,        (category = ?) AS typematch FROM record WHERE type = ? AND       (category = ? OR category = ?        OR category = 'Default') ORDER BY catmatch DESC, typematch DESC#012Bindings were:#012:CAT1="", :CAT2="", :CATTYPE1="", :CATTYPE2="", :TEMPLATE=11#012Driver error was [2/2013]:#012QMYSQL3: Unable to reset statement#012Database error was:#012Lost connection to MySQL server during query
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: E TVRecEvent mythdbcon.cpp:877 (prepare) Error preparing query: SELECT name FROM playgroup WHERE name = :TITLE1 OR       name = :CATEGORY OR       (titlematch <> '' AND        :TITLE2 REGEXP titlematch)
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: E TVRecEvent mythdbcon.cpp:879 (prepare) Driver error was [2/2006]:#012QMYSQL3: Unable to prepare statement#012Database error was:#012MySQL server has gone away
Sep  8 18:01:32 hn mythbackend: mythbackend[12196]: I TVRecEvent mythdbcon.cpp:651 (exec) MySQL server disconnected

Could it be related to the prepared statement?

[bill6502]

Good mythbackend.log. <MAYBE> there's more info in /var/log/mysql.error.log.

Since the query worked, we still don't know the cause of MariaDB failure.

If you only did the last query (FROM record), I'd try the previous one. It too works for me,
but also is unique to your DB plus it's more complex. It happens in the same second as
the last query.

Code: Select all

SELECT program.chanid, program.starttime, program.endtime, program.title, program.subtitle, program.description, program.category, channel.channum, channel.callsign, channel.name, program.previouslyshown, channel.commmethod, channel.outputfilters, program.seriesid, program.programid, program.airdate, program.stars, program.originalairdate, program.category_type, oldrecstatus.recordid, oldrecstatus.rectype, oldrecstatus.recstatus, oldrecstatus.findid, program.videoprop+0, program.audioprop+0, program.subtitletypes+0, program.syndicatedepisodenumber, program.partnumber, program.parttotal, program.season, program.episode, program.totalepisodes  FROM program LEFT JOIN channel ON program.chanid = channel.chanid LEFT JOIN oldrecorded AS oldrecstatus ON     oldrecstatus.future = 0 AND     program.title = oldrecstatus.title AND     channel.callsign = oldrecstatus.station AND     program.starttime = oldrecstatus.starttime WHERE program.chanid    = '53296'  AND       program.starttime > '2019-09-08T17:01:50Z' GROUP BY program.starttime ORDER BY program.starttime LIMIT 1;

To answer your question, it could be the query, but I sill contend that the the DB server shouldn't
fail because of it. It should return an error if the query is malformed (but the same query is working
for others OK.)

[gustaf]

There is nothing of value in /var/log/mysqld/.

I just wiresharked the connection between backend and frontend. Have a look at the screenshots below.
First: there is the normal sequence of 'Prepare', 'Response', 'Reset', 'Response OK', 'Execute', 'Response' (385-390).

Capture1.PNG (21.34 KiB) Viewed 2761 times

It then repeats in the following queries. 394 is the offending query:

Capture2.PNG (12.45 KiB) Viewed 2761 times

(the 'truncated' is due to wireshark)
395, 396 and 397 are identical to previous sequences as far as I can tell, until in 398 the connection drops:

Capture3.PNG (16.05 KiB) Viewed 2761 times

Mythbackend only manages to send 1.5 of the 5 fields to mariadb before it crashes.

I am seriously out of my depth

Happy to share the pcap file, but only in private.

[bill6502]

Interesting capture. I started LiveTV and captured the protocol, but didn't see
the malformed packet (in Ubuntu.)

Two ideas. 1st, I'm guessing that in your config.xml, <Host> isn't set to localhost
(as it should be for a combined backend/frontend.) Rather, it's the IP address in
the Wireshark above or perhaps a resolvable hostname. I'd repeat the test with
this: <Host>localhost</Host>. You'll need to restart the BE after changing
it. Maybe even MariaDB just to be sure.

I'm not suggesting that that's a fix, just trying to duplicate the problem.

2nd, in the earlier SQL, I suggested running with --host=localhost. That (and the above)
means that a socket will be used, not TCP. I'd retry that test with --host=192.168.22.48.
Again trying to get MythTV out of the picture and duplicate the failure directly.

[gustaf]

Thank you for your continued support

Host was originally set to localhost, but as it is apparently hard to sniff on a socket, I changed it to enable the packet capture. So unix socket / tcp based communication between mythbackend and mariadb makes no difference.

The malformated packages only seem to appear on certain channels for me, particularly if the query bindings are "CAT1="", :CAT2="", :CATTYPE1="", :CATTYPE2="", :TEMPLATE=11".
From the wireshark log it seem like these query bindings cause the mythtv sql driver to produce an incorrect binary representation of the execution of the prepared statement. The below can just not be reconciled with the specifications https://dev.mysql.com/doc/internals/en/ ... ecute.html. So I guess MariaDBs crash is valid. I guess the next point of debug is to try to recreate a minimal C++ program that uses the same SQL library as mythtv and runs executes the same query?

Capture4.PNG (30.37 KiB) Viewed 2753 times

[bill6502]

Not ignoring you, out of time. Plus my arch host has (I think) a bad power supply and doesn't stay up long.

[hamelg]

Few days ago, this issue has begun to hit me. I use the livetv of mythtv v30.0 every day since it is released and I never see this bug before. I use archlinux and sometimes mariadb 10.4.11 crashes on the same query with the same stack. Someone has any progress on this issue ?