Stopping screen share sometimes breaks e2ee #973

revertiz · 2023-12-15T12:28:08Z

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/)

davidzhao · 2023-12-16T06:46:23Z

could you confirm if this still happens with the latest server? you are using 1.2.7, which is quite old

revertiz · 2023-12-18T08:54:03Z

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

arnasledev · 2023-12-20T13:25:43Z

up! this is important - any ideas whats happening?

devosonder · 2023-12-25T10:02:36Z

+1

davidzhao · 2023-12-26T02:04:12Z

This looks to be a bug with the JS client SDK. moving the issue there.

lukasIO · 2024-01-04T13:13:49Z

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?

raphaelluchini · 2024-01-18T23:17:02Z

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.

AurimasG12 · 2024-02-05T10:26:43Z

+1

lukasIO · 2024-02-05T12:40:43Z

@AurimasG12 do you have a way to reproduce this?

arnasledev · 2024-02-05T13:46:08Z

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

lukasIO · 2024-02-05T13:53:35Z

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

lukasIO · 2024-02-05T13:58:23Z

it would be really helpful if you could, in addition, set debug level also for the lk-e2ee logger with setLogLevel('debug', 'lk-e2ee')

revertiz · 2024-02-13T10:58:36Z

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

lukasIO · 2024-02-13T11:26:34Z

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?

lukasIO · 2024-02-13T11:44:12Z

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.

revertiz · 2024-02-13T14:59:21Z

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?

using ExternalE2EEKeyProvider from 'livekit-client'. We create Room instance and set the key (setKey) and E2EEEnabled (setE2EEEnabled(true)) immediately.

lukasIO · 2024-02-14T08:56:29Z

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 ?

revertiz · 2024-02-28T11:19:22Z

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

lukasIO · 2024-03-01T16:59:59Z

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".

revertiz · 2024-03-19T09:31:42Z

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

lukasIO · 2024-03-19T10:51:07Z

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'}

revertiz · 2024-03-19T18:19:14Z

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

lukasIO · 2024-03-20T12:48:13Z

got it, I added some sanity checks and some logs specifically to give more insight for this issue in #1082.

revertiz · 2024-04-02T08:40:49Z

Hi, @lukasIO, do you need more tests for this?

lukasIO · 2024-04-03T14:11:41Z

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.

revertiz · 2024-04-05T10:28:39Z

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

lukasIO · 2024-04-05T12:31:27Z

@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.

revertiz · 2024-04-08T08:22:22Z

Sent you over PM in slack

revertiz · 2024-05-10T07:56:32Z

Hey @lukasIO, any news on this?

lukasIO · 2024-05-13T09:16:04Z

Unfortunately no news yet.

Gulianrdgd · 2024-07-03T09:35:12Z

I don't know If this helps. You can delete otherwise. I am implementing my own video calling application. And I have found that the video stream works and i can see the camera stream in a <video> element. But when I right-click on it and press pause, wait a bit and then press play again. I also get this behavior.

No decryption error in the logs. (with setLogLevel('debug', 'lk-e2ee');)

revertiz changed the title ~~Stopping screen share sometimes break e2ee~~ Stopping screen share sometimes breaks e2ee Dec 15, 2023

davidzhao transferred this issue from livekit/livekit Dec 26, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Stopping screen share sometimes breaks e2ee #973

Stopping screen share sometimes breaks e2ee #973

revertiz commented Dec 15, 2023 •

edited

Loading

davidzhao commented Dec 16, 2023

revertiz commented Dec 18, 2023

arnasledev commented Dec 20, 2023 •

edited

Loading

devosonder commented Dec 25, 2023

davidzhao commented Dec 26, 2023

lukasIO commented Jan 4, 2024

raphaelluchini commented Jan 18, 2024

AurimasG12 commented Feb 5, 2024

lukasIO commented Feb 5, 2024

arnasledev commented Feb 5, 2024

lukasIO commented Feb 5, 2024 •

edited

Loading

lukasIO commented Feb 5, 2024

revertiz commented Feb 13, 2024

lukasIO commented Feb 13, 2024

lukasIO commented Feb 13, 2024

revertiz commented Feb 13, 2024

lukasIO commented Feb 14, 2024

revertiz commented Feb 28, 2024

lukasIO commented Mar 1, 2024

revertiz commented Mar 19, 2024

lukasIO commented Mar 19, 2024 •

edited

Loading

revertiz commented Mar 19, 2024

lukasIO commented Mar 20, 2024

revertiz commented Apr 2, 2024

lukasIO commented Apr 3, 2024

revertiz commented Apr 5, 2024

lukasIO commented Apr 5, 2024

revertiz commented Apr 8, 2024

revertiz commented May 10, 2024

lukasIO commented May 13, 2024

Gulianrdgd commented Jul 3, 2024 •

edited

Loading

Stopping screen share sometimes breaks e2ee #973

Stopping screen share sometimes breaks e2ee #973

Comments

revertiz commented Dec 15, 2023 • edited Loading

davidzhao commented Dec 16, 2023

revertiz commented Dec 18, 2023

arnasledev commented Dec 20, 2023 • edited Loading

devosonder commented Dec 25, 2023

davidzhao commented Dec 26, 2023

lukasIO commented Jan 4, 2024

raphaelluchini commented Jan 18, 2024

AurimasG12 commented Feb 5, 2024

lukasIO commented Feb 5, 2024

arnasledev commented Feb 5, 2024

lukasIO commented Feb 5, 2024 • edited Loading

lukasIO commented Feb 5, 2024

revertiz commented Feb 13, 2024

lukasIO commented Feb 13, 2024

lukasIO commented Feb 13, 2024

revertiz commented Feb 13, 2024

lukasIO commented Feb 14, 2024

revertiz commented Feb 28, 2024

lukasIO commented Mar 1, 2024

revertiz commented Mar 19, 2024

lukasIO commented Mar 19, 2024 • edited Loading

revertiz commented Mar 19, 2024

lukasIO commented Mar 20, 2024

revertiz commented Apr 2, 2024

lukasIO commented Apr 3, 2024

revertiz commented Apr 5, 2024

lukasIO commented Apr 5, 2024

revertiz commented Apr 8, 2024

revertiz commented May 10, 2024

lukasIO commented May 13, 2024

Gulianrdgd commented Jul 3, 2024 • edited Loading

revertiz commented Dec 15, 2023 •

edited

Loading

arnasledev commented Dec 20, 2023 •

edited

Loading

lukasIO commented Feb 5, 2024 •

edited

Loading

lukasIO commented Mar 19, 2024 •

edited

Loading

Gulianrdgd commented Jul 3, 2024 •

edited

Loading