"recent conversations" screen slow to load

"recent conversations" screen slow to load

by David Rogers -
Number of replies: 5

I'm running Moodle 2.9.2+ (Build: 20151002) on a dedicated Intel Xeon 8 core 8GB RAM machine running PHP 5.5.30/Apache 2.4.16/MySQL 5.5.45 on CentOS 2.6.32-573.7.1.el6.x86_64.  InnoDB buffer pool is set to 5GB and the database is 3.7GB in size, and OpCache is enabled.


The site is running great with one exception. For a user that has 1500+ messages, loading the "recent conversation" screen causes a very slow page load, up to a minute. Strangely, reloading that page, which should be cached, remains slow. The mysqld process pegs at 100% while working to load this screen. Typical utilization is under 10%.


Any thoughts what might be causing this problem, and how to fix it?

Average of ratings: Useful (1)
In reply to David Rogers

Re: "recent conversations" screen slow to load

by Thiago Araujo -

I have the same problem, any suggestions?

Average of ratings: Useful (1)
In reply to Thiago Araujo

Re: "recent conversations" screen slow to load

by Tim Hunt -
Picture of Core developers Picture of Documentation writers Picture of Particularly helpful Moodlers Picture of Peer reviewers Picture of Plugin developers

The general procedure in these cases looks like this:

  1. Find the query that is running slowly. (Some databases have the option to log any particularly slow queries.
  2. Re-run the query directly on the database server and EXPLAIN it.
  3. Baded on what you learn there, take appropriate action. (Could be a performance bug fix to Moodle, which might involve changing the query to perform better, or adding an index to a table. Alternatively, there might be a configuration change needed on your database server.)
Average of ratings: Useful (1)
In reply to Tim Hunt

Re: "recent conversations" screen slow to load

by David Rogers -

This is the slow query, executed every time /message/index.php?viewing=recentconversations is loaded:

SELECT Concat(message.useridfrom, '-', message.useridto), 
       otheruser.id, 
       otheruser.picture, 
       otheruser.firstname, 
       otheruser.lastname, 
       otheruser.firstnamephonetic, 
       otheruser.lastnamephonetic, 
       otheruser.middlename, 
       otheruser.alternatename, 
       otheruser.imagealt, 
       otheruser.email, 
       otheruser.lastaccess, 
       message.id AS mid, 
       message.notification, 
       message.smallmessage, 
       message.fullmessage, 
       message.fullmessagehtml, 
       message.fullmessageformat, 
       message.timecreated, 
       contact.id AS contactlistid, 
       contact.blocked 
FROM   mdl_message_read message 
       JOIN (SELECT Max(id) AS messageid, 
                    matchedmessage.useridto, 
                    matchedmessage.useridfrom 
             FROM   mdl_message_read matchedmessage 
                    INNER JOIN (SELECT Max(recentmessages.timecreated) 
                                       timecreated, 
                                       recentmessages.useridfrom, 
                                       recentmessages.useridto 
                                FROM   mdl_message_read recentmessages 
                                WHERE  ( recentmessages.useridfrom = '2467' 
                                          OR recentmessages.useridto = '2467' ) 
                                GROUP  BY recentmessages.useridfrom, 
                                          recentmessages.useridto) recent 
                            ON matchedmessage.useridto = recent.useridto 
                               AND matchedmessage.useridfrom = recent.useridfrom 
                               AND matchedmessage.timecreated = 
                                   recent.timecreated 
             GROUP  BY matchedmessage.useridto, 
                       matchedmessage.useridfrom) messagesubset 
         ON messagesubset.messageid = message.id 
       JOIN mdl_user otheruser 
         ON ( message.useridfrom = '2467' 
              AND message.useridto = otheruser.id ) 
             OR ( message.useridto = '2467' 
                  AND message.useridfrom = otheruser.id ) 
       LEFT JOIN mdl_message_contacts contact 
              ON contact.userid = '2467' 
                 AND contact.userid = otheruser.id 
WHERE  otheruser.deleted = 0 
       AND message.notification = 0 
ORDER  BY message.timecreated DESC 
LIMIT  0, 100 ;

And this is the explain:


+----+-------------+----------------+--------+-----------------------------------------------------+-------------------------+---------+-----------------------------------+-------+---------------------------------+
| id | select_type | table          | type   | possible_keys                                       | key                     | key_len | ref                               | rows  | Extra                           |
+----+-------------+----------------+--------+-----------------------------------------------------+-------------------------+---------+-----------------------------------+-------+---------------------------------+
|  1 | PRIMARY     | <derived2>     | ALL    | NULL                                                | NULL                    | NULL    | NULL                              |  1810 | Using temporary; Using filesort |
|  1 | PRIMARY     | otheruser      | range  | PRIMARY,mdl_user_del_ix                             | mdl_user_del_ix         | 1       | NULL                              |  5607 | Using where; Using join buffer  |
|  1 | PRIMARY     | contact        | ref    | mdl_messcont_usecon_uix                             | mdl_messcont_usecon_uix | 8       | const                             |     3 |                                 |
|  1 | PRIMARY     | message        | eq_ref | PRIMARY,mdl_messread_use2_ix,mdl_messread_useuse_ix | PRIMARY                 | 8       | messagesubset.messageid           |     1 | Using where                     |
|  2 | DERIVED     | <derived3>     | ALL    | NULL                                                | NULL                    | NULL    | NULL                              |  1810 | Using temporary; Using filesort |
|  2 | DERIVED     | matchedmessage | ref    | mdl_messread_use2_ix,mdl_messread_useuse_ix         | mdl_messread_useuse_ix  | 16      | recent.useridfrom,recent.useridto |     1 | Using where                     |
|  3 | DERIVED     | recentmessages | index  | mdl_messread_use2_ix,mdl_messread_useuse_ix         | mdl_messread_useuse_ix  | 16      | NULL                              | 25175 | Using where                     |
+----+-------------+----------------+--------+-----------------------------------------------------+-------------------------+---------+-----------------------------------+-------+---------------------------------+
7 rows in set (0.05 sec)


In reply to David Rogers

Re: "recent conversations" screen slow to load

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 query comes from around like 700 of message/lib.php. It has been changed several time to try to improve performance, e.g. MDL-45594 and most recently MDL-48108. (That last fix was in 2.9, and that seems to be the version of the code you have.)

Seems the problem is still not 100% solved. sad

Average of ratings: Useful (1)