search

twilio / video-quickstart-ios

Twilio Video Quickstart for iOS
https://www.twilio.com/docs/api/video
MIT License
457 stars 177 forks source link

iOS - Camera Source not resumed due to `videoDeviceInUseByAnotherClient` when app moves from Background to Foreground #597

Closed tuando3i closed 3 years ago

tuando3i commented 3 years ago

Description

In my application, before starting Twilio call, there is one screen to preview user's background. In there the app shows a camera preview, we use AVCaptureSession here. The AVCaptureSession is stopped whenever the view disappear.

After that user starts Twilio call, if user moves the app to background CameraSourceDelegate::cameraSourceWasInterrupted fires with reason: videoDeviceNotAvailableInBackground which is normal.

But then when app returns to Foreground, CameraSourceDelegate::cameraSourceWasInterrupted fires one more time with reason: videoDeviceInUseByAnotherClient, no new frame emit, the receiver doesn't receive video any more

Steps to Reproduce

  1. Start a View Controller with AVCaptureSession, start session when view appear and stop session when view disappear.
  2. Start Twilio Call
  3. Moves app to background
  4. Moves app to foreground

Expected Behavior

Twilio call should continue as normal

Actual Behavior

Black preview, no new video frame arrive to receiver side

Reproduces How Often

Sometimes it work, sometimes doesn't work. About 80% doesn't work

Logs

// Log output when the issue occurs

2021-03-30 10:51:51.707594+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Rendering inactive scene at 30 fps. 2021-03-30 10:51:51.707888+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Rendering inactive scene at 30 fps. 2021-03-30 10:51:51.849696+0900 [4453:395365] INFO:Twilio:Platform: AVCaptureSession interrupted with reason: 1 2021-03-30 10:51:51.849931+0900 [4453:395365] INFO:Twilio:Platform: ... Capture pipeline did stop. 2021-03-30 10:51:51.850061+0900 [4453:395365] DEBUG:Twilio:Platform: Teardown video output pipeline ... 2021-03-30 10:51:51.850427+0900 [4453:395365] DEBUG:Twilio:Platform: Finished video output pipeline teardown. 2021-03-30 10:51:51.850560+0900 [4453:395365] DEBUG:Twilio:Platform: Video pipeline did finish running 2021-03-30 10:51:51.942642+0900 [4453:395212] INFO:Twilio:Platform: AVCaptureSession interrupted with reason: 1 2021-03-30 10:51:51.942815+0900 [4453:395212] INFO:Twilio:Platform: ... Capture pipeline did stop. 2021-03-30 10:51:51.942931+0900 [4453:395212] DEBUG:Twilio:Platform: Teardown video output pipeline ... 2021-03-30 10:51:51.943235+0900 [4453:395212] DEBUG:Twilio:Platform: Finished video output pipeline teardown. 2021-03-30 10:51:51.943349+0900 [4453:395212] DEBUG:Twilio:Platform: Video pipeline did finish running [DEBUG CAMERA] interrupted: 1 2021-03-30 10:51:51.943612+0900 [4453:395212] INFO:Twilio:Platform: AVCaptureSession stopped running 2021-03-30 10:51:51.943675+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call setEnabled 2021-03-30 10:51:51.944894+0900 [4453:395608] DEBUG:Twilio:[Core](MediaFactoryImpl::signaling 0x0x28108c930): API Call isEnabled 2021-03-30 10:51:51.945105+0900 [4453:395608] DEBUG:Twilio:[Core](MediaFactoryImpl::signaling 0x0x28108c930): API Call getTrackId 2021-03-30 10:51:51.945209+0900 [4453:395608] DEBUG:Twilio:[Core](MediaFactoryImpl::signaling 0x0x28108c930): API Call getTrackId 2021-03-30 10:51:51.945438+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call isEnabled 2021-03-30 10:51:51.945716+0900 [4453:395211] DEBUG:Twilio:Core: API Call getTrackId 2021-03-30 10:51:51.945957+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call getWebRtcTrack 2021-03-30 10:51:51.946113+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call getWebRtcTrack 2021-03-30 10:51:52.660685+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Scene did enter background. Pausing rendering. 2021-03-30 10:51:52.660990+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Scene did enter background. Pausing rendering. 2021-03-30 10:51:53.447124+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Application will enter foreground. 2021-03-30 10:51:53.447295+0900 [4453:394988] INFO:Twilio:[Platform](Thread 0x0x10d63f3f0): Manually restarting interrupted session. 2021-03-30 10:51:53.455571+0900 [4453:395521] [connection] nw_read_request_report [C11] Receive failed with error "Software caused connection abort" 2021-03-30 10:51:53.455945+0900 [4453:395521] [connection] nw_read_request_report [C5] Receive failed with error "Software caused connection abort" 2021-03-30 10:51:53.456744+0900 [4453:395521] [connection] nw_read_request_report [C6] Receive failed with error "Software caused connection abort" 2021-03-30 10:51:53.460394+0900 [4453:395521] Connection 10: received failure notification 2021-03-30 10:51:53.460537+0900 [4453:395521] [connection] nw_flow_add_write_request [C10.1 54.230.62.58:443 failed channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, dns)] cannot accept write requests 2021-03-30 10:51:53.460640+0900 [4453:395521] [connection] nw_write_request_report [C10] Send failed with error "Socket is not connected" 2021-03-30 10:51:53.462231+0900 [4453:395521] Connection 9: received failure notification 2021-03-30 10:51:53.462339+0900 [4453:395521] [connection] nw_flow_add_write_request [C9.1 204.12.208.124:443 failed channel-flow (satisfied (Path is satisfied), viable, interface: en0, ipv4, dns)] cannot accept write requests 2021-03-30 10:51:53.462426+0900 [4453:395521] [connection] nw_write_request_report [C9] Send failed with error "Socket is not connected" 2021-03-30 10:51:53.463120+0900 [4453:395521] Task .<3> HTTP load failed, 1959/0 bytes (error code: -1005 [1:53]) 2021-03-30 10:51:53.468431+0900 [4453:395742] Task .<3> finished with error [-1005] Error Domain=NSURLErrorDomain Code=-1005 "The network connection was lost." UserInfo={_kCFStreamErrorCodeKey=53, NSUnderlyingError=0x2834de070 {Error Domain=kCFErrorDomainCFNetwork Code=-1005 "(null)" UserInfo={NSErrorPeerAddressKey=<CFData 0x2818c58b0 [0x1d2679b20]>{length = 16, capacity = 16, bytes = 0x100201bb6bb2f09f0000000000000000}, _kCFStreamErrorCodeKey=53, _kCFStreamErrorDomainKey=1}}, _NSURLErrorFailingURLSessionTaskErrorKey=LocalDataTask .<3>, _NSURLErrorRelatedURLSessionTaskErrorKey=( "LocalDataTask .<3>" ), NSLocalizedDescription=The network connection was lost., NSErrorFailingURLStringKey=https://api.mixpanel.com/track/, NSErrorFailingURLKey=https://api.mixpanel.com/track/, _kCFStreamErrorDomainKey=1} 2021-03-30 10:51:53.778941+0900 [4453:395523] INFO:Twilio:Platform: AVCaptureSession interrupted with reason: 3 2021-03-30 10:51:53.779518+0900 [4453:395523] INFO:Twilio:Platform: ... Capture pipeline did stop. 2021-03-30 10:51:53.780040+0900 [4453:395523] DEBUG:Twilio:Platform: Teardown video output pipeline ... 2021-03-30 10:51:53.782112+0900 [4453:395523] DEBUG:Twilio:Platform: Finished video output pipeline teardown. 2021-03-30 10:51:53.782463+0900 [4453:395523] DEBUG:Twilio:Platform: Video pipeline did finish running 2021-03-30 10:51:53.783228+0900 [4453:395523] DEBUG:Twilio:Platform: Interruption is not recoverable, will not attempt to resume. 2021-03-30 10:51:53.831974+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Application will enter foreground. 2021-03-30 10:51:53.832168+0900 [4453:395211] INFO:Twilio:Platform: AVCaptureSession interruption ended 2021-03-30 10:51:53.832369+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): No manual restart of the session required. 2021-03-30 10:51:53.832710+0900 [4453:395211] INFO:Twilio:Platform: Best device format was: <AVCaptureDeviceFormat: 0x2839e71e0 'vide'/'420f' 960x 540, { 2- 30 fps}, HRSI:3840x2160, fov:67.564, max zoom:135.00 (upscales @4.00), ISO:19.0-1824.0, SS:0.000013-0.500000, supports wide color> 2021-03-30 10:51:53.833959+0900 [4453:395211] INFO:Twilio:Platform: AVCaptureSession started running [DEBUG CAMERA] interrupted: 3 2021-03-30 10:51:53.853482+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call setEnabled 2021-03-30 10:51:53.855964+0900 [4453:394988] DEBUG:Twilio:[Core](Thread 0x0x10d63f3f0): API Call isEnabled 2021-03-30 10:51:53.862230+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Rendering active scene at 60 fps. 2021-03-30 10:51:53.862431+0900 [4453:394988] DEBUG:Twilio:[Platform](Thread 0x0x10d63f3f0): Rendering active scene at 60 fps. 2021-03-30 10:51:53.935415+0900 [4453:395521] DEBUG:Twilio:Platform: Video device will start running: <AVCaptureFigVideoDevice: 0x10d645d50 [Front Camera][com.apple.avfoundation.avcapturedevice.built-in_video:1]>.

Versions

All relevant version information for the issue.

Video iOS SDK

4.3.0

Xcode

12.4

ceaglest commented 3 years ago

Hi @tuando3i,

Sorry for the late response. A good rule is to only have a single AVCaptureSession alive at a time and make sure there is no overlap.

  1. Start a View Controller with AVCaptureSession, start session when view appear and stop session when view disappear.
  2. Start Twilio Call

Are you sure that you are stopping the AVCaptureSession before step 2 where you create TVICameraSource? Stopping AVCaptureSession can take a long time and you should wait for it to complete. If not, in step 2 Twilio can interrupt your AVCaptureSession when it starts capturing video for the Room.

Logs

Can you include logs that show between steps 1 to 2, including logs from your use of AVCaptureSession?

Based on the later steps it looks like there are two instances of TVICameraSource in your app. Make sure to stop and destroy TVICameraSource when you are done with it, and don't overlap use with your own AVCaptureSession. Our example code shows one way to do this.

Best, Chris

tuando3i commented 3 years ago

It turns out that our application has a retain cycle bug which cause the Twilio AVCaptureSession not released. We fixed it then the app works well now. Thank you

paynerc commented 3 years ago

@tuando3i,

Thanks for letting us know you got it resolved. Let us know if you have any further questions.

Ryan