Forum archive 2000-2006

Šarūnas Burdulis - Timing log values

Šarūnas Burdulis - Timing log values

by Arnold Pizer -
Number of replies: 0
inactiveTopicTiming log values topic started 10/22/2004; 12:11:19 PM
last post 10/26/2004; 1:03:40 PM
userarūnas Burdulis - Timing log values  blueArrow
10/22/2004; 12:11:19 PM (reads: 1046, responses: 4)
Hello,

Could somebody explain what does the value in the second column of timing.log mean (the one after the [date-time-year])?

[Fri Oct 22 11:57:55 2004] 3216 1098460675 > WeBWorK::PG::new [user=xxxxx,problem=m3f04/22Oct04/8,mode=images] [Fri Oct 22 11:57:55 2004] 3216 1098460675 - WeBWorK::PG::new [initialized] [Fri Oct 22 11:57:55 2004] 3216 1098460675 < WeBWorK::PG::new []

WW2 usage has recently put a higher load on our system (http://www.math.dartmouth.edu/mrtg/index-webwork.html). On the process level almost all of the load appears to come from Apache, which in turn probably comes from mod_perl.

Sarunas Burdulis Linux sysadmin Math@Dartmouth

<| Post or View Comments |>

userMichael Gage - Re: Timing log values  blueArrow
10/22/2004; 1:53:30 PM (reads: 1239, responses: 0)
The second number is the process number of the perl program running the script.

This may vary from version to version of WW2 -- we've been adjusting the information put into the error logs in an attempt to maximize their usefulness for the maximum number of users.

I have timing data on using webwork 2 on our development machine (which is fairly slow). For the delivery of a given student problem the speed is about 3 times as fast as for WW1.9. The apache sites have suggestions for tuning a server to be most efficient when running mod_perl, but I have not had much direct experience with this. If you are interested in our timing data for comparison send me an email.

-- Mike

<| Post or View Comments |>

userarūnas Burdulis - Re: Timing log values  blueArrow
10/22/2004; 2:38:48 PM (reads: 1193, responses: 0)
Thanks. That perl program is actually an apache. I can now correlate those numbers in the timing.log and the output of `ps`. How do you derive the speed or performance from this?

P.S. By timing.log I have in mind the log file created by setting $webworkFiles{logs}{timing} = "$webworkDirs{logs}/timing.log"; in global.conf. There is a mention of "WeBWorK::Timing mechanism" in global.conf. What is the status of this and can it be enabled globally somehow? By looking at the Timing.pm source it seems that one still has to put timers into WW2 code and then add Use/enable WeBWorK::Timing.

Thanks,

Sarunas

<| Post or View Comments |>

userSam Hathaway - Re: Timing log values  blueArrow
10/22/2004; 4:07:45 PM (reads: 1248, responses: 0)
WeBWorK::Timing timers are enabled in lib/WeBWorK/Constants.pm. They log to the apache error log, or to a file specified in lib/WeBWorK/Constants.pm.

There are some timers in place that use the WeBWorK::Timing mechanism, but they are not comprehensive. Then again, neither is the timing data written to timing.log.

See also the =bin/timing= script. It will sort and format timing data for you.

We plan to improve timing and activity logging after the release of WeBWorK 2.1.

<| Post or View Comments |>

userarūnas Burdulis - Re: Timing log values  blueArrow
10/26/2004; 1:03:40 PM (reads: 1248, responses: 0)
Thanks for the explanation and the timing script. Timing log works fine as well as the sorting script.

While tuning MySQL and Apache I used super-smack and ApacheBench respectively. However I only used generic scenarios ("smacks") that come with super-smack and only the vey basic HTTP request for $webwork_url and some hardcopy genration. Ideally a WW2-tailored "smack" doing typical WW2 SQL queries should be used as well as an HTTP requests should be made imitating the full range of WW2 actions.

Has somebody done something similar with WW2 and maybe could share their benchmarking scenarios/scripts?

Thanks, Sarunas

<| Post or View Comments |>