Re: [WWdevel] speed of WeBWorK/mysql

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

Hi Arnie,

I haven't heard of student complaints, but I have had a couple from 
instructors.  We used all "sql" last semester and "sql_single" this 
semester.  I was just starting to look at this.  My guess is that the 
difference for us is related to database indexing.  Last semester, I had 
my own patch to index the tables.  Some of them looked like they needed 
multiple indexes.  Looking at the code, it looks like sql_single does 
one multi-index per table.  For some tables, this is not going to be 
enough.  In other cases, it is possible it isn't building the "right" 
multi-index.

My understanding of the multi-indexes is like this.  If you index off of 
fields user_id, set_id (in that order, it will basically build strings 
of the user_id and the set_id, possibly with a separator in between, and 
keeps a sorted list of them.  It can then binary search this list.  Then 
the lookups are fast if you provide the user_id, or if you provide the 
user_id and the set_id.  But, if you only provide the set_id the index 
is not used, and mysql goes linearly through the table.  The more 
entries in the table, of course, the longer it takes.

To test this, I plan to redo the indexes on some tables by hand, and 
then see if operations in that course get faster.  If this is right, 
then I think webwork will need to store information about what indexes 
to build, maybe in DB/Record/*.pm.

John

Arnold Pizer wrote:

> Hi John et al,
>
> My students in MTH 162 are seeing a significant slowdown in WeBWorK 
> this semester and I'm not sure what is going on.  I'm wondering if any 
> of you have seen similar things or if the symptoms bring to mind what 
> the problem might be.  What my students report is that "WeBWorK has 
> been getting progressively slower every week".  I copied below a bit 
> of the timing log from last Sunday night (162 hw is due early Monday 
> morning) and it shows that 162 requests are taking 30 or 40 seconds!  
> The fewer number of requests form other courses were generally under10 
> seconds.  MTH 162 is the largest course this semester with about 275 
> students.  Also this semester all courses are using sql_single.  Last 
> semester all but one course used gdbm  (with  WeBWorK 2) and 97% of 
> requests took 0 or 1 second.  Also the fall courses are larger than 
> the spring courses. In particular, the largest course last semester 
> (161) was larger than 162 is now and it used gdbm.   Early in the 
> semester we had a problem with the mysql log filling up the var 
> partition but that doesn't seem to be the problem now.   162 is using 
> exactly the same problem sets that have  been used for the past 2 
> years, so that's not the problem.  Also the fact that students report 
> the problem is getting worst every week seems to rule out server 
> problems.  I assume the table size for mth162 is increasing every week 
> --- could this be relevant?  What else could cause the problem to get 
> progressively worst?  When I looked at the output from top, I saw that 
> the load was about 1 (i.e. not excessive), mysql was taking almost 100 
> % of the cpu, the http processes were taking very little cpu, and no 
> process was using a lot of memory (this is from memory --- I didn't 
> make a copy of the out put).
>
> If we are seeing this problem at Rochester, it hard to believe others 
> will not see it in the future.  If others are not seeing it  yet, 
> maybe it has to do with how mysql is configured here.  Are we and 
> others using a "standard" mysql configuration?
>
> Below is a bit of the timing log.
>
> Arnie
>
>
> [Sun Feb 27 21:17:47 2005] 71659 1109557067 - [/webwork2/mth162/6/3/] 
> [runTime = 46.0 sec sql_single]
> [Sun Feb 27 21:17:50 2005] 71702 1109557070 - [/webwork2/mth162/6/2/] 
> [runTime = 17.0 sec sql_single]
> [Sun Feb 27 21:17:53 2005] 71592 1109557073 - [/webwork2/mth161/5/] 
> [runTime = 5.0 sec sql_single]
> [Sun Feb 27 21:17:55 2005] 71659 1109557075 - [/webwork2/mth161/6/14/] 
> [runTime = 3.0 sec sql_single]
> [Sun Feb 27 21:17:56 2005] 71564 1109557076 - [/webwork2/mth162/6/3/] 
> [runTime = 46.0 sec sql_single]
> [Sun Feb 27 21:17:56 2005] 70570 1109557076 - [/webwork2/mth162/6/5/] 
> [runTime = 49.0 sec sql_single]
> [Sun Feb 27 21:17:57 2005] 71592 1109557077 - [/webwork2/mth161/5/8/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:17:57 2005] 70937 1109557077 - [/webwork2/mth162/6/3/] 
> [runTime = 49.0 sec sql_single]
> [Sun Feb 27 21:18:03 2005] 71564 1109557083 - [/webwork2/mth165/7/14/] 
> [runTime = 3.0 sec sql_single]
> [Sun Feb 27 21:18:08 2005] 71659 1109557088 - [/webwork2/ast105/04/9/] 
> [runTime = 1.0 sec sql_single]
> [Sun Feb 27 21:18:11 2005] 70571 1109557091 - [/webwork2/mth162/6/1/] 
> [runTime = 34.0 sec sql_single]
> [Sun Feb 27 21:18:11 2005] 71433 1109557091 - [/webwork2/mth162/6/5/] 
> [runTime = 36.0 sec sql_single]
> [Sun Feb 27 21:18:15 2005] 71702 1109557095 - 
> [/webwork2/ast105/logout/] [runTime = 1.0 sec sql_single]
> [Sun Feb 27 21:18:15 2005] 71628 1109557095 - [/webwork2/mth162/6/3/] 
> [runTime = 21.0 sec sql_single]
> [Sun Feb 27 21:18:16 2005] 71137 1109557096 - [/webwork2/mth162/6/8/] 
> [runTime = 47.0 sec sql_single]
> [Sun Feb 27 21:18:22 2005] 71666 1109557102 - [/webwork2/mth162/6/2/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:18:22 2005] 71479 1109557102 - [/webwork2/mth162/6/3/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:18:26 2005] 71433 1109557106 - [/webwork2/mth162/6/7/] 
> [runTime = 14.0 sec sql_single]
> [Sun Feb 27 21:18:28 2005] 71239 1109557108 - [/webwork2/mth162/6/7/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:18:28 2005] 71161 1109557108 - [/webwork2/mth162/6/3/] 
> [runTime = 30.0 sec sql_single]
> [Sun Feb 27 21:18:38 2005] 71628 1109557118 - [/webwork2/mth162/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:18:38 2005] 71258 1109557118 - [/webwork2/mth162/6/] 
> [runTime = 44.0 sec sql_single]
> [Sun Feb 27 21:18:42 2005] 70570 1109557122 - [/webwork2/mth162/6/3/] 
> [runTime = 34.0 sec sql_single]
> [Sun Feb 27 21:18:45 2005] 71433 1109557125 - [/webwork2/mth165/7/14/] 
> [runTime = 6.0 sec sql_single]
> [Sun Feb 27 21:18:46 2005] 71479 1109557126 - [/webwork2/mth162/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:18:46 2005] 70937 1109557126 - [/webwork2/mth162/6/5/] 
> [runTime = 37.0 sec sql_single]
> [Sun Feb 27 21:18:47 2005] 71659 1109557127 - [/webwork2/mth162/6/6/] 
> [runTime = 39.0 sec sql_single]
> [Sun Feb 27 21:18:48 2005] 70937 1109557128 - [/webwork2/mth142/6/3/] 
> [runTime = 1.0 sec sql_single]
> [Sun Feb 27 21:18:50 2005] 71592 1109557130 - [/webwork2/mth162/6/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:18:51 2005] 71702 1109557131 - [/webwork2/mth162/6/3/] 
> [runTime = 36.0 sec sql_single]
> [Sun Feb 27 21:18:52 2005] 71564 1109557132 - [/webwork2/mth162/6/3/] 
> [runTime = 37.0 sec sql_single]
> [Sun Feb 27 21:18:57 2005] 71479 1109557137 - [/webwork2/mth162/6/3/] 
> [runTime = 11.0 sec sql_single]
> [Sun Feb 27 21:18:58 2005] 71788 1109557138 - [/webwork2/mth162/6/3/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:19:02 2005] 71592 1109557142 - [/webwork2/mth162/6/6/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:19:03 2005] 71702 1109557143 - [/webwork2/mth162/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:19:09 2005] 70937 1109557149 - [/webwork2/mth164/09/2/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:19:13 2005] 71659 1109557153 - [/webwork2/mth162/6/3/] 
> [runTime = 14.0 sec sql_single]
> [Sun Feb 27 21:19:16 2005] 71592 1109557156 - [/webwork2/mth161/6/14/] 
> [runTime = 2.0 sec sql_single]
> [Sun Feb 27 21:19:16 2005] 71239 1109557156 - [/webwork2/mth162/6/7/] 
> [runTime = 41.0 sec sql_single]
> [Sun Feb 27 21:19:20 2005] 71788 1109557160 - [/webwork2/mth162/6/4/] 
> [runTime = 18.0 sec sql_single]
> [Sun Feb 27 21:19:20 2005] 71137 1109557160 - [/webwork2/mth162/6/] 
> [runTime = 43.0 sec sql_single]
> [Sun Feb 27 21:19:21 2005] 71161 1109557161 - [/webwork2/mth162/6/3/] 
> [runTime = 41.0 sec sql_single]
> [Sun Feb 27 21:19:24 2005] 71258 1109557164 - [/webwork2/mth162/6/] 
> [runTime = 45.0 sec sql_single]
> [Sun Feb 27 21:19:26 2005] 71666 1109557166 - [/webwork2/mth162/6/3/] 
> [runTime = 41.0 sec sql_single]
> [Sun Feb 27 21:19:27 2005] 71628 1109557167 - [/webwork2/mth162/6/3/] 
> [runTime = 37.0 sec sql_single]
> [Sun Feb 27 21:19:30 2005] 71702 1109557170 - [/webwork2/mth162/6/3/] 
> [runTime = 15.0 sec sql_single]
> [Sun Feb 27 21:19:31 2005] 71433 1109557171 - [/webwork2/mth162/6/5/] 
> [runTime = 34.0 sec sql_single]
> [Sun Feb 27 21:19:32 2005] 70570 1109557172 - [/webwork2/mth162/6/3/] 
> [runTime = 38.0 sec sql_single]
> [Sun Feb 27 21:19:37 2005] 71258 1109557177 - [/webwork2/mth162/6/6/] 
> [runTime = 12.0 sec sql_single]
> [Sun Feb 27 21:19:37 2005] 71564 1109557177 - [/webwork2/mth162/6/] 
> [runTime = 45.0 sec sql_single]
> [Sun Feb 27 21:19:40 2005] 71788 1109557180 - [/webwork2/mth165/7/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:19:40 2005] 71479 1109557180 - [/webwork2/mth162/6/3/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:19:42 2005] 70937 1109557182 - [/webwork2/mth142/6/1/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:19:43 2005] 71666 1109557183 - [/webwork2/mth162/6/4/] 
> [runTime = 16.0 sec sql_single]
> [Sun Feb 27 21:19:55 2005] 71258 1109557195 - [/webwork2/mth165/7/] 
> [runTime = 6.0 sec sql_single]
> [Sun Feb 27 21:19:57 2005] 71666 1109557197 - [/webwork2/mth161/5/8/] 
> [runTime = 2.0 sec sql_single]
> [Sun Feb 27 21:20:06 2005] 71161 1109557206 - [/webwork2/mth162/6/3/] 
> [runTime = 34.0 sec sql_single]
> [Sun Feb 27 21:20:06 2005] 71161 1109557206 - [/webwork2/mth142/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:07 2005] 71137 1109557207 - [/webwork2/mth162/6/3/] 
> [runTime = 35.0 sec sql_single]
> [Sun Feb 27 21:20:08 2005] 71666 1109557208 - [/webwork2/mth162/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:09 2005] 71659 1109557209 - [/webwork2/mth162/6/5/] 
> [runTime = 44.0 sec sql_single]
> [Sun Feb 27 21:20:12 2005] 71592 1109557212 - [/webwork2/mth162/6/] 
> [runTime = 44.0 sec sql_single]
> [Sun Feb 27 21:20:14 2005] 71239 1109557214 - [/webwork2/mth162/6/3/] 
> [runTime = 46.0 sec sql_single]
> [Sun Feb 27 21:20:15 2005] 71564 1109557215 - [/webwork2/mth162/6/6/] 
> [runTime = 38.0 sec sql_single]
> [Sun Feb 27 21:20:17 2005] 71161 1109557217 - [/webwork2/mth142/] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:17 2005] 71628 1109557217 - [/webwork2/mth162/6/] 
> [runTime = 50.0 sec sql_single]
> [Sun Feb 27 21:20:18 2005] 70570 1109557218 - [/webwork2/mth162/6/] 
> [runTime = 45.0 sec sql_single]
> [Sun Feb 27 21:20:20 2005] 71788 1109557220 - [/webwork2/mth162/6/2/] 
> [runTime = 40.0 sec sql_single]
> [Sun Feb 27 21:20:24 2005] 71666 1109557224 - [/webwork2/mth162/6/5/] 
> [runTime = 11.0 sec sql_single]
> [Sun Feb 27 21:20:25 2005] 71659 1109557225 - [/webwork2/mth164/09/6/] 
> [runTime = 4.0 sec sql_single]
> [Sun Feb 27 21:20:27 2005] 71137 1109557227 - [/webwork2/mth142/6/3/] 
> [runTime = 8.0 sec sql_single]
> [Sun Feb 27 21:20:27 2005] 71564 1109557227 - [/webwork2/mth162] 
> [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:28 2005] 71161 1109557228 - [/webwork2/mth142/6/] 
> [runTime = 9.0 sec sql_single]
> [Sun Feb 27 21:20:31 2005] 71592 1109557231 - [/webwork2/mth162/6/2/] 
> [runTime = 16.0 sec sql_single]
> [Sun Feb 27 21:20:35 2005] 70570 1109557235 - [/webwork2/mth162/6/4/] 
> [runTime = 15.0 sec sql_single]
> [Sun Feb 27 21:20:36 2005] 71161 1109557236 - [/webwork2/mth142/6/4/] 
> [runTime = 1.0 sec sql_single]
> [Sun Feb 27 21:20:36 2005] 71659 1109557236 - 
> [/webwork2/mth165/logout/] [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:36 2005] 71702 1109557236 - [/webwork2/mth162/6/6/] 
> [runTime = 41.0 sec sql_single]
> [Sun Feb 27 21:20:37 2005] 71258 1109557237 - [/webwork2/mth162/6/3/] 
> [runTime = 42.0 sec sql_single]
> [Sun Feb 27 21:20:38 2005] 71479 1109557238 - [/webwork2/mth162/6/6/] 
> [runTime = 46.0 sec sql_single]
> [Sun Feb 27 21:20:39 2005] 71564 1109557239 - 
> [/webwork2/mth162/logout/] [runTime = 0.0 sec sql_single]
> [Sun Feb 27 21:20:40 2005] 71433 1109557240 - [/webwork2/mth162/6/] 
> [runTime = 44.0 sec sql_single]
> [Sun Feb 27 21:20:42 2005] 70937 1109557242 - [/webwork2/mth162/6/3/] 
> [runTime = 47.0 sec sql_single]
> [Sun Feb 27 21:20:45 2005] 71592 1109557245 - [/webwork2/mth162/6/4/] 
> [runTime = 14.0 sec sql_single]
> [Sun Feb 27 21:20:49 2005] 71137 1109557249 - [/webwork2/mth162/6/7/] 
> [runTime = 11.0 sec sql_single]
> [Sun Feb 27 21:20:50 2005] 71161 1109557250 - [/webwork2/mth142/6/3/] 
> [runTime = 3.0 sec sql_single]
> [Sun Feb 27 21:20:53 2005] 71659 1109557253 - [/webwork2/mth161/5/2/] 
> [runTime = 5.0 sec sql_single]
> [Sun Feb 27 21:20:55 2005] 71628 1109557255 - [/webwork2/mth162/6/7/] 
> [runTime = 37.0 sec sql_single]
> [Sun Feb 27 21:21:01 2005] 71258 1109557261 - [/webwork2/mth162/6/6/] 
> [runTime = 12.0 sec sql_single]
> [Sun Feb 27 21:21:04 2005] 71788 1109557264 - [/webwork2/mth162/6/8/] 
> [runTime = 32.0 sec sql_single]
> [Sun Feb 27 21:21:06 2005] 71239 1109557266 - [/webwork2/mth162/6/3/] 
> [runTime = 40.0 sec sql_single]
> [Sun Feb 27 21:21:12 2005] 70570 1109557272 - [/webwork2/mth162/6/4/] 
> [runTime = 31.0 sec sql_single]
> [Sun Feb 27 21:21:17 2005] 71666 1109557277 - [/webwork2/mth162/6/8/] 
> [runTime = 40.0 sec sql_single]
> [Sun Feb 27 21:21:18 2005] 71479 1109557278 - [/webwork2/mth162/6/6/] 
> [runTime = 40.0 sec sql_single]
> [Sun Feb 27 21:21:21 2005] 71788 1109557281 - [/webwork2/mth162/6/6/] 
> [runTime = 12.0 sec sql_single]
> [Sun Feb 27 21:21:23 2005] 70937 1109557283 - [/webwork2/mth162/6/4/] 
> [runTime = 41.0 sec sql_single]
> [Sun Feb 27 21:21:29 2005] 71433 1109557289 - [/webwork2/mth162/6/] 
> [runTime = 48.0 sec sql_single]
> [Sun Feb 27 21:21:30 2005] 71702 1109557290 - [/webwork2/mth162/6/6/] 
> [runTime = 44.0 sec sql_single]
> [Sun Feb 27 21:21:32 2005] 70570 1109557292 - [/webwork2/mth161/5/8/] 
> [runTime = 7.0 sec sql_single]
>
>
> Prof. Arnold K. Pizer
> Dept. of Mathematics
> University of Rochester
> Rochester, NY 14627
> (585) 275-7767
>
>
>
> -------------------------------------------------------
> SF email is sponsored by - The IT Product Guide
> Read honest & candid reviews on hundreds of IT Products from real users.
> Discover which products truly live up to the hype. Start reading now.
> http://ads.osdn.com/?ad_id=6595&alloc_id=14396&op=click
> _______________________________________________
> OpenWeBWorK-Devel mailing list
> Ope...@li...
> https://lists.sourceforge.net/lists/listinfo/openwebwork-devel