11
$\begingroup$

I previously posted this question on Mathgroup but received no response

I am using Workbench to profile my code.

Suppose I have 2 modules, let's call them A, B (they are too long to replicate here). While running my code, Module B is called repeatedly from A, say in a Do loop. Module A is called once. I would like to profile total usage of B (not just one instance), which rules out embedding each call to B in a Profile[] statement (as this generates a Profile output for each call).

I could, of course, profile A, but the information produced on B would be buried in between timing data pertaining to other parts of A (which for my long module A makes it virtually impossible to understand what's happening in B).

Is there a way to accomplish this?

$\endgroup$
  • 2
    $\begingroup$ Welcome to SE, Eric! $\endgroup$ – user21 Feb 15 '12 at 14:55
12
$\begingroup$

If you can settle for anything other than Workbench's Profile, here is a simplistic profiler function with a fairly low latency:

ClearAll[profile];
SetAttributes[profile, HoldAll];
profile[code_] :=
  Block[{$totalTime = 0, t, res, time,exclude},
     SetAttributes[{time, exclude}, HoldAll];
     exclude[cd_] := 
       (t = AbsoluteTime[];res = cd; $totalTime -= AbsoluteTime[] - t; res);
     time[cd_] := 
       (t = AbsoluteTime[];res = cd; $totalTime += AbsoluteTime[] - t; res);
     {code, $totalTime}];

To illustrate how you can use it:

b[] := Do[Range[10], {100}];
aa[] :=
  Module[{},
     Pause[2];
     Do[time@b[], {1000}];
     Pause[3];
  ];

Note that I inserted time wrapper in the place in the code which I want to profile. All invocations of time will add up:

profile[aa[]]

(*
   ==> {Null, 0.0791}
*)

Note that profile has some overhead, but it seems to at least give the right order of magnitude for the result:

a[] :=
  Module[{},
     Pause[2];
     time@Do[b[], {1000}];
     Pause[3];
  ]; 

profile[a[]]

(*
   ==> {Null,0.0781250}
*)

The granularity may be not as good as in Profile, but in case it is not enough (meaning you are timing something very fast), you should try to wrap time around pieces of code where your very fast operation is repeated (like loops). You can wrap pieces inside those which you want to exclude, in the exclude wrapper. Obviously, the code or functions it uses should not use the symbols time and exclude for other purposes, but this is easy to fix by placing profile into a separate context / package.

$\endgroup$
3
$\begingroup$

Could you not write a small wrapper function C1 that generates dummy input for B and profile that. Then you could profile a second function C2 that just generates the dummy input to see what the overhead is.

$\endgroup$
  • $\begingroup$ Yes, that is always possible, in case of a Do loop. My post really was not specific enough. In my case, the module I'd like to profile, say C, is called (once) from another module, say B, which is called repeatedly from A. I'd like to profile C without putting a wrapper around B. $\endgroup$ – Eric Feb 15 '12 at 15:55
  • $\begingroup$ Yes, that is always possible, in case of a Do loop. My post really was not specific enough. In my case, the module I'd like to profile, say C, is called (once) from another module, say B, which is called repeatedly from A. I'd like to profile C without putting a wrapper around B. Sometimes, the situation is even worse, say when I call a matrix-vector multiplication routine from LinearSolve as in LinearSolve[mymatrixvectormultiplicationroutine,f, ... using Krylov]. Now I do not even have access to the call to the routine. $\endgroup$ – Eric Feb 15 '12 at 16:04
  • $\begingroup$ @Eric, it might be good if you update your question, with this additional information. Just follow the 'edit' link under your question. $\endgroup$ – user21 Feb 15 '12 at 16:13

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.