From: Arnold P. <ap...@ma...> - 2005-03-02 15:34:23
|
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 |
From: John J. <jj...@as...> - 2005-03-02 17:44:00
|
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 |
From: John J. <jj...@as...> - 2005-03-02 18:48:43
|
After more looking, I recant my guess about table indexing. After figuring out how to have mysql report the indexing it is using, I found that webwork was putting in all the indexes I used last semester (and a few more). 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 |
From: Sam H. <sh...@ma...> - 2005-03-03 06:30:36
|
On Mar 2, 2005, at 10:35 AM, Arnold Pizer wrote: > 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. If someone's feeling ambitious, they could write a custom version of DB.pm that makes SQL calls directly. I think we could get some savings if we avoided the "Schema" abstraction. -sam |
From: Arnold P. <ap...@ma...> - 2005-03-03 03:59:59
|
At 09:45 PM 3/2/2005, Sam Hathaway wrote: >On Mar 2, 2005, at 10:35 AM, Arnold Pizer wrote: > >>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. > >If someone's feeling ambitious, they could write a custom version of DB.pm >that makes SQL calls directly. I think we could get some savings if we >avoided the "Schema" abstraction. >-sam Hi Sam, The slow downs I'm seeing are significant --- e.g. 40 times slower than what we are used to. Could the "Schema" abstraction have that great an overhead? Arnie Prof. Arnold K. Pizer Dept. of Mathematics University of Rochester Rochester, NY 14627 (585) 275-7767 |
From: Sam H. <sh...@ma...> - 2005-03-03 03:44:04
|
\On Mar 2, 2005, at 10:20 PM, Arnold Pizer wrote: > At 09:45 PM 3/2/2005, Sam Hathaway wrote: >> On Mar 2, 2005, at 10:35 AM, Arnold Pizer wrote: >> >>> 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. >> >> If someone's feeling ambitious, they could write a custom version of >> DB.pm that makes SQL calls directly. I think we could get some >> savings if we avoided the "Schema" abstraction. >> -sam > > Hi Sam, > > The slow downs I'm seeing are significant --- e.g. 40 times slower > than what we are used to. Could the "Schema" abstraction have that > great an overhead? It can't account for all of the slowdown, but I think there's room for significant improvement. I'll take a closer look once devel is back up. -sam |
From: Arnold P. <ap...@ma...> - 2005-03-03 03:50:32
|
At 10:43 PM 3/2/2005, Sam Hathaway wrote: >\On Mar 2, 2005, at 10:20 PM, Arnold Pizer wrote: > >>At 09:45 PM 3/2/2005, Sam Hathaway wrote: >>>On Mar 2, 2005, at 10:35 AM, Arnold Pizer wrote: >>> >>>>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. >>> >>>If someone's feeling ambitious, they could write a custom version of >>>DB.pm that makes SQL calls directly. I think we could get some savings >>>if we avoided the "Schema" abstraction. >>>-sam >> >>Hi Sam, >> >>The slow downs I'm seeing are significant --- e.g. 40 times slower than >>what we are used to. Could the "Schema" abstraction have that great an >>overhead? > >It can't account for all of the slowdown, but I think there's room for >significant improvement. I'll take a closer look once devel is back up. >-sam Thanks, Arnie >------------------------------------------------------- >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 Prof. Arnold K. Pizer Dept. of Mathematics University of Rochester Rochester, NY 14627 (585) 275-7767 |
From: John J. <jj...@as...> - 2005-03-04 05:55:25
|
Hi all, I was looking at mysql speed today during set assignment. It was slowing down mainly by having lots of calls asking if items exist in the database. So, I looked at the indexing again and I think that is where the problem lies after all. There are enough indexes being kept in mysql, but I don't think the queries get to use them. Because of another bug, the mysql select commands have the modifier "binary" added when specifying the key information (e.g., the set_id, etc.). This made that information checked in a case sensitive way. The problem is that the indexing in mysql seems to be case insensitive. So, when we try to look something up in mysql specifying case sensitive matches, I think it ignores the index and walkd linearly through all of the records. The bigger the course, the longer this takes, and it of course, will get worse. If you want to test this theory at home, login to your server (in a unix shell). Then connect to mysql (e.g., mysql -uroot -p). Then, do something like this: > mysql> use webwork; > Database changed > mysql> select count(*) from Jones_MAT_117_Spring_2005_problem_user > where user_id="jjones" and set_id="Homework_3" and problem_id="2"; > +----------+ > | COUNT(*) | > +----------+ > | 1 | > +----------+ > 1 row in set (0.00 sec) > > mysql> select count(*) from Jones_MAT_117_Spring_2005_problem_user > where BINARY user_id="jjones" and BINARY set_id="Homework_3" and > BINARY problem_id="2"; > +----------+ > | COUNT(*) | > +----------+ > | 1 | > +----------+ > 1 row in set (0.08 sec) The same query, but using the binary modifier goes from ~ 0 secs to 0.08 secs. I looked at the mysql documentation for the create index command, and did not see a way of specifying the entries so that they would be treated as binary. Maybe if the original database types where binary (if that is possible), it would work. Alternatively, webwork could remove the binary modifier, get its result, and then sift out the ones which match in a case sensitive way. I will look at doing that when I have a chance. All changes are probably just to the file DB/Schema/SQL.pm, which is nice. John Arnold Pizer wrote: > At 10:43 PM 3/2/2005, Sam Hathaway wrote: > >> \On Mar 2, 2005, at 10:20 PM, Arnold Pizer wrote: >> >>> At 09:45 PM 3/2/2005, Sam Hathaway wrote: >>> >>>> On Mar 2, 2005, at 10:35 AM, Arnold Pizer wrote: >>>> >>>>> 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. >>>> >>>> >>>> If someone's feeling ambitious, they could write a custom version >>>> of DB.pm that makes SQL calls directly. I think we could get some >>>> savings if we avoided the "Schema" abstraction. >>>> -sam >>> >>> >>> Hi Sam, >>> >>> The slow downs I'm seeing are significant --- e.g. 40 times slower >>> than what we are used to. Could the "Schema" abstraction have that >>> great an overhead? >> >> >> It can't account for all of the slowdown, but I think there's room >> for significant improvement. I'll take a closer look once devel is >> back up. >> -sam > > > Thanks, > > Arnie > > >> ------------------------------------------------------- >> 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 > > > > 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 |
From: Michael G. <ga...@ma...> - 2005-03-03 12:53:24
|
On Mar 2, 2005, at 11:33 PM, Michael Gage wrote: > I also don't understand why the mth162 times were up by a factor of 40 > while the other courses were only up by a factor of 10 or less? What > could account for that difference? > I've thought of one possibility. The tables for mth162 are larger, since it is a bigger class. If we missed instituting an index in mth162, say in the user-problem table, then this might explain why the server would take more time to respond to a request from a large class member as opposed to a small class member. We might not notice the difference when there is no load. Take care, Mike |