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 |