lang: funcs: dage: Nested if expressions can permanently wedge the function graph

[flavio-fernandes]

Summary

On current master (ea6066a9), an mcl program containing a nested if expression whose conditions change over time can permanently wedge the function graph. Reactive updates stop reaching resources, no error is logged, the process keeps running and looks healthy, and it never recovers without a restart. In the reproducer below it wedges within ~3 seconds and stays wedged indefinitely.

Two things combine:

1. An if expression swaps its branch subgraph when the condition flips. During that swap, the exprIfSubgraphOutput vertex is observable with only 1 of its 2 incoming edges, so the traversal is (correctly) marked incomplete.
2. dage does not advance epoch for an incomplete traversal. From that moment every node that already ran satisfies node.epoch >= epoch forever, so the epoch skip at dage.go#L390 drops all of them — including the streaming functions that would deliver new values, and including the function whose Call would finish the subgraph swap that made the traversal incomplete in the first place.

So the failure is self-sustaining: the condition that freezes the epoch can only be cleared by work that the frozen epoch prevents.

This needs nothing but core mcl — no particular resource, function, or hardware.

Reproducer

repro.mcl, using only datetime, math and fmt:

import "datetime"
import "fmt"
import "math"

$now = datetime.now()
$two = math.mod($now, 2) == 0
$three = math.mod($now, 3) == 0

$inner = if $three {
	"three"
} else {
	"none"
}

$s = if $two {
	"two"
} else {
	$inner
}

print "out" {
	msg => fmt.printf("now=%d s=%s", $now, $s),
}

./mgmt run --tmp-prefix lang repro.mcl

datetime.now() ticks once per second, so the expected output is one print[out] line per second, indefinitely.

Actual: output stops after a few lines and never resumes. A 90 second run produced 3 lines:

18:23:08 engine: print[out]: Msg: now=1785349388 s=two
18:23:09 engine: print[out]: Msg: now=1785349389 s=three
18:23:10 engine: print[out]: Msg: now=1785349390 s=two
<nothing for the remaining 87 seconds>

Line counts over a 45 second run, same binary and machine:

program	expected	actual
single if (control: $s = if $two { "even" } else { "odd" }, no $inner)	~45	45
nested if (above)	~45	7
three-deep nested if	~45	5

A single, non-nested if did not reproduce it in 45 seconds. Nesting makes it near-immediate, presumably because it widens the window in which a swap is observable.

What the engine is doing

Temporary instrumentation on the edge skip, epoch skip and !valid branches of Engine.process, on unmodified master, running the reproducer above:

18:29:10 engine: print[out]: Msg: now=1785349750 s=two          <- last output
PROBE edge skip: node=exprIfSubgraphOutput sig.Ord=2 incoming=1 realEdgeCount=1 epoch=6
PROBE epoch skip: node=const: str("out") node.epoch=6 epoch=6
PROBE epoch skip: node=_operator node.epoch=6 epoch=6
PROBE traversal INVALID, epoch frozen at 6
PROBE epoch skip: node=now node.epoch=6 epoch=6                 <- the event source itself
PROBE epoch skip: node=math.mod node.epoch=6 epoch=6
PROBE epoch skip: node=call node.epoch=6 epoch=6
...

Totals for a 25 second run: 4 print lines, then 20 incomplete traversals, 413 epoch skips, epoch frozen at 6 for the rest of the run.

Note node=now: datetime.now() is a StreamableFunc, its Stream keeps ticking and init.Event() keeps returning successfully, but Call is never invoked again, so nothing it produces is ever read. Everything downstream is likewise skipped, which is why the process looks completely healthy — the graph is traversed on every event, it just cannot compute anything.

Suggested fix

Advance the epoch after every traversal, and keep withholding the table when it is incomplete. The two concerns are separate: "is this table safe to publish" is not the same question as "may nodes be recomputed next time".

--- a/lang/funcs/dage/dage.go
+++ b/lang/funcs/dage/dage.go
@@
 		} // end of single graph traversal
 
-		if !valid { // don't send table yet, it's not complete
+		// XXX: implement epoch rollover by relabelling all nodes
+		epoch++ // increment it after each traversal
+		if obj.Debug {
+			obj.Logf("epoch(%d) increment to %d", epoch-1, epoch)
+		}
+
+		if !valid { // don't send the table yet, it's not complete
 			continue
 		}
 
@@
 		// The table must get cleaned up over time to be consistent. It
 		// currently happens in interrupt as a result of a node delete.
 
-		// XXX: implement epoch rollover by relabelling all nodes
-		epoch++ // increment it after a successful traversal
-		if obj.Debug {
-			obj.Logf("epoch(%d) increment to %d", epoch-1, epoch)
-		}
-
 		// NOTE: increment epoch above b/c it's needed for table skip!

This is the same move as 285df59 ("lang: funcs: dage: Increment epoch for table skip"), which put epoch++ above the table-skip continue for the same class of reason; the !valid continue above it appears to have been missed.

With the patch applied to master, over 60 second runs:

program	before	after
nested if	3 lines, then wedged	54 lines
three-deep nested if	5 lines, then wedged	42 lines

go test ./lang/... passes (including all 382 TestAstFunc2 subtests), as do ./lang/funcs/dage and ./test/test-govet.sh.

Residual: the underlying trigger

The patch removes the permanent wedge, but not its cause. After it, roughly one tick in ten still produces no output — exactly the ticks where a branch swap happens — because exprIfSubgraphOutput genuinely is observable with 1 of its 2 incoming edges. The value is then one cycle stale until the next event:

gap of 2 seconds after 1785349516
gap of 2 seconds after 1785349524
gap of 2 seconds after 1785349528

So the dage change converts a permanent, silent wedge into a bounded one-cycle delay, which seems worth having regardless. But a maintainer who knows the ExprIf runtime graph swap may prefer to also make the output vertex never observable with an incomplete edge set, which would remove the incomplete traversal entirely. Happy to split that into its own issue if you would rather track it separately.

Environment

• mgmt: ea6066a9 (master, 2026-07-24), reproduced with a plain go build of the tree
• golang: go1.26.4 linux/amd64
• Linux 6.8.0-136-generic x86_64

How this was found

It first showed up while driving an ESPHome device from mcl: mgmt's view of the device would freeze after the first classification, and a conveyor belt would never start again. That work lives on a feature branch of a fork and is not needed to reproduce this — the repro.mcl above uses nothing but upstream core functions, and the instrumented output in this report was captured on unmodified master. The device case was just what made a silent freeze visible, because a motor that will not start is hard to miss.

If it is ever useful, the same bug can also be driven end to end against the pure-golang ESPHome device simulator with no hardware, but the datetime.now() reproducer is smaller and does not depend on anything outside this repo.

[flavio-fernandes]

A follow-up from the bench, because the user-visible symptom turns out to be much worse than "one tick in ten is late", and the shape that triggers it is easy to write by accident.

The symptom on real hardware

An RGB status light kept animating after the object it described was removed. Not for a cycle — indefinitely, until something unrelated happened to the light. On a bench that is however long it takes to reach for the next object, and the demo looks broken rather than late.

What made it confusing is that it depended on which value changed. The mcl was:

$traveling = if $en_route { "Traveling Blink" } else { "" }

esphome:light "Status Light" {
	color  => if $is_red { "red" } else { "white" },
	effect => if $is_other { "Rainbow" } else { $traveling },
}

Removing a red object worked every time. Removing any other object left the rainbow running. The difference is exactly the nesting: the color rule is a flat if between two constants, while the effect rule has an if ($traveling) inside the else branch of another if. Switching out of the Rainbow branch instantiates the nested one, and that update is the one that gets dropped.

Measured

Device publishes the value that should clear the effect, and mgmt computes nothing at all:

21:04:45.247  operator lifts the object
21:04:45.594  device publishes the "nothing here" value
              <mgmt produces no table, no print, no command>
21:04:49.749  next object arrives -> mgmt finally reacts

The print that eventually ran at 21:04:49 showed the value from .594, so it had been sitting unread in the cache for four seconds. It was not lost, and nothing errored; the traversal that would have read it never completed.

Workaround, for anyone hitting this

Keep every if flat and combine the results with an ordinary function instead of nesting. Where the branches are mutually exclusive, string concatenation does it:

$rainbow   = if $is_other { "Rainbow" } else { "" }
$traveling = if $en_route { "Traveling Blink" } else { "" }
...
	effect => $rainbow + $traveling,

Same three outcomes, no nested subgraph to swap. After this change the same transition is measured at 2ms instead of four seconds, over repeated cycles.

Why this may deserve more than the epoch fix

The patch in the first comment turns the permanent wedge into a one-cycle delay, and that is worth having on its own. But this case shows the residual is not always cosmetic: when the dropped update is the one that returns a device to its resting state, "one cycle late" can mean "until the next unrelated event", which may be never. Making exprIfSubgraphOutput unobservable with an incomplete edge set would remove the whole class. Happy to test a patch against the reproducers here if that is useful.

[purpleidea]

Nice find @flavio-fernandes thank you! I will merge a fix shortly.

[purpleidea]

Merged in 938e045 thanks! \o/

If you still think there is an issue with the exprif one cycle late stuff, please feel free to propose a patch. I haven't had time to dig into it yet, although my suspicion would be either a bug in dage.go or a missing edge possibly in ./lang/funcs/structs/exprif.go

Thank you!

PS: If you could disclose what model and effort level you used to generate the above, it would be appreciated!

[flavio-fernandes]

Merged in 938e045 thanks! \o/

If you still think there is an issue with the exprif one cycle late stuff, please feel free to propose a patch. I haven't had time to dig into it yet, although my suspicion would be either a bug in dage.go or a missing edge possibly in ./lang/funcs/structs/exprif.go

ack.

Thank you!

My pleasure.

PS: If you could disclose what model and effort level you used to generate the above, it would be appreciated!

I used Claude Opus 5 on "High" effort to get to the bottom of this issue.