The panel that hid itself
PopsicleBoat has video calling. One person clicks call, the other gets a little toast notification, and they answer or they don’t (or they miss it entirely). If they answer, WebRTC does its thing through NAT, with a STUN server and a TURN server, one of each for now. I’ll add more if I ever need to.
Most of that lived in one file, app.js, which had gotten to 6,371 lines. This is about a bug in there and how long it took me to find it.
The bug #
I’ve got a browser test that runs before I deploy. It opens two real browsers, starts a call from one, and answers it from the other. Twice, out of a lot of runs (like… hundreds), it failed in a weird way. The call connected fine, video going both ways, everything working, except the call panel was hidden. A working call with no interface. Not every time, not even often. Just twice.
An intermittent bug in code that’s juggling timers, WebSockets, WebRTC callbacks, and a DOM patcher. That’s a race, pretty much guaranteed.
Finding it #
You can’t really put a breakpoint on “sometimes.” Something was setting hidden on the panel after the answer, and there were a few things that could’ve done it: my own show/hide helpers, the retry logic around the ring, and LiveView’s morphdom patcher, which quietly re-syncs the DOM back to whatever the server rendered.
That last one doesn’t show up when you just read the code, so it’s easy to forget it’s even there.
So I added some logging. It wraps every place I legitimately change the panel’s visibility, and separately watches for the panel changing from anywhere at all. Every time the visibility changes, it logs who did it. If something changed and there’s no matching entry from my own code, that’s an outside write, which basically means morphdom. I also tagged each panel with a serial number so I could tell a panel that got patched apart from one that got swapped out entirely. The log just piles up on a window global and waits for the bug to happen again.
I figured it was morphdom. A patcher whose whole job is rewriting attributes to match the server is exactly the kind of thing that hides a panel, and honestly I added the logging mostly to catch it. Turned out it was innocent. Its writes were all re-syncs to the right state. The writes that actually broke things had my name on them. The call was coming from my own code.
The race #
Three steps, and the ends are about six seconds apart.
- A ring event comes in and kicks off a prepare loop for the panel, a retry that runs for up to six seconds making sure the incoming-call UI is ready.
- The user answers. That clears the ring alert and shows the in-call panel. Good so far.
- A duplicate of the ring event shows up late (these aren’t guaranteed to be unique) and its handler re-remembers the ring alert before it gets to the check for whether the call was already answered. That wakes up a prepare tick still pending from step 1, which does exactly what it was told to: hides the panel and marks it
incoming. A state sync later puts the call back toin_call, but nothing ever tells the panel to show again.
Everything here worked correctly. The retry loop retried like it should. The duplicate handler did catch the duplicate, just one line too late. The state sync synced the state, but the panel’s visibility wasn’t part of the state it was syncing. Nothing was broken on its own. The bug only existed in the order it all ran.
The fix #
Two guards, either one of which would’ve been enough by itself. The prepare tick now skips any panel that’s already accepted, answering, or in a call. And the duplicate-ring handler bails out before re-remembering the alert if the call’s already been answered. I pinned both with regression tests that grep the source, since the bug was an ordering between lines, not a wrong output I could assert on.
The file #
The 6,371 lines were really the other half of the problem. A race like this hides easy in a file where the signaling, the media, the DOM, and the timers are all sharing one scope. app.js is down to 2,156 lines now. The call stuff moved out into thirty smaller modules. The main piece is a state machine for the call lifecycle, a plain reducer, transition(state, event) -> { state, actions }, with no DOM, no peer connection, no timers in it. It replaced about seven booleans I’d been keeping in sync by hand. And there’s one rule for duplicates now: every call has a key, and remote events with the wrong key just get ignored, which took the place of all the per-message dedup flags. The side effects come back as a list of named actions for the caller to run, so the whole lifecycle, including the kind of ordering that caused this, is something I can actually unit test now.
This was a hell of a journey, deeply hidden bug inside a huge JS file that I had to pull apart and split up before I could identify where things were going wrong. I got it now though, web calling works. I’m testing it daily, and it’s a lot of work but fixing things is so much fun I can’t resist. (I might need my head examined lol)
