Issue Details (XML | Word | Printable)

Key: MDL-14911
Type: Bug Bug
Status: Open Open
Priority: Major Major
Assignee: Eloy Lafuente (stronk7)
Reporter: Ian Ralph
Votes: 9
Watchers: 15
Operations

Add/Edit UI Mockup to this issue
If you were logged in you would be able to see more operations.
Moodle

Database Module causes mysql-max process to hog CPU after upgrade from 1.8 to 1.9

Created: 20/May/08 06:06 AM   Updated: 17/Nov/09 03:52 AM
Component/s: Database activity module
Affects Version/s: 1.9
Fix Version/s: None

File Attachments: 1. Text File test-query.txt (1 kB)

Environment: This behaviour has been see in my environment: SuSe Linux 10.1 running MySQL v5.0.26, php v5.1.2 and Joann Poock's ebvironment: Windows Server 2003 running MySQL v4.1.22, and php v4.4.0.

Database: MySQL
Participants: A.J. Colianni, Anthony Borrow, Doug Holton, Eloy Lafuente (stronk7), Harry Smith, Helen Foster, Ian Ralph, Jerome Charaoui, Lewis Carr, Martin Dougiamas, Matthew West, Petr Škoda (skodak), Ryan Kelley, Tomasz Muras and Tuttle, James
Security Level: None
Affected Branches: MOODLE_19_STABLE


 Description  « Hide
After an upgrade of our instance of Moodle from 1.8 to 1.9 (Build 20080423) a very simple database, created with the "database Module" in V1.8, with 8 text fields and 12 records takes 12.4 seconds to move between one record and the next one in Single View. In a slightly larger database of about 50 fields and 120 records, the time is up to 30s

To investigate this behaviour I opened one of the simple databases we have created using the database module in v1.8. I then went to Single View and attempted to move from one record to the next. On the server I used Top (http://linux.about.com/od/commands/l/blcmdl1_top.htm) to watch the processes and the % of CPU usage each process is using. The process "mysql-max" hogs the processor and it peaks at 100% for the duration of any activity related to the database created using the Database module.

It may take up to 30 seconds before processor usage by mysql-max returns to <1%. No other activity in Moodle has the same effect - for example opening a "survey" shows mysql-max taking 1% of the processor's capacity.

Another user, Joann Poock, has also seen this behaviour - for Joann the server effectively hangs whenever she does anything related to displaying and organising data created using the Database Module. The only way she can resolve the "hang" is by re-booting the server. Joann reports that the problem affects databases created using the Database module in v1.9 as well as those created in v1.8.

Neither Joann nor I find any other functionality of our instances of Moodle are impared after upgrading from 1.8 to 1.9

Ian



 All   Comments   Change History   Version Control      Sort Order: Ascending order - Click to sort in descending order
Martin Dougiamas added a comment - 20/May/08 09:55 AM
OK, that's odd.

You can see http://moodle.org/modules for an example of a perfectly fast Database activity with quite a few records so the reported problem is not endemic.

Something else is going on ... perhaps a tuning problem. Your system might be running out of memory during this operation and the operating system is paging.

Can you post your MySQL configuration (my.cnf) as well as information about your CPU and RAM?


Helen Foster added a comment - 20/May/08 03:04 PM

Harry Smith added a comment - 10/Jul/08 09:02 AM
Hi folks

Just found out I have the same problem on one of my sites. Started as Moodle 1.6, upgraded to 1.9 (did a CVS update last night).

Server specs:
8 x Intel Xeon E5310 processors (1.6GHz)
4GB
2 x 250GB harddrives
CENTOS Enterprise 4.5
PHP 5.1.6
MySQL 4.1.22
Apache 1.3.37

Problem:

  • I've got three databases that where all set up within a day or two max.
  • None of them are large (17, 30, and 4 entries)
  • The database with 17 entries is fine, no problem at all so far.
  • The other two are killing me.
  • While investigating, it was averaging 5-7 minutes from clicking the database name to the list view showing (if it actually did, most of yesterday it tried for 5+ minutes then said "done" but no listings).
  • Averaging 5-10 minutes trying to get to single view, if it showed up.
  • When it was trying to load it was hitting the CPU at 100%

After hunting on the forums, found this tracker entry and followed Ian's advice re Top (no real idea what I was looking at though!). I did a screen capture of trying the three databases if it helps, it can be viewed at http://filexchange.cfals.info/emcp_database/emcp_database.html It quite clearly shows CPU at 100% on the dodgy ones, RAM only using about 2/3 max and the load difference between the good and the bad.

Had a look at "my.cnf" that Martin mentioned, contents of that file:

[mysqld]
set-variable = max_connections=500
safe-show-database

Have not hit this problem on any of my other installs (another 4, all followed the same upgrade path e.g. jumping from 1.6+ to 1.9+). Unfortunately, the site in question is one I am trying to get up and going for collaboration across various emergency service organisations.

The uptake has been reluctant and very slow (most of the entries in the databases are dummy entries to try and get them using it). It is not a high traffic site but I have the guy who's supposed to be running the project coming for a meeting next week - it was he who raised the issue of it being that slow it's unusable

Any ideas on where the problem lies would be much appreciated.

Regards
H


Harry Smith added a comment - 10/Jul/08 09:06 AM
Sorry folks . . . just to clarify, by "did a CVS update last night" I meant that to show it was the latest version. The site's where all upgraded about a couple of weeks before 1.9 went gold.

I did reread before posting, my excuse is I worked through the night and kinda tired!


Anthony Borrow added a comment - 10/Jul/08 08:49 PM
I would also want to see the database structure for the data tables in the new database just to make sure something strange didn't happen during the upgrade. Next I would want a look at the mysql logs to see what it is doing when it is maxed out. Peace - Anthony

Harry Smith added a comment - 11/Jul/08 12:19 PM
I'll look into the areas that Anthony mentioned over the weekend (can't do much from work due to firewalls).

In the meantime, turned on "Performance info" on the live site and an old test site that I thought I had decommisioned (test site was a snapshot of the live before doing the upgrade).

The test site is still running 1.9 Beta 4 and has 23 less entries in one of the affected databases (27 as opposed to 30 on the live site). The performance results for clicking the database name are interesting.

Test site:
1.428711 secs
Included 54 files
ticks: 143 user: 27 sys: 5 cuser: 0 csys: 0
Load average: 0.48
Record cache hit/miss ratio : 0/0

Live site:
216.307581 secs
Included 66 files
ticks: 21631 user: 31 sys: 5 cuser: 0 csys: 0
Load average: 0.99
Record cache hit/miss ratio : 0/0

I really need to figure out exactly what all that means Thing that jumps out immediately is the discrepancy in "ticks" which I assume is the culprit?


Harry Smith added a comment - 11/Jul/08 12:21 PM
Sorry (wish there was an edit button):

"23 less entries" = "3 less entries"


Harry Smith added a comment - 16/Jul/08 02:45 PM
Hi folks

Sorry to be a pain but got the "project owner" coming tomorrow (from another organisation so a bit embarrasing).

Not having much luck tracking anything down, any pointers as to tracking down why the huge jump from 143 to 2163 ticks would be much appreciated.

Regards
H


A.J. Colianni added a comment - 15/Aug/08 04:34 AM
I'm seeing the exact same issue here on our recently upgraded to 1.9 server. The server is a quad-core intel XServe running 10.5.x (have to verify-- i think it is on 10.5.4)

Here's the environment details:
Name Information Report Status
moodle version 1.0 is required and you are running 1.9.2 OK
unicode must be installed and enabled OK
database mysql version 4.1.16 is required and you are running 5.0.45 OK
php version 4.3.0 is required and you are running 5.2.4 OK
php_extension iconv should be installed and enabled for best results OK
php_extension mbstring should be installed and enabled for best results OK
php_extension curl should be installed and enabled for best results OK
php_extension openssl should be installed and enabled for best results OK
php_extension tokenizer should be installed and enabled for best results OK
php_extension xmlrpc should be installed and enabled for best results OK
php_extension ctype should be installed and enabled for best results OK

What else can I post that might be helpful?


Matthew West added a comment - 20/Aug/08 05:39 AM
Hi All,

I am also experiencing this problem. As soon as anyone hits the database, the mysql process on one of our processors sits at around 25% until the database loads. It then drops back to normal.

Check
moodle version 1.0 is required and you are running 1.9.2 OK
unicode must be installed and enabled OK
database mysql version 4.1.16 is required and you are running 5.0.24 OK
php version 4.3.0 is required and you are running 5.2.0 OK
php_extension iconv should be installed and enabled for best results OK
php_extension mbstring should be installed and enabled for best results OK
php_extension tokenizer should be installed and enabled for best results OK
php_extension ctype should be installed and enabled for best results OK

I'm running this on a Solaris 10 box using Apache 2, PHP 5, and MySQL 5. Please let me know if I can be of any help.

Thanks,

Matthew


Petr Škoda (skodak) added a comment - 20/Aug/08 06:05 AM
Could you please try the next weekly build (tomorrow)? it should be already fixed for some time I think.

A.J. Colianni added a comment - 20/Aug/08 10:23 AM
Our server was running the latest weekly build as of yesterday and was still exhibiting the issue, so unless it has been fixed in the past week?, we are still seeing the problem.

At this time we have reverted our server back to the 1.8.6+ release.


Petr Škoda (skodak) added a comment - 20/Aug/08 03:16 PM
hmm, the change I was talking about was done some weeks ago

Tuttle, James added a comment - 30/Aug/08 10:34 PM
We are seeing this behavior on only some of our databases. We have a database that we have been using for about 2 years, with hundreds of entries, that is not affected, however, new databases we have created since we upgraded from 1.8.3 to 1.9.2 are suffering from this issue.

We are running the Moodle build released just a few days ago on Windows Server 2003, Apache 2.2.9, PHP 5.2.6, and MySQL 5.0.51b. Our box is a Dell PowerEdge 2950 with two dual-core Intel Xeon processors running at 2.00 GHz, with 4 GB of RAM.

I have a database with 5 dummy entries in a relatively simple structure (less than 10 fields), and I put it to the Windows Performance Monitor to see what was happening. The main counters I used were

Memory

Page Faults /sec
Page Reads/sec
Page Writes/sec
Pages/sec

PhysicalDisk
Avg. Disk Queue Length
Current Disk Queue Length
Disk Reads/sec
Disk Writes/sec

Processor
% Processor Time (separate entry for each core)

When clicking on the database it takes about a minute for any entries to show up. In that minute, the processor activity takes turns between the cores hitting between 75-100% (though most of the activity stays on one of the cores), but there is almost no disk activity or memory paging at all, (referring to Martin's question above about paging). I can't figure out what the processor is doing all that time, but it doesn't appear to be waiting for memory or disk activity.


Tuttle, James added a comment - 04/Sep/08 10:33 PM
I was working on another Moodle database today, one that was not suffering from this issue. I had created all my fields & templates, and even added an entry. The database was behaving quite well until I decided to delete a text field & replace it with a URL field instead. I updated all my templates to reflect the change, but when I went to "View List" so that I could edit my one entry that I had already put in, I was presented with the long wait for entry display. Up until this point, the database had been behaving quite fast.

Now, however, could it be that the system is getting hung up because I have a database entry that refers to data in a field that no longer exists?

Alas, even after editing my entry & putting data into the correct field, my long wait persists. I thought maybe it was looking for that ghost data in the field I deleted.

I did some MySQL queries on the actual data that exists in the database, and the fields & entries I deleted are indeed gone...but ever since I deleted that database field & put a new one in, database operations have become very slow.


Tuttle, James added a comment - 18/Sep/08 01:50 AM
In a test environment, I pulled the database module out of the latest 1.8.6 download, and over-wrote the database module in my 1.9 install with the older code. I then modified the version.php so my Administration module wouldn't complain.

My databases immediately returned to their former speedy operation.

Anyone know of any problems I'd encounter in this scenario?


Eloy Lafuente (stronk7) added a comment - 18/Sep/08 04:19 PM
Hi James,

just to be 100% sure. Can you paste here the first line of your mod/data/view.php file ? Should be something like this:

<?php // $Id: view.php,v 1.70.2.23 2008/04/21 14:15:30 skodak Exp $

TIA and ciao


Tuttle, James added a comment - 19/Sep/08 03:35 AM
Here is the first line of my view.php file:

<?php // $Id: view.php,v 1.56.2.8 2008/03/31 06:18:11 nicolasconnault Exp $


Eloy Lafuente (stronk7) added a comment - 19/Sep/08 05:57 AM
Sorry James, but that's the version corresponding to Moodle 1.8. I wanted to know the 1.9 version you were using.

Tuttle, James added a comment - 19/Sep/08 07:49 PM
My apologies. Here is the version of the database module we were using prior to the "downgrade."

<?php // $Id: view.php,v 1.70.2.24 2008/07/18 07:49:27 moodler Exp $


Tomasz Muras added a comment - 23/Sep/08 07:21 PM
We had the same problem and we have tracked it to the missing indices in MySQL database.

Tuttle, James added a comment - 24/Sep/08 08:16 PM
Yes! This has fixed our problem. Once I created the missing indices, I put the 1.9 database back in, and now it's even faster than the 1.8 version was.

I'm not sure how I ended up with these missing indices, but we've been upgrading this installation since 1.4, so it's been through a few rounds. Thanks for your solution. I hope it benefits many others as well!


A.J. Colianni added a comment - 24/Sep/08 08:48 PM
Which indices did you find to be missing? I will test this out on our test server and report back.

Thank you for your work!


A.J. Colianni added a comment - 24/Sep/08 08:50 PM
Oh, I went back to the forum discussion linked above to find your answer Tomasz, thank you.

The solution noted in the forum is:

As an admin go to:
Site Administration -> Miscellaneous -> XMLDB editor and click on [Check Indexes] to see if it's the same problem.
If yes - create the missing indices.


Lewis Carr added a comment - 13/Jan/09 09:24 PM
I have the same problem with Moodle 1.9. The CPU will max out when several searches are run at once. The only solution is to restart the server.
We run a Windows Apache MySQL config with 4 gig RAM. Other than this our Moodle installation is very very fast considering its large size.
We have no missing indices and I'm at a loss as what to do. Our install was upgraded to 1.9 from 1.8 and since then the problem has been apparent.

Jerome Charaoui added a comment - 10/Feb/09 07:15 AM
I can confirm this issue here using Moodle 1.9.1+ (Build: 20080625). When performing a very simple (one or two fields) search in a small database of about 50 entries, it works but there is a noticeable 4-5 second delay. However, filling more fields in the search form dramatically increases the time required for the query to complete. At worst, this causes MySQL to completely hang for an indefinite amount of time, rendering the Moodle site completely inaccessible.

Doug Holton added a comment - 14/Feb/09 02:37 AM
I'm also seeing indefinite hangs, rendering the site inaccessible

Anthony Borrow added a comment - 14/Feb/09 02:50 AM
Doug, Lewis and Jerome - Please make sure you are running the latest weekly version (1.9.4+) and then do the index check. If you are still having troubles let me know and I will do what I can to help out. If possible tail your mysql logs to see exactly which query is causing the problem. That will help us to track down what might be happening. Peace - Anthony

Lewis Carr added a comment - 17/Feb/09 08:45 PM
I can't upgrade our production server at the moment but I'll install a test site, replicate the issue and get back to you.
In the mean time I have solved the problem by making a small change to the code. I have replaced the select distinct with a select * statement, obviously I have lost pagination but results are returned instantly with no load on the CPU.

Jerome Charaoui added a comment - 03/Jul/09 09:46 PM
I just tested for this problem with version 20090629 and it's still happening. I'm attaching a text file containing an example query, where I'm doing a search using 9 fields in a database activity module with less than 100 entries. Launching the search produces this query, which in turn causes MySQL to top 100% cpu usage for an unreasonable amount of time.

Ryan Kelley added a comment - 05/Oct/09 09:11 PM
We are also having this issue. I have upgraded Moodle and xampp to the latest versions. (xampp 1.7.2). I am running this on linux in VMware.

Once we have about 20 users log into Moodle our CPU spikes to 100%. The memory seems to be ok. The process that is causing the high load is httpd.

I am running out of ideas and soon we will have about 3000 users on the system. Which is a problem since 20 users are overloading it right now. Moodle was working just fine on verson 1.8 last year. I would downgrade if I was not worried about database issues.


A.J. Colianni added a comment - 06/Oct/09 09:57 PM
Ryan-

do the index check and see what that gives you... totally cleared up the problem for us:

Administration ? Miscellaneous ? XMLDB editor - check indicies


Ryan Kelley added a comment - 06/Oct/09 10:30 PM
Thank you for the reply.
I did run the check index and it found a problem with a log table. I fixed that a couple of weeks ago and still have this issue. I rechecked it today and it is showing no errors.

Jerome Charaoui added a comment - 17/Nov/09 03:52 AM
Recently upgraded to Moodle 1.9.6+ (Build: 20091112), in the hopes of seeing this bug resolved. It's not, and our Database module is virtually useless since we have to keep the search function disabled. The cause and symptom is exactly the same from when I previously commented this issue.

I'm willing to help test any kind of proposed solution for this.