Recursive call to interpreter

[Waldek Hebisch]

There is trouble with recusive calls to intepreter. Ralf reported
problem with use of 'systemCommand("read foo.input")', after
fixing part of it I got a hang. Earlier, doing

s := "1 + 1"
interpret_block(s)$Lisp

we got a hang. I now found the reason: recursive call to
intepreter mangles '$timedNameStack' (and other timing
variables) causing infinite loop in statisctics code.
I am not sure what is proper fix for this (more precisely,
how should we time recursive calls). The attached patch
works around infinite loop and fixes abort when doing 'read'
as system command.


--
Waldek Hebisch

[Hill Strong]

There is a simple fix to this problem.

Create a stack onto which you push a copy of the current dynamic variables that you want to keep just before you do the recursive call and restore those dynamic variables immediately after the recursive call finishes.

The best place for this code is in a wrapper for the recursive call of the interpreter, this wrapper is responsible for doing the timing.

Of course if you want to do something similar for other aspects of the FriCAS system, this simple approach can quickly get out of hand. But that is a consequence of the use of the Common List dynamic environment.

Mind you, as long as it is only affecting timing, this should remain simple.

--
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 fricas-devel...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/fricas-devel/ZXZjgLsGX6dRcAN4%40fricas.org.

[Qian Yun]

Based on my experience when I was adding ')storage' and tweaking
g-timer.boot, the problem is that '$timedNameStack' should not
be initialized multiple times.

Aka 'initializeTimedNames' should not be called in 'processInteractive'
(it is already called at toplevel 'interpsysInitialization').

diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
index 20b4773c..04d37850 100644
--- a/src/interp/i-toplev.boot
+++ b/src/interp/i-toplev.boot
@@ -130,8 +130,6 @@ processInteractive(form, posnForm) ==
-- and then calls processInteractive1 to do most of the work.
-- This function receives the output from the parser.

- initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
-
$op: local:= (form is [op,:.] => op; form) --name of operator
$Coerce: local := NIL
$compErrorMessageStack:local := nil

With this change, the looping problem is gone.

Also if my analysis is right, 'savedTimerStack' can also be removed.

This needs more testing and analysis. A side effect of this is
that stats are not working properly.

I'll take a deeper look.

- Qian

[Qian Yun]

Let's test this version: only '$timedNameStack' is initialized once,
the rest stats variables are initialized for each line typed into
interpreter.

- Qian

diff --git a/src/interp/g-timer.boot b/src/interp/g-timer.boot
index cb373c43..02e53450 100644
--- a/src/interp/g-timer.boot
+++ b/src/interp/g-timer.boot
@@ -148,7 +148,6 @@ initializeTimedNames(listofnames,listofclasses) ==
for [.,name,:.] in listofclasses repeat
PUT( name, 'ClassTimeTotal, 0.0)
PUT( name, 'ClassSpaceTotal, 0)
- $timedNameStack := '(other)
computeElapsedTime()
computeElapsedSpace()
PUT('gc, 'TimeTotal, 0.0)
diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
index 20b4773c..00d793ee 100644
--- a/src/interp/i-toplev.boot
+++ b/src/interp/i-toplev.boot
@@ -70,6 +70,7 @@ interpsysInitialization(display_messages) ==
createInitializers()
if $displayStartMsgs then sayKeyedMsg("S2IZ0053",['"interpreter"])
initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
+ $timedNameStack := '(other)
$InteractiveFrame := makeInitialModemapFrame()
initializeSystemCommands()
initializeInterpreterFrameRing()

[Qian Yun]

On 12/11/23 11:49, Qian Yun wrote:
>

> Also if my analysis is right, 'savedTimerStack' can also be removed.
>

savedTimerStack is there because when an error is thrown, it is used
to restore $timedNameStack.

While debugging this problem, I find two more problems:

1. in a line like this:

stepA; systemCommand("read fileB"); stepC;

Stats on stepA is ignored and stats on stepC is the sum of
stats on stepC and stats on last line of fileB.

That's because stats are initialized to 0 at the beginning
of 'systemCommand'.

So the correct solution is to move the initialization of
stats to the end of "Read-Eval-Print-Loop".
^was here ^move here

Now the stats on stepA will be mixed with first line of fileB.
But it's an improvement over current situation.

Nested stats is not that useful, right? I don't see any use case
for it yet.

2. some stats are printed before the collection is over.

So stats initialization should be at the end of one "REPL",
and the printing of stats should be just before that.

====

Back to the original problem, I separated 'initializeTimedNames'
into 'initStatToplevel', which should be initialized at the
end of toplevel initialization process.

The following patch should be broken down into 3 patches to
address the above mentioned 3 problems, then apply Waldek's
patch for 'do_read'.

- Qian

=================

diff --git a/src/interp/g-timer.boot b/src/interp/g-timer.boot
index cb373c43..e6f1ea1d 100644
--- a/src/interp/g-timer.boot
+++ b/src/interp/g-timer.boot
@@ -141,6 +141,15 @@ DEFPARAMETER($interpreterTimedClasses, '(
( 4 reclaim . GC) _
))

+-- This init function should only be called once, at the very end of
+-- system initialization sequence.
+initStatToplevel() ==
+ initializeTimedNames($interpreterTimedNames, $interpreterTimedClasses)
+ $timedNameStack := '(other)
+ $oldElapsedTime := get_run_time()
+ $oldElapsedGCTime := elapsedGcTime()
+ $oldElapsedSpace := HEAPELAPSED()
+
initializeTimedNames(listofnames,listofclasses) ==
for [name,:.] in listofnames repeat
PUT(name, 'TimeTotal, 0.0)
@@ -148,9 +157,6 @@ initializeTimedNames(listofnames,listofclasses) ==

for [.,name,:.] in listofclasses repeat
PUT( name, 'ClassTimeTotal, 0.0)
PUT( name, 'ClassSpaceTotal, 0)
- $timedNameStack := '(other)

- computeElapsedTime()
- computeElapsedSpace()
PUT('gc, 'TimeTotal, 0.0)
PUT('gc, 'SpaceTotal, 0)
NIL
diff --git a/src/interp/i-syscmd.boot b/src/interp/i-syscmd.boot
index 0b3e09f5..84a9c1d3 100644
--- a/src/interp/i-syscmd.boot
+++ b/src/interp/i-syscmd.boot
@@ -2212,8 +2212,6 @@ do_read(ll, quiet, pile_mode) ==
$nopiles : local := pile_mode
$edit_file := ll
read_or_compile(quiet, false)
- terminateSystemCommand()
- spadPrompt()

basename(x) == NAMESTRING(PATHNAME_-NAME(x))

diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
index 20b4773c..b71ef2d6 100644
--- a/src/interp/i-toplev.boot
+++ b/src/interp/i-toplev.boot
@@ -69,7 +69,6 @@ interpsysInitialization(display_messages) ==
interpOpen(display_messages)

createInitializers()
if $displayStartMsgs then sayKeyedMsg("S2IZ0053",['"interpreter"])

- initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)

$InteractiveFrame := makeInitialModemapFrame()
initializeSystemCommands()
initializeInterpreterFrameRing()

@@ -104,6 +103,7 @@ interpsys_restart() ==
browseOpen(true)
makeConstructorsAutoLoad()
createInitializers2()
+ initStatToplevel()

readSpadProfileIfThere() ==
-- reads SPADPROF INPUT if it exists

@@ -130,8 +130,6 @@ processInteractive(form, posnForm) ==
-- and then calls processInteractive1 to do most of the work.
-- This function receives the output from the parser.

- initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
-
$op: local:= (form is [op,:.] => op; form) --name of operator
$Coerce: local := NIL
$compErrorMessageStack:local := nil

@@ -159,6 +157,9 @@ processInteractive(form, posnForm) ==
CLRHASH $instantRecord
writeHistModesAndValues()
updateHist()
+ if $printTimeIfTrue then printTime()
+ if $printStorageIfTrue then printStorage()
+ initializeTimedNames($interpreterTimedNames, $interpreterTimedClasses)
object

processInteractive1(form, posnForm) ==
@@ -199,31 +200,16 @@ recordAndPrint(x,md) ==
if $QuietCommand = false then
output(x',md')
putHist('%,'value,objNewWrap(x,md),$e)
- if $printTimeIfTrue or $printTypeIfTrue then printTypeAndTime(x',md')
- if $printStorageIfTrue then printStorage()
+ if $printTypeIfTrue then printType(x', md')
'done

-printTypeAndTime(x,m) == --m is the mode/type of the result
- printTypeAndTimeNormal(x, m)
-
-printTypeAndTimeNormal(x,m) ==
- -- called only if either type or time is to be displayed
+printType(x, m) == -- m is the mode/type of the result
if m is ['Union, :argl] then
x' := retract(objNewWrap(x,m))
m' := objMode x'
m := ['Union, :[arg for arg in argl | sameUnionBranch(arg, m')],
'"..."]
- if $printTimeIfTrue then
- timeString := makeLongTimeString($interpreterTimedNames,
- $interpreterTimedClasses)
if $printTypeIfTrue then
type_string := outputDomainConstructor(m)
- $printTimeIfTrue and $printTypeIfTrue =>
- $collectOutput =>
- $outputLines := [msgText("S2GL0012", [type_string]), :$outputLines]
- sayKeyedMsg("S2GL0014", [type_string, timeString])
- $printTimeIfTrue =>
- $collectOutput => nil
- sayKeyedMsg("S2GL0013",[timeString])
$printTypeIfTrue =>
$collectOutput =>
$outputLines :=
@@ -248,6 +234,11 @@ justifyMyType(t) ==
typeTimePrin x ==
maprinSpecial(x,0,79)

+printTime() ==
+ $collectOutput => nil
+ s := makeLongTimeString($interpreterTimedNames, $interpreterTimedClasses)
+ sayKeyedMsg("S2GL0013", [s])
+
printStorage() ==
$collectOutput => nil
storeString :=
@@ -259,6 +250,7 @@ printStorage() ==
interpretTopLevel(x, posnForm) ==
-- Top level entry point from processInteractive1. Sets up catch
-- for a thrown result
+ -- $timedNameStack is saved and restored in case an error is thrown.
savedTimerStack := COPY $timedNameStack
c := CATCH('interpreter,interpret(x, posnForm))
while savedTimerStack ~= $timedNameStack repeat

[Waldek Hebisch]

On Mon, Dec 11, 2023 at 12:05:52PM +0800, Qian Yun wrote:
> Let's test this version: only '$timedNameStack' is initialized once,
> the rest stats variables are initialized for each line typed into
> interpreter.

Well, first question is: what timing routines should do?
Currently, ')read' is printing time for each toplevel expression
in input file separately. It is reasonable to handle
'read' executed via system command in the same way. However,
then we have question what should be included in timing report
for statement including call to system command?

Beside 'read' we can call intepreter via 'interpret_block',
'parseAndEvalStr' and 'interpret'. Arguably 'interpret'
should not be timed separately but as part of caller.


--
Waldek Hebisch

[Qian Yun]

On 12/11/23 20:19, Waldek Hebisch wrote:
> On Mon, Dec 11, 2023 at 12:05:52PM +0800, Qian Yun wrote:
>> Let's test this version: only '$timedNameStack' is initialized once,
>> the rest stats variables are initialized for each line typed into
>> interpreter.
>
> Well, first question is: what timing routines should do?
> Currently, ')read' is printing time for each toplevel expression
> in input file separately. It is reasonable to handle
> 'read' executed via system command in the same way. However,
> then we have question what should be included in timing report
> for statement including call to system command?

If you only want stats on the whole block, then by arranging
some variables to indicate inner call of 'interpret' to stop
collection and reporting (and init) of stats.

But if you want stats reporting in each line of a block,
and a total stats on the whole block, then it's more complicated
but still doable: using local instead of global variable to
store the stats.

- Qian

[Ralf Hemmecke]

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.

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.

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?

Ralf

[Waldek Hebisch]

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.

--
Waldek Hebisch

[Qian Yun]

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

[Qian Yun]

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

[Qian Yun]

Now I have a series of 7 patches, hopefully to solve this problem.

You can view them in attachment or at
https://github.com/oldk1331/fricas/commits/stats

I'm not very sure about
"reinit stats global variables when error happens".

Is "int_loop" the right place to reset $timedNameStack
when error happens? (e.g. "1/0").

- Qian

On 12/11/23 09:18, Waldek Hebisch wrote:

[Waldek Hebisch]

On Wed, Dec 13, 2023 at 07:44:16PM +0800, Qian Yun wrote:
> Now I have a series of 7 patches, hopefully to solve this problem.
>
> You can view them in attachment or at
> https://github.com/oldk1331/fricas/commits/stats
>
> I'm not very sure about
> "reinit stats global variables when error happens".
>
> Is "int_loop" the right place to reset $timedNameStack
> when error happens? (e.g. "1/0").

The code looks mostly good. But concerning reseting $timedNameStack
I am not sure what to do. Typical pattern in interpreter is
use of Lisp dynamic variables. When something THROW-s, then
dynamic variables are automatically restored to value they had
at outer level. Reseting in different way is problematic,
in principle every place containing CATCH must be checked if
it is doing correct thing, that is restores varibles before
wrong value is in use. There is extra complication: in Spad
code we have no way do do dynamic binding, so Spad has
"try ... finally ..." construct which ensures that cleanup
code is run even in case of abnormal exit (that is THROW).
This construct translates to Lisp UNWIND-PROTECT (via
'finally' macro), and in principle UNWIND-PROTECT (or
'finally' macro) could be used to implement cleanup also
at BOOT level.

Anyway, given interpreter => algebra(Spad) => interpeter
chain, THROW from inner interpreter may be intercepted by
in algebra and return to outer interpeter. So there is
need for cleanup in 'interpret' so that return from
algebra call have consistent state.

Remark: calls from algebra to interpeter are rare and
probablity that somebody will time them is low. But it
is better to write correct code, than to bet that nobody
will see bugs.

BTW: AFAICS first patch and the last one are somewhat independent,
but to other seem to be tightly related, so it looks
unnatural to split this part into 5 patches.

--
Waldek Hebisch

[Qian Yun]

On 12/17/23 09:46, Waldek Hebisch wrote:
> On Wed, Dec 13, 2023 at 07:44:16PM +0800, Qian Yun wrote:
>> Now I have a series of 7 patches, hopefully to solve this problem.
>>
>> You can view them in attachment or at
>> https://github.com/oldk1331/fricas/commits/stats
>>
>> I'm not very sure about
>> "reinit stats global variables when error happens".
>>
>> Is "int_loop" the right place to reset $timedNameStack
>> when error happens? (e.g. "1/0").
>
> The code looks mostly good. But concerning reseting $timedNameStack
> I am not sure what to do. Typical pattern in interpreter is
> use of Lisp dynamic variables. When something THROW-s, then
> dynamic variables are automatically restored to value they had
> at outer level. Reseting in different way is problematic,

Yes, I tried to use dynamic variables, aka ":local" variable
in BOOT. But I failed. Now that you mentioned it, I tried again:

====
diff --git a/src/interp/i-map.boot b/src/interp/i-map.boot
index cbe7aa3c..c3a3620b 100644
--- a/src/interp/i-map.boot
+++ b/src/interp/i-map.boot
@@ -630,13 +630,10 @@ interpMap(opName,tar) ==
$mapName : local := opName
$mapTarget : local := tar
body:= get(opName,'mapBody,$e)
- savedTimerStack := COPY $timedNameStack
catchName := mapCatchName $mapName
c := CATCH(catchName, interpret1(body,tar,nil))
-- $interpMapTag and $interpMapTag ~= mapCatchName $mapName =>
-- THROW($interpMapTag,c)
- while savedTimerStack ~= $timedNameStack repeat
- stopTimingProcess peekTimedName()
c -- better be a triple

analyzeDeclaredMap(op,argTypes,sig,mapDef,$mapList) ==
diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
index 20b4773c..54e87a15 100644
--- a/src/interp/i-toplev.boot
+++ b/src/interp/i-toplev.boot
@@ -130,6 +130,7 @@ processInteractive(form, posnForm) ==

-- and then calls processInteractive1 to do most of the work.
-- This function receives the output from the parser.

+ $timedNameStack : local := NIL
initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)

$op: local:= (form is [op,:.] => op; form) --name of operator

@@ -259,10 +260,7 @@ printStorage() ==

interpretTopLevel(x, posnForm) ==
-- Top level entry point from processInteractive1. Sets up catch
-- for a thrown result

- savedTimerStack := COPY $timedNameStack

c := CATCH('interpreter,interpret(x, posnForm))

- while savedTimerStack ~= $timedNameStack repeat
- stopTimingProcess peekTimedName()
c = 'tryAgain => interpretTopLevel(x, posnForm)
c

====

So the "$timedNameStack : local" declaration is the key here.

>
> BTW: AFAICS first patch and the last one are somewhat independent,
> but to other seem to be tightly related, so it looks
> unnatural to split this part into 5 patches.
>

I break them down so that it's easier for me to write and test,
and easier for reviewers.

How about let's proceed like this:

1. apply the patch in this mail, to prevent infinity recursion
2. apply your patch, to allow evaluation after "systemCommand"
3. apply my first patch in branch "stats", to separate printTime
from printType

Then I will do some minor changes to the code to allow recursive
timing, and let's discuss that in another thread.

- Qian

[Waldek Hebisch]

For just restoring value there is construction:

fun1(x, $var) ==
-- do work

fun(x) == fun1(x, $var)

The effect is that 'fun1' uses current value of '$var' but any
changes inside 'fun1' are discarde when 'fun1' resturns (Lisp
restores value that '$var' had at entry to 'fun1').

> > BTW: AFAICS first patch and the last one are somewhat independent,
> > but to other seem to be tightly related, so it looks
> > unnatural to split this part into 5 patches.
> >
>
> I break them down so that it's easier for me to write and test,
> and easier for reviewers.
>
> How about let's proceed like this:
>
> 1. apply the patch in this mail, to prevent infinity recursion

I am affraid that we need to do something in 'interpMap' in (i-map.boot).

> 2. apply your patch, to allow evaluation after "systemCommand"
> 3. apply my first patch in branch "stats", to separate printTime
> from printType
>
> Then I will do some minor changes to the code to allow recursive
> timing, and let's discuss that in another thread.

--
Waldek Hebisch

[Qian Yun]

On 12/17/23 23:56, Waldek Hebisch wrote:
>>
>> So the "$timedNameStack : local" declaration is the key here.
>
> For just restoring value there is construction:
>
> fun1(x, $var) ==
> -- do work
>
> fun(x) == fun1(x, $var)
>
> The effect is that 'fun1' uses current value of '$var' but any
> changes inside 'fun1' are discarde when 'fun1' resturns (Lisp
> restores value that '$var' had at entry to 'fun1').
>

This is the same as ":local" declaration, right? The ":local"
declaration creates an implicit "PROG" scope.

>> How about let's proceed like this:
>>
>> 1. apply the patch in this mail, to prevent infinity recursion
>
> I am affraid that we need to do something in 'interpMap' in (i-map.boot).
>

So the dynamic variable shadowing should also happen in "interpret1"?

BTW, can you give an example of "interpOnly"? So that I can test it.

- Qian

[Waldek Hebisch]

On Mon, Dec 18, 2023 at 08:29:49AM +0800, Qian Yun wrote:
>
>
> On 12/17/23 23:56, Waldek Hebisch wrote:
> > >
> > > So the "$timedNameStack : local" declaration is the key here.
> >
> > For just restoring value there is construction:
> >
> > fun1(x, $var) ==
> > -- do work
> >
> > fun(x) == fun1(x, $var)
> >
> > The effect is that 'fun1' uses current value of '$var' but any
> > changes inside 'fun1' are discarde when 'fun1' resturns (Lisp
> > restores value that '$var' had at entry to 'fun1').
> >
>
> This is the same as ":local" declaration, right? The ":local"
> declaration creates an implicit "PROG" scope.

There is a subtle difference: ":local" requires explicit initial
value (if you omit inital value you will get NIL). Above,
initial value is taken from function argument. And two-stage
call allows to use current value of variable as initial value
in dynamic scope. AFAIR trying to have the same effect in
one stage did not work.

> > > How about let's proceed like this:
> > >
> > > 1. apply the patch in this mail, to prevent infinity recursion
> >
> > I am affraid that we need to do something in 'interpMap' in (i-map.boot).
> >
>
> So the dynamic variable shadowing should also happen in "interpret1"?
>
> BTW, can you give an example of "interpOnly"? So that I can test it.

Interpreter uses somewhat funky data structures, so it is hard to make
a separate call. "interpOnly" is called when interpreter fails to compile
a function, basically when it does not see that types match.
There is a message:

FriCAS will attempt to step through and interpret the code.

you can use it to search for examples.

--
Waldek Hebisch

[Qian Yun]

On 12/18/23 08:56, Waldek Hebisch wrote:
>
>>>> How about let's proceed like this:
>>>>
>>>> 1. apply the patch in this mail, to prevent infinity recursion
>>>
>>> I am affraid that we need to do something in 'interpMap' in (i-map.boot).
>>>
>>
>> So the dynamic variable shadowing should also happen in "interpret1"?
>>
>> BTW, can you give an example of "interpOnly"? So that I can test it.
>
> Interpreter uses somewhat funky data structures, so it is hard to make
> a separate call. "interpOnly" is called when interpreter fails to compile
> a function, basically when it does not see that types match.
> There is a message:
>
> FriCAS will attempt to step through and interpret the code.
>
> you can use it to search for examples.
>

One such example of "interpOnly" is:

f==n+->sum(sum(1/i,i=1..j),j=1..n)
f(1)

Back to this bug:

So it seems that "savedTimerStack" is intentionally paired with "CATCH".
Given the nature of stack, I presume a simple assignment is enough, copy
is not needed?

savedTimerStack := $timedNameStack

c := CATCH('interpreter,interpret(x, posnForm))

$timedNameStack := savedTimerStack

Otherwise I'm a bit lost to this bug.

Waldek, what's your opinion on fixing this bug?

- Qian

[Waldek Hebisch]

Well, original had:

while savedTimerStack ^= $timedNameStack repeat
stopTimingProcess peekTimedName()

'stopTimingProcess' calls 'updateTimedName' which was/is needed
to update counters. IIUC without this statistics will be wrong
(time will be "charged" to different use).

> Waldek, what's your opinion on fixing this bug?

AFAICS loop here and in interpretTopLevel where right. I am not
sure if the loop is really necessary, but we need to do proper
accounting and the loop is "obviously correct" way of doing this.
Another approach may easily get broken by changes.

IMO proper fix for this bug involves making sure that we always
have valid '$timedNameStack' and that it is in sync with other
variables. One way to ensure this is doing "push" on init,
instead of assignment.

--
Waldek Hebisch

[Qian Yun]

On 12/19/23 08:01, Waldek Hebisch wrote:
>
> Well, original had:
>
> while savedTimerStack ^= $timedNameStack repeat
> stopTimingProcess peekTimedName()
>
> 'stopTimingProcess' calls 'updateTimedName' which was/is needed
> to update counters. IIUC without this statistics will be wrong
> (time will be "charged" to different use).

'stopTimingProcess' will run only when exceptions are thrown and
catched. In this case, stats are already messed up.

>> Waldek, what's your opinion on fixing this bug?
>
> AFAICS loop here and in interpretTopLevel where right. I am not
> sure if the loop is really necessary, but we need to do proper
> accounting and the loop is "obviously correct" way of doing this.
> Another approach may easily get broken by changes.
>
> IMO proper fix for this bug involves making sure that we always
> have valid '$timedNameStack' and that it is in sync with other
> variables. One way to ensure this is doing "push" on init,
> instead of assignment.
>

OK, to recap on this problem:

We need to make sure '$timedNameStack' is valid.

'$timedNameStack' can be messed up in two cases:

1. recursion
2. thrown and catch exceptions

For 1, correct way is to use dynamic bindings.
For 2, I believe simple assignment is enough. Or keep current
code if we fix problem 1.

- Qian

[Waldek Hebisch]

On Tue, Dec 19, 2023 at 05:58:37PM +0800, Qian Yun wrote:
>
>
> On 12/19/23 08:01, Waldek Hebisch wrote:
> >
> > Well, original had:
> >
> > while savedTimerStack ^= $timedNameStack repeat
> > stopTimingProcess peekTimedName()
> >
> > 'stopTimingProcess' calls 'updateTimedName' which was/is needed
> > to update counters. IIUC without this statistics will be wrong
> > (time will be "charged" to different use).
>
> 'stopTimingProcess' will run only when exceptions are thrown and
> catched. In this case, stats are already messed up.

I do not think so. More preciesely, 'startTimingProcess' adds
position to '$timedNameStack' and causes timing to be charged
to given name up to point of another 'startTimingProcess'
or 'stopTimingProcess'. When 'THROW' happens time is still
charged to code responible for 'THROW' which is more or less
resonable. Normal return would call 'stopTimingProcess', the
loop simulates this.

> > > Waldek, what's your opinion on fixing this bug?
> >
> > AFAICS loop here and in interpretTopLevel where right. I am not
> > sure if the loop is really necessary, but we need to do proper
> > accounting and the loop is "obviously correct" way of doing this.
> > Another approach may easily get broken by changes.
> >
> > IMO proper fix for this bug involves making sure that we always
> > have valid '$timedNameStack' and that it is in sync with other
> > variables. One way to ensure this is doing "push" on init,
> > instead of assignment.
> >
>
> OK, to recap on this problem:
>
> We need to make sure '$timedNameStack' is valid.
>
> '$timedNameStack' can be messed up in two cases:
>
> 1. recursion
> 2. thrown and catch exceptions
>
> For 1, correct way is to use dynamic bindings.

Dynamic bindings would be good if the loop was not present. We
need to make sure that variables are still valid when we execute
the loop.

I think that simplest solution is to avoid _assignment to
'$timedNameStack'. Instead initialization should push, so
that when there is timing in progress poping will get old value.

> For 2, I believe simple assignment is enough. Or keep current
> code if we fix problem 1.

Simplest way is to keep current loops. More complicated way
could put UNWIND-PROTECT in strategic places and use cleanup
part to handle '$timedNameStack'.

--
Waldek Hebisch

[Qian Yun]

On 12/19/23 20:19, Waldek Hebisch wrote:
> On Tue, Dec 19, 2023 at 05:58:37PM +0800, Qian Yun wrote:
>>
>>
>> On 12/19/23 08:01, Waldek Hebisch wrote:
>>>
>>> Well, original had:
>>>
>>> while savedTimerStack ^= $timedNameStack repeat
>>> stopTimingProcess peekTimedName()
>>>
>>> 'stopTimingProcess' calls 'updateTimedName' which was/is needed
>>> to update counters. IIUC without this statistics will be wrong
>>> (time will be "charged" to different use).
>>
>> 'stopTimingProcess' will run only when exceptions are thrown and
>> catched. In this case, stats are already messed up.
>
> I do not think so. More preciesely, 'startTimingProcess' adds
> position to '$timedNameStack' and causes timing to be charged
> to given name up to point of another 'startTimingProcess'
> or 'stopTimingProcess'. When 'THROW' happens time is still
> charged to code responible for 'THROW' which is more or less
> resonable. Normal return would call 'stopTimingProcess', the
> loop simulates this.

I can agree on this part.

>>>> Waldek, what's your opinion on fixing this bug?
>>>
>>> AFAICS loop here and in interpretTopLevel where right. I am not
>>> sure if the loop is really necessary, but we need to do proper
>>> accounting and the loop is "obviously correct" way of doing this.
>>> Another approach may easily get broken by changes.
>>>
>>> IMO proper fix for this bug involves making sure that we always
>>> have valid '$timedNameStack' and that it is in sync with other
>>> variables. One way to ensure this is doing "push" on init,
>>> instead of assignment.
>>>
>>
>> OK, to recap on this problem:
>>
>> We need to make sure '$timedNameStack' is valid.
>>
>> '$timedNameStack' can be messed up in two cases:
>>
>> 1. recursion
>> 2. thrown and catch exceptions
>>
>> For 1, correct way is to use dynamic bindings.
>
> Dynamic bindings would be good if the loop was not present. We
> need to make sure that variables are still valid when we execute
> the loop.
>
> I think that simplest solution is to avoid _assignment to
> '$timedNameStack'. Instead initialization should push, so
> that when there is timing in progress poping will get old value.

If you want to use "push", then what happens to not catched errors,
for example "1/0"?

Then '$timedNameStack' will keep growing.

So I think use assignment to initialize this dynamic variable
is the correct approach.

- Qian

[Waldek Hebisch]

Well, eventually something should catch error. And the place catching
it should do the unwinding loop. We need to look what is simpler:
unwinding loop at all relevant catchers (many only catches where
timing context changes are relevant) or putting 'stopTimedName'
inside UNWIND-PROTECT cleanup.

> Then '$timedNameStack' will keep growing.

Well, if cleanup is done correctly than no.

> So I think use assignment to initialize this dynamic variable
> is the correct approach.

Assignment has trouble with accounting

--
Waldek Hebisch

[Qian Yun]

Currently we are collecting stats on a line-by-line basis,
"processInteractive" can be considered as "toplevel" for
line-by-line execution.

So it is natural to reset '$timedNameStack' here.

>> Then '$timedNameStack' will keep growing.
>
> Well, if cleanup is done correctly than no.
>
>> So I think use assignment to initialize this dynamic variable
>> is the correct approach.
>
> Assignment has trouble with accounting
>

You mean current problem with nested stats collection?
If using each '$timedNameStack is in its own dynamic scope,
then there will be no problem.

- Qian

[Waldek Hebisch]

There is a problem: we need to run 'stopTimingProcess' with
correct argument, othewise we will charge resources to
wrong group. And once '$timedNameStack' is poped we lost
info about group. So we need to run 'stopTimingProcess'
before restoring previous value of '$timedNameStack'.
Current loop works here. Calling '$timedNameStack' in
UNWID-PROTECT cleanup could work too. Just restoring
'$timedNameStack' as dynamic variable will miss
calls to 'stopTimingProcess' leading to wrong accounting.

--
Waldek Hebisch

[Qian Yun]

I thought more about this and realized the key differences between:

1. modifying a dynamic variable
2. creating a new dynamic binding, shadowing the old dynamic variable

So I think following patch fix the loop in
interpret_block("1+1")$Lisp
perfectly. '$timedNameStack' is still balanced.

WDYT?

- Qian

diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
index 20b4773c..03a3c870 100644

[Waldek Hebisch]

On Fri, Dec 22, 2023 at 07:28:32PM +0800, Qian Yun wrote:
>
>
> On 12/20/23 09:58, Waldek Hebisch wrote:
> > On Wed, Dec 20, 2023 at 08:03:02AM +0800, Qian Yun wrote:
> > >
> > > You mean current problem with nested stats collection?
> > > If using each '$timedNameStack is in its own dynamic scope,
> > > then there will be no problem.
> >
> > There is a problem: we need to run 'stopTimingProcess' with
> > correct argument, othewise we will charge resources to
> > wrong group. And once '$timedNameStack' is poped we lost
> > info about group. So we need to run 'stopTimingProcess'
> > before restoring previous value of '$timedNameStack'.
> > Current loop works here. Calling '$timedNameStack' in
> > UNWID-PROTECT cleanup could work too. Just restoring
> > '$timedNameStack' as dynamic variable will miss
> > calls to 'stopTimingProcess' leading to wrong accounting.
> >
>
> I thought more about this and realized the key differences between:
>
> 1. modifying a dynamic variable
> 2. creating a new dynamic binding, shadowing the old dynamic variable
>
> So I think following patch fix the loop in
> interpret_block("1+1")$Lisp
> perfectly. '$timedNameStack' is still balanced.
>
> WDYT?

Well, with this '$timedNameStack' is balanced. But there is still
trouble with acconting: since 'stopTimingProcess' was not called
we will either ignore or assign to wrong context resources used
in context that did 'THROW'.

> - Qian
>
> diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
> index 20b4773c..03a3c870 100644
> --- a/src/interp/i-toplev.boot
> +++ b/src/interp/i-toplev.boot
> @@ -130,6 +130,7 @@ processInteractive(form, posnForm) ==
> -- and then calls processInteractive1 to do most of the work.
> -- This function receives the output from the parser.
>
> + $timedNameStack : local := NIL
> initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
>
> $op: local:= (form is [op,:.] => op; form) --name of operator

I think that we need something like:

$timedNameStack : local := NIL
finally(
(initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses);
object := processInteractive1(form, posnForm)),
while $timedNameStack repeat stopTimingProcess peekTimedName();
)

Note: this looks obscure, but first thing is normal code, second in
cleanup that is executed both during normal return and in case of
abnormal exit ('THROW', Lisp exceptions).

--
Waldek Hebisch

[Qian Yun]

If there's throw to top level, then stats will not be printed,
so there's no need to continue collect stats.
And '$timedNameStack' will leave this dynamic scope and reinit in
next call, so it will not affect future accountings.

>> - Qian
>>
>> diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
>> index 20b4773c..03a3c870 100644
>> --- a/src/interp/i-toplev.boot
>> +++ b/src/interp/i-toplev.boot
>> @@ -130,6 +130,7 @@ processInteractive(form, posnForm) ==
>> -- and then calls processInteractive1 to do most of the work.
>> -- This function receives the output from the parser.
>>
>> + $timedNameStack : local := NIL
>> initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
>>
>> $op: local:= (form is [op,:.] => op; form) --name of operator
>
> I think that we need something like:
>
> $timedNameStack : local := NIL
> finally(
> (initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses);
> object := processInteractive1(form, posnForm)),
> while $timedNameStack repeat stopTimingProcess peekTimedName();
> )
>
> Note: this looks obscure, but first thing is normal code, second in
> cleanup that is executed both during normal return and in case of
> abnormal exit ('THROW', Lisp exceptions).
>

You mean 'finally' to catch all exceptions? Wouldn't that conflict
with ')set break break/etc...' handlers?

- Qian

[Waldek Hebisch]

Forget about toplevel. This tread is above recursive calls.
In particular algebra may perform call to interpreter and
catch errors. When algebra returns to outer interpreter
we should print statistics. Similar thing happens inside
interpreter.

BTW: It is debatable if not printing stats in case of errors
is right thing to do.

> And '$timedNameStack' will leave this dynamic scope and reinit in
> next call, so it will not affect future accountings.

That is true.

> > > - Qian
> > >
> > > diff --git a/src/interp/i-toplev.boot b/src/interp/i-toplev.boot
> > > index 20b4773c..03a3c870 100644
> > > --- a/src/interp/i-toplev.boot
> > > +++ b/src/interp/i-toplev.boot
> > > @@ -130,6 +130,7 @@ processInteractive(form, posnForm) ==
> > > -- and then calls processInteractive1 to do most of the work.
> > > -- This function receives the output from the parser.
> > >
> > > + $timedNameStack : local := NIL
> > > initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses)
> > >
> > > $op: local:= (form is [op,:.] => op; form) --name of operator
> >
> > I think that we need something like:
> >
> > $timedNameStack : local := NIL
> > finally(
> > (initializeTimedNames($interpreterTimedNames,$interpreterTimedClasses);
> > object := processInteractive1(form, posnForm)),
> > while $timedNameStack repeat stopTimingProcess peekTimedName();
> > )
> >
> > Note: this looks obscure, but first thing is normal code, second in
> > cleanup that is executed both during normal return and in case of
> > abnormal exit ('THROW', Lisp exceptions).
> >
>
> You mean 'finally' to catch all exceptions? Wouldn't that conflict
> with ')set break break/etc...' handlers?

Well, ')set break break' should give unmolested stack to debugger,
before stack unwinding and cleanups. In case of 'THROW' or
exceptions: once the cleanup part is done 'THROW' (or exception)
is supposed to propagate further as if nothing happended. In principle
there may be some confusion when cleanup code throws errors,
but intention is that cleanups should consist of safe code
which does not cause errors.

--
Waldek Hebisch

[Qian Yun]

On 12/24/23 09:41, Waldek Hebisch wrote:
>>>
>>> Well, with this '$timedNameStack' is balanced. But there is still
>>> trouble with acconting: since 'stopTimingProcess' was not called
>>> we will either ignore or assign to wrong context resources used
>>> in context that did 'THROW'.
>>
>> If there's throw to top level, then stats will not be printed,
>> so there's no need to continue collect stats.
>
> Forget about toplevel. This tread is above recursive calls.
> In particular algebra may perform call to interpreter and
> catch errors. When algebra returns to outer interpreter
> we should print statistics. Similar thing happens inside
> interpreter.
>
> BTW: It is debatable if not printing stats in case of errors
> is right thing to do.
>

"When algebra returns to outer interpreter", the $timedNameStack
in outer interpreter is not affected by inner interpreter.
The total time spent in inner interpreter is accounted under
"evaluation" of outer interpreter.

Can you give an example (inner interpreter catches exception)
so that I can verify if it messes up stats accounting?

- Qian

[Waldek Hebisch]

On Sun, Dec 24, 2023 at 09:55:03AM +0800, Qian Yun wrote:
>
>
> On 12/24/23 09:41, Waldek Hebisch wrote:
> > > >
> > > > Well, with this '$timedNameStack' is balanced. But there is still
> > > > trouble with acconting: since 'stopTimingProcess' was not called
> > > > we will either ignore or assign to wrong context resources used
> > > > in context that did 'THROW'.
> > >
> > > If there's throw to top level, then stats will not be printed,
> > > so there's no need to continue collect stats.
> >
> > Forget about toplevel. This tread is above recursive calls.
> > In particular algebra may perform call to interpreter and
> > catch errors. When algebra returns to outer interpreter
> > we should print statistics. Similar thing happens inside
> > interpreter.
> >
> > BTW: It is debatable if not printing stats in case of errors
> > is right thing to do.
> >
>
> "When algebra returns to outer interpreter", the $timedNameStack
> in outer interpreter is not affected by inner interpreter.
> The total time spent in inner interpreter is accounted under
> "evaluation" of outer interpreter.

Well, deciding what to do in such situation is part
of solving problem. AFAICS before your patches inner
interpreter messed statistic variables of outer one,
and printing nothing in outer interpreter masked the
trouble. IMO when some code is aborted, but error is
caught and computation continues, we should count
time spent in aborted code. Which means that we should
ensure consitent statistics. This may require use of
different function than 'processInteractive' (or change
to 'processInteractive').

To put this differently: there is 'read' which separately
times toplevel expressions in a file, which requires recursive
timing. But we also have calls from algebra to interpreter
and those IMO should be timed togethere with toplevel call.
If we assume that recursive calls via 'processInteractive'
only deal with 'read' than you change looks OK.

> Can you give an example (inner interpreter catches exception)
> so that I can verify if it messes up stats accounting?

In algebra we can use: 'trapNumericErrors', 'trappedSpadEval'
and 'eval_with_timeout'. More can be added if needed. Code
executed by constructs above may call 'interpret',
'interpret_block' or other interpeter constructs. There is
also possibility of passing interpeter functions to algebra
code. Normaly, such functions are compiled, but sometimes
interpreter really interpret functions. I am not sure if
interpretation is allowed for functions passed to algebra,
but one can argue that they should be supported.

Note: part of problem is deciding which calls should do recursive
timings and how those should behave. Past behaviour is of
limited help here, as we want to fix trouble with current
code which probably will involve changing behaviour to more
desirable one.

--
Waldek Hebisch

[Qian Yun]

OK, this might not be that complicated after all, hear my analysis:

1. Assume there is only 1 (global) scope for $timedNameStack,
and it is only modified by push or pop, never gets assignment.

When an exception is thrown in somewhere and catched somewhere else,
now there's a "stopTimingProcess A", but the head of $timedNameStack
is B. We can simply attribute the stats to A, and continue.
(Current "savedTimerStack" is attributing the stats to B.)

The only downside is that $timedNameStack will grow indefinitely.

2. Now let's have a dynamic scope for $timedNameStack for each nested
"processInteractive". Problem solved. No need to wrap around every
CATCH. $timedNameStack will not grow indefinitely.


What I'm saying is:

1. dynamic scoping for $timedNameStack
2. do not use savedTimerStack around CATCH
3. do not check with "peekTimedName" in "stopTimingProcess".
(aka allow unbalanced $timedNameStack, which is a price has to be paid
for exception handling)

- Qian

[Waldek Hebisch]

On Sun, Dec 24, 2023 at 08:16:46PM +0800, Qian Yun wrote:
> OK, this might not be that complicated after all, hear my analysis:
>
> 1. Assume there is only 1 (global) scope for $timedNameStack,
> and it is only modified by push or pop, never gets assignment.
>
> When an exception is thrown in somewhere and catched somewhere else,
> now there's a "stopTimingProcess A", but the head of $timedNameStack
> is B. We can simply attribute the stats to A, and continue.
> (Current "savedTimerStack" is attributing the stats to B.)
>
> The only downside is that $timedNameStack will grow indefinitely.
>
> 2. Now let's have a dynamic scope for $timedNameStack for each nested
> "processInteractive". Problem solved. No need to wrap around every
> CATCH. $timedNameStack will not grow indefinitely.
>
>
> What I'm saying is:
>
> 1. dynamic scoping for $timedNameStack
> 2. do not use savedTimerStack around CATCH
> 3. do not check with "peekTimedName" in "stopTimingProcess".
> (aka allow unbalanced $timedNameStack, which is a price has to be paid
> for exception handling)

I think that this would be a regression. Most cases of unwinding
probably happens in a single invocation of interpreter and now
AFAICS they work fine.

AFAICS main thing is deciding which interpreter calls should use
"unified" timing (that is timing context from outside) and which
should use new timing context. ')read' should use new timing
context and for this dynamic '$timedNameStack' probably is fine.
IMO 'interpret' calls from algebra should use unified timing
context, that is skip 'initializeTimedNames' or arrange things
so that 'initializeTimedNames' do not create new context.

'interpret_block' and various 'eval...' functions probably should
be treated as 'interpret'.

--
Waldek Hebisch

[Waldek Hebisch]

On Sun, Dec 24, 2023 at 08:16:46PM +0800, Qian Yun wrote:

> OK, this might not be that complicated after all, hear my analysis:
>
> 1. Assume there is only 1 (global) scope for $timedNameStack,
> and it is only modified by push or pop, never gets assignment.
>
> When an exception is thrown in somewhere and catched somewhere else,
> now there's a "stopTimingProcess A", but the head of $timedNameStack
> is B. We can simply attribute the stats to A, and continue.
> (Current "savedTimerStack" is attributing the stats to B.)
>
> The only downside is that $timedNameStack will grow indefinitely.
>
> 2. Now let's have a dynamic scope for $timedNameStack for each nested
> "processInteractive". Problem solved. No need to wrap around every
> CATCH. $timedNameStack will not grow indefinitely.
>
>
> What I'm saying is:
>
> 1. dynamic scoping for $timedNameStack
> 2. do not use savedTimerStack around CATCH
> 3. do not check with "peekTimedName" in "stopTimingProcess".
> (aka allow unbalanced $timedNameStack, which is a price has to be paid
> for exception handling)

Well, I am trying to simply remove call to 'initializeTimedNames'
from 'processInteractive'. Few simple tests show no ill effects,
OTOH after such change 'interpret_block' finishes and with
change to 'i-syscmd.boot' Ralf's example works. But I did
not check how this affects case when we actually need statistics.

My main point here is that 'processInteractive' looks like
wrong place to handle recursive statistics. This should
be done in different place.

--
Waldek Hebisch