Freezing with channels, goroutines and timers

[abulka]

My Pi Pico 2040 freezes when running the code below. It may take twenty seconds up to several minutes to freeze, depending on variations of the code discussed later.

The code is a minimal example taken from a larger program where I need to use channels, goroutines and timers in the way that I do. That's why it isn't any simpler.

The code is basically:

• A go routine sending a func callback to a channel every 300ms.
• A go routine listening to that channel and calling drawScreen() that toggles the LED state.
• A main loop that sleeps for 1ms, and uses a timer to wake up every 30ms to print a dot.

Run with:

tinygo flash -target=pico --monitor ./cmd-demos/bug-tg

Code:

package main

import (
	"machine"
	"runtime"
	"time"
)

func main() {
	time.Sleep(1 * time.Second)
	app := App{}
	app.Run()
}

type State struct {
	scheduler *ChannelScheduler
	taskChan  chan func()
	ledOn     bool
	led       machine.Pin
}

func (s *State) drawScreen() {
	println("D")
	if s.ledOn {
		s.led.High()
	} else {
		s.led.Low()
	}
	s.ledOn = !s.ledOn
	s.scheduler.AddTask()
}

type App struct{}

func (App) Run() {

	state := &State{
		taskChan:  make(chan func(), 16),
	}
	state.scheduler = NewChannelScheduler(state.taskChan)

	state.led = machine.LED
	state.led.Configure(machine.PinConfig{Mode: machine.PinOutput})

	// Initial values
	state.ledOn = true

	go state.scheduler.Run()
	time.Sleep(1 * time.Second) // Allow time for the goroutine to start

	go func() {
		for range state.taskChan {
			state.drawScreen()
			runtime.Gosched()
		}
	}()
	time.Sleep(1 * time.Second) // Allow time for the goroutine to start

	// Main Loop
	var timer *time.Timer
	var timerC <-chan time.Time
	for {
		nextWake := 30 * time.Millisecond // 10ms is too fast and crashes

		if timer == nil {
			timer = time.NewTimer(nextWake)
			timerC = timer.C
		} else {
			timer.Stop()
			timer.Reset(nextWake) // Update the timer to the new duration
		}

		select {
		case <-timerC:
			print(".")
		}

		// Sleep 1ms here makes freeze come much sooner. 
		// Sleep 10ms freezes a bit later. 
		// Gosched() delays freeze too. 
		// With neither, it still freezes after about 5min.
		time.Sleep(1 * time.Millisecond)
		
	} // End of main loop
}

type ChannelScheduler struct {
	schedule chan struct{}
	taskChan chan func()
}

func NewChannelScheduler(taskChan chan func()) *ChannelScheduler {
	return &ChannelScheduler{
		schedule: make(chan struct{}, 64),
		taskChan: taskChan,
	}
}

func (cs *ChannelScheduler) AddTask() {
	select {
	case cs.schedule <- struct{}{}:
		// Do nothing
	default:
		println("[ERROR] Schedule channel full, task dropped")
	}
}

func (cs *ChannelScheduler) Run() {
	var timer *time.Timer
	var timerC <-chan time.Time
	for {
		nextWake := 300 * time.Millisecond

		if timer == nil {
			timer = time.NewTimer(nextWake)
			timerC = timer.C
		} else {
			timer.Stop()
			timer.Reset(nextWake)
		}

		select {
		case <-cs.schedule:
			// Do nothing
		case <-timerC:
			select {
			case cs.taskChan <- fake:
				// Tell go routine listening to wake up and run draw
			default:
				println("[ERROR] taskChan channel full, task dropped")
			}
		}
		// Sleep or Gosched() here doesn't help avoid freeze
	}
}

func fake() {}

Output:

% tinygo flash -target=pico --monitor ./cmd-demos/bug-tg
Connected to /dev/cu.usbmodem101. Press Ctrl-C to exit.
D
D
D
D
D
D
......D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
..........D
.........D
..........D
.........D
.

Freeze.

Discussion

Yes the freeze can be avoided by coding things slightly differently, but I happen to need this specific architecture.

Hundreds of freezes later, I believe there is bug in the TinyGo scheduler/runtime that this repro case demonstrates. Slight changes in code (see comments in the code and Observations discussion below) can make the freeze happen sooner or later, which might offer insights into the issue.

Observations

This version of the Main Loop does not freeze:

for {
	print(".")
	time.Sleep(30 * time.Millisecond)
}

This version of Run() avoids the freeze:

func (cs *ChannelScheduler) Run() {
	for {

		// if there is anything on cs.schedule: read it and do nothing
		select {
		case <-cs.schedule:
			// Do nothing, just wake up
		default:
			// Do nothing, no task to run
		}

		cs.taskChan <- fake
		time.Sleep(300 * time.Millisecond)
	}
}

Making taskChan a taskChan chan bool instead of a taskChan chan func() avoids freeze for much, much longer. Weird huh?

At the bottom on the main loop:

• Sleep 1ms here makes freeze come much sooner.
• Sleep 10ms freezes a bit later.
• Gosched() delays freeze too.
• With neither Sleep() or Gosched(), it still freezes after about 5min.

Altering sleep and timer timings can change the time it takes to freeze.

Thoughts

This repro case took me ages to whittle down. I am aware that the TinyGo scheduler is different to Go, more cooperative etc. but I'm not relying on pre-emption here. And the TinyGo scheduler should be able to handle this.

I'm hoping this issue flushes out a real bug somewhere rather than it being a case of excusing TinyGo scheduling semantics as just "different". It is just way too easy for TinyGo to freeze when using goroutines, channels, sleep and timers. I'm finding it impossible to reason about them anymore.

[eliasnaur]

I don't have a good answer, only 2 notes:

1. Does the problem reproduce with the latest TinyGo release that adds multicore support for rp2040?
2. Does it reproduce on your machine (tinygo run ...)?

[abulka]

1. Yes its the latest tinygo version 0.38.0 darwin/arm64 (using go version go1.24.3 and LLVM version 19.1.2) with multicore support for rp2040.
2. No, interestingly it doesn't reproduce on my machine (Mac M2) with tinygo run --monitor ./cmd-demos/bug-tg. Runs fine.

I hadn't thought to try running tinygo on my desktop for testing such things. Of course I had to comment out the machine import and LED code, but that code isn't relevant. The same example without LED flashing code also freezes on my RP2040.

[eliasnaur]

Interesting. I would then try without multicore support, since it's relatively new. I believe the -scheduler tasks flag switches to the single-core scheduler.

[abulka]

Wow, running with the single core scheduler works fine.

tinygo flash -target=pico --monitor -scheduler tasks ./cmd-demos/bug-tg

[eliasnaur]

Good find. Can you reproduce the default scheduler hang with tinygo gdb and use the gdb command bt to get a useful backtrace?

[abulka]

Have ordered a pico debug kit - will let you know.

[abulka]

My findings:

• gdb on pico doesn’t work properly with the normal dual core scheduler.
• Sleep() commands freeze with any scheduler.
• print() statements are not visible anywhere.

Details:

Testing with a regular simple TinyGo program (nothing fancy) I’m finding that gdb with the normal scheduler

tinygo gdb -target=pico  -opt=0  ./cmd-demos/probe

doesn’t stop at breakpoints, hitting c just results in a freeze/loop and my app doesn’t execute.

Program received signal SIGINT, Interrupt.
runtime.multicore_fifo_pop_blocking () at /opt/homebrew/Cellar/tinygo/0.38.0/src/runtime/runtime_rp2040.go:219

Since the whole point of using gdb here is to run it with the dual core scheduler - this is a problem.

Further problem with time.Sleep()

Even when running with single core scheduler

tinygo gdb -target=pico  -opt=0 -scheduler tasks ./cmd-demos/probe

I can get programs to run, however whenever we hit any time.Sleep() calls, again, the debugger freezes/loops forever

Program received signal SIGINT, Interrupt.
(gdb) bt
#0  0x10005f8a in (*machine.timerType).lightSleep (tmr=0x40054000, us=<optimized out>) at /opt/homebrew/Cellar/tinygo/0.38.0/src/machine/machine_rp2_timer.go:99
#1  0x10005f24 in runtime.machineLightSleep (ticks=<optimized out>) at /opt/homebrew/Cellar/tinygo/0.38.0/src/machine/machine_rp2.go:70
#2  0x10006a2c in runtime.sleepTicks (d=4294968370085904) at /opt/homebrew/Cellar/tinygo/0.38.0/src/runtime/runtime_rp2040.go:43
#3  0x10006880 in runtime.scheduler (returnAtDeadlock=<optimized out>) at /opt/homebrew/Cellar/tinygo/0.38.0/src/runtime/scheduler_cooperative.go:206
#4  0x10008a06 in runtime.run () at /opt/homebrew/Cellar/tinygo/0.38.0/src/runtime/scheduler_cooperative.go:253
#5  0x100089de in Reset_Handler () at /opt/homebrew/Cellar/tinygo/0.38.0/src/runtime/runtime_rp2040.go:365

So even if debugging with the multicore scheduler worked, this would be another problem.

Using print

Finally, I can’t get print statements to appear anywhere. I’ve tried several technques including connecting the UART port to the pico and using e.g. minicom -b 115200 -D /dev/tty.usbmodem2102 however no print statements appear. This further limits our debugging options.

I am new to gdb so perhaps more advanced users would have better luck.

[eliasnaur]

Thanks for investigating. You should get print statements to appear on UART with the -serial uart option to tinygo flash/gdb/build.

[eliasnaur]

Also, have you tried without -opt 0? The default optimization is tested more often and as such may work better even in debugging.

[abulka]

Thanks for the tip re -serial uart that worked. Removing -opt 0 makes no difference, unfortunately.

[tinkerator]

Not surprisingly, this issue also reproduces with the RP2350B part used in the pico2-ice board.