I believe I have a mostly working patch, now:

(1) -> )time long
(1) -> systemCommand("read foo.input")$MoreSystemCommands
integrate(sin x, x)


   (1)  - cos(x)
Type: Union(Expression(Integer),...) Time: 0.0007(coercion) + 0.0112(evaluation) + 0.0013(instantiation) + 0.0663(load) + 0.0008(modemaps) + 0.0015(querycoerce) + 0.0006(diskread) + 0.0003(resolve) + 0.0002(print) = 0.0829 sec

Type: Void
Time: 0.0001(analysis) + 0.0835(evaluation) + 0.0003(load) + 0.0002(diskread) = 0.0843 sec

As you can see, the integral in foo.input takes 0.0829s in total,
and the second "Time:" line shows the stats on "systemCommand":
the time spent in ')read' is accounted into 'evaluation', which is
0.0835s, just a little over 0.0829s.

The basic idea is to modify the '$timedNameStack' to contain both timer
info and the resulting stats.

$timedNameStack := [['other, [get_run_time(), elapsedGcTime(), HEAPELAPSED()], [[CAR item, 0.0, 0] for item in $interpreterTimedNames]]]

Is this approach worth pursuing?  If so, I'll workout the remaining
details of this patch.

- Qian

On 12/12/23 09:08, Qian Yun wrote:
The most natural and right thing to do is to support nested timing:

just treat 'systemCommand' or other block evaluation as a normal
function, return a timing for this whole block.  Inside this
block, timing should also be given for each line.

This is doable, and not require too much changes in code.

The most important change is to stop using $oldElapsedTime and
$oldElapsedSpace global variables for tracking timing --
they are easily mangled during nested calls.

Instead, those (old) timing values should be stored in stack --
$timedNameStack, then we can get nested stats.

I have a almost working version, will post later after working
out remaining details.

- Qian

On 12/11/23 23:52, Waldek Hebisch wrote:
On Mon, Dec 11, 2023 at 02:35:06PM +0100, Ralf Hemmecke wrote:
If I have a word to say...

I definitely want ")read ..." and systemCommand("read ...) behave exactly the same. I used systemCommand only, because there I can programmatically
specify the file to read.

Well, hopefully we agree that 'systemCommand' in

systemCommand("read ...)

and

a := 1; systemCommand("read ...); a := 2

should behave "the same".  This forces some differences, for
example normal system command return no result, while FriCAS
functions including 'systemCommand' return a value.  This
value is trivial, but it causes extra printout:

Type: Void

When ')set messages time on' is active timing system behaves
differently:

(1) -> )set messages time on
(1) -> )version
"FriCAS 2023-06-17 compiled at Mon Dec  4 23:24:12 UTC 2023"
(1) -> systemCommand("version")
"FriCAS 2023-06-17 compiled at Mon Dec  4 23:24:12 UTC 2023"
Type: Void Time: 0 sec

I used 'version' above, but after fixing problem with skipped
statements similar thing will apply to 'read': plain system
commands are not subject to timing, while using 'systemCommand'
we have ordinary FriCAS statement which is timed.  Closest
to "the same" probably would be recursive timing: suspending
timing of 'systemCommand' during actual execution of 'read',
timing expressions executed by 'read' like now (that is
each separately) and restarting timing of 'systemCommand'
after 'read' has finished.  One can argue that timing
of 'systemCommand' does not mater much, but as you have
shown 'systemCommand' may be part of bigger expression
which should be timed as a single unit.

Since also interpret_block popped up... yes, it is the question whether one
wants to time each individual command or the whole as a block.

How about having "timing each individual command" by default? That means
that each time the REPL is completed, the stats are printed.

Do completition of expression in 'interpret_block' count as
"REPL completed"?  One interpretation is that 'interpret_block'
is just a part of bigger expression and only when this bigger
expression is done "REPL is completed".  But if you want to
use 'interpret_block' do get a kind of copy of FriCAS repl,
than it looks that each toplevel epression executed by
'interpret_block' counts as "REPL completed".

Additionally, we could have something like

)start-cumulative-statistics

which wouldn't print any individual statistics, but rather sum the stuff
until it reaches

)print-cumulative-statistics

for an intermediate output and

)stop-cumulative-statistics

for stopping the stats-taking and printing it?

Possibly.  We could have extra argument to 'interpret_block' and
similar routines to decide how timinig is handled.  The question
still remain: is such an argument worth enough to implement?
If no we should make sane rules how timing behaves.  If yes we
still should have reasonable default behaviour.


--
You received this message because you are subscribed to the Google Groups "FriCAS - 
computer algebra system" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to [email protected].
To view this discussion on the web visit 
https://groups.google.com/d/msgid/fricas-devel/812638c9-c453-4083-9c0e-08fe88e7ffaa%40gmail.com.

Reply via email to