06 July 2011, 2:32

We have recently hit a problem where ae are seing very slow login times and our mysql montoring tool is reporting database locks.

The last time I saw this the mysql slow query log whoed the following:

# Time: 110706  8:28:36# User@Host: root[root] @ localhost [127.0.0.1]# Query_time: 217.316672  Lock_time: 0.000000 Rows_sent: 6  Rows_examined: 109946use mahara;SET timestamp=1309937316;SELECT n.id, n.subject, n.message, n.url, n.urltext, n.read, t.name AS type                FROM "notification_internal_activity" n JOIN "activity_type" t ON n.type = t.id                WHERE n.usr = '1'                AND t.name IN ('feedback','groupmessage','institutionmessage','maharamessage','usermessage','viewaccess','watchlist')                ORDER BY n.ctime DESC                LIMIT 6;

Notice the very high query time. We haveing made any notable  changes recently other then upgrading to 1.4 and changing the site theme to aqua.

06 July 2011, 18:12

Dan, thanks for spotting that, we're having similar problems with slow logins on mahara.org, and it looks like it's the same query causing the problem on postgres as well.

06 July 2011, 22:42

Dan,

I asked Mark Kirkwood, our Postgres expert about it and he took a look at the query and tested out a few things.

Reading from notification_internal_activity is slow because the table tends to get quite big, and the records for any particular user end up scattered around all through it.

In theory the 1.4 upgrade should have improved things, because it installs a cron job to delete old notifications out of the table and should hugely reduce the total table size.  But the thing that really improved the performance was clustering the table on the usr index, so all the records for a user end up bunched together.  In postgres, the command to do it is "cluster notification_internal_activity using notiinteacti_usr_ix;", and I think we'll consider installing a cron job to run this every week or so.

In MySQL >= 5.1 he suggested using hash partitioning on the usr column of notification_internal_activity to achieve the same result.  I'm afraid I haven't tested that, and can't give you the exact commands yet, but if you're in a position to test it out and see if it delivers an improvement, we'd certainly be keen to add it into the next version of Mahara.

07 July 2011, 1:55

I've also been looking at this and the problem seems to stem from some regression in the mail handling in 1.4. 

Last night I deleted all the unread mail messages in the admin dashboard and this morning I have 1100 waiting for me to tell me that:

exception 'EmailException' with message 'Couldn't send email to Admin User (admin) with subject MKC Mahara: User notification error was probably caused by your server configuration..

Before the clear down I had 58,000 messages which probably accounts for the slow login.

The mailing issue is being discussed here:

http://mahara.org/interaction/forum/topic.php?id=3833#post16889

07 July 2011, 19:09

Just for completeness. The equivalant Mysql command to reorder the table is "alter table notification_internal_activity order by usr". Like its Postgres counterpart, it is invasive (blocks access while running)... and needs to be repeated regularly to reorder the new records. I had hoped to use partitioning, but the current implementation requires all unique keys use all of the partition columns - so we would have to partition on "id" (not useful) or drop the primary key (yuck) to use "usr".

It looks like the 1.4 cron to remove older entries actually helps the most (altho unfortunately not for Dan until he can tame the sheer volume of messages)!

21 July 2011, 10:00

I managed to solve this.

it was a borkeed email relay Once that was fixed and I'd cleared out all the thousands of stacked up emails to the admin then it all started working peachy