Dangling Broadcast: can be spectated, but no events ever arrive

[jmlee337]

This has been report and discussed extensively on discord. I will reproduce the relevant excerpts (at time of writing) here:

kadence — 03/07/2024 8:29 AM

~ 7pm central time (march 5th)
I have a clear example of a Slippi Broadcast issue, where at least 4(?) separate broadcasters are in my list, and are confirmed mid match (according to SGG)
Yet clicking “watch” results in a black “waiting for game” screen on all 4 broadcasts.

kadence — 03/07/2024 10:46 AM

You can def reproduce this yourself - let a broadcast run for about an hour from the issuing of a new Auth token, and most of the time if you try watching a broadcast, it will fail around the hour mark
Failure looks like one of two ways from my testing today
Either the broadcast will turn off by itself, almost always under the hour mark
OR
it won’t disconnect by itself, and the text changes to “connecting” in the bottom right of the spectate screen
The second scenario cause a “dangling” broadcast where it shows up in the spectate list but shows a waiting for game black screen when watched

Nicolet — 03/13/2024 at 9:46 AM

I've repro'd dangling broadcast on a local build with extra logging, let me paste it in here

08:38:57.525 (broadcast.worker)             > Starting broadcast to: wNn4p9p2LZbqPTKBZJuZHWSuELF2-ojtxY5FBLn2v18nG7JLsMn
09:39:07.018 (broadcast.worker)             > WS connection closed: 1006, Connection dropped by remote peer.
09:39:07.503                                > Starting broadcast
09:39:07.505 (broadcast.worker)             > Connecting to WS service
09:39:07.782 (broadcast.worker)             > WS connection successful
09:39:07.783 (broadcast.worker)             > getBroadcasts: {"type":"get-broadcasts"}
09:39:08.005 (broadcast.worker)             > {"type":"get-broadcasts-resp","broadcasts":[{"id":"wNn4p9p2LZbqPTKBZJuZHWSuELF2-uctcQjLFtXYuLCvmGe2Mtp","name":"TEST#127","broadcaster":{"uid":"wNn4p9p2LZbqPTKBZJuZHWSuELF2","name":"jmlee337 test"}},{"id":"wNn4p9p2LZbqPTKBZJuZHWSuELF2-ojtxY5FBLn2v18nG7JLsMn","name":"TEST#127","broadcaster":{"uid":"wNn4p9p2LZbqPTKBZJuZHWSuELF2","name":"jmlee337 test"}}]}
09:39:08.006 (broadcast.worker)             > get-broadcasts-resp: existing broadcastId wNn4p9p2LZbqPTKBZJuZHWSuELF2-ojtxY5FBLn2v18nG7JLsMn
09:39:08.006 (broadcast.worker)             > startBroadcast: {"type":"start-broadcast","name":"TEST#127","broadcastId":"wNn4p9p2LZbqPTKBZJuZHWSuELF2-ojtxY5FBLn2v18nG7JLsMn"}
09:39:08.161 (broadcast.worker)             > {"type":"start-broadcast-resp","broadcastId":"wNn4p9p2LZbqPTKBZJuZHWSuELF2-ojtxY5FBLn2v18nG7JLsMn","recoveryGameCursor":375397}
09:39:08.162 (broadcast.worker)             > Picking broadcast back up from 375397. Last not sent: undefined
09:39:08.162 (broadcast.worker)             > Missing new first event

Missing new first event corresponds to

slippi-launcher/src/broadcast/broadcast_manager.ts

Line 261 in 071751b

this.emit(BroadcastEvent.LOG, "Missing new first event");

haven't looked enough to know what the problem is with this.backupEvents yet, but I think error cases need to be handled with abort or retry logic instead of nothing. Hanging while not fully connected is definitely the wrong thing to do here.

Nicolet — 03/14/2024 at 12:05 AM

I think I have a consistent repro (at least for this error path). Being in-game but paused will always cause a dangling broadcast on the hourly reconnect. This is due to backupEvents having no relevant events (as everything has already been successfully sent) and incomingEvents being empty (due to pause). I've attached a log that demonstrates this (again, at HEAD with a little extra logging)

19:31:12.729                                > Starting broadcast
19:31:12.730 (broadcast.worker)             > broadcast: Spawning worker
19:31:13.344 (broadcast.worker)             > broadcast: Spawning worker: Done
Connecting to: 127.0.0.1:51441
19:31:13.378 (broadcast.worker)             > Dolphin status change: 1
(node:18720) V8: C:\Users\jmlee337\Documents\GitHub\slippi-launcher\node_modules\enet\build\enet.js:11 Invalid asm.js: Invalid member of stdlib
(Use `electron --trace-warnings ...` to show where the warning was created)
19:31:13.404 (broadcast.worker)             > Dolphin status change: 2
19:31:13.405 (broadcast.worker)             > Connecting to WS service
19:31:13.685 (broadcast.worker)             > WS connection successful
19:31:13.910 (broadcast.worker)             > { type: 'get-broadcasts-resp', broadcasts: [] }
19:31:14.064 (broadcast.worker)             > {
  type: 'start-broadcast-resp',
  broadcastId: 'wNn4p9p2LZbqPTKBZJuZHWSuELF2-iJJtUKgbZwM6zCuZcxLBDD'
}
19:31:14.064 (broadcast.worker)             > Starting broadcast to: wNn4p9p2LZbqPTKBZJuZHWSuELF2-iJJtUKgbZwM6zCuZcxLBDD
[2688:0313/193236.297:ERROR:gpu_init.cc(481)] Passthrough is not supported, GL is disabled, ANGLE is
20:31:23.563 (broadcast.worker)             > WS connection closed: 1006, Connection dropped by remote peer.
20:31:24.087                                > Starting broadcast
20:31:24.089 (broadcast.worker)             > Connecting to WS service
20:31:24.307 (broadcast.worker)             > WS connection successful
20:31:24.510 (broadcast.worker)             > {
  type: 'get-broadcasts-resp',
  broadcasts: [
    {
      id: 'wNn4p9p2LZbqPTKBZJuZHWSuELF2-iJJtUKgbZwM6zCuZcxLBDD',
      name: 'TEST#127',
      broadcaster: [Object]
    }
  ]
}
20:31:24.665 (broadcast.worker)             > {
  type: 'start-broadcast-resp',
  broadcastId: 'wNn4p9p2LZbqPTKBZJuZHWSuELF2-iJJtUKgbZwM6zCuZcxLBDD',
  recoveryGameCursor: 295
}
20:31:24.667 (broadcast.worker)             > start-broadcast-resp this.incomingEvents length: 0
20:31:24.667 (broadcast.worker)             > Picking broadcast back up from 295. Last not sent: undefined
20:31:24.668 (broadcast.worker)             > start-broadcast-resp this.backupEvents: [0,0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53,54,55,56,57,58,59,60,61,62,63,64,65,66,67,68,69,70,71,72,73,74,75,76,77,78,79,80,81,82,83,84,85,86,87,88,89,90,91,92,93,94,95,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110,111,112,113,114,115,116,117,118,119,120,121,122,123,124,125,126,127,128,129,130,131,132,133,134,135,136,137,138,139,140,141,142,143,144,145,146,147,148,149,150,151,152,153,154,155,156,157,158,159,160,161,162,163,164,165,166,167,168,169,170,171,172,173,174,175,176,177,178,179,180,181,182,183,184,185,186,187,188,189,190,191,192,193,194,195,196,197,198,199,200,201,202,203,204,205,206,207,208,209,210,211,212,213,214,215,216,217,218,219,220,221,222,223,224,225,226,227,228,229,230,231,232,233,234,235,236,237,238,239,240,241,242,243,244,245,246,247,248,249,250,251,252,253,254,255,256,257,258,259,260,261,262,263,264,265,266,267,268,269,270,271,272,273,274,275,276,277,278,279,280,281,282,283,284,285,286,287,288,289,290,291,292,293,294,295]
20:31:24.668 (broadcast.worker)             > Missing new first event

I think the check that causes this version of dangling broadcast may not be necessary at all?

const newFirstEvent = this.incomingEvents[0];
if (!newFirstEvent) {
  this.emit(BroadcastEvent.LOG, "Missing new first event");
  return;
}

Nicolet — 03/13/2024 at 9:54 AM

I have confirmed that removing this check doesn't cause any problems at least in this case (reconnect while paused). Broadcast/spectate continues as expected when unpaused.

[jmlee337]

both petra (Slippi Sauce) and DevDogg (Waddle Wednesday) have reported noticeable improvements since 2.11.5 so I think we can consider this squashed.