5
$\begingroup$

I have a main function f[x] that calls three sub-functions:

f1[x_] := x^2;
f2[x_] := x + 5;
f3[x_] := Sin[x];

f[x_] := f1[x] + f2[f3[x]]

(In my real application, the functions are more complicated.)

I would like to time how long f1, f2, and f3 take to execute, without re-defining them or f.

One idea is to temporarily replace f1 with a function that times f1 and uses Sow to return the time, like this:

With[
 {
  f1[x_] := Block[{t, z}, {t, z} = AbsoluteTiming[f1[x]]; Sow[t]; Return[z]]
  },
 Reap[f[x]]
 ]

Or this:

Block[
 {
  f1 = Function[x, Block[{t, z}, {t, z} = AbsoluteTiming[f1[x]]; Sow[t]; Return[z]]]
  },
 Reap[f[x]]
 ]

(And do the same for f2 and f3)

However, both these forms produce errors.

Is there a way to temporarily "inject" AbsoluteTiming into a function, and use Sow/Reap to obtain timing information?

Update

It seems that TraceScan was just what I needed:

g[x_] := (Pause[.1]; Cos[x])
h[x_] := (Pause[.2]; Tan[x])
f[x_] := h[x] + Sin[g[x]]

Block[
 {list = {}, t},
 TraceScan[
  (t = Now) &,
  f[x],
  _g | _h,
  (AppendTo[list, {#, Now - t}];) &
  ];
 Column[list]
 ]

returns

{h[x],0.201649s}
{g[x],0.100481s}

Thanks Carl Woll for your example use of TracePrintEvaluate!

Improve this question
$\endgroup$
2
  • $\begingroup$ i think you need to elaborate on what you are actually trying to accomplish. If you are modifying the calling code with Reap why not just directly use AbsolutTiming ? $\endgroup$
    – george2079
    Oct 2, 2017 at 20:31
  • $\begingroup$ I have a big complicated function that calls several other complicated sub-functions. The big function runs slowly, so I'd like to append a section to my notebook that performs a timing analysis. However, I would prefer to not re-write my functions to include AbsoluteTiming because I feel it would distract the reader from the main goal of my code. That is, I would like to perform a timing investigation after the functions have been defined and demonstrated, without modifying them with timing code. $\endgroup$
    – ConvexMartian
    Oct 7, 2017 at 12:45

1 Answer 1

Reset to default
7
$\begingroup$

One idea is to use my TracePrintEvaluate function:

TracePrintEvaluate[f[x], _f1|_f2|_f3, "Timing"->True]

f1[x]

f2[f3[x]]

f3[x]

f2[Sin[x]]

5 + x^2 + Sin[x]

Clicking on any of the trace outputs will show what the expression evaluated to, and then the time it took to do the evaluation. Below, I show the output after clicking on each of the trace outputs twice:

TracePrintEvaluate[f[x], _f1|_f2|_f3, "Timing"->True]

0.000077

0.000404

0.000038

0.000032

5 + x^2 + Sin[x]

Note that using TracePrintEvaluate, just like using any Trace* function, will instrument the evaluation process, hence the timings shown will be larger than the actual timings. However, it will give you an idea of where slow points are so that you can speed up those portions of the code.

Improve this answer
$\endgroup$
1
  • $\begingroup$ Thanks Carl, that's a neat tool. Reading your code inspired me to explore TraceScan, and I think it will work. I've added my findings to my post. $\endgroup$
    – ConvexMartian
    Oct 7, 2017 at 14:08

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

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