9

I have an application that I want to profile wrt how much time is spent in various activities. Since this application is I/O intensive, I want to get a report that will summarize how much time is spent in every library/system call (wall time).

I've tried oprofile, but it seems it gives time in terms of Unhalted CPU cycles (thats cputime, not real time)

I've tried strace -T, which gives wall time, but the data generated is huge and getting the summary report is difficult (and awk/py scripts exist for this ?)

Now I'm looking upto SystemTap, but I don't find any script that is close enough and can be modified, and the onsite tutorial didn't help much either. I am not sure if what I am looking for can be done.

I need someone to point me in the right direction. Thanks a lot!

Nickolay
  • 31,095
  • 13
  • 107
  • 185
sandt1g3r
  • 143
  • 1
  • 6
  • As for system calls: syscalltime - Combination shell/systemtap script to measure system call counts and times. Can be filtered by process IDs, process names and users.https://sourceware.org/systemtap/examples/process/syscalltimes –  Dec 13 '13 at 05:44

3 Answers3

5

Judging from this commit, the recently released strace 4.9 supports this with:

strace -w -c

They call it "syscall latency" (and it's hard to see from the manpage alone that's what -w does).

Nickolay
  • 31,095
  • 13
  • 107
  • 185
  • This is a working solution. Can't believe this was added as late as 2014. – nh2 Mar 15 '15 at 00:21
  • 1
    And I can't believe it's still not available in CentOS 7! – ndemou May 05 '17 at 07:04
  • It's good that strace.io points to https://build.opensuse.org/package/show/home:ldv_alt/strace/ where they have packages for many distros – ndemou May 05 '17 at 07:20
1

See the fntimes.stp systemtap sample script. https://sourceware.org/systemtap/examples/index.html#profiling/fntimes.stp

The fntimes.stp script monitors the execution time history of a given function family (assumed non-recursive). Each time (beyond a warmup interval) is then compared to the historical maximum. If it exceeds a certain threshold (250%), a message is printed.

# stap fntimes.stp 'kernel.function("sys_*")'

or

# stap fntimes.stp 'process("/path/to/your/binary").function("*")'

The last line of that .stp script demonstrates the way to track time consumed in a given family of functions

probe $1.return { elapsed = gettimeofday_us()-@entry(gettimeofday_us()) }
fche
  • 2,641
  • 20
  • 28
1

Are you doing this just out of measurement curiosity, or because you want to find time-drains that you can fix to make it run faster?

If your goal is to make it run as fast as possible, then try random-pausing. It doesn't measure anything, except very roughly. It may be counter-intuitive, but what it does is pinpoint the code that will result in the greatest speed-up.

Community
  • 1
  • 1
Mike Dunlavey
  • 40,059
  • 14
  • 91
  • 135
  • speeding it up might be the eventual goal, and random pausing might be a quick way to the solution, but i would prefer to have a proper analysis that can be presented if necessary , thanks btw – sandt1g3r Jul 05 '11 at 14:10