This third article on advanced debugging techniques for Embedded JavaScript introduces tracepoints, a breakpoint that logs to the debug console instead of stopping execution. Console logging is a common debugging technique that reveals the flow of execution along with the values of key variables. This technique helps developers identify unexpected code execution by visualizing the actual order of execution. Console logging has another benefit: because it doesn't pause execution, the timing of code execution doesn't change. That's important since many embedded systems have real-time execution requirements and a long pause at a breakpoint could lead to failures.

Tracepoints versus trace()

The usual way of logging in the Moddable SDK is to add calls to the global trace function:

trace(`this.x = ${this.x}\n`);
trace("enter function doRead\n");

This works well. After making a change to the logging code, it is necessary to build, deploy, and launch a new build. This is fast in the Moddable SDK's simulator, but for an embedded device this takes some time, slowing the debugging process. Tracepoints solve this problem. A tracepoint is equivalent to calling trace() but it is set immediately while the program is still running. By making tracepoints so fast to add and modify, the usefulness of console logging for debugging increases significantly.

Setting a Tracepoint

To create a tracepoint, first create an unconditional breakpoint by clicking to the left of the source code line.

Next, bring up the breakpoint editor by tapping the green breakpoint arrow.

All you need to do to make this a tracepoint is input an expression to trace on the line labeled "Trace Expression". This can be any JavaScript expression. Once you've entered your trace expression, either click the "Set" button on the right or press the return key to install the tracepoint. To convert the tracepoint back to a breakpoint that pauses execution, just delete the trace expression and click "Set".

Example Expressions

Any valid JavaScript expression can be used in a trace expression. Here are some examples:

x – outputs the value of the variable x
"x = " + x – outputs the value of variable x preceded by "x = ", for example x = 12
`x = ${x}` – same as the preceding example, but using JavaScript's template literal instead
this.x – outputs the value of the x property of this
this.width * this.height – outputs the area of the this
Date.now() – outputs the current time in milliseconds
Date() – outputs the current time as a human readable string (slower than Date.now())

Complex Tracepoints

The example tracepoint above logs "x" in the Piu Balls example, which bounces four balls around the screen. The output looks like this:

$MODDABLE/examples/piu/balls/main.js (43) 26
$MODDABLE/examples/piu/balls/main.js (43) 0
$MODDABLE/examples/piu/balls/main.js (43) 96
$MODDABLE/examples/piu/balls/main.js (43) 93
$MODDABLE/examples/piu/balls/main.js (43) 30
$MODDABLE/examples/piu/balls/main.js (43) 5
$MODDABLE/examples/piu/balls/main.js (43) 90

It would be useful to see both the x and y coordinates and to know which ball the coordinates correspond to. In the balls example, the ball's index is contained in the variant property. Using a trace expression of "ball #${ball.variant} @ ${x}, ${y} gives much more useful output. The trace expression here is JavaScript's template literal (aka template string). Template strings are convenient for tracepoints because they easily combine strings, variables, and expressions.

$MODDABLE/examples/piu/balls/main.js (43) ball #3 @ 249, 63
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 14, 158
$MODDABLE/examples/piu/balls/main.js (43) ball #1 @ 45, 55
$MODDABLE/examples/piu/balls/main.js (43) ball #0 @ 66, 6
$MODDABLE/examples/piu/balls/main.js (43) ball #3 @ 252, 60
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 10, 154
$MODDABLE/examples/piu/balls/main.js (43) ball #1 @ 40, 50
$MODDABLE/examples/piu/balls/main.js (43) ball #0 @ 72, 0

The log reveals that balls are called in the reverse order from which they were created. This is the kind of detail that console logging is good at uncovering.

Conditional Tracepoints

If there was a problem with how ball 2 is moving, it would be convenient to focus the log by logging only ball 2. This can be done by adding a conditional expression (see the article on Conditional Breakpoints for more details). Here the conditional expression is ball.variant === 2.

The resulting log now shows only ball 2:

$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 258, 106
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 254, 110
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 250, 114
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 246, 118
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 242, 122
$MODDABLE/examples/piu/balls/main.js (43) ball #2 @ 238, 126

If this tracepoint was written directly in JavaScript it would look like this:

if (ball.variant === 2)
    trace(`ball #${ball.variant} @ ${x}, ${y}\n`);

Hit Count expressions and Functions Tracepoint

Tracepoints work with Hit Count expressions too. That lets you enable tracing trace based on the number of times the tracepoint has been encountered, for example just the first 10 times or every 12th time.

Tracepoints also work with Function breakpoints. You can use this to trace a message each time any implementation function of a given name (e.g. onReadable) executes. (See the previous article in this series to learn about Function breakpoints.

Control Tracepoints using a Device Button

When debugging, you might want to only enable logging under certain conditions. You can do this manually by toggling the Enabled switch in the Breakpoint Editor. But that takes time and can be inconvenient if there are several tracepoints you want enable or disable. Since this article is about advanced debugging techniques for Embedded JavaScript, let's use a physical button to control tracepoints. Just hold down the button to enable logging and release it to stop.

The first step is to create a digital input object to check the state of the button. Here's how to do that using the ECMA-419 Digital constructor. Add this to your project. It assigns the digital input object to the global variable logButton. This code example uses GPIO 0 by specifying pin as 0; change that to match the pin your button is connected to.

const Digital = device.io.Digital;
globalThis.logButton = new Digital({
    mode: Digital.InputPullUp,
    pin: 0
});

Since this button uses a pull-up resistor, the value is 1 when the button is not pressed and 0 when the button is pressed. To enable a tracepoint when the button is pressed, enter a Condition Expression of logButton.read() === 0.

Reading a digital input is very fast, so this check won't noticeably slow your project.

Instead of a push button, you could use a slider switch instead. This would eliminate the need to hold a button down to enable logging -- just slide the switch. You might even use several switches to control console logging of different categories of information.

Other kinds of input can be used to control tracepoints. Moddable Four has a built-in accelerometer that can be used to enable tracepoints only when the device in a particular orientation, for example face-up.

Don't Over Do It

A common mistake with console log debugging is logging too much data. When this happens, it can slow execution of your project which can change its behavior. The XS JavaScript engine in the Moddable SDK is evaluates tracepoints quickly but, if there many of them, eventually the cost adds up.

The messages logged to the console are sent from the embedded device to the computer over a high-speed serial connection. This connection is fast, but not infinitely so. If your project sends data faster than the connection can handle, execution will be slowed.

There are two easy solutions to reduce the impact of your tracepoints:

Keep your log messages as short as practical to reduce the data transmitted over the serial connection
Use conditional expressions to focus logging to when necessary

That said, in most cases you usually don't need to worry about the performance of tracepoints. These notes are just to help in case you into issues.

Trace!

Tracepoints make something very familiar -- debugging by console logging -- so much faster use that it changes how you debug. Conditional expressions can be used creatively, as in the tracepoint button example, to focus logs on exactly the information you need so you don't waste time reading lengthy logs.