[mythtv-users] MySQL related BE deadlocks - collective wisdom needed

Brian J. Murrell brian at interlinx.bc.ca
Fri Jul 29 12:04:48 UTC 2011


On 11-07-29 05:41 AM, warpme wrote:
> Hi *
>
> Having this thread as kind of "mysql and myth" I'm seizing an opportunity to clarify following mysql-myth related issue:
> I have occasionally following error in myth log:  
>
> 2011-07-29 03:00:02.713306 I  EITScanner (5): Started passive scan.
> 2011-07-29 03:00:02.725219 I  TVRec(5): rec->GetPathname(): '/myth/tv/15315_20110729030000.mpg'
> 2011-07-29 03:00:21.058767 E  DB Error (change_program):
> Query was:
> UPDATE program SET starttime = ?,     endtime   = ? WHERE chanid    = ? AND       starttime = ?
> Bindings were:
> :CHANID=21023, :NEWEND=2011-07-29T06:00:00, :NEWSTART=2011-07-29T05:00:00,
> :OLDSTART=2011-07-29T04:00:00
> Driver error was [2/1062]:
> QMYSQL3: Unable to execute statement
> Database error was:
> Duplicate entry '21023-2011-07-29 05:00:00-0' for key 'PRIMARY'
> 2011-07-29 03:01:57.645007 I  EITScanner (5): Added 869 EIT Events
I've seen similar in the past:

2011-07-24 22:46:31.945 DB Error (Frame rate insert):
Query was:
INSERT INTO recordedmarkup    (chanid, starttime, mark, type, data)   
VALUES ( ?, ?, ?, ?, ?);
Bindings were:
:CHANID=1035, :DATA=29970, :MARK=83569, :STARTTIME=2011-07-24T22:00:00,
:TYPE=32
Driver error was [2/1062]:
QMYSQL3: Unable to execute statement
Database error was:
Duplicate entry '1035-2011-07-24 22:00:00-32-83569' for key 'PRIMARY'

and these ones:

2011-07-27 16:27:43.255 Error preparing query: SELECT
r.title,            r.subtitle,     r.description,           
r.category,         r.chanid,       c.channum,               
c.callsign,         c.name,         c.outputfilters,         
r.recgroup,         r.playgroup,    r.storagegroup,          
r.basename,         r.hostname,     r.recpriority,           
r.seriesid,         r.programid,    r.filesize,              
r.progstart,        r.progend,      r.stars,                 
r.starttime,        r.endtime,      p.airdate+0,             
r.originalairdate,  r.lastmodified, r.recordid,              
c.commmethod,       r.commflagged,  r.previouslyshown,       
r.transcoder,       r.transcoded,   r.deletepending,         
r.preserve,         r.cutlist,      r.autoexpire,            
r.editing,          r.bookmark,     r.watched,               
p.audioprop+0,      p.videoprop+0,  p.subtitletypes+0,       
r.findid,           rec.dupin,      rec.dupmethod      FROM recorded AS
r LEFT JOIN channel AS c ON (r.chanid    = c.chanid) LEFT JOIN
recordedprogram AS p ON (r.chanid    = p.chanid AND     r.progstart =
p.starttime) LEFT JOIN record AS rec ON (r.recordid = rec.recordid)
WHERE r.chanid    = :CHANID AND       r.starttime = :RECSTARTTS
2011-07-27 16:27:43.259 Driver error was [2/2013]:
QMYSQL3: Unable to prepare statement
Database error was:
Lost connection to MySQL server during query

2011-07-27 16:27:43.261 MySQL reconnected successfully
2011-07-27 16:27:43.285 DB Error (LoadProgramFromRecorded):
Query was:
SELECT r.title,            r.subtitle,     r.description,           
r.category,         r.chanid,       c.channum,               
c.callsign,         c.name,         c.outputfilters,         
r.recgroup,         r.playgroup,    r.storagegroup,          
r.basename,         r.hostname,     r.recpriority,           
r.seriesid,         r.programid,    r.filesize,              
r.progstart,        r.progend,      r.stars,                 
r.starttime,        r.endtime,      p.airdate+0,             
r.originalairdate,  r.lastmodified, r.recordid,              
c.commmethod,       r.commflagged,  r.previouslyshown,       
r.transcoder,       r.transcoded,   r.deletepending,         
r.preserve,         r.cutlist,      r.autoexpire,            
r.editing,          r.bookmark,     r.watched,               
p.audioprop+0,      p.videoprop+0,  p.subtitletypes+0,       
r.findid,           rec.dupin,      rec.dupmethod      FROM recorded AS
r LEFT JOIN channel AS c ON (r.chanid    = c.chanid) LEFT JOIN
recordedprogram AS p ON (r.chanid    = p.chanid AND     r.progstart =
p.starttime) LEFT JOIN record AS rec ON (r.recordid = rec.recordid)
WHERE r.chanid    = :CHANID AND       r.starttime = :RECSTARTTS
Bindings were:
:CHANID=2917, :RECSTARTTS=2011-06-18T20:00:00
Driver error was [2/1064]:
QMYSQL: Unable to execute query
Database error was:
You have an error in your SQL syntax; check the manual that corresponds
to your MySQL server version for the right syntax to use near ':CHANID
AND       r.starttime = :RECSTARTTS' at line 1

and:

2011-07-28 04:14:46.275 Error preparing query: SELECT
r.title,            r.subtitle,     r.description,           
r.category,         r.chanid,       c.channum,         
      c.callsign,         c.name,         c.outputfilters,         
r.recgroup,         r.playgroup,    r.storagegroup,          
r.basename,         r.hostname,     r.recp
riority,            r.seriesid,         r.programid,   
r.filesize,               r.progstart,        r.progend,     
r.stars,                  r.starttime,        r.endtim
e,      p.airdate+0,              r.originalairdate,  r.lastmodified,
r.recordid,               c.commmethod,       r.commflagged, 
r.previouslyshown,        r.transcoder,
      r.transcoded,   r.deletepending,          r.preserve,        
r.cutlist,      r.autoexpire,             r.editing,         
r.bookmark,     r.watched,               
p.audioprop+0,      p.videoprop+0,  p.subtitletypes+0,       
r.findid,           rec.dupin,      rec.dupmethod      FROM recorded AS
r LEFT JOIN channel AS c ON (r.chanid
   = c.chanid) LEFT JOIN recordedprogram AS p ON (r.chanid    = p.chanid
AND     r.progstart = p.starttime) LEFT JOIN record AS rec ON
(r.recordid = rec.recordid) WHERE r.c
hanid    = :CHANID AND       r.starttime = :RECSTARTTS
2011-07-28 04:14:46.276 Driver error was [2/2013]:
QMYSQL3: Unable to prepare statement
Database error was:
Lost connection to MySQL server during query

2011-07-28 04:14:46.278 MySQL reconnected successfully
2011-07-28 04:14:46.313 DB Error (LoadProgramFromRecorded):
Query was:
SELECT r.title,            r.subtitle,     r.description,           
r.category,         r.chanid,       c.channum,               
c.callsign,         c.name,         c.outputfilters,         
r.recgroup,         r.playgroup,    r.storagegroup,          
r.basename,         r.hostname,     r.recpriority,           
r.seriesid,         r.programid,    r.filesize,              
r.progstart,        r.progend,      r.stars,                 
r.starttime,        r.endtime,      p.airdate+0,             
r.originalairdate,  r.lastmodified, r.recordid,              
c.commmethod,       r.commflagged,  r.previouslyshown,       
r.transcoder,       r.transcoded,   r.deletepending,         
r.preserve,         r.cutlist,      r.autoexpire,            
r.editing,          r.bookmark,     r.watched,               
p.audioprop+0,      p.videoprop+0,  p.subtitletypes+0,       
r.findid,           rec.dupin,      rec.dupmethod      FROM recorded AS
r LEFT JOIN channel AS c ON (r.chanid    = c.chanid) LEFT JOIN
recordedprogram AS p ON (r.chanid    = p.chanid AND     r.progstart =
p.starttime) LEFT JOIN record AS rec ON (r.recordid = rec.recordid)
WHERE r.chanid    = :CHANID AND       r.starttime = :RECSTARTTS
Bindings were:
:CHANID=1005, :RECSTARTTS=2010-11-04T20:00:00
Driver error was [2/1064]:
QMYSQL: Unable to execute query
Database error was:
You have an error in your SQL syntax; check the manual that corresponds
to your MySQL server version for the right syntax to use near ':CHANID
AND       r.starttime = :RECSTARTTS' at line 1

and from earlier logs:

2011-07-06 06:30:04.730 DB Error (SimpleDBStorage::Load()):
Query was:
SELECT value  FROM codecparams WHERE profile = ? AND name = ?
Bindings were:
:WHERENAME=mpeg4minquality, :WHEREPROFILE=5
Driver error was [2/2013]:
QMYSQL3: Unable to execute statement
Database error was:
Lost connection to MySQL server during query

2011-07-06 06:30:04.744 MySQL reconnected successfully
QMYSQLResult::cleanup: unable to free statement handle
QMYSQLResult::cleanup: unable to free statement handle
2011-07-06 06:30:04.845 TVRec(15): rec->GetPathname():
'/video/mythtv/1019_20110705223000.mpg'
2011-07-06 06:30:04.881 MySQL reconnected successfully
2011-07-06 06:30:04.887 MySQL reconnected successfully
2011-07-06 06:30:04.892 MythSocket(ffffffffb4ee15e8:-1):
writeStringList: Error, writeBlock failed. (NetworkFailure)
2011-07-06 06:30:04.892 MythSocket(8f38250:-1): writeStringList: Error,
writeBlock failed. (NetworkFailure)
2011-07-06 06:30:04.893 MainServer, Warning: Unknown socket closing
MythSocket(0xffffffffa777a9d0)
2011-07-06 06:30:04.894 MainServer, Warning: Unknown socket closing
MythSocket(0xffffffffa0ec3050)
2011-07-06 06:30:04.915 MythSocket(ffffffffa777a9d0:-1):
writeStringList: Error, socket went unconnected.
                        We wrote 0 of 33 bytes with 1 errors
2011-07-06 06:30:04.915 MythSocket(ffffffffa0ec3050:-1):
writeStringList: Error, socket went unconnected.
                        We wrote 0 of 33 bytes with 1 errors
2011-07-06 06:30:04.968 MythSocket(ffffffffa7402a90:-1):
writeStringList: Error, writeBlock failed. (NetworkFailure)
2011-07-06 06:30:04.971 MythSocket(ffffffffa77f3a58:-1):
writeStringList: Error, writeBlock failed. (NetworkFailure)

The NetworkFailure there is somewhat of a red herring since the database
on the same machine as the backend and at 6:30am, there is no viewing
going on from a remote frontend.

and:

2011-07-08 06:20:26.992 Error preparing query: SELECT inputname,
sourceid, cardid FROM cardinput WHERE cardinputid = :INPUTID
2011-07-08 06:20:26.997 Driver error was [2/2013]:
QMYSQL3: Unable to prepare statement
Database error was:
Lost connection to MySQL server during query

2011-07-08 06:20:26.999 MySQL reconnected successfully
2011-07-08 06:20:27.001 DB Error (CardUtil::GetInputInfo()):
Query was:
SELECT inputname, sourceid, cardid FROM cardinput WHERE cardinputid =
:INPUTID
Bindings were:
:INPUTID=18
Driver error was [2/1064]:
QMYSQL: Unable to execute query
Database error was:
You have an error in your SQL syntax; check the manual that corresponds
to your MySQL server version for the right syntax to use near ':INPUTID'
at line 1

QMYSQLResult::cleanup: unable to free statement handle
2011-07-08 06:20:27.056 MythSocket(9d53258:-1): writeStringList: Error,
writeBlock failed. (NetworkFailure)

and again, no viewing by any remote FE at 6:20am.

Now that I look at it more closely, it seems i get mysql errors more
often that i thought I did.  But I'm not convinced that they are the
cause of lockups and recording failures since they just do not correlate.

For example, I did apply the "MYSQL_OPT_RECONNECT=1" patch last night,
had no mysql errors but I still had a failed recording with the only
anomalous looking log entries being:

2011-07-28 21:00:56.705 MythSocket(96f35a0:12): readStringList: Error,
timed out after 30000 ms.
2011-07-28 21:00:56.706 Connection to backend server lost
2011-07-28 21:00:56.707 MythCoreContext: Connecting to backend server:
10.75.22.2:6543 (try 1 of 5)
2011-07-28 21:00:56.713 Using protocol version 63
2011-07-28 21:00:56.717 MainServer::ANN Playback
2011-07-28 21:00:56.718 adding: pvr as a client (events: 0)
2011-07-28 21:00:56.721 MainServer::ANN Monitor
2011-07-28 21:00:56.722 adding: pvr as a client (events: 1)
2011-07-28 21:01:26.730 MythSocket(96f3b40:9): readStringList: Error,
timed out after 30000 ms.
2011-07-28 21:01:26.731 Reconnection to backend server failed
2011-07-28 21:01:26.732 Unable to find active recorder for this
recording, realtime flagging will not be enabled.
2011-07-28 21:01:26.817 MythCoreContext: Connecting to backend server:
10.75.22.2:6543 (try 1 of 5)
2011-07-28 21:01:26.830 Using protocol version 63
2011-07-28 21:01:26.831 MainServer::ANN Playback

And subsequent to that clients were again unable to connect to the
backend which required a restart to be usable with any FE, including
mythweb.

The stack trace when it was locked up did have the tell-tale mysql
thread in it:

Thread 19 (Thread 0xb3aa3b70 (LWP 15517)):
#0  0x00ee9422 in __kernel_vsyscall ()
No symbol table info available.
#1  0x00c95f5b in read () at ../sysdeps/unix/syscall-template.S:82
No locals.
#2  0x03480ab8 in vio_read () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#3  0x03480b16 in vio_read_buff () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#4  0x03481d13 in ?? () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#5  0x034820a7 in my_net_read () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#6  0x0347ba3f in cli_safe_read () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#7  0x03448f3e in cli_read_prepare_result () from
/usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#8  0x0344640e in mysql_stmt_prepare () from /usr/lib/libmysqlclient_r.so.16
No symbol table info available.
#9  0x03400592 in QMYSQLResult::prepare (this=0x8c5a600, query=...) at
../../../sql/drivers/mysql/qsql_mysql.cpp:883
        r = <value optimized out>
        encQuery = {static shared_null = {ref = {_q_value = 1}, alloc =
0, size = 0, data = 0x1e013a8 "", array = ""}, static shared_empty =
{ref = {_q_value = 13}, alloc = 0, size = 0, data = 0x1e013bc "", array
= ""}, d = 0x8ef3be0}
#10 0x007dc061 in QSqlResult::savePrepare (this=0x90a8ef0, query=...) at
kernel/qsqlresult.cpp:597
No locals.
#11 0x007ccf80 in QSqlQuery::prepare (this=0xb3aa2aec, query=...) at
kernel/qsqlquery.cpp:920
No locals.
#12 0x0058bbae in MSqlQuery::prepare (this=0xb3aa2aec, query=...) at
mythdbcon.cpp:627
        ok = true
#13 0x005c340f in SimpleDBStorage::Load (this=0x93e646c) at
mythstorage.cpp:14
        query = {<QSqlQuery> = {d = 0x92225e0}, m_db = 0x8c55268,
m_isConnected = true, m_returnConnection = true, m_last_prepared_query =
{static null = {<No data fields>}, static shared_null = {ref = {_q_value
= 3398}, alloc = 0, size = 0, data = 0x1e0147a, clean = 0, simpletext =
0, righttoleft = 0, asciiCache = 0, capacity = 0, reserved = 0, array =
{0}}, static shared_empty = {ref = {_q_value = 495}, alloc = 0, size =
0, data = 0x1e0148e, clean = 0, simpletext = 0, righttoleft = 0,
asciiCache = 0, capacity = 0, reserved = 0, array = {0}}, d = 0x92f3230,
static codecForCStrings = 0x0}}
        bindings = {{d = 0x8ef43c8, e = 0x8ef43c8}}
#14 0x03862e0b in ConfigurationGroup::Load (this=0x94a92d8) at
mythconfiggroups.cpp:91
        it = {_M_current = 0x8d2bee0}
#15 0x03862e0b in ConfigurationGroup::Load (this=0x9001b00) at
mythconfiggroups.cpp:91
        it = {_M_current = 0x8f9abfc}
#16 0x01215440 in ConfigurationDialog::Load (this=0xb3aa2e64) at
../libmyth/mythconfigdialogs.h:110
No locals.
#17 0x011d525d in RecordingProfile::loadByID (this=0xb3aa2e5c,
profileId=17) at recordingprofile.cpp:1299
        result = {<QSqlQuery> = {d = 0x8f5fd78}, m_db = 0xa992cb60,
m_isConnected = true, m_returnConnection = true, m_last_prepared_query =
{static null = {<No data fields>}, static shared_null = {ref = {_q_value
= 3398}, alloc = 0, size = 0, data = 0x1e0147a, clean = 0, simpletext =
0, righttoleft = 0, asciiCache = 0, capacity = 0, reserved = 0, array =
{0}}, static shared_empty = {ref = {_q_value = 495}, alloc = 0, size =
0, data = 0x1e0148e, clean = 0, simpletext = 0, righttoleft = 0,
asciiCache = 0, capacity = 0, reserved = 0, array = {0}}, d = 0x9040428,
static codecForCStrings = 0x0}}
        type = {static null = {<No data fields>}, static shared_null =
{ref = {_q_value = 3398}, alloc = 0, size = 0, data = 0x1e0147a, clean =
0, simpletext = 0, righttoleft = 0, asciiCache = 0, capacity = 0,
reserved = 0, array = {0}}, static shared_empty = {ref = {_q_value =
495}, alloc = 0, size = 0, data = 0x1e0148e, clean = 0, simpletext = 0,
righttoleft = 0, asciiCache = 0, capacity = 0, reserved = 0, array =
{0}}, d = 0x9342c88, static codecForCStrings = 0x0}
#18 0x011d588c in RecordingProfile::loadByType (this=0xb3aa2e5c,
name=..., cardtype=...) at recordingprofile.cpp:1356
        hostname = {static null = {<No data fields>}, static shared_null
= {ref = {_q_value = 3398}, alloc = 0, size = 0, data = 0x1e0147a, clean
= 0, simpletext = 0, righttoleft = 0, asciiCache = 0, capacity = 0,
reserved = 0, array = {0}}, static shared_empty = {ref = {_q_value =
495}, alloc = 0, size = 0, data = 0x1e0148e, clean = 0, simpletext = 0,
righttoleft = 0, asciiCache = 0, capacity = 0, reserved = 0, array =
{0}}, d = 0x93db408, static codecForCStrings = 0x0}
        recid = 17
        result = {<QSqlQuery> = {d = 0x9078e40}, m_db = 0xa9937d40,
m_isConnected = true, m_returnConnection = true, m_last_prepared_query =
{static null = {<No data fields>}, static shared_null = {ref = {_q_value
= 3398}, alloc = 0, size = 0, data = 0x1e0147a, clean = 0, simpletext =
0, righttoleft = 0, asciiCache = 0, capacity = 0, reserved = 0, array =
{0}}, static shared_empty = {ref = {_q_value = 495}, alloc = 0, size =
0, data = 0x1e0148e, clean = 0, simpletext = 0, righttoleft = 0,
asciiCache = 0, capacity = 0, reserved = 0, array = {0}}, d = 0x9019bb0,
static codecForCStrings = 0x0}}
#19 0x0169e71f in load_profile (cardtype=..., tvchain=0x0,
rec=0x92d6cf0, profile=...) at tv_rec.cpp:4015
        profileName = {static null = {<No data fields>}, static
shared_null = {ref = {_q_value = 3398}, alloc = 0, size = 0, data =
0x1e0147a, clean = 0, simpletext = 0, righttoleft = 0, asciiCache = 0,
capacity = 0, reserved = 0, array = {0}}, static shared_empty = {ref =
{_q_value = 495}, alloc = 0, size = 0, data = 0x1e0148e, clean = 0,
simpletext = 0, righttoleft = 0, asciiCache = 0, capacity = 0, reserved
= 0, array = {0}}, d = 0xb3aa2e18, static codecForCStrings = 0x0}
        profileName = DWARF-2 expression error: DW_OP_reg operations
must be used either alone or in conjuction with DW_OP_piece.

b.


-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 262 bytes
Desc: OpenPGP digital signature
Url : http://www.mythtv.org/pipermail/mythtv-users/attachments/20110729/bc6c89cf/attachment.bin 


More information about the mythtv-users mailing list