Slow question edition

Slow question edition

by Eduardo Hernandez -
Number of replies: 16
Hello!

I don't know if this is the forum to post this issue, but we are facing a perfomance problem while editing questions.

We run Moodle 1.6, MySQL 5.x, with almost 1,035 courses and 83,000 questions created; When you try to edit a question, it takes 10 seconds to display the question itself.  Any idea why question edition is being slow. Could it be an index issue?.

I think 83,000 questions is a lot of question, but not THAT big. We also have the internalmail module with more than 350,000 entries, and it is not slow.

Eduardo
Average of ratings: -
In reply to Eduardo Hernandez

Re: Slow question edition

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
This is a bug, and it would be really good to track down the root of the problem. It is probably a neccessary index missing from one of the database tables. Marting Langhoff, and the CatalystIT people have some code for logging slow page loads and slow database queries. Would it be possible for you to find out about these and get them enabled on your sever? Sorry, I don't know any more details than this.
In reply to Tim Hunt

Re: Slow question editing

by Michael Penney -
Hi Tim, we've been experiencing this here, as well, with >37,000 questions (MySQL 4.1.20, Moodle 1.5.4 + (2005060240)). We've been logging slow queries, with so far inconclusive results. I'll ask Jeff Graham (who has been working directly on this) to post what we have so far.

Thanks!
Michael
In reply to Michael Penney

Re: Slow question editing

by Jeff Graham -
From my observation the load seems to be entirely httpd, implying that php is the real culprit in this performance issue. We have not seen any related slow queries in mysql's slow query log. I have been watching this on my local machine and the load tanks out for httpd, mysql doesn't even show up in the top CPU users list when loading the edit question page.

12.996584 secs Included 42 files ticks: 1299 user: 984 sys: 68 cuser: 0 csys: 0 Load average: 0.25
11.081296 secs Included 42 files ticks: 1108 user: 963 sys: 66 cuser: 0 csys: 0 Load average: 0.44
11.265873 secs Included 42 files ticks: 1126 user: 979 sys: 67 cuser: 0 csys: 0 Load average: 0.51

Above are the moodle stats for loading a question to edit. This was on my local machine:
  • MySQL: 4.1.18
  • Moodle: 1.5.4+
  • PHP: 4.4.1
  • Apache: 1.3.33
  • Mac OSX:  10.4.7
  • iMac: 1.83 GHz Core Duo 1GB RAM

I'm real busy right now, but when I get a chance I will try to help narrow down the issue.
In reply to Jeff Graham

Re: Slow question editing

by Jeff Graham -
Hi Tim,

I think I have narrowed down the issue. For the above page stats there is a function call to "add_indented_names($categories);" that takes 11 seconds to run.

This is the problem function, its also recursive. mixed

From a quick scan of it, it seems reasonable that this could be considerably cleaned up. Also, it doesn't seem to make sense to call this funciton in this context, unless I'm missing something.

hope that helps; if you need any more info to help resolve this issue let me know.

regards,
Jeff
In reply to Jeff Graham

Re: Slow question editing

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
Thank you for narrowing it down.

I looked at the add_indented_names function myself a few months ago and had the same thoughts as you. (I also spotted there were bugs when your site had a published category whose parent was not published).

So I completely rewrote the function. Can you try getting the new implementation of that function (from 1.7dev, or indeed any release after 1.6.1) and its helper function flatten_category_tree() from just above it in questionlib, and seeing if it works in 1.5.x. I think it should. Then, more importantly, does it fix the performance problems.


(( Building hierarchical trees like this is one of the few things that relational databases really can't cope with very well, which is why it has to be done in PHP. I am pretty sure the new code is ONo in the number of categories, which is as good as you can get. ))
In reply to Tim Hunt

Re: Slow question editing

by Eduardo Hernandez -
Hi Tim,

I just wanted to share with you that today in our development server, I commented these lines:

/* if (!$categories = question_category_menu($course->id, false)) {
        error("No categories!");
 }*/

from question.php (line 260 aprox).

And the problem was solved,

I thought that after commeting these lines, I was going to be unable to see the combo box of categories while editing my question, however I still see the questions categories in the combo box as the picture as I posted in this thread.

Eduardo
In reply to Eduardo Hernandez

Re: Slow question editing

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
That line of code is entirely unnecessary.

I have removed it from 1.6.2+ and 1.7dev.

Tim.
In reply to Tim Hunt

Re: Slow question editing

by Jeff Graham -
Hi Tim,
Just did a fresh update from head, and grabbed the two mentioned functions replacing add_indented_names() in /mod/quiz/locallib.php.

The performance is a lot better, but still IMO slow. 2-3 seconds can seem like forever in front of a computer. wink

This update makes it a lot more usable though.

2.421563 secs Included 42 files ticks: 242 user: 138 sys: 61 cuser: 0 csys: 0 Load average: 0.35 
2.502905 secs Included 42 files ticks: 251 user: 140 sys: 60 cuser: 0 csys: 0 Load average: 0.27 
2.468266 secs Included 42 files ticks: 247 user: 139 sys: 61 cuser: 0 csys: 0 Load average: 0.39 
2.464595 secs Included 42 files ticks: 246 user: 139 sys: 61 cuser: 0 csys: 0 Load average: 0.33 
2.532676 secs Included 42 files ticks: 253 user: 141 sys: 62 cuser: 0 csys: 0 Load average: 0.35 
We're going live with the update on our production server. I will keep you posted of performance and see if I can give you any more information.
In reply to Jeff Graham

Re: Slow question editing

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
Thanks.
In reply to Tim Hunt

Re: Slow question editing

by Michael Penney -
Since the goal of the edit question screen is a quick edit of a single question and there already is a way to move questions from one category to another, I'd say that rendering the categories on this screen is a non-essential (maybe even confusing) feature.

IOW, maybe we are trying to fix a broken idea?
In reply to Michael Penney

Re: Slow question editing

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers
I know the general principle of UI design, that giving people two ways to do one task is confusing and actually slows them down. But in this specific case, I think the two ways of changing a question category are sufficiently different that they are not confusing, and they are both useful in different circumstances, so I think we should keep them both.

I am sure that it should not take more than a few hundred milliseconds to get the list of all the categories.

No one has said whether they have a lot of publised course categories. With a lot of published categores, question_category_coursename() function will querying the database once for each published category. That is really bad. It would be better to use a join to get the coursename.

Are you able to try the attached patch on your system, and see whether it makes a difference? If so, I'll check it in. The patch is against 1.6.2+. I hope it makes sense in the 1.5.x context. Thanks.
In reply to Jeff Graham

Re: Slow question editing

by Eduardo Hernandez -
Hi Jeff,

We have a couple of developers who can help to track this issue. We will take a look at the code. Today we took the production DB to our development machine, and being the only user connected (as teacher) to our development machine, the edition was slow.

If there's any suggestion or comment on how to proceed with this issue; we thank in advance.

Eduardo
In reply to Eduardo Hernandez

Re: Slow question editing

by Jeff Graham -
Hi Eduardo,

It since the add_indented_names() function is causing the issue (at least with my setup) it seems that should be the place to look.

I only quickly glanced over the code and noticed two issues;
  • I don't understand what the purpose of this function is when editing a question. It seems that this function should only show up on the "Edit Quiz" add/import a question page and when you are editing categories.  Does add_indented_names() even need to be called when we are actually editing a question? Why does it take so much longer in this context? Is it being passed the wrong parameter... I think this seems reasonable thoughtful
  • If the above is not a fix... It seems that the logic in this function could be cleaned up. Keep in mind I only took a quick look at the code.
    • Does it really need to be recursive?
    • If necessary storing the nesting depth, and adding an appropriate number of spaces for the category could be a simple fix.
    • Limit the category nesting level, might break existing installs.
Just a few ideas for resolving the issue. The first option should definitely be pursued first.


Slightly off topic a UI issue concerning the category drop down box; it is different between the "Edit Quiz" and "Edit Categories" screens. (at least in 1.5.4+)

I can check against head, but don't currently have a populated database for head, let me know if you need current information on any of the above.
In reply to Jeff Graham

Re: Slow question editing

by Eduardo Hernandez -
Hi Jeff,

When you are editing a question, the first field is a combo box with the available categories, showing them in a hierarchy; That explains the recursive calls. Please see my image below. (Spanish interface). So, probably it is an issue on how this category tree is generated.



Attachment foro.jpg
In reply to Eduardo Hernandez

Re: Slow question editing

by Jeff Graham -
Eduardo,

Thanks for pointing that out.

Then my question is why does that function call take so long? That same combo box is displayed on the "Edit Quiz" tab where the categories are in the upper right. That page loads very quickly on our system. It is not until you try to edit a question that the page load time is slow.

Just posing questions as that is all I have the time for right now, and it looks like the investigation may take some time. big grin
In reply to Tim Hunt

Re: Slow question edition

by Eduardo Hernandez -
Tim,

Thanks for your reply. If there's any thing we can do to track this issue, we are happy help. Let's see what Graham can say.

Today we realized that when you click on the edit icon it is the httpd process that takes 99% of the CPU time, and not mysqld.. I really don't know if this could lead to a PHP issue.

Eduardo