[Building Sakai] MFR_MESSAGE_T table performance enhancement

[Kyong Kim]

Earle,
I had a question.
Can you reproduce the same profile consistently?
InnoDB performs very differently depending on what's residing in the cache.
I'm wondering if you can profile the same query and see different results.
Thanks for the link on the profiler.
It's a neat new feature.
Kyong

At 10:53 AM 4/27/2009, Earle Nietzel wrote:
>Thanks for the info Kyong.
>
>I am using MySQL 5.0.45 from RHEL5 (x86_64), 4x2.33GHz (2 Dual Core's) with
>8GB RAM.
>innodb_buffer_pool_size = 6000M
>The database resides on a SAN so I should be getting decent I/O from it.
>
>The profiler was a nice feature added to mysql since 5.0.37, you can check
>it out here:
>http://dev.mysql.com/tech-resources/articles/using-new-query-profiler.html
>
>Earle
>
>
>-----"Kyong Kim" <kimkyong at fhda.edu> wrote: -----
>
>To: "Earle Nietzel" <Earle.Nietzel at marist.edu>
>From: "Kyong Kim" <kimkyong at fhda.edu>
>Date: 04/24/2009 07:37PM
>cc: sakai-dev at collab.sakaiproject.org
>Subject: Re: [Building Sakai] MFR_MESSAGE_T table performance enhancement
>
>Which profiler are you using? Are you running on MySQL or Oracle?
>It's nice to be able to see the time measurements. I normally use EXPLAIN
>on MySQL which also gives very nice output to see how the optimizer is
>choosing to execute the query but it doesn't give such fine grained time
>measurements.
>
>On MySQL, you might even consider a multi-column covering index approach
>to reduce i/o's on index scanning. The downside is the covering indexes
>are likely to get fairly large for larger tables and you might end up
>starving the buffer pool. I always wondered about the size of some of the
>secondary indexes of Sakai on InnoDB. I know for sure I saw some ugly key
>lengths being used. You would need to throw a lot of RAM to innodb buffer
>pool for consistent index and table data caching.
>
>There was an interesting presentation on indexes at the MySQL conference.
>I don't know if it applies to Oracle but...it really opened my eyes. Take
>a look at the random i/o's required for different types of scanning. Some
>of the benchmark numbers on SSD are pretty out of this world.
>
>http://assets.en.oreilly.com/1/event/21/Mastering%20the%20Art%20of%20Indexing%20Presentation.pdf
>
>
>Kyong
>
>
>
> >
> > Found a query that was appearing in our slow query log rather frequently
> > recently and did some testing with the mysql profiler tool and found a
> > speed up for the MFR_MESSAGE_T table.
> >
> > The query in question is a rather large query but i will list the
> > important
> >    pieces:
> >    select ..... (left out for to save space)
> >    from MFR_MESSAGE_T privatemes0_ left outer join MFR_PVT_MSG_USR_T
> >    recipients1_ on privatemes0_.ID=recipients1_.messageSurrogateKey
> >    where privatemes0_.MESSAGE_DTYPE='PM' and
> >    recipients1_.USER_ID='27024526-9c61-4cef-9fd4-0840b52a300b' and
> >    recipients1_.TYPE_UUID='e6d3664d-d75e-46c0-00f1-81cf3288a29e' and
> >    recipients1_.CONTEXT_ID='a722e35d-ca3f-4192-a5de-0f2444a40b27'
> >    order by privatemes0_.CREATED desc;
> >
> > This query produce the following profiler ouput:
> >
> > +--------------------+-----------+
> > | Status             | Duration  |
> > +--------------------+-----------+
> > | (initialization)   | 0.000001  |
> > | Opening tables     | 0.00001   |
> > | System lock        | 0.000004  |
> > | Table lock         | 0.000005  |
> > | init               | 0.0000660 |
> > | optimizing         | 0.00002   |
> > | statistics         | 0.000025  |
> > | preparing          | 0.000014  |
> > | executing          | 0.000002  |
> > | Sorting result     | 0.539899  |
> > | Sending data       | 1.096705  |
> > | end                | 0.000011  |
> > | query end          | 0.000004  |
> > | freeing items      | 0.000019  |
> > | closing tables     | 0.000005  |
> > | logging slow query | 0.000002  |
> > +--------------------+-----------+
> >
> > Notice the Sorting result took approx .54 seconds everything else appears
> > to be normal.
> >
> > After adding the following index:
> >
> > create index MFR_MESSAGE_T_CREATED_I on MFR_MESSAGE_T (CREATED);
> >
> > The profiler then shows that Sorting was reduced to 0.000005 and the
> > overall query was reduced by .5 seconds.
> >
> > +--------------------+----------+
> > | Status             | Duration |
> > +--------------------+----------+
> > | (initialization)   | 0.000001 |
> > | Opening tables     | 0.00001  |
> > | System lock        | 0.000003 |
> > | Table lock         | 0.000006 |
> > | init               | 0.000072 |
> > | optimizing         | 0.000021 |
> > | statistics         | 0.000029 |
> > | preparing          | 0.000017 |
> > | executing          | 0.000002 |
> > | Sorting result     | 0.000005 |
> > |*Sending data       | 1.444712 |
> > | end                | 0.000012 |
> > | query end          | 0.000003 |
> > | freeing items      | 0.000019 |
> > | closing tables     | 0.000006 |
> > | logging slow query | 0.000002 |
> > +--------------------+----------+
> >
> > *note although the sending data time did go up i believe that to be
>linked
> > to the client I am using as I have seen varying times depending on the
> > client that is used.
> >
> > Comments are welcome,
> >
> > Earle
> >
> > _______________________________________________
> > sakai-dev mailing list
> > sakai-dev at collab.sakaiproject.org
> > http://collab.sakaiproject.org/mailman/listinfo/sakai-dev
> >
> > TO UNSUBSCRIBE: send email to
> > sakai-dev-unsubscribe at collab.sakaiproject.org with a subject of
> > "unsubscribe"
> >
>
>
>Inst. Web Programmer
>CMDBA 5.0


Kyong Kim
Instructional Multimedia/Web Programmer
Foothill College
12345 El Monte Rd
3601
Los Altos Hills, CA 94022
650-949-7091