search

opentok / opentok-ios-sdk-samples-swift

Sample applications using the OpenTok iOS SDK in Swift
https://tokbox.com/
MIT License
137 stars 65 forks source link

iOS 16 "Timed out while attempting to publish." #183

Closed knightcode closed 1 year ago

knightcode commented 1 year ago

Prior to iOS 16, we were able to initiate and publish to a session in response to a PushKit notification, which elevated the app's priority and allowed a session to form while the app remained in the background, maybe with the system's Call UI visible to the user via CallKit (if audio-only).

With iOS 16, the OTPublisher seems to be having trouble. The OTSession can be created, incoming streams are announced, session.subscribe() is successful, and even session.publish() returns no error. But the OTPublisherDelegate.publisher(didFailWithError:) method is called after a few seconds with an undocumented code of 1541 and a message saying "Timed out while attempting to publish." The result is a state where the user can (see and) hear all the other participants, but they do not (see or) hear the iOS user.

There's no trouble if the session is initiated through the app's UI while the app is active.

There also seems to be a race condition somewhere in if the user can click through the CallKit UI fast enough to bring the app into the foreground before...something.. happens, publishing succeeds. We haven't determined what that something is.

Moreover, when it's on its way to timing out, someone's code is polluting the console with these errors, which seem germane to this issue:

App[13956:3993378] [aurioc]            AURemoteIO.cpp:1139  failed: 561017449 (enable 1, outf< 1 ch,      0 Hz, Float32> inf< 1 ch,  48000 Hz, Int16>)
App[13956:3993378] [aurioc]            AURemoteIO.cpp:1139  failed: 561017449 (enable 1, outf< 1 ch,      0 Hz, Float32> inf< 1 ch,  48000 Hz, Int16>)
App[13956:3993378] [aurioc]            AURemoteIO.cpp:1139  failed: 561017449 (enable 1, outf< 1 ch,      0 Hz, Float32> inf< 1 ch,  48000 Hz, Int16>)
App[13956:3993378] [aurioc]            AURemoteIO.cpp:1139  failed: 561017449 (enable 1, outf< 1 ch,      0 Hz, Float32> inf< 1 ch,  48000 Hz, Int16>)
App[13956:3993378] [aurioc]            AURemoteIO.cpp:1139  failed: 561017449 (enable 1, outf< 1 ch,      0 Hz, Float32> inf< 1 ch,  48000 Hz, Int16>)
...
App[14038:4007966] ERROR[OpenTok]:Audio device error: startCapture.AudioOutputUnitStart returned error: !pri

Also, we've experimented both with and without the recommended use of OTDefaultAudioDevice, which is initialized before the call to CXProvider.reportNewIncomingCall. No change.

IGitGotIt commented 1 year ago

Just so we narrow down the issue more, can you initialize the background publisher with audioTrack = false and check if you get the same error. If it works it can be an audio driver acquisition issue (maybe some other app is playing audio or CallKit itself is playing a ringtone/audio etc..). Thanks

knightcode commented 1 year ago

@IGitGotIt audioTrack = false seems to work. The session publishes, the same AURemoteIO.cpp lines print to the console. And, assuming you know this, but there doesn't seem to be any published sound even the OTPublisher.publishAudio is set to true after creation.

knightcode commented 1 year ago

Actually, I'm not able to publish audio at all... even when the app is active. The session connects; all parties can publish and receive video, but no audio is received from iOS devices. With the DefaultAudioDevice from the custom audio driver sample, we sometimes get a few moments of audio before it cuts out. Without setting a custom audio device, ...nothing.

I think this is separate from the timeout issue, though.

Also, the OTPublisher.init() is now hanging the main thread. Should that be created in the background?

Edit: The audio cuts out after CXProviderDelegate.provider(_:didActivate:AVAudioSession) is called by CallKit. I'm guessing the provided AVAudioSession is not the one set up by OTAudioDeviceManager.. ? ...this is needed even when the app is active so that the system knows a "call" is in progress and gracefully handles another phone call coming in.

the AVAudioSession passed to the CXProviderDelegate method is the same as returned by AVAudioSession.sharedInstance()

IGitGotIt commented 1 year ago

I recommended turning off audioTrack so we can narrow the issue and diagnose the problem. It was not a solution and yes, audio will not work . With the publisher now publishing, we can assume it was an audio driver acquisition problem originally.

My guess, w/o looking at your code , is that you need to activate the audio rendering and capturing whenever your logic/flow dictates. Till then the audio drivers will be in a passive mode. We have an ObjC sample app , which serializes audio driver acquisition, while a ringtone plays first. Maybe you need to implement something similar to it .

knightcode commented 1 year ago

Oh, to clarify, the audio would cease with audioTrack=true. CallKit seemed to be doing something. A route change coincides with the didActivate call.

knightcode commented 1 year ago

Both our use cases are currently broken. These are the steps we perform for each

PushKit Initiated

  1. Receive Notification
  2. Call OTAudioDeviceManager.setAudioDevice(audioController!) setting to an instance of DefaultAudioDevice from this repo
  3. Call CXProvider.reportNewIncomingCall()
  4. User Accepts Call, reported by CXProviderDelegate.provider(_, perform: CXAnswerCallAction)
  5. Call DefaultAudioDevice.startCapture()
  6. Create publisher: OTPublisher(delegate:settings:), videoTrack=true and audioTrack=true
  7. Set OTPublisher.publishVideo=false, OTPublisher.publishAudio=true
  8. Create session: OTSession(apiKey:sessionId:delegate)
  9. Call OTSession.connect()
  10. Wait for sessionDidConnect() callback, then
  11. Call OTSession.publish()
  12. Receive session(_:streamCreated:OTStream) as usual
  13. Eventually receive publisher(_:didFailWithError:OTError) with the timeout
  14. Call action.fail() on the CXAnswerCallAction from step 4 because of the timeout (would call action.fulfill() on successful publish).

User Initiated

  1. Create publisher: OTPublisher(delegate:settings:), videoTrack=true and audioTrack=true (we offer a selfie preview to the user before they join a session)
  2. Set OTPublisher.publishVideo=true, OTPublisher.publishAudio=true
  3. Call OTAudioDeviceManager.setAudioDevice(audioController!) setting to an instance of DefaultAudioDevice from this repo
  4. Create session: OTSession(apiKey:sessionId:delegate)
  5. Call OTSession.connect()
  6. Wait for sessionDidConnect() callback, then
  7. Call OTSession.publish()
  8. Receive session(_:streamCreated:OTStream), hold on subscribing until publish succeeds
  9. Eventually receive publisher(_:didFailWithError:OTError) with the timeout

At other times, the publishing would succeed for the User Initiated flow, but only a few moments of audio would publish before the outgoing stream went silent. In that case, we would do the following:

  1. Wait for publish success: publisher(_:streamCreated:OTStream)
  2. Call DefaultAudioDevice.startCapture()
  3. Create CXStartCallAction transaction for CXCallController. The system knows we're in a call now.
  4. Subscribe to all held streams
  5. Log a few called to DefaultAudioDevice.recordCb
  6. Log a last call to DefaultAudioDevice.onRouteChangeEvent before calls to recordCb stopped.
knightcode commented 1 year ago

Seeing this error now:

ERROR[OpenTok]:Audio device error: startCapture.AudioOutputUnitStart returned error: what

By removing any use of the DefaultAudioDevice and the CXCallController, I was able to make the User Initiated flow above work on a second device, but not my primary phone. Reintroducing the DefaultAudioDevice still allowed the second device to work, but the primary device still timed out publishing. Adding back the calls for CXCallController, the secondary device would publish audio for a few moments and then go silent after the CXCallController did its thing and fired its didActivate:AVAudioSession callback in response to the CXStartCallAction described above. The primary device again had no change.

DefaultAudioDevice fails at startCapture(). It gets an error result from AudioOutputUnitStart, which doesn't always coincide with the error message listed at the top of this post. That message is absent.

knightcode commented 1 year ago

Error in DefaultAudioDevice.setupAudioSession() during PushKit flow:

Error setting up audio session Error Domain=NSOSStatusErrorDomain Code=561017449 "Session activation failed" UserInfo={NSLocalizedDescription=Session activation failed}

It fails at the try session.setActive(true) call.

knightcode commented 1 year ago

Found a possible solution/work-around the User Initiated Flow. The startCapture() method of DefaultAudioDevice is called automatically by the OpenTok SDK. I'm not sure where. The backtrace just had it on the WebRTCThread, so that I'm not sure what queued it. In any case, by making this a no-op, I was able to call it manually in the CXProviderDelegate.provider(_:didActivate:AVAudioSession) callback. This, btw, was how my DefaultAudioDevice was already set up, only it was calling startCapture(), which I guess had already been called earlier. So I'm guessing the latest update changed that behavior.

Still having an issue with the PushKit Initiated flow.

knightcode commented 1 year ago

Found some better behavior with the PushKit flow by moving the action.fulfill() earlier in the flow when the sessionDidConnect() callback. Fulfilling the action lets CallKit proceed to calling CXProviderDelegate.provider(_:didActivate:AVAudioSession), and that's when the audio can be set up, session.publish(), and any outstanding streams can be subscribed to.

With this, the printed errors are reduced to:

2022-11-09 17:48:57.609935-0500 WorkBeta[18066:2488628] [as] ATAudioSessionPropertyManager.mm:89    Error 2003329396 while getting property value from AVAudioSession

CoreAudio repeatedly triggers recordCb and renderCb for 15 seconds, and then the publishing timeout error still occurs.

knightcode commented 1 year ago

The next question, which I can't answer, is why would the publisher time out even if recordCb is writing data to the OTAudioBus?

knightcode commented 1 year ago

Working Flows for anyone who might come across this in the future.

One change to DefaultAudioDevice: remove AVAudioSession.sharedInstance().setActive(true) from setupAudioSession(). This is handled by CallKit. I reverted the change discussed above that moved the startCapture() functionality to a different function. By holding all publish and subscribe calls, we can, in turn, hold off on the SDK from calling startCapture(). The custom audio driver is also necessary to be able to call to setupAudioSession() earlier than session.publish() would, specifically in the CXProviderDelegate callback.

User Initiated Flow (Outgoing call)

  1. Call OTAudioDeviceManager.setAudioDevice(audioController!) setting to an instance of DefaultAudioDevice
  2. Create publisher: OTPublisher(delegate:settings:), videoTrack=true and audioTrack=true
  3. Set OTPublisher.publishVideo=true, OTPublisher.publishAudio=true
  4. Create session: OTSession(apiKey:sessionId:delegate)
  5. Call OTSession.connect()
  6. Wait for sessionDidConnect() callback, then
  7. Receive session(_:streamCreated:OTStream), hold on subscribing until publish succeeds
  8. Call DefaultAudioDevice.setupAudioSession()
  9. Create and send CXStartCallAction transaction for CXCallController.
  10. Wait for CXProviderDelegate.provider(_:didActivate:AVAudioSession), then
  11. Finally Call OTSession.publish()
  12. Wait for publish success: publisher(_:streamCreated:OTStream), then
  13. Subscribe to all held streams

PushKit Flow (Incoming Call)

  1. Receive Notification
  2. Call OTAudioDeviceManager.setAudioDevice(audioController!) setting to an instance of DefaultAudioDevice
  3. Call CXProvider.reportNewIncomingCall()
  4. User Accepts Call, reported by CXProviderDelegate.provider(_, perform: CXAnswerCallAction)
  5. Call DefaultAudioDevice.setupAudioSession()
  6. Create publisher: OTPublisher(delegate:settings:)
  7. Set OTPublisher.publishVideo=false, OTPublisher.publishAudio=true
  8. Create session: OTSession(apiKey:sessionId:delegate)
  9. Call OTSession.connect()
  10. Wait for sessionDidConnect() callback, then
  11. Receive session(_:streamCreated:OTStream) as usual, queue streams for later subscription
  12. Call action.fulfill() on earlier CXAnswerCallAction
  13. Wait for CXProviderDelegate.provider(_:didActivate:AVAudioSession), then
  14. Call OTSession.publish()
  15. Wait for publish success: publisher(_:streamCreated:OTStream), then
  16. Subscribe to all held streams

The downside of this is that the system's calling UI (used when you don't unlock the phone) moves from a "connecting" state to a "in progress" state with the upwardly counting timer as soon as action.fulfill() is called, but no streams are published or subscribed at that moment. So there's a few moments silence when the user expects to be able to start talking.

Leaving this open so that the dev's still address the timeout I was getting before.

v-kpheng commented 1 year ago

Any ideas, @IGitGotIt?

hieultse03355 commented 1 year ago

I got this issue also. I am using tokbox version 2.18.1. Any ideas about this. Please

IGitGotIt commented 1 year ago

Publisher timeout can happen for many reason - access to camera , microphone, networking issues, no media (video/audio) frames received on the peer connection and CallKit delays . I am assuming you are seeing this issue on using CallKit , if so can you please try our sample app and check if the issue persists there.
https://github.com/opentok/opentok-ios-sdk-samples-swift/tree/main/CallKit

Also iOS version of 2.18 is no longer supported , please use the latest one - 2.25 or 2.24

Thanks

hieultse03355 commented 1 year ago

I got it. So when Publisher timeout then I can re-doPublish it again until it can be published? @IGitGotIt Thank you so much

IGitGotIt commented 1 year ago

I got it. So when Publisher timeout then I can re-doPublish it again until it can be published? @IGitGotIt Thank you so much

Yes that would be the suggested way. You can republish , and again after 2 seconds or so, if it failed on the first retry. If it still does not work , on a regular basis, there is something inherently wrong in the app code.

The retry typically helps if it was a network issue or some device media lock on audio/camera working it way out. Else not.