[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