livekit / client-sdk-swift

LiveKit Swift Client SDK. Easily build live audio or video experiences into your mobile app, game or website.
https://livekit.io
Apache License 2.0
174 stars 84 forks source link

VideoView sporadically shows nothing #353

Open bombruch opened 4 months ago

bombruch commented 4 months ago

Describe the bug VideoView sporadically shows nothing after track is set. In order to minimise explanation this bug is reproduced and reported based on minimal UIKit example. But I also reproduce it for local track but within flip animation when camera is switched. So seems like issue not due to CollectionView.reloadData(). Reproduction is very sporadic. Sometimes it can be stable as rock, sometimes it shows empty VideoView after a few reloadData calls.

SDK Version 1.1.6

iOS/macOS Version iPhone SE 2 gen, iOS 15.5

Steps to Reproduce 1) Download minimal UIKit example (https://github.com/livekit-examples/swift-example-collection) 2) Switch to commit aa4cb2c (before LiveKit 2.x.x). (can be found in attached screenshots) 3) Update Livekit to 1.1.6 instead of 0.9.13 (can be found in attached screenshots) 4) Update server and token (can be found in attached screenshots) 5) Update bundleID so app can run on your device (can be found in attached screenshots) 6) Compile and run app 7) Do some taps on cell and/or do some taps on shuffle button and get empty VideoView (step can be found in attached video)

Expected behavior VideoView should show video track

Screenshots

Screenshot 2024-03-07 at 17 09 45 Screenshot 2024-03-07 at 17 10 03 Screenshot 2024-03-07 at 17 10 10

https://github.com/livekit/client-sdk-swift/assets/135046095/678e3027-8226-4680-a323-77f979e0d614

Logs

logs_without_server.txt

hiroshihorie commented 4 months ago

This is in v1.1.6 ? Can you make sure all access to the VideoView is from the main thread ?

bombruch commented 3 months ago

This is in v1.1.6 ?

As far as I can use Xcode and SPM I'd say it is 1.1.6. Logs that I've attached earlier also have line:

2024-03-07T17:05:59+0300 debug LiveKitSDK : [LiveKit] Engine.init(connectOptions:) sdk: 1.1.6, os: iOS(15.5), modelId: iPhone8,4

So seems like yes - it is 1.1.6

Can you make sure all access to the VideoView is from the main thread ?

As for my current project that tries to use LiveKit as a solution to organise Video calls so I can't be sure for 100% as there are many abstraction layers. But minimal example seems to be pretty easy and seems to have access from main thread. Anyway let's go from different side - let's explicitly use background thread and see if something happens. So I changed setFirstVideoTrack to something like:

private func setFirstVideoTrack() {
   DispatchQueue.global(qos: .background).async {
       let track = self.participant?.videoTracks.first?.track as? VideoTrack
       self.videoView.track = track
   }
}

I am a bit confused but it works. I haven't tired to reproduce the issue but tapping on shuffle button or on cell itself still OK. I even set breakpoint and got clarification that self.videoView.track = track was executed from background. Also I slightly dived into track setter and seems like it is executed via _state.mutate and it inside has lock but found no main thread dispatch.

After a careful eyeballing initial logs I found 2 lines that look suspicious to me. Line 608 or thereabout:

2024-03-07T17:06:22+0300 debug LiveKitSDK : [LiveKit] RemoteTrackPublication.onAdaptiveStreamTimer() [adaptiveStream] disabling sid: TR_VCYTsCdRLAHHwh, videoRenderersCount: 0, 
2024-03-07T17:06:22+0300 debug LiveKitSDK : [LiveKit] RemoteTrackPublication.onAdaptiveStreamTimer() VideoTrack.shouldReceive: false

Attaching one more log. Same steps - tap on cell or on shuffle button. To make it more obvious I killed app after I got grey video view. So it is easier to extract logs with issue.

002_adaptive_noo_serrver.txt

Line 461 or thereabout also contains suspicious [adaptiveStream] disabling sid. Adding abstract here with extra !!!! to point this 2 suspicious lines:

numberOfItemsInSection...
sizeForItemAt...
prepareForReuse, cellId: 1
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] VideoView.init(frame:) isRendering true -> false
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<VideoViewDelegate>.notify(label:_:) [notify] videoView.didUpdate isRendering: false
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] VideoView.createNativeRendererView(for:) Using RTCMTLVideoView for VideoView's Renderer
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] VideoView.createNativeRendererView(for:) preferredFramesPerSecond = 60
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] VideoView.init(frame:) rendering cached frame tack: TR_VCkYAZTEF4Z9FE
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<TrackDelegate>.notify(label:_:) [notify] track.didAttach videoView: <LiveKit.VideoView: 0x105d2f8d0; frame = (0 0; 160 160); clipsToBounds = YES; layer = <CALayer: 0x281bcb9a0>>
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] VideoView.init(frame:) removing nativeRenderer
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<TrackDelegate>.notify(label:_:) [notify] track.didDetach videoView: <LiveKit.VideoView: 0x105d2f8d0; frame = (0 0; 160 160); clipsToBounds = YES; layer = <CALayer: 0x281bcb9a0>>
!!!!!!    
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] RemoteTrackPublication.onAdaptiveStreamTimer() [adaptiveStream] disabling sid: TR_VCkYAZTEF4Z9FE, videoRenderersCount: 0, 
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] RemoteTrackPublication.onAdaptiveStreamTimer() VideoTrack.shouldReceive: false
!!!!!!
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] RemoteTrackPublication.send(trackSettings:) [adaptiveStream] sending TrackSettings(enabled: false, dimensions: Dimensions(0x0), videoQuality: low), sid: TR_VCkYAZTEF4Z9FE
2024-03-10T21:40:27+0300 debug LiveKitSDK : [LiveKit] SignalClient.sendUpdateTrackSettings(sid:settings:) sending track settings... sid: TR_VCkYAZTEF4Z9FE, settings: TrackSettings(enabled: false, dimensions: Dimensions(0x0), videoQuality: low)
2024-03-10T21:40:28+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<RoomDelegateObjC>.notify(label:_:) [notify] room.didReceive data: 0 bytes
2024-03-10T21:40:28+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<ParticipantDelegate>.notify(label:_:) [notify] participant.didReceive data: 0 bytes
2024-03-10T21:40:28+0300 debug LiveKitSDK : [LiveKit] VideoView.init(frame:) isRendering true -> false
2024-03-10T21:40:28+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<VideoViewDelegate>.notify(label:_:) [notify] videoView.didUpdate isRendering: false
2024-03-10T21:40:29+0300 debug LiveKitSDK : [LiveKit] MulticastDelegate<RoomDelegateObjC>.notify(label:_:) [notify] room.didReceive data: 0 bytes
2024-03-10T21:40:29
hiroshihorie commented 1 month ago

Hello, thanks for the hints. Do you still see this issue with v2 ?

bombruch commented 1 month ago

Alas haven't moved to v2. Still using v1.1.6.

Yabby1997 commented 2 weeks ago

Hi @hiroshihorie , I'm having similar issue on 2.0.7. Occasionally nothing redered on VideoView for remote participants. @bombruch 's work-around actually resolves this issue for me too.

This doesn't work

func room(_ room: Room, participant: RemoteParticipant, didSubscribeTrack publication: RemoteTrackPublication) {
    guard let videoTrack = publication.track as? RemoteVideoTrack  else { return }
    DispatchQueue.main.async { [weak self] in
        let videoView = VideoView()
        // setting remote participant's video track on main thread
        videoView.track = videoTrack

        ....

    }
}

but this works.

func room(_ room: Room, participant: RemoteParticipant, didSubscribeTrack publication: RemoteTrackPublication) {
    guard let videoTrack = publication.track as? RemoteVideoTrack  else { return }
    DispatchQueue.main.async { [weak self] in
        let videoView = VideoView()
        // setting remote participant's video track on background thread
        DispatchQueue.global().async { 
            videoView.track = videoTrack 
        }

        ....

    }
}

Interestingly, LocalParticipant's track is OK within main thread like below:

func room(_ room: Room, participant: LocalParticipant, didPublishTrack publication: LocalTrackPublication) {
    guard let videoTrack = publication.track as? LocalVideoTrack else { return }
    Task { 
        await MainActor.run { [weak self] in
            let videoView = VideoView()
            // setting local participant's video track on main thread
            videoView.track = videoTrack

            ....

        }
    }
}

Please take a look. Thank you.

hiroshihorie commented 2 weeks ago

Thanks @Yabby1997 for the detailed report, this is interesting and odd... I've noticed you let videoView = VideoView() in the delegate, can you initialize VideoView somewhere else (but main thread) and try again ?