Debugging SVG visualizations

If during a simulation an SVG visualization does not behave as you would expect it to behave, there are several ways to debug such problems.

The following approaches are available to debug behavioral issues:

The following approaches are available to debug timing/smoothness issues:

Console debugging for CIF/SVG declarations

Console debugging output for CIF/SVG declarations can be enabled or disabled by using the Debug output option (Output category). It is disabled by default. If enabled, it produces debug output to the console, whenever CIF/SVG declarations are applied. Here is an example of what such output looks like:

SVG output ("some_file.svg") id "a" text: "10.00"
SVG output ("some_file.svg") id "b" text: "0.0"
SVG output ("some_file.svg") id "c" text: "3.16"
SVG output ("some_file.svg") id "n" attr "fill" (CSS attr): "#ff0000"
SVG output ("some_file.svg") id "water" attr "height" (SVG attr): "75.0"
SVG output ("some_file.svg") id "water" attr "y" (SVG attr): "104.5"

Each of the output mappings that is applied, results in a line of debugging output. For output mappings that update the value of an attribute, the output indicates whether the attribute is handled as an SVG presentation attribute or as a CSS style attribute.

The textual representations of the values that are set, are put between double quotes, and their content is not escaped in any way.

Due to the asynchronous nature of the SVG visualizer, the simulator will continue to calculate the next states that are to become a frame, while the SVG visualizer is still applying mappings for previous frames. As such, the debug output and other simulation output are likely to be out of sync and interleaved. To ease debugging, you can enable the test mode option, which ensures synchronous execution, and thus synchronous output.

For the input mappings, whenever an interactive SVG element is clicked, and the corresponding mapping is used to determine the event or update to take, a line of debug output is produced. Here is an example of what such output looks like:

SVG input ("some_file.svg") id "button": event "button.u_pushed"
Transition: event button.u_pushed

From the line of debugging output, it can be seen that the SVG element with id button was clicked, and this resulted in the execution of event button.u_pushed.

Similar debug output is available for the other CIF/SVG declarations:

SVG copy ("some_file.svg") id "button" post "1".
SVG copy ("some_file.svg") id "button" post "2".

SVG move ("some_file.svg") id "button1" to 10.0, 10.0.
SVG move ("some_file.svg") id "button2" to 30.0, 10.0.

Save as SVG

During simulation, the SVG visualizer can be used to save the currently visible image as an SVG image file. This way, the actual XML representation of the SVG image as it is displayed at that time, can be inspected in an XML editor or text editor. This may give insight in the actual effect of the CIF/SVG declarations applied until that moment.

Stack traces

If the application of a CIF/SVG declaration results in a runtime error, a stack trace is printed to the console. This stack trace makes it possible to track the exact origin of the error. Here is an example of such a stack trace for an output mapping:

ERROR: Simulation resulted in a runtime error.
CAUSE: Evaluation of the SVG output mapping ("some_file.svg") for the text of the SVG element with id "txt1" failed for state: time=0.0, x=-1.5265566588595902e-16.
CAUSE: Evaluation of SVG output mapping value "sqrt(x)" failed.
CAUSE: Invalid operation: sqrt(-1.5265566588595902e-16).

Here, we see that simulation resulted in a runtime error. The cause is that the SVG output mapping for the text of the SVG element with id txt1 failed. This points to the exact CIF/SVG mapping that failed, and includes the file name of the SVG image file, as the same id may exist in multiple images. It also includes the state at which the error occurred. The stack trace further indicates that evaluation of the value expression failed, and the actual failure was the evaluation of the sqrt standard library function, with a negative argument.

Console debugging for CIF/SVG real-time timing

Console debugging output for CIF/SVG real-time timing can be enabled or disabled by using the Debug output option (Output category). It is disabled by default. If enabled, it produces debug output to the console, whenever a new frame is displayed for an SVG visualizer. Here is an example of what such output looks like:

SVG#1: frame#1: no sleep for first frame...
SVG#1: frame#2: slept for (ms): 26, real-time time (ms): 50.6353, model time (ms): 50.0, total behind on real-time (ms): 0.6353000000000009, delta behind on real-time (ms): 0.6353000000000009
SVG#1: frame#3: slept for (ms): 49, real-time time (ms): 104.5802, model time (ms): 100.0, total behind on real-time (ms): 4.580200000000005, delta behind on real-time (ms): 3.944900000000004

The first frame is always immediately displayed. Subsequent frames may be delayed by a sleep to ensure they are displayed at exactly the right time. Each line for a non-first frame contains the following information:

  • The number of the SVG image, to distinguish the output for different SVG images in case the CIF model has multiple SVG images associated to it.

  • The frame number.

  • The sleep time, as the number of milliseconds that the simulator slept before displaying this frame, after displaying the previous frame.

  • The time that has passed since the simulation started.

  • The model time for which the frame was rendered.

  • How much behind the simulator is in real-time time, in total.

  • How much behind the simulator is in real-time time, for this frame with respect to the previous frame.

  • Optionally, if the sleep time is non-positive, the line explicitly indicates that the simulator did not sleep between displaying this frame and the previous frame.

This information can be used to see whether the simulator can keep up with calculating new states, rendering frames and displaying them in time before the next one needs to be displayed. As long as the sleep times are non-negative, the simulator can keep up. If the sleep times are negative, and thus the sleep is skipped, the simulator could not keep up. Note that the simulator does not try to catch up later on; it only tries to display each frame after the right amount of time has passed since the previous frame was displayed. In case the simulator cannot keep up, you may want to reduce the frame rate.