2

I had a large number of Selenium based perl Testscripts. After the complete Testing it prints a log as follows. What does this specify? How the time below is calculated and on what basis

Files=1, Tests=17, 209 wallclock secs ( 0.13 usr +  0.01 sys =  0.14 CPU)
Harshavardhan Konakanchi
  • 4,238
  • 6
  • 36
  • 54

1 Answers1

7
209 wallclock secs ( 0.13 usr +  0.01 sys =  0.14 CPU)

It took 209 seconds to run. These seconds are time elapsed as per the clock on the wall (or on your wrist).

Most of this time has been spent waiting on something. Waiting? Well, the CPU spent a lot of time waiting, so while time elapsed the CPU wasn't working on the program being timed. We know this because the actual CPU time is reported to be only 0.14 seconds, so that means almost all of the 209 seconds just waiting.

There's a further distinction to be made between time spent in usermode and time spent in syscalls. Briefly, the former refers to time the CPU spent on your program proper while the latter refers to time the CPU spent dealing with syscalls, that is calls made into the operating system on behalf of your program.

Addendum for multi-cores: As @ArtM pointed out, or rather made me discover, the times given for usr and sys are cumulative for all cores the program has run on, which means that there may be cases when the total CPU time or even any one of usr and sys may be higher than the wallclock time, which may seem odd but makes sense when you think about the parallelism on multiple cores.

If you want to learn more about this usr/sys or user-mode versus kernel-mode issue, take a look at this more comprehensive answer.

Community
  • 1
  • 1
Lumi
  • 14,775
  • 8
  • 59
  • 92
  • @HarshaVardhan - There was one test script file containing 17 tests. (A test is something like `is $got, 'bla', 'got bla';` - see [`Test::Simple`](https://metacpan.org/module/Test::Simple) and [`Test::More`](https://metacpan.org/module/Test::More) for details.) – Lumi May 16 '12 at 11:19
  • @Lumi, probably it would be a good point to mention how these times are related to CPU cores on multi-cores CPUs – ArtMat May 16 '12 at 12:46
  • @ArtM - Feel free to add the info. I don't know of any special relationship. Wallclock is wallclock, and I would guess the others are cumulative over all cores. - Okay, a quick search indicates that [this assumption seems to be correct](http://stackoverflow.com/a/2734965/269126). – Lumi May 16 '12 at 13:00
  • 1
    @ArtM that's right. The only interesting fact is that it's possible for total CPU time to be greater than wallclock time, if the system is multi-core, and the test code is both parallel and CPU-bound. – hobbs May 16 '12 at 15:24
  • @hobbs, yes, I know; the intention of the previous comment was to point Lumi to this aspect too, so (s)he could complete the answer if (s)he wants – ArtMat May 16 '12 at 16:28
  • That waiting time might also be something that is I/O or network bound. You aren't waiting for resources locally, but for something remote to respond. And, that time is only for the local resources, even if you are chewing up resources on the remote side. :) – brian d foy May 16 '12 at 20:42