Debugging Hints

Suppose your model gives an error during evaluation, or doesn't give plausible results. How can you figure out the source of problem and fix it? Debugging software is a deep subject.

In several ways, Analytica makes debugging much easier than conventional programming languages: First, because you can see the value of each variable very easily, just by selecting its node and clicking the Result icon (or Ctrl+R). Second, Analytica has a "no side-effects" rule -- meaning that you can see how it is computed simply by looking at its Definition without worrying whether some other part of the program might be changing its value. This makes it much simpler to understand how model works than with conventional procedural languages that allow side effects -- like Python, R, Visual Basic, or C++.

Nevertheless, debugging can still sometimes be a challenge. Here are some tips on how to figure out what's going on.

Comment out sections of an expression

Suppose you have a variable containing multiple expressions that isn't giving the result you expect. In order to find out which expression is causing the problem, you can add a curly comment bracket { after the first expression and } at the end. This makes Analytica ignore the rest as a comment. Then evaluate the variable to see if the result of the first expression makes sense. If so, you can move the { to go after the second expression. Repeat until you find which expression is causing a problem. When you've fixed it, remember to remove the curly brackets.

Use MsgBox to show intermediate values

By temporarily inserting calls to the MsgBox function within an expression, you can easily peek at intermediate values. When the MsgBox call gets evaluated, a message box appears on the screen with the value. Array values can be placed, which are printed in a textual form in the message box, allowing you to verify dimensionality, etc.

The simple use of MsgBox is to call with a single parameter, the value you wish to examine. When inserting a call to MsgBox, it is common to separate the call from other parts of the expression using semi-colons.

If source = dest Then 0 
Else ( 
  MsgBox(loc - loc[source - dest]);  
  Sqrt(Sum(Sqr(loc - loc[source = dest]), Coord))
  )

The optional «title» parameter to MsgBox is often useful for presenting other (scalar) information. In a Dynamic model, you may want to place the variable name and current time in the title:

 Dynamic(init_pos, 
   Local x := PosUpdate(Self[Time - 1]);
   MsgBox(x, title: "Pos at Time = "&Time);
   x
   )

Use ConsolePrint to log intermediate values

When the point in the expression gets hit many times, you may need to press OK too many times when using MsgBox. A good alternative is to use the ConsolePrint function instead. Open the Typescript window to see the output. When using ConsolePrint, the code doesn't pause, it just prints and continues.

 Dynamic(init_pos, 
   Local  x := PosUpdate(Self[Time - 1]);
   ConsolePrint(x, title: "Pos at Time" = &Time);
   x
)

Log to a file

Similar to the use of ConsolePrint, from the Enterprise edition or greater you can log intermediate values to a file using WriteTextFile with the «append» option, and then scan the log in a text editor.

Capture intermediate arrays in a mutable

When your intermediate values contain large arrays or binary data, logging to the Typescript window or a file might not be convenient for viewing. Using a mutable, you can save the array result in another variable and then view it later after you've stopped or cancelled your calculation. Normally Side effects are disallowed, but with a mutable you can save them in memory without invalidating downstream results. You can then view the intermediate result as a table, and perform additional calculations on the result (in a new variable) to understand it. See Using mutables for debugging.

Break up a complicated variable into simpler ones

Suppose you are getting an evaluation error within a variable V, or simply suspect there's a problem in its definition. If the definition is complicated -- more than a one-line expression -- it's often useful to break it up by creating a separate variable for each subexpression. For example, suppose you suspect an error in

Variable V 
Definition: IF g_run_mode = 'Deterministic' Or H_use_stoch_or_deter[H_r_d_or_lbd = 'R&D'] = 'Deterministic'
           Then LinearInterp(H_r_d_years, H_deterministic_tpi, time - H_acceleration, H_r_d_years)
           Else Begin
               Local x := G_interpolate_dists(H_bounded_tpi_distri, H_r_d_years, Time, H_variability_in_int);
               LinearInterp(Time, x, Time - H_acceleration, Time)
           End
           *H_sensit_factor(H_impro_params)

You can decompose V into V_decomp using intermediate variables in this way:

Variable V1 := g_run_mode = 'Deterministic' Or H_use_stoch_or_deter[H_r_d_or_lbd = 'R&D'] = 'Deterministic'
Variable V2 := LinearInterp(H_r_d_years, H_deterministic_tpi, time - H_acceleration, H_r_d_years)
Variable X := G_interpolate_dists(H_bounded_tpi_distri, H_r_d_years, Time, H_variability_in_int)
Variable V3 :=LinearInterp(Time, x, Time - H_acceleration, Time)
Variable V4 := H_sensit_factor(H_impro_params)
Variable V_decomp := (If V1 
           Then V2
           Else V3)*V4

Note that Variable X replaces the local variable X in the original Definition with a global X, now used in V3.

You can now look at each intermediate variable and see if looks right, which should be much simpler than trying to decode the original definition.

When creating a model, the question often arises about how much to decompose a complex calculation into separate variables, or combine many variables into one. If you had created the model originally using this decomposed version, it might have been simpler to understand and debug in the first place. On the other hand, using more variables makes it harder to understand at the higher level. Plus, since Analytica usually stores the value of each variable after computing it, the decomposed version results in saving six result values instead of one -- using more memory.

There is a way to avoid the memory problem by preventing selected variables from saving the results into memory when they are not needed. See Controlling When Result Values Are Cached for details.

Trace evaluation with the Memory Dialog

A key tool for tracking down bugs is tracing evaluation -- that is looking at the order in which variables and functions are evaluated.

The Memory Usage Dialog helps here.

Select Show Memory Usage from the Window menu.
Check "Expanded View"
Check "Show object being evaluated"

When you evaluate a variable, it will show the identifier of each variable or function as it is evaluated. During dynamic simulation, it also shows the value of Time for each evaluation.

Of course, these variables usually go by very rapidly -- too fast to follow them. But, if it takes an inordinately long time to evaluate a single variable, perhaps because it is an infinite loop, you will see it stuck on that variable. You can then click the Stop Computing button (or control-break) to interrupt evaluation. To look at the guilty variable, use Find... from the Object menu and type in its identifier.

Note: We recommend you don't leave "Show object being evaluated" checked during normal evaluation, since tracing can slow down evaluation noticeable.

Trace evaluation in the Typescript

The Memory dialog only shows the current variable being evaluated. If it's a function, you often want to know where it was called from. You can do that in the Typescript. Press Ctrl+' (control comma) or the F12 key to open the Typescript window. Type in

>Verbosity:6

to set the tracing verbosity -- i.e. the type of information it displays. Now, when you evaluate a variable, it shows a trace of each variable evaluated in the Typescript, for example:

Evaluating F_ind_gas_dmd[Time = 2050] dloop=15142 .

Evaluating F_natgas[Time = 2050] dloop = 15142 .

Evaluating G_conversion_facto1.

Evaluating Check_for_price.

Evaluating G_uid_from_units.

This value is particularly useful when debugging dynamic loops:

>Verbosity: 134

which also causes the trace to be intended to indicate when one variable is "called" by another, thus revealing the call graph.

Lines displaying a Time subscript are those evaluated within a Dynamic context, showing you which time point is being evaluated. Variables located within a dynamic loop also display a dloop id. Each dynamic loop has a unique number (the specific number may change with model edits, but remains unique in a given evaluation trace). If you see two variables with the same dloop number, then they are in the same dynamic loop. If the dloop is different, they are in different dynamic loops.

Remember to reset this back to

>Verbosity: 2

when finished debugging, because things evaluate very slowly when this flag is on.

Save a trace file with Photo

For a large model, the number of variable evaluations in the Typescript may be large, especially when multiplied by the number of Time periods for a Dynamic model. The Typescript will only show the most recent steps (usually about 700 lines worth). You can save the entire trace to file by typing into the Typescript:

Model_name>Photo "trace.log"

You may want to include a pathname into the file name. Then evaluate the variable you are interested in. When it finishes evaluation (or if you Stop computing), you should close the trace file by typing into the Typescript:

Model_name>EndPhoto

You can now open the trace file in a text editor to search or analyze it.