client-sdk-js
client-sdk-js copied to clipboard
Stopping screen share sometimes breaks e2ee
Describe the bug When couple participants stop screen sharing (possibly in a quick succession) the e2ee breaks and a random 1-2 tracks are not decrypted
Server
- Version: 1.5.1
- Environment: local, dev, livekit demo page (https://meet.livekit.io/)
Client
- SDK: js
- Version: 1.15.0
To Reproduce Steps to reproduce the behavior:
The steps are a bit unclear and reproduce is not easy, but the general idea is:
- many (5+) participants join the room
- more than 2 participants share screen
- stopping 2 or more screen shares (possibly in a quick succession)
- some participants' camera or screen share tile appears not decrypted
Expected behavior e2ee continues to work for every participant
Screenshots
If applicable, add screenshots to help explain your problem.
Additional context I can reproduce both in my app and in livekit demo page (https://meet.livekit.io/)
could you confirm if this still happens with the latest server? you are using 1.2.7, which is quite old
could you confirm if this still happens with the latest server? you are using 1.2.7, which is quite old
Sorry, the version is 1.5.1, updated
up! this is important - any ideas whats happening?
+1
This looks to be a bug with the JS client SDK. moving the issue there.
I tried to reproduce the issue with the steps outlined in the description, but it continued to work for me in all cases (tried ~5 times of sharing screen from two participants with 5 in the room). Are all participants using the same browser or did you notice this occuring more frequently with a certain browser combination?
It's happening with some of our users where one of them was using IPad, but I couldn't reproduce either. We just updated the SDK and Server to the latest versions and we will continue to investigate.
+1
@AurimasG12 do you have a way to reproduce this?
we have found a way to reproduce it - we all jumped into the room, we all started sharing multiple screens (our app allows that) and then on the count of 3, we started stopping shared screens by leaving only 1 from each participant. One guy stopped all his screens at once (he had 4 shared screens). I'm adding a video how everything went and also the logs from our loki (both in json and txt)
video: https://we.tl/t-N3EiB8AOK3
logs: Explore-logs-2024-02-05 15_35_01.txt Explore-logs-2024-02-05 15_34_27.json
oh, that's great! thank you, for e2ee the server logs are unfortunately not very telling, could you also post client debug logs of
- the participants that stopped the screen share (and mark the one were the tiles appear broken)
- at least one of the participants that see the broken e2ee
it would be really helpful if you could, in addition, set debug level also for the lk-e2ee
logger with setLogLevel('debug', 'lk-e2ee')
Hey, we set the log level as suggested and reproduced.
Broken screen for participant with id: dcc89602-fdba-4818-b78f-9f83c3449f92 . Logs: Dooman-ignasp-local.front-4229.pr.meedio.pro-1707819812604.log
Participants that see broken screen: 0a14c645-1719-4ab9-a0b6-186b4e40dbb2, 117d568a-f3fb-4a0e-8eb2-9d92d5e63033, c6cbde2c-2cbd-4b39-8d50-28d4de57f186, 47cfb99b-23d4-4d01-91dc-3ec62a5aee8e Logs: Titas-ignasp-local.front-4229.pr.meedio.pro-1707819790409.log IgnasB-ignasp-local.front-4229.pr.meedio.pro-1707819802823.log Aurimas-ignasp-local.front-4229.pr.meedio.pro-1707819764415.log Svajunas-ignasp-local.front-4229.pr.meedio.pro-1707819762602.log
Participant that doesn’t see broken screen: d6acd8a1-1a54-4d48-aa32-b7a66ae3b54b Logs: IgnasP-ignasp-local.front-4229.pr.meedio.pro-1707820541257.log Video: https://we.tl/t-9TJ6kboLId
thanks!
are you using the ExternalE2EEKeyProvider
or a modified/custom version ?
Could you also elaborate on when you call setKey
on the key provider and whether that key ever changes?
I see some errors when trying to decrypt
12:16:27.510 livekit-client.e2ee.worker.mjs:1043 TypeError: Destination stream closed
at yUe.<anonymous> (index-a4841935.js:1205:66344)
at Generator.next (<anonymous>)
at index-a4841935.js:1171:39721
at new Promise (<anonymous>)
at ye (index-a4841935.js:1171:39518)
at yUe.handleReceiver (index-a4841935.js:1205:65753)
at yUe.setupE2EEReceiver (index-a4841935.js:1205:65482)
at YUe.<anonymous> (index-a4841935.js:1205:63527)
at Pr.emit (index-a4841935.js:1171:42543)
at YUe.emit (index-a4841935.js:1207:135702)
(anonymous) @ livekit-client.e2ee.worker.mjs:1043
Promise.catch (async)
setupTransform @ livekit-client.e2ee.worker.mjs:1042
onmessage @ livekit-client.e2ee.worker.mjs:1628
Show 3 more frames
Show less
12:16:27.516 console.js:213 InternalError: Destination stream closed
overrideMethod @ console.js:213
onWorkerMessage @ livekit-client.esm.mjs:14443
Show 2 more frames
Show less
12:16:27.516 livekit-client.esm.mjs:23124 room event encryptionError {room: 'f4a2314a-cbc1-4d2f-b573-465b69fbb7ca', roomSid: 'RM_AE7x4GgZ4UTs', identity: '117d568a-f3fb-4a0e-8eb2-9d92d5e63033', event: 'encryptionError', args: Array(1)}
This should however have no impact for longer than a frame (it only shows up twice in the whole session) and also the participant that continued to see the screen share has the same errors in their logs. So it's unlikely that this is the root issue.
thanks! are you using the
ExternalE2EEKeyProvider
or a modified/custom version ? Could you also elaborate on when you callsetKey
on the key provider and whether that key ever changes?
using ExternalE2EEKeyProvider from 'livekit-client'. We create Room instance and set the key (setKey) and E2EEEnabled (setE2EEEnabled(true)) immediately.
got it. I can't see anything unexpected in the logs. I audited the code paths that get executed when a track gets unpublished/unsubscribed and found a potential edge case. Could you try if it still repros for you with the changes in https://github.com/livekit/client-sdk-js/pull/1032 ?
got it. I can't see anything unexpected in the logs. I audited the code paths that get executed when a track gets unpublished/unsubscribed and found a potential edge case. Could you try if it still repros for you with the changes in #1032 ?
Hey, we've updated the client version to v2.0.3, which includes the changes from #1032. Unfortunately, the problem still persists
v2.0.4 has some (very) verbose e2ee logs. It'll be hard to sift through them, but another repro on that version with setLogLevel('debug', 'lk-e2ee')
would be great. The important part would be that the log context is fully present in those logs. You should be able to get those by right-clicking in the js developer console and clicking "save".
Hey, sorry for the delay, we reproduced on client v2.0.7
Participants with broken e2ee: paulius_log.log dooman_log.log
Participants that didn't see anything wrong: ovi_log.log auri_log.log svajuno_log.log ignas_log.log
Complementary video (of participant without visible broken e2ee): https://we.tl/t-3IES9Tca1N
thanks! Did the e2ee display for paulius and dooman break only of one participant?
And if so, is that participant @shq9agyxow:matrix.meedio.pro:DFLHOQSHFI
for paulius and @red-similar-barracuda:matrix.meedio.pro:LDYGUMTRTH
for dooman?
If not, can you tell me which tracks broke for paulius and dooman respectively?
dropping some filtered logs here around what looks like an issue with transceiver reuse
06:13:50.992 livekit-client.e2ee.worker.mjs:1047 Setting up frame cryptor transform {operation: 'decode', passedTrackId: 'TR_VScqUdXi2jor7A', codec: 'vp8', participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: undefined, …}
06:14:15.353 livekit-client.esm.mjs:23960 room event trackUnsubscribed {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackUnsubscribed', …}
06:14:15.354 livekit-client.esm.mjs:23960 room event trackSubscriptionStatusChanged {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackSubscriptionStatusChanged', …}
06:14:15.354 livekit-client.e2ee.worker.mjs:1010 unsetting participant {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:14:15.354 livekit-client.esm.mjs:23960 room event trackUnpublished {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackUnpublished', …}06:14:54.110 livekit-client.esm.mjs:20549 update publication info {trackID: 'TR_VScqUdXi2jor7A', enabled: true, muted: false, trackInfo: {…}, info: ZFe.s}
06:14:54.110 livekit-client.esm.mjs:20549 update publication info {trackID: 'TR_VScqUdXi2jor7A', enabled: true, muted: false, trackInfo: {…}, info: ZFe.s}
06:14:54.110 livekit-client.esm.mjs:22348 received a second track publication for @shq9agyxow:matrix.meedio.pro:DFLHOQSHFI with the same source: screen_share {rpID: 'PA_L29C7pPnGkDF', remoteParticipant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', oldTrack: {…}, newTrack: {…}}
06:14:54.649 livekit-client.e2ee.worker.mjs:1047 Setting up frame cryptor transform {operation: 'decode', passedTrackId: 'TR_VScqUdXi2jor7A', codec: 'vp8', participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', …}
06:15:26.574 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.608 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.641 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.673 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.707 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.739 livekit-client.e2ee.worker.mjs:1166 enqueue SIF {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.783 livekit-client.esm.mjs:20549 update publication info {trackID: 'TR_AM6Y2ejf9RMTfV', enabled: true, muted: false, trackInfo: {…}, info: ZFe.s}
06:15:26.783 livekit-client.esm.mjs:20549 update publication info {trackID: 'TR_VCFRo2zWvksxuw', enabled: true, muted: false, trackInfo: {…}, info: ZFe.s}
06:15:26.783 livekit-client.esm.mjs:20549 update publication info {trackID: 'TR_VScqUdXi2jor7A', enabled: true, muted: false, trackInfo: {…}, info: ZFe.s}
06:15:26.784 livekit-client.esm.mjs:23960 room event trackUnsubscribed {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackUnsubscribed', …}
06:15:26.784 livekit-client.esm.mjs:23960 room event trackSubscriptionStatusChanged {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackSubscriptionStatusChanged', …}
06:15:26.784 livekit-client.e2ee.worker.mjs:1010 unsetting participant {participant: '@shq9agyxow:matrix.meedio.pro:DFLHOQSHFI', mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.784 livekit-client.esm.mjs:23960 room event trackUnpublished {room: '!ydFiczgktCZrUaMDUK:matrix.meedio.pro', roomID: 'RM_2JyNYg9KrVAS', participant: '@pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL', pID: 'PA_ftdYYjJBuYgL', event: 'trackUnpublished', …}
06:15:26.830 livekit-client.e2ee.worker.mjs:1161 skipping empty frame {participant: undefined, mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.841 livekit-client.e2ee.worker.mjs:1161 skipping empty frame {participant: undefined, mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:26.958 livekit-client.e2ee.worker.mjs:1161 skipping empty frame {participant: undefined, mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:27.059 livekit-client.e2ee.worker.mjs:1161 skipping empty frame {participant: undefined, mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
06:15:27.080 livekit-client.e2ee.worker.mjs:1161 skipping empty frame {participant: undefined, mediaTrackId: 'TR_VScqUdXi2jor7A', fallbackCodec: 'vp8'}
Did the e2ee display for paulius and dooman break only of one participant? And if so, is that participant @shq9agyxow:matrix.meedio.pro:DFLHOQSHFI for paulius and @red-similar-barracuda:matrix.meedio.pro:LDYGUMTRTH for dooman?
Paulius : @pink-careful-anglerfish:matrix.meedio.pro:TDZFDRTEXL K6admin(dooman): @shq9agyxow:matrix.meedio.pro:DFLHOQSHFI Ovi: @pink-preliminary-flea:matrix.meedio.pro:MREMYMAADW svajunas: @copper-condemned-locust:matrix.meedio.pro:PJASLXOGVM ignas: @7z74jll4pc:matrix.meedio.pro:PRTXHSDUYQ auri: @red-similar-barracuda:matrix.meedio.pro:LDYGUMTRTH
not 100% that only 1 participant broke, as some tiles had their video feeds muted. But can confirm that this participant(dooman) @shq9agyxow:matrix.meedio.pro:DFLHOQSHFI broke for paulius
got it, I added some sanity checks and some logs specifically to give more insight for this issue in https://github.com/livekit/client-sdk-js/pull/1082.
Hi, @lukasIO, do you need more tests for this?
Yeah, we still weren't able to repro this. If you can repro with the changes from #1082 (they're released in the latest client version) we would get more info on what's going on. Sorry for this dragging on for so long, but it's really tricky to debug without a way to repro it on our side.
Client version: 2.0.10
Participant ids: Svajunas @gxhiwckl6j:matrix.meedio.pro:JXLGKHKYKW Aurimas @black-supposed-prawn:matrix.meedio.pro Ignas @7z74jll4pc:matrix.meedio.pro:DNDMIYKWMH Ovidijus @7g5tcf49w7:matrix.meedio.pro:DNLNWJCDXZ Paulius @cyan-unsightly-walrus:matrix.meedio.pro
Logs (e2ee for screenshare tile breaks at ~12:39:38): svajunas-broken.log aurimas.log ovidijus.log paulius.log Ignasp.log
Video (Ignas): https://we.tl/t-jdcjlnnMEu
@revertiz thank you, that's helpful. Some of the logs are unfortunately truncated due to the browsers log export function. Do you happen to have server logs for this session, too? You can also share them with me on the LiveKit community slack in a PM.
Sent you over PM in slack