#471 recursive calls not correctly accounted in timing

open
nobody
Lisp Core (471)
5
2010-06-22
2003-12-14
No

TIMER_INFO gets units of time mixed up -- in the
example below, should show 0.25 seconds instead of 25
seconds; setting TIMER_DEVALUE:TRUE before calling
FF(200) makes the time come out as 0.25 seconds as
expected.

Note that the time reported for GG is 25 seconds while
the time for FF is 0.25 seconds -- the two should be
identical or nearly so.

See also bug report #572835 ("timer_info gives
incorrect time").

Maxima 5.9.0 cvs version of 20031128, clisp 2.31,
redhat linux 7.1 (kernel 2.4.2).

--- begin example about timing_info ---
(C1) GG(n):=if equal(n,0) then 0 else n+GG(n-1);
(D1) GG(n) := IF EQUAL(n, 0) THEN 0 ELSE n + GG(n - 1)
(C2) FF(n):=GG(n);
(D2) FF(n) := GG(n)
(C3) timer(FF,GG);
(D3) [FF, GG]
(C4) timer_info();
[ FUNCTION TIME//CALL CALLS RUNTIME
GCTIME ]
[
]
[ GG 0 0 0
0 ]
(D4) [
]
[ FF 0 0 0
0 ]
[
]
[ TOTAL 0 0 0
0 ]
(C5) FF(200);
(D5) 20100
(C6) timer_info();
[ FUNCTION TIME//CALL CALLS
RUNTIME GCTIME ]
[
]
[ GG .1262686567164179 SEC 201
25.38 SEC 0 ]
(D6) [
]
[ FF 0.25 SEC 1 0.25
SEC 0 ]
[
]
[ TOTAL .1268811881188119 SEC 202
25.63 SEC 0 ]
--- end example about timing_info ---

Discussion

  • Dieter Kaiser

    Dieter Kaiser - 2009-11-03

    I think we have no longer a problem with the function timer_info. The time per call for the reported example is not very accurate, but the values are sumed correctly.

    (%i3) GG(n):=if equal(n,0) then 0 else GG(n-1)+n
    (%i4) FF(n):=GG(n)
    (%i5) timer(FF,GG)
    (%i6) FF(500)
    (%i7) timer_info()
    (%o7) matrix([function,time\/\/call,calls,runtime,gctime],
    [GG,.07129367864271456*sec,501,35.718133*sec,0],
    [FF,0.144009*sec,1,0.144009*sec,0],
    [total,.07143852988047808*sec,502,35.862142*sec,0])

    This is an example for a function which needs much more time:

    (%i8) ff(x):=block([fpprec:x],gamma_incomplete(5.0b-1,1.0b0),done)

    The first call is needed to initialize internal values:

    (%i9) ff(1024)
    (%i10) untimer(FF,GG)
    (%i11) timer(ff)

    On my (slow) computer the function needs about 2.7 seconds per call. This is displayed correctly:

    (%i12) ff(1024)
    (%i13) timer_info()
    (%o13) matrix([function,time\/\/call,calls,runtime,gctime],
    [ff,2.684167*sec,1,2.684167*sec,0],
    [total,2.684167*sec,1,2.684167*sec,0])

    Further calls are added up correctly:

    (%i14) ff(1024)
    (%i15) timer_info()
    (%o15) matrix([function,time\/\/call,calls,runtime,gctime],
    [ff,2.708169*sec,2,5.416338*sec,0],
    [total,2.708169*sec,2,5.416338*sec,0])
    (%i16) ff(1024)
    (%i17) timer_info()
    (%o17) matrix([function,time\/\/call,calls,runtime,gctime],
    [ff,2.654832333333333*sec,3,7.964497*sec,0],
    [total,2.654832333333333*sec,3,7.964497*sec,0])

    Setting the status to "pending" and "works for me".

    Dieter Kaiser

     
  • Dieter Kaiser

    Dieter Kaiser - 2009-11-03
    • status: open --> pending
     
  • SourceForge Robot

    This Tracker item was closed automatically by the system. It was
    previously set to a Pending status, and the original submitter
    did not respond within 14 days (the time period specified by
    the administrator of this Tracker).

     
  • SourceForge Robot

    • status: pending --> closed
     
  • Robert Dodier

    Robert Dodier - 2010-06-22
    • status: closed --> open
     
  • Robert Dodier

    Robert Dodier - 2010-06-22

    Reopening this report. On looking at this again, it appears that the problem is that Maxima is not correctly accounting for time spent in recursive calls in GG, and that this problem still exists.

     
  • Robert Dodier

    Robert Dodier - 2010-06-22

    Looks like problem was misidentified before, therefore changing summary.

     
  • Robert Dodier

    Robert Dodier - 2010-06-22
    • summary: TIMING_INFO gets time units mixed up --> recursive calls not correctly accounted in timing
     

Get latest updates about Open Source Projects, Conferences and News.

Sign up for the SourceForge newsletter:





No, thanks