Skip to content

Commit e5b6041

Browse files
osiewiczdinocostazed-zippy[bot]
authored
audio: Fix phantom presence in channels (#59195)
# Objective You know that feeling? You join the channel, crack a banger joke to break the ice - yet, nobody laughs. Worse yet, you're swarmed with Slack messages like "Piotr, we can't hear you". After a while you realize that maybe it's for the best as the joke was not as good as you've initially thought, but still: it's possible to get into a state where other participants see you as muted. You don't hear anybody. Bummer. That's what happened when we were hoping to pair with @dinocosta today. I could not hear him. However, he had some logs to share which indicated that while collab thought he's in the room with me, live-kit was rejecting his token as it was revoked. What clanker helped us figure out is that there's a race-y code path where if you disconnect from a given room abruptly, collab can put you in a limbo. <details><summary>Clanker's idea of what's going on</summary> <p> Found the whole story. Here's what those logs mean and where the bug surface is. What's happening The error at room.rs:1809 is the detach_and_log_err on the task spawned by spawn_room_connection (crates/call/src/call_impl/room.rs:1754-1810). So this is the initial livekit::Room::connect call failing — the LiveKit SDK internally retried 3 times (that's the retrying... (1/3) lines), got 401 invalid token: revoked every time, gave up, and the error propagated out of the ? at line 1762 and was logged-and-dropped. The "revoked" comes from the collab server: leave_room_for_session (crates/collab/src/rpc.rs:4091-4095) calls live_kit.remove_participant(livekit_room, session.user_id().to_string()), and LiveKit Cloud treats a removed participant's token as revoked. Crucially, the LiveKit identity is just the user id, not the connection id, while the DB-side leave_room(connection_id) is per-connection. leave_room_for_session fires from three places: 1. Explicit leave (rpc.rs:1666) 2. connection_lost, after RECONNECT_TIMEOUT expires (rpc.rs:1342) 3. Stale-connection cleanup when re-joining a channel (rpc.rs:3401) So there's a race: an old connection's delayed cleanup (path 2) can fire after the same user has rejoined the room on a new connection and been issued a fresh token — and remove_participant(room, user_id) kicks/revokes the user's current LiveKit participant, because the identity is shared across connections. Quick restart of Zed, two instances, or a reconnect that straddles the server's RECONNECT_TIMEOUT all set this up. Client-side consequences (this connects to your first question) When that initial connect fails: - this.live_kit stays None and this.diagnostics is never created — lines 1780-1791 only run on success. So in this failure mode CallDiagnostics doesn't exist at all; the "stats never overridden" path I described earlier isn't even reached. - There is no retry and no token refresh. The failure is detach_and_log_err'd and that's the end of it. The user stays in the room at the collab level (status is still Online, they appear in the channel), but with no audio and no way to recover short of leaving and rejoining. - Even a collab-level reconnect doesn't help: RejoinRoomResponse (crates/proto/proto/call.proto:58) carries no live_kit_connection_info, and rejoin() never calls spawn_room_connection — the LiveKit connection is established exactly once, in Room::new, with the token from the original join response. So the user-visible symptom is: you're "in" the call, everyone sees you, but you can't hear or be heard, and there's no error surfaced in the UI — just this log line. If you want to fix it, the two angles are server-side (make leave_room_for_session skip the LiveKit removal when the user still has a live connection in that room, or scope LiveKit identities per-connection) and client-side (treat a failed spawn_room_connection as fatal-but-recoverable: surface it, and have rejoin request fresh connection info instead of silently carrying on). Happy to dig into either if you want. </p> </details> So tl;dr: our token was swapped out underneath us. One way to "fix" it was to just go into another channel, but that was a bummer. We have a good and reliable repro for it though: `kill -9 $ZED_PID` followed by an attempt to rejoin the same channel within 30s would consistently put us in that state. Put another way: you panic and thus do not send a clean "leave room" message to LK. if you rejoin the channel within 30s (after restarting), LK will invalidate the very token you're attempting to use (as it cleans up old tokens). It may also happen without crashing, but that's the most reliable way to repro the issue. Long story short your LK token gets tainted and you can't share the audio anyhow. ## Solution The fix is both client and server-side. On client's side, we now retry the reconnection with a back-off and we grab a fresh token off of reconnect attempts. On server's side, we share the current token on room reconnect attempts. We've also tweaked the call diagnostics to not use `unwrap_or_default` so much: it was hard for us to tell that we're in a totally bogus state and we've only reached that conclusion based on source code analysis. We now show some generic "ok you're in a borked state pls report a bug" message instead. ## Testing We added tests that present the flacky scenario. We've also tried to setup an infra to test the new behaviour, but sadly, local LK instance seems to revoke tokens more leniently than the prod.. OTOH, we are quite confident that once new collab is deployed, we'll be able to mince the new tokens and life is going to be good. Even when running against the current prod instance we could see that our code changed the behaviour for the better, as now we'll actually try to use a new token if one is provided by collab. For that to happen we need to redeploy though. ## Self-Review Checklist: - [x] I've reviewed my own diff for quality, security, and reliability - [x] Unsafe blocks (if any) have justifying comments - [x] The content adheres to Zed's UI standards ([UX/UI](https://github.com/zed-industries/zed/blob/main/CONTRIBUTING.md#uiux-checklist) and [icon](https://github.com/zed-industries/zed/blob/main/crates/icons/README.md) guidelines) - [x] Tests cover the new/changed behavior - [x] Performance impact has been considered and is acceptable Release Notes: - Fixed a race condition that caused collab users to not receive/send any audio to their peers. --------- Co-authored-by: dino <dinojoaocosta@gmail.com> Co-authored-by: Dino <dino@zed.dev> Co-authored-by: zed-zippy[bot] <234243425+zed-zippy[bot]@users.noreply.github.com>
1 parent b6c7496 commit e5b6041

8 files changed

Lines changed: 267 additions & 61 deletions

File tree

crates/call/src/call_impl/room.rs

Lines changed: 110 additions & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,7 @@ pub struct Room {
9393
room_update_completed_rx: watch::Receiver<Option<()>>,
9494
pending_room_update: Option<Task<()>>,
9595
maintain_connection: Option<Task<Option<()>>>,
96+
livekit_connection_task: Option<Task<()>>,
9697
created: Instant,
9798
}
9899

@@ -123,7 +124,7 @@ impl Room {
123124
user_store: Entity<UserStore>,
124125
cx: &mut Context<Self>,
125126
) -> Self {
126-
spawn_room_connection(livekit_connection_info, cx);
127+
let livekit_connection_task = spawn_room_connection(livekit_connection_info, cx);
127128

128129
let maintain_connection = cx.spawn({
129130
let client = client.clone();
@@ -164,6 +165,7 @@ impl Room {
164165
user_store,
165166
follows_by_leader_id_project_id: Default::default(),
166167
maintain_connection: Some(maintain_connection),
168+
livekit_connection_task,
167169
room_update_completed_tx,
168170
room_update_completed_rx,
169171
created: cx.background_executor().now(),
@@ -360,6 +362,7 @@ impl Room {
360362
self.diagnostics.take();
361363
self.pending_room_update.take();
362364
self.maintain_connection.take();
365+
self.livekit_connection_task.take();
363366
}
364367

365368
fn emit_video_track_unsubscribed_events(&self, cx: &mut Context<Self>) {
@@ -400,7 +403,10 @@ impl Room {
400403

401404
let Some(this) = this.upgrade() else { break };
402405
let task = this.update(cx, |this, cx| this.rejoin(cx));
403-
if task.await.log_err().is_some() {
406+
if let Some(live_kit_connection_info) = task.await.log_err() {
407+
this.update(cx, |this, cx| {
408+
this.ensure_livekit_connection(live_kit_connection_info, cx);
409+
});
404410
return true;
405411
} else {
406412
remaining_attempts -= 1;
@@ -447,7 +453,10 @@ impl Room {
447453
anyhow::bail!("can't reconnect to room: client failed to re-establish connection");
448454
}
449455

450-
fn rejoin(&mut self, cx: &mut Context<Self>) -> Task<Result<()>> {
456+
fn rejoin(
457+
&mut self,
458+
cx: &mut Context<Self>,
459+
) -> Task<Result<Option<proto::LiveKitConnectionInfo>>> {
451460
let mut projects = HashMap::default();
452461
let mut reshared_projects = Vec::new();
453462
let mut rejoined_projects = Vec::new();
@@ -507,7 +516,8 @@ impl Room {
507516
cx.spawn(async move |this, cx| {
508517
let response = response.await?;
509518
let message_id = response.message_id;
510-
let response = response.payload;
519+
let mut response = response.payload;
520+
let live_kit_connection_info = response.live_kit_connection_info.take();
511521
let room_proto = response.room.context("invalid room")?;
512522
this.update(cx, |this, cx| {
513523
this.status = RoomStatus::Online;
@@ -530,10 +540,22 @@ impl Room {
530540
}
531541

532542
anyhow::Ok(())
533-
})?
543+
})??;
544+
Ok(live_kit_connection_info)
534545
})
535546
}
536547

548+
fn ensure_livekit_connection(
549+
&mut self,
550+
connection_info: Option<proto::LiveKitConnectionInfo>,
551+
cx: &mut Context<Self>,
552+
) {
553+
if connection_info.is_none() || self.is_connected(cx) {
554+
return;
555+
}
556+
self.livekit_connection_task = spawn_room_connection(connection_info, cx);
557+
}
558+
537559
pub fn id(&self) -> u64 {
538560
self.id
539561
}
@@ -1754,60 +1776,93 @@ impl Room {
17541776
fn spawn_room_connection(
17551777
livekit_connection_info: Option<proto::LiveKitConnectionInfo>,
17561778
cx: &mut Context<Room>,
1757-
) {
1758-
if let Some(connection_info) = livekit_connection_info {
1759-
cx.spawn(async move |this, cx| {
1760-
let (room, mut events) =
1761-
livekit::Room::connect(connection_info.server_url, connection_info.token, cx)
1762-
.await?;
1779+
) -> Option<Task<()>> {
1780+
let mut connection_info = livekit_connection_info?;
1781+
Some(cx.spawn(async move |this, cx| {
1782+
let mut backoff = Duration::from_secs(1);
1783+
loop {
1784+
match livekit::Room::connect(
1785+
connection_info.server_url.clone(),
1786+
connection_info.token.clone(),
1787+
cx,
1788+
)
1789+
.await
1790+
{
1791+
Ok((room, mut events)) => {
1792+
let weak_room = this.clone();
1793+
let Ok(share_microphone) = this.update(cx, |this, cx| {
1794+
let _handle_updates = cx.spawn(async move |this, cx| {
1795+
while let Some(event) = events.next().await {
1796+
if this
1797+
.update(cx, |this, cx| {
1798+
this.livekit_room_updated(event, cx).warn_on_err();
1799+
})
1800+
.is_err()
1801+
{
1802+
break;
1803+
}
1804+
}
1805+
});
17631806

1764-
let weak_room = this.clone();
1765-
this.update(cx, |this, cx| {
1766-
let _handle_updates = cx.spawn(async move |this, cx| {
1767-
while let Some(event) = events.next().await {
1768-
if this
1769-
.update(cx, |this, cx| {
1770-
this.livekit_room_updated(event, cx).warn_on_err();
1771-
})
1772-
.is_err()
1773-
{
1774-
break;
1807+
let muted_by_user = Room::mute_on_join(cx);
1808+
this.live_kit = Some(LiveKitRoom {
1809+
room: Rc::new(room),
1810+
screen_track: LocalTrack::None,
1811+
microphone_track: LocalTrack::None,
1812+
input_lag_us: None,
1813+
next_publish_id: 0,
1814+
muted_by_user,
1815+
deafened: false,
1816+
speaking: false,
1817+
_handle_updates,
1818+
});
1819+
this.diagnostics = Some(cx.new(|cx| CallDiagnostics::new(weak_room, cx)));
1820+
cx.notify();
1821+
1822+
// Always open the microphone track on join, even when
1823+
// `muted_by_user` is set. Note that the microphone will still
1824+
// be muted, as it is still gated in `share_microphone` by
1825+
// `muted_by_user`. For users that have `mute_on_join` enabled,
1826+
// this moves the Bluetooth profile switch (A2DP -> HFP) (which
1827+
// can cause 1-2 seconds of audio silence on some Bluetooth
1828+
// headphones) from first unmute to channel join, where
1829+
// instability is expected.
1830+
if this.can_use_microphone() {
1831+
this.share_microphone(cx)
1832+
} else {
1833+
Task::ready(Ok(()))
17751834
}
1776-
}
1777-
});
1835+
}) else {
1836+
return;
1837+
};
1838+
share_microphone.await.log_err();
1839+
return;
1840+
}
1841+
Err(error) => {
1842+
log::error!("failed to connect to LiveKit room: {error:#}");
1843+
}
1844+
}
17781845

1779-
let muted_by_user = Room::mute_on_join(cx);
1780-
this.live_kit = Some(LiveKitRoom {
1781-
room: Rc::new(room),
1782-
screen_track: LocalTrack::None,
1783-
microphone_track: LocalTrack::None,
1784-
input_lag_us: None,
1785-
next_publish_id: 0,
1786-
muted_by_user,
1787-
deafened: false,
1788-
speaking: false,
1789-
_handle_updates,
1790-
});
1791-
this.diagnostics = Some(cx.new(|cx| CallDiagnostics::new(weak_room, cx)));
1792-
1793-
// Always open the microphone track on join, even when
1794-
// `muted_by_user` is set. Note that the microphone will still
1795-
// be muted, as it is still gated in `share_microphone` by
1796-
// `muted_by_user`. For users that have `mute_on_join` enabled,
1797-
// this moves the Bluetooth profile switch (A2DP -> HFP) (which
1798-
// can cause 1-2 seconds of audio silence on some Bluetooth
1799-
// headphones) from first unmute to channel join, where
1800-
// instability is expected.
1801-
if this.can_use_microphone() {
1802-
this.share_microphone(cx)
1803-
} else {
1804-
Task::ready(Ok(()))
1846+
cx.background_executor().timer(backoff).await;
1847+
backoff = (backoff * 2).min(Duration::from_secs(30));
1848+
1849+
// The token we were given may no longer be valid: LiveKit revokes
1850+
// it when this user's stale connection is cleaned up around the
1851+
// time the token is issued (e.g. when rejoining a channel right
1852+
// after a crash). Rejoin the room to obtain fresh connection info
1853+
// before trying again.
1854+
let Ok(rejoin) = this.update(cx, |this, cx| this.rejoin(cx)) else {
1855+
return;
1856+
};
1857+
match rejoin.await {
1858+
Ok(Some(new_connection_info)) => connection_info = new_connection_info,
1859+
Ok(None) => {}
1860+
Err(error) => {
1861+
log::error!("failed to refresh LiveKit connection info: {error:#}");
18051862
}
1806-
})?
1807-
.await
1808-
})
1809-
.detach_and_log_err(cx);
1810-
}
1863+
}
1864+
}
1865+
}))
18111866
}
18121867

18131868
struct LiveKitRoom {

crates/collab/src/db.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -487,6 +487,7 @@ pub struct RejoinedRoom {
487487
pub rejoined_projects: Vec<RejoinedProject>,
488488
pub reshared_projects: Vec<ResharedProject>,
489489
pub channel: Option<channel::Model>,
490+
pub role: ChannelRole,
490491
}
491492

492493
pub struct ResharedProject {

crates/collab/src/db/queries/rooms.rs

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -499,6 +499,16 @@ impl Database {
499499
return Err(anyhow!("room does not exist or was already joined"))?;
500500
}
501501

502+
let participant = room_participant::Entity::find()
503+
.filter(
504+
Condition::all()
505+
.add(room_participant::Column::RoomId.eq(room_id))
506+
.add(room_participant::Column::UserId.eq(user_id)),
507+
)
508+
.one(&*tx)
509+
.await?
510+
.context("participant not found")?;
511+
502512
let mut reshared_projects = Vec::new();
503513
for reshared_project in &rejoin_room.reshared_projects {
504514
let project_id = ProjectId::from_proto(reshared_project.project_id);
@@ -591,6 +601,7 @@ impl Database {
591601
channel,
592602
rejoined_projects,
593603
reshared_projects,
604+
role: participant.role.unwrap_or(ChannelRole::Member),
594605
})
595606
})
596607
.await

crates/collab/src/rpc.rs

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1493,6 +1493,44 @@ async fn rejoin_room(
14931493
.rejoin_room(request, session.user_id(), session.connection_id)
14941494
.await?;
14951495

1496+
// Include fresh LiveKit connection info so that clients whose LiveKit
1497+
// connection failed (e.g. because their token was revoked by a stale
1498+
// connection cleanup) can re-establish it.
1499+
let live_kit_connection_info =
1500+
session
1501+
.app_state
1502+
.livekit_client
1503+
.as_ref()
1504+
.and_then(|live_kit| {
1505+
let (can_publish, token) = if rejoined_room.role == ChannelRole::Guest {
1506+
(
1507+
false,
1508+
live_kit
1509+
.guest_token(
1510+
&rejoined_room.room.livekit_room,
1511+
&session.user_id().to_string(),
1512+
)
1513+
.trace_err()?,
1514+
)
1515+
} else {
1516+
(
1517+
true,
1518+
live_kit
1519+
.room_token(
1520+
&rejoined_room.room.livekit_room,
1521+
&session.user_id().to_string(),
1522+
)
1523+
.trace_err()?,
1524+
)
1525+
};
1526+
1527+
Some(LiveKitConnectionInfo {
1528+
server_url: live_kit.url().into(),
1529+
token,
1530+
can_publish,
1531+
})
1532+
});
1533+
14961534
response.send(proto::RejoinRoomResponse {
14971535
room: Some(rejoined_room.room.clone()),
14981536
reshared_projects: rejoined_room
@@ -1512,6 +1550,7 @@ async fn rejoin_room(
15121550
.iter()
15131551
.map(|rejoined_project| rejoined_project.to_proto())
15141552
.collect(),
1553+
live_kit_connection_info,
15151554
})?;
15161555
room_updated(&rejoined_room.room, &session.peer);
15171556

crates/collab/tests/integration/channel_tests.rs

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -366,6 +366,72 @@ async fn test_joining_channel_ancestor_member(
366366
);
367367
}
368368

369+
#[gpui::test]
370+
async fn test_channel_call_recovers_from_livekit_connect_failure(
371+
executor: BackgroundExecutor,
372+
cx_a: &mut TestAppContext,
373+
) {
374+
let mut server = TestServer::start(executor.clone()).await;
375+
let client_a = server.create_client(cx_a, "user_a").await;
376+
client_a.initialize_channel_store(cx_a);
377+
378+
let channel_id = server
379+
.make_channel("zed", None, (&client_a, cx_a), &mut [])
380+
.await;
381+
382+
// Simulate LiveKit rejecting the token issued for this join. In
383+
// production this happens when the collab server's stale connection
384+
// cleanup (`leave_room_for_session`) calls `remove_participant` for this
385+
// user's identity just before issuing a new token for the same identity
386+
// and room (e.g. rejoining a channel right after an abrupt disconnect or
387+
// restart): LiveKit Cloud revokes the freshly issued token and the
388+
// client's initial connection fails with "401 invalid token: revoked".
389+
let identity = client_a.user_id().unwrap().to_string();
390+
server
391+
.test_livekit_server
392+
.set_token_revoked(&identity, true);
393+
394+
let active_call_a = cx_a.read(ActiveCall::global);
395+
active_call_a
396+
.update(cx_a, |active_call, cx| {
397+
active_call.join_channel(channel_id, cx)
398+
})
399+
.await
400+
.unwrap();
401+
executor.run_until_parked();
402+
403+
// The collab server considers user A a participant in the call...
404+
let room_a =
405+
cx_a.read(|cx| active_call_a.read_with(cx, |call, _| call.room().unwrap().clone()));
406+
cx_a.read(|cx| {
407+
client_a.channel_store().read_with(cx, |channels, _| {
408+
assert_participants_eq(
409+
channels.channel_participants(channel_id),
410+
&[client_a.user_id().unwrap()],
411+
);
412+
})
413+
});
414+
// ...but the LiveKit connection failed, so they have no audio.
415+
cx_a.read(|cx| room_a.read_with(cx, |room, cx| assert!(!room.is_connected(cx))));
416+
417+
// Once LiveKit accepts the user's tokens again, the client should
418+
// re-establish its LiveKit connection instead of silently staying in the
419+
// call without audio.
420+
server
421+
.test_livekit_server
422+
.set_token_revoked(&identity, false);
423+
executor.advance_clock(RECONNECT_TIMEOUT);
424+
executor.run_until_parked();
425+
cx_a.read(|cx| {
426+
room_a.read_with(cx, |room, cx| {
427+
assert!(
428+
room.is_connected(cx),
429+
"client should have re-established its LiveKit connection"
430+
)
431+
})
432+
});
433+
}
434+
369435
#[gpui::test]
370436
async fn test_channel_room(
371437
executor: BackgroundExecutor,

0 commit comments

Comments
 (0)