Skip to content

Session 2: Logging and Runtime Observability on Embedded Devices

Synopsis

Introduces practical instrumentation strategies, serial logs, event markers, and lightweight runtime metrics for constrained hardware.

Session Content

Session 2: Logging and Runtime Observability on Embedded Devices

Session Overview

Duration: ~45 minutes
Focus: Using logging, status indicators, and simple telemetry to observe MicroPython applications on the Raspberry Pi Pico 2 W in real time.
Audience: Python developers with basic programming knowledge who are new to embedded development.

Learning Objectives

By the end of this session, learners will be able to:

  • Explain why runtime observability is critical on embedded systems
  • Use print() and structured log messages for debugging MicroPython applications
  • Implement simple log levels in MicroPython
  • Observe runtime state using LEDs and serial output
  • Capture and review error information safely with try/except
  • Add basic telemetry for device status and activity tracking

Prerequisites

  • Raspberry Pi Pico 2 W
  • USB cable
  • Computer with Thonny IDE installed
  • MicroPython firmware installed on the Pico 2 W
  • Basic familiarity with Python syntax
  • Optional: onboard LED knowledge from a previous session

Development Environment Setup

1. Install Thonny

  • Download and install Thonny from: https://thonny.org/
  • Open Thonny

2. Connect the Pico 2 W

  • Plug the Pico 2 W into your computer via USB
  • In Thonny, go to:
  • Run → Select interpreter
  • Choose MicroPython (Raspberry Pi Pico)
  • Select the correct port

3. Verify Serial Output

  • Open the Thonny Shell
  • Run a simple test:
print("Hello, Pico 2 W")

Expected output:

Hello, Pico 2 W

4. Save Files to the Device

  • Save the main script as main.py on the Pico so it runs automatically on boot
  • Use File → Save as... → MicroPython device

Session Structure

1. Theory: Why Observability Matters in Embedded Systems

Embedded devices often run without a screen, keyboard, or user interface. When something goes wrong, the only clues may be: - serial logs - LED patterns - sensor values - watchdog resets - network status messages

Observability helps answer: - Is the program running? - What step is it on? - Did Wi-Fi connect successfully? - Did a sensor read fail? - Why did the system restart?

Common Observability Techniques

  • Text logging via USB serial
  • LED status indicators
  • Exception reporting
  • Counters and timestamps
  • Network telemetry
  • Heartbeat messages

2. Theory: Logging Levels

A simple logging strategy makes debugging easier.

Typical levels: - DEBUG: detailed information for development - INFO: normal operational events - WARNING: unusual but recoverable conditions - ERROR: failures that affect a task - CRITICAL: severe failures requiring attention

On MicroPython, a lightweight custom logger is often enough.

3. Hands-On Exercise 1: Simple Structured Logger

Goal

Create a reusable logger that prints timestamped messages with levels.

Code: main.py

# main.py
# Session 2 Exercise 1: Basic structured logging on Pico 2 W

from time import ticks_ms, ticks_diff, sleep
from machine import Pin

# Onboard LED for visual status
led = Pin("LED", Pin.OUT)

# Program start time
start_ms = ticks_ms()

# Logging levels
DEBUG = 10
INFO = 20
WARNING = 30
ERROR = 40

# Set the minimum log level to display
LOG_LEVEL = DEBUG


def elapsed_ms():
    """Return milliseconds since program start."""
    return ticks_diff(ticks_ms(), start_ms)


def log(level, message):
    """Print a timestamped log message if the level is enabled."""
    if level >= LOG_LEVEL:
        if level == DEBUG:
            level_name = "DEBUG"
        elif level == INFO:
            level_name = "INFO"
        elif level == WARNING:
            level_name = "WARNING"
        elif level == ERROR:
            level_name = "ERROR"
        else:
            level_name = "LOG"

        print("[{0:08d} ms] {1}: {2}".format(elapsed_ms(), level_name, message))


def blink(times, on_ms=200, off_ms=200):
    """Blink the onboard LED a number of times."""
    for _ in range(times):
        led.on()
        sleep(on_ms / 1000)
        led.off()
        sleep(off_ms / 1000)


log(INFO, "System booting")
blink(2)
log(DEBUG, "LED blink test complete")
log(INFO, "Entering main loop")

count = 0

while True:
    log(INFO, "Heartbeat {}".format(count))
    blink(1, 50, 150)
    count += 1
    sleep(1)

Expected Output

[00000000 ms] INFO: System booting
[00000401 ms] DEBUG: LED blink test complete
[00000401 ms] INFO: Entering main loop
[00000401 ms] INFO: Heartbeat 0
[00001502 ms] INFO: Heartbeat 1
[00002603 ms] INFO: Heartbeat 2

Discussion

  • The logger adds a timestamp to each message
  • The onboard LED provides a visible heartbeat
  • The log level can be changed to reduce output noise

Activity

Change LOG_LEVEL = DEBUG to LOG_LEVEL = WARNING and observe how the output changes.

4. Hands-On Exercise 2: Observing Errors Safely

Goal

Use try/except to capture runtime errors and log them clearly.

Code: main.py

# main.py
# Session 2 Exercise 2: Error logging and safe recovery

from time import sleep
from machine import Pin

led = Pin("LED", Pin.OUT)

DEBUG = 10
INFO = 20
WARNING = 30
ERROR = 40

LOG_LEVEL = DEBUG


def log(level, message):
    """Simple level-based logger."""
    levels = {
        DEBUG: "DEBUG",
        INFO: "INFO",
        WARNING: "WARNING",
        ERROR: "ERROR",
    }

    if level >= LOG_LEVEL:
        print("{}: {}".format(levels.get(level, "LOG"), message))


def safe_divide(a, b):
    """Divide two numbers and allow ZeroDivisionError to be handled by caller."""
    return a / b


log(INFO, "Starting error handling demo")

values = [(10, 2), (8, 0), (6, 3)]

for a, b in values:
    try:
        result = safe_divide(a, b)
        log(INFO, "Result of {}/{} = {}".format(a, b, result))
        led.on()
        sleep(0.1)
        led.off()
    except ZeroDivisionError as exc:
        log(ERROR, "Division failed for {}/{}: {}".format(a, b, exc))
        led.on()
        sleep(0.3)
        led.off()
    except Exception as exc:
        log(ERROR, "Unexpected error: {}".format(exc))

log(INFO, "Demo complete")

Expected Output

INFO: Starting error handling demo
INFO: Result of 10/2 = 5.0
ERROR: Division failed for 8/0: division by zero
INFO: Result of 6/3 = 2.0
INFO: Demo complete

Activity

Modify values to include another invalid case and observe the error output.

5. Theory: Visual Observability with LEDs

LEDs are extremely useful on embedded systems because they: - work without a terminal - show state even when the program crashes - provide immediate status feedback

Typical patterns: - Fast blink: active processing - Slow blink: idle / heartbeat - Solid on: error or connected state - Short pulse: event occurred

6. Hands-On Exercise 3: Status LED and Event Logging

Goal

Create distinct LED patterns for different system states.

Code: main.py

# main.py
# Session 2 Exercise 3: LED status patterns and event logs

from machine import Pin
from time import sleep, ticks_ms, ticks_diff

led = Pin("LED", Pin.OUT)
start_ms = ticks_ms()

DEBUG = 10
INFO = 20
WARNING = 30
ERROR = 40

LOG_LEVEL = DEBUG


def elapsed_ms():
    return ticks_diff(ticks_ms(), start_ms)


def log(level, message):
    levels = {
        DEBUG: "DEBUG",
        INFO: "INFO",
        WARNING: "WARNING",
        ERROR: "ERROR",
    }
    if level >= LOG_LEVEL:
        print("[{0:08d} ms] {1}: {2}".format(elapsed_ms(), levels.get(level, "LOG"), message))


def led_pulse(duration_ms):
    led.on()
    sleep(duration_ms / 1000)
    led.off()


def led_blink(count, on_ms, off_ms):
    for _ in range(count):
        led_pulse(on_ms)
        sleep(off_ms / 1000)


log(INFO, "Boot sequence started")
led_blink(2, 150, 150)

log(INFO, "Connecting to service")
led_blink(1, 50, 50)

log(INFO, "Service connected")
led.on()
sleep(1)
led.off()

log(WARNING, "Low battery warning simulated")
led_blink(3, 100, 100)

log(ERROR, "Simulated fault condition")
for _ in range(5):
    led.on()
    sleep(0.05)
    led.off()
    sleep(0.05)

log(INFO, "Status demo finished")

Expected Output

[00000000 ms] INFO: Boot sequence started
[00000301 ms] INFO: Connecting to service
[00000402 ms] INFO: Service connected
[00001402 ms] WARNING: Low battery warning simulated
[00002003 ms] ERROR: Simulated fault condition
[00002503 ms] INFO: Status demo finished

Activity

Change the blinking patterns to represent: - booting - Wi-Fi connecting - Wi-Fi connected - error state

7. Theory: Lightweight Telemetry

Telemetry is data sent from a device to another system for monitoring.

Examples: - temperature readings - uptime - loop count - error count - Wi-Fi signal quality - memory usage

For embedded devices, telemetry is usually kept small and simple.

8. Hands-On Exercise 4: Runtime Telemetry Snapshot

Goal

Print periodic runtime metrics such as loop count, uptime, and free memory.

Code: main.py

# main.py
# Session 2 Exercise 4: Basic runtime telemetry

from machine import Pin
from time import sleep, ticks_ms, ticks_diff
import gc

led = Pin("LED", Pin.OUT)
start_ms = ticks_ms()

DEBUG = 10
INFO = 20

LOG_LEVEL = DEBUG


def elapsed_ms():
    return ticks_diff(ticks_ms(), start_ms)


def log(level, message):
    if level >= LOG_LEVEL:
        name = "DEBUG" if level == DEBUG else "INFO"
        print("[{0:08d} ms] {1}: {2}".format(elapsed_ms(), name, message))


def telemetry_snapshot(loop_count):
    """Print a small telemetry record."""
    gc.collect()
    free_mem = gc.mem_free()
    allocated_mem = gc.mem_alloc()

    print(
        "TELEMETRY | uptime_ms={} | loops={} | free_mem={} | alloc_mem={}".format(
            elapsed_ms(),
            loop_count,
            free_mem,
            allocated_mem,
        )
    )


log(INFO, "Telemetry demo started")

loop_count = 0

while loop_count < 5:
    led.on()
    sleep(0.1)
    led.off()

    telemetry_snapshot(loop_count)
    loop_count += 1
    sleep(1)

log(INFO, "Telemetry demo finished")

Expected Output

[00000000 ms] INFO: Telemetry demo started
TELEMETRY | uptime_ms=100 | loops=0 | free_mem=129760 | alloc_mem=20160
TELEMETRY | uptime_ms=1201 | loops=1 | free_mem=129760 | alloc_mem=20160
TELEMETRY | uptime_ms=2302 | loops=2 | free_mem=129760 | alloc_mem=20160
TELEMETRY | uptime_ms=3403 | loops=3 | free_mem=129760 | alloc_mem=20160
TELEMETRY | uptime_ms=4504 | loops=4 | free_mem=129760 | alloc_mem=20160
[00005505 ms] INFO: Telemetry demo finished

Activity

Add a counter for errors and include it in the telemetry output.

9. Optional Extension: Logging Wi-Fi Connection State

If Wi-Fi is available in your setup, log connection progress.

Example Snippet

import network
from time import sleep

wlan = network.WLAN(network.STA_IF)
wlan.active(True)

print("INFO: Connecting to Wi-Fi...")
wlan.connect("YOUR_WIFI_SSID", "YOUR_WIFI_PASSWORD")

timeout = 10
while timeout > 0 and not wlan.isconnected():
    print("DEBUG: Waiting for Wi-Fi connection...")
    sleep(1)
    timeout -= 1

if wlan.isconnected():
    print("INFO: Wi-Fi connected")
    print("INFO: Network config:", wlan.ifconfig())
else:
    print("ERROR: Wi-Fi connection timed out")

Example Output

INFO: Connecting to Wi-Fi...
DEBUG: Waiting for Wi-Fi connection...
DEBUG: Waiting for Wi-Fi connection...
INFO: Wi-Fi connected
INFO: Network config: ('192.168.1.42', '255.255.255.0', '192.168.1.1', '8.8.8.8')

10. Best Practices for Embedded Logging

  • Keep logs concise and meaningful
  • Use log levels to reduce noise
  • Avoid logging too frequently in tight loops
  • Include context: sensor name, loop number, state
  • Use LEDs for critical status when serial is unavailable
  • Always catch expected exceptions where recovery is possible
  • Call gc.collect() before measuring memory in diagnostics
  • Save stable startup code in main.py

11. Common Issues and Troubleshooting

  • No output in Thonny
  • Check interpreter selection
  • Confirm correct board and COM port
  • Restart the shell
  • Script keeps crashing
  • Wrap risky code in try/except
  • Reduce log frequency
  • LED does not light
  • Confirm correct board onboard LED access using Pin("LED", Pin.OUT)
  • Unexpected reset loop
  • Check for memory issues or uncaught exceptions
  • Simplify the script and add logs step by step

12. Wrap-Up and Review

Key Takeaways

  • Observability is essential for debugging embedded Python applications
  • Serial logging and LED indicators provide complementary visibility
  • Structured logs make it easier to understand runtime behavior
  • Telemetry helps track health, performance, and errors
  • Safe exception handling prevents silent failures

Quick Review Questions

  1. Why is observability more important on embedded devices than on desktop apps?
  2. What is the difference between INFO and ERROR logs?
  3. How can an LED help when serial output is unavailable?
  4. Why should you avoid logging too often in a fast loop?
  5. What runtime metrics are useful for telemetry?

13. Suggested Take-Home Task

Create a small program that: - blinks the onboard LED - logs a heartbeat every second - counts errors - prints a telemetry snapshot every 10 iterations - uses try/except around a simulated sensor read

Back to Chapter | Back to Master Plan | Previous Session | Next Session