Bill, the time required to look up functions does not seem to be
the problem here, as is illustrated by the following timings:
. mata: x = uniform(1000,1)
r; t=0.00 22:24:32
. mata: for (i=1;i<=1000;i++) {; z = x:*x:*x:*x:*x; }
r; t=0.24 22:24:32
. mata: for (i=1;i<=1000;i++) {; z = test1(x); }
r; t=0.36 22:24:32
. mata: for (i=1;i<=1000;i++) {; z = test2(x); }
r; t=0.22 22:24:33
. mata: for (i=1;i<=1000;i++) {; z = test3(x); }
r; t=0.38 22:24:33
. mata: for (i=1;i<=1000;i++) {; z = test4(x); }
r; t=0.23 22:24:33
. mata: for (i=1;i<=1000;i++) {; z = test5(x); }
r; t=0.40 22:24:34
. mata: for (i=1;i<=1000;i++) {; z = test6(x); }
r; t=0.22 22:24:34
Note that I came across the problem in a very different
context and then started to track it down. After a couple of
tests it was clear that the problem had to do with nesting
although this was hard to believe.
I assume that there is a problem with my computer or OS.
I'll check using another machine.
ben
> -----Original Message-----
> From: [email protected] [mailto:owner-
> [email protected]] On Behalf Of William Gould, Stata
> Sent: Wednesday, April 12, 2006 9:08 PM
> To: [email protected]
> Subject: Re: st: Weird problem with nested functions in Mata
>
> Ben Jann <[email protected]> has done an experiment in Mata
and
> observed execution times:
>
> : real colvector test1(x) return(x:*x:*x:*x:*x)
>
> : real colvector test2(x) return(test1(x))
>
> : real colvector test3(x) return(test2(x))
>
> : real colvector test4(x) return(test3(x))
>
> : real colvector test5(x) return(test4(x))
>
> : real colvector test6(x) return(test5(x))
>
> test1() does something. test2() does the same something, and so do
> test3(), test4(), and so on. And yet, when Ben Jann writes down
> execution times, he gets strange results, with execution speeds
speeding
> up
> and slowing down. He writes,
>
> > This really puzzles me. What would be the logic behind this? Does
anyone
> > have an explanation?
>
> I have repeated Ben's experiment, and I do not get the see-saw pattern
> of timings that Ben reports. My timings are:
>
> . mata: z = x:*x:*x:*x:*x
> r; t=0.30 13:50:17
>
> . mata: z = test1(x)
> r; t=0.31 13:50:18
>
> . mata: z = test2(x)
> r; t=0.30 13:50:18
>
> . mata: z = test3(x)
> r; t=0.30 13:50:18
>
> . mata: z = test4(x)
> r; t=0.30 13:50:18
>
> . mata: z = test5(x)
> r; t=0.31 13:50:19
>
> . mata: z = test6(x)
> r; t=0.30 13:50:19
>
> If Ben really wishes to measure the time of nesting (it is close to
zero),
> Ben needs to set up experiments where the *SAME* routine is called
> over and over again, and he will need the number of calls to be in the
> 1,000s, or more.
>
> That's because the time required to execute a function call is much
> greater
> the first time than subsequent times. The first time a function is
> called,
> Mata must look up its address based on the function's name. After
that,
> Mata
> remembers it.
>
> For example:
>
> real colvector test5(x) return(text4(x))
>
> The first time you call test5(), the function test4() will need to be
> looked
> up by name. That linkage information (an address) is then stored with
> test5()'s compiled code, so that the next time test5() is called, the
> lookup
> can be skipped.
>
> That happens within an execution. So if test6() called test5() a
thousand
> times, the first call linkage would be slow, but the remaining 999
would
> be instant.
>
> When Mata comes back to a prompt, all that linkage information is
thrown
> away,
> and Mata starts rebuilding it from scratch. Why? Because, at the
prompt,
> you
> might throw away the current test4() and write a new one. The way to
> ensure
> that test5()'s table is updated to invalidate all the information in
all
> the
> tables.
>
> -- Bill
> [email protected]
> *
> * For searches and help try:
> * http://www.stata.com/support/faqs/res/findit.html
> * http://www.stata.com/support/statalist/faq
> * http://www.ats.ucla.edu/stat/stata/
*
* For searches and help try:
* http://www.stata.com/support/faqs/res/findit.html
* http://www.stata.com/support/statalist/faq
* http://www.ats.ucla.edu/stat/stata/
