[mythtv-users] High mysql cpu usage

Fri Mar 23 22:43:48 UTC 2012

I have been running the master branch for many months but over the last 
few weeks I have seen the system become very unresponsive. Unfortunately 
I can't say exactly when the problem started. When I looked at cpu usage 
it shows mysql at 100% usage for long periods of time.

The log below was produced with -v schedule.

2012-03-23 21:37:20.770916 I [24958/24985] Scheduler scheduler.cpp:2011 
(HandleReschedule) - Reschedule requested for id -1.
2012-03-23 21:37:20.775287 I [24958/24985] Scheduler scheduler.cpp:3345 
(UpdateMatches) - Query 0: /record.search = :NRST AND program.manualid = 
0 AND program.title = record.title
2012-03-23 21:37:20.775317 I [24958/24985] Scheduler scheduler.cpp:3345 
(UpdateMatches) - Query 1: /record.search = :NRST AND program.manualid = 
0 AND program.seriesid <> '' AND program.seriesid = record.seriesid
2012-03-23 21:37:20.775485 I [24958/24985] Scheduler scheduler.cpp:3406 
(UpdateMatches) -  |-- Start DB Query 0...
2012-03-23 21:37:20.849820 I [24958/24985] Scheduler scheduler.cpp:3431 
(UpdateMatches) -  |-- -1 results in 0.074297 sec.
2012-03-23 21:37:20.849932 I [24958/24985] Scheduler scheduler.cpp:3406 
(UpdateMatches) -  |-- Start DB Query 1...
2012-03-23 21:37:51.050528 I [24958/25333] DVBRead mythdbcon.cpp:453 
(CloseDatabases) - Closing DB connection named 'DBManager23'
2012-03-23 21:37:58.901735 I [24958/24985] Scheduler scheduler.cpp:3431 
(UpdateMatches) -  |-- -1 results in 38.0518 sec.
2012-03-23 21:37:58.901814 I [24958/24985] Scheduler scheduler.cpp:3435 
(UpdateMatches) -  +-- Done.
2012-03-23 21:37:58.903036 I [24958/24985] Scheduler scheduler.cpp:360 
(FillRecordList) - BuildWorkList...
2012-03-23 21:37:58.903049 I [24958/24985] Scheduler scheduler.cpp:365 
(FillRecordList) - AddNewRecords...
2012-03-23 21:37:58.988499 I [24958/24985] Scheduler scheduler.cpp:3792 
(AddNewRecords) -  |-- Start DB Query...
2012-03-23 21:37:59.301672 I [24958/24985] Scheduler scheduler.cpp:3813 
(AddNewRecords) -  |-- 596 results in 0.313128 sec. Processing...
2012-03-23 21:37:59.331165 I [24958/24985] Scheduler scheduler.cpp:3988 
(AddNewRecords) -  +-- Cleanup...
2012-03-23 21:37:59.331998 I [24958/24985] Scheduler scheduler.cpp:367 
(FillRecordList) - AddNotListed...
2012-03-23 21:37:59.332031 I [24958/24985] Scheduler scheduler.cpp:4038 
(AddNotListed) -  |-- Start DB Query...
2012-03-23 21:37:59.332747 I [24958/24985] Scheduler scheduler.cpp:4056 
(AddNotListed) -  |-- 0 results in 0.000698 sec. Processing...
2012-03-23 21:37:59.332791 I [24958/24985] Scheduler scheduler.cpp:370 
(FillRecordList) - Sort by time...
2012-03-23 21:37:59.333603 I [24958/24985] Scheduler scheduler.cpp:372 
(FillRecordList) - PruneOverlaps...
2012-03-23 21:37:59.333648 I [24958/24985] Scheduler scheduler.cpp:375 
(FillRecordList) - Sort by priority...
2012-03-23 21:37:59.378252 I [24958/24985] Scheduler scheduler.cpp:377 
(FillRecordList) - BuildListMaps...
2012-03-23 21:37:59.378513 I [24958/24985] Scheduler scheduler.cpp:379 
(FillRecordList) - SchedNewRecords...
2012-03-23 21:37:59.378517 I [24958/24985] Scheduler scheduler.cpp:1228 
(SchedNewRecords) - Scheduling:

### Lines not copied

2012-03-23 21:37:59.378687 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) -   +Click                             80 BBC NEW 24 
01:30-02:00  1 13 13  C 13 0/13
2012-03-23 21:37:59.378735 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) -   +Saturday Kitchen                   1 BBC ONE 24 
10:00-11:30  1 13 13  C 13 0/13
2012-03-23 21:37:59.378770 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) -   #This Morning - Saturday            3 ITV1    24 
11:20-12:25  1 13 13  C - 0/13
2012-03-23 21:37:59.378792 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) -      !Saturday Kitchen                1 BBC ONE 24 
10:00-11:30  1 13 13  C 13 0/13

### Similar lines not copied

2012-03-23 21:37:59.399954 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) - Narrow Boat Afloat - Knowle to Roy   38 QUEST   30 
13:30-14:00  1 0 0  C R 0
2012-03-23 21:37:59.399974 I [24958/24985] Scheduler scheduler.cpp:549 
(PrintRec) - New Tricks - Where There's Smoke      1 BBC ONE 30 
21:00-22:00  1 0 0  C P 0
2012-03-23 21:37:59.399977 I [24958/24985] Scheduler scheduler.cpp:516 
(PrintList) - ---  print list end  ---
2012-03-23 21:37:59.399994 I [24958/24985] Scheduler scheduler.cpp:2069 
(HandleReschedule) - Scheduled 55 items in 38.6 = 38.13 match + 0.49 place
2012-03-23 21:37:59.400459 I [24958/24985] Scheduler scheduler.cpp:1818 
(run) - sleeping for 60000 ms (interuptable)
2012-03-23 21:38:27.145753 I [24958/25370] DVBRead mythdbcon.cpp:75 
(MSqlDatabase) - Database connection created: DBManager24

As you can see from the above logs the scheduling run took approx 39 
secs and mysqld was showing 100% cpu usage for the whole time.

I have done all the mysql tuning suggested in previous messages and also 
run mysqltuner.pl but it hasn't helped. I have also "repaired" and 
"optimised" the database. The backend uses a AMD Athlon(tm) 64 X2 Dual 
Core Processor 5200+ with 2Gb of RAM so is not short of power.

Any ideas would be appreciated.

Thanks
Martin