Monitoring execution

set arg_check {on,off};  
This turns argument checking on or off. Argument checking is on by default and includes bounds checking, divide by zero checking, and range checking. Runtime errors  detected by argument checking print a message of the form:

<Nesl> let a = [2,3,4] in a[5];

Compiling..Writing..Loading..Running..
RUNTIME ERROR: Sequence reference (a[i]) out of bounds.
Exiting..Reading..

Argument checking takes time, so it can be turned off to generate faster code.

set trace funname n;  
This sets the tracing level for any non-primitive function. Tracing is used for debugging and prints out a message each time the function is entered and exited. The argument n specifies the level of tracing. The choices are:

1

Print the function name when entering and exiting the function.

2

Print the function name along with the values of its arguments and the result.

3

Print the function name, and the variable names for each binding in the outermost let statement when it is assigned. This can be used to help locate a runtime error.

4

A combination of 2 and 3, plus it prints the value of each binding in the outermost let statement.

Tracing can be turned off for the function by specifying a trace level of 0. An example use is:

<Nesl> function norm(a,b) = sqrt(a^2 + b^2);

norm = fn : (float, float) -> float
<Nesl> set trace norm 2;

<Nesl> set trace sqrt 1;

<Nesl> norm(3.0,4.0);

Compiling..Writing..Loading..Running..
Entering NORM
  A = 3.000000e0
  B = 4.000000e0
Entering SQRT
Leaving SQRT
Leaving NORM
  RESULT = 5.000000e0
Exiting..Reading..
5.0 : float

NESL primitives cannot be traced. If you would like to trace a primitive, you can create a stub function that calls the primitive, and then replace calls to the primitive with calls to the stub. For example:

<Nesl> set trace sin 4;

SIN is a primitive, you cannot trace it.

<Nesl> function my_sin (x) = sin(x);

<Nesl> set trace my_sin 4;

When tracing prints values, it truncates sequences and only prints the first few elements. It also only prints nested sequences  down to a fixed depth. The truncation of sequences for tracing is different than the print-length set by set print_length, and is controlled by the two variables, trace_string_length  and trace_string_depth . They are ordinary NESL variables and should be set at top level using var = val.

When tracing functions that are called in parallel, NESL will only print an ``entering foo'' message once even though the functions is being entered many times in parallel. It will, however, print any values (arguments, results, or values of let statements) for each parallel call. For example:

<Nesl> function foo(a) = a + 3;

foo = fn : int -> int
<Nesl> set trace foo 2;

<Nesl> {foo(a): a in [2,3,4]};

Compiling..Writing..Loading..Running..
Entering FOO
  A = 2
  A = 3
  A = 4
Leaving FOO
  RESULT = 5
  RESULT = 6
  RESULT = 7
Exiting..Reading..
it = [5, 6, 7] : [int]

set trace off;  
Turns tracing off for all functions.

set profile funname {on,off};   
When profiling is turned on for a function, the time taken for each expression on the right of a let binding in that function are printed. The profiling also works on functions that are called in parallel: it prints the total time taken across all parallel calls.

In the example below, suppose we would like to profile a function that scrambles the order of elements in a vector. We could first use the time  function to measure the total running time:

function scramble (vec) =
  let
    n = #vec;
    rands = {rand(j): j in dist(n,n)};
    random_permutation = rank(rands)
  in
    vec->random_permutation;

<Nesl> time(#scramble([100000:200000]));

it = (100000, 0.042053647356) : int, float

To find out where the time is going, we turn on profiling as shown below. The timings indicate that the rank function is consuming most of the running time.

<Nesl> set profile scramble on;

Turning timing on for each let binding of SCRAMBLE.

<Nesl> #scramble([100000:200000]);

5.106242e-5 seconds for expression: 
      #vec
5.976757e-3 seconds for expression: 
      {rand(j): j in dist(n, n)}
3.046853e-2 seconds for expression: 
      rank(rands)
3.965526e-3 seconds for expression: 
      vec -> random_permutation

To get more accurate profiling, we turn argument checking off. Note that some functions are much faster with argument checking off.

<Nesl> set arg_check off;

<Nesl> #scramble([100000:200000]);

5.183748e-5 seconds for expression: 
      #vec
3.150965e-3 seconds for expression: 
      {rand(j): j in dist(n, n)}
3.034669e-2 seconds for expression: 
      rank(rands)
8.495138e-4 seconds for expression: 
      vec -> random_permutation

It should be noted that timing will give erroneous numbers when nested. This means that if you profile a recursive function, the times for the let bindings that do not make recursive calls will be accurate, but the time for the recursive call itself will meaningless. It should also be noted that to get reasonably accurate timings, the function should be profiled a few times, since the time taken by an expression can vary depending on the system load.

• Redefining monitored functions: