iOS 6 audio End Interruption fails to restore audio system
| Originator: | ewmailing | ||
| Number: | rdar://12373227 | Date Originated: | 2012-09-25 |
| Status: | Open | Resolved: | |
| Product: | iPhone / iPod touch | Product Version: | 6.0 (10A403) |
| Classification: | Serious Bug | Reproducible: | Sometimes |
25-Sep-2012 06:20 PM Eric Wing:
Summary:
In iOS 6, audio interruptions completely break my audio which require the app to be completely killed and restarted to get it back.
By Audio Interruptions, I mean things that actually trigger the official Audio Interruption callback in Core Audio, such as a phone call and Siri.
I'm with the Corona SDK and our users are starting to report that Siri and phone calls breaks audio in their apps. We have hundreds if not thousands of apps on the store now, and they are all affected so this is quite serious for us.
Our users just need to be using audio in some way, then bring up Siri. When Siri dismisses, usually (not always), audio in the app doesn't work anymore. We are using OpenAL so the problem may be specific to OpenAL and audio interruptions. I'm pretty sure our code is correct because we've dealt with this problem many times in the past and used to work.
Steps to Reproduce:
Attached is a sample program that can reproduce the problem. Build and run on an iOS 6 device that has Siri (iPad 3, iPhone 5).
You will hear a repeating laser sound. You can also press the button to fire additional lasers.
Bring up Siri which causes audio to pause.
Dismiss Siri.
Audio should return and the laser should keep blasting. You should be able to press the button to fire additional lasers.
(If audio works, keep repeating until it breaks.)
Expected Results:
After the Siri interruption, audio should continue to work as before.
Actual Results:
The app is completely silent. I am not getting any OpenAL errors.
Regression:
I'm pretty sure this worked in 5.1 and before though I haven't been able to reconfirm. But I have had lots of bugs related to audio interruptions and OpenAL; in fact I think it has been every iOS release.
I know my audio interruption code worked in 3.0, 3.1, 3.2. I recall something broke around 4.2 but I fixed it. I'm pretty sure I tested again in 4.3, 5.0, and 5.1 trying to work around a semi-related Notification Center bug where you leave the app via a notification in Notification Center and then return and audio doesn't restore. I think interruptions worked then because I retested with the alarm in Clock.app. This is the first time I've tested with Siri though.
Notes:
The app uses a preloaded audio file. I also tested streaming audio with OpenAL buffer streaming. It has the same problem.
I noticed that the sequence of events looked wrong from the callbacks in my debug output after calling Siri:
2012-09-25 17:38:26.747 OpenALStopStart[4264:907] applicationWillResignActive:
2012-09-25 17:38:26.761 OpenALStopStart[4264:907] beginInterruption
2012-09-25 17:38:26.767 OpenALStopStart[4264:907] beginning interruption
2012-09-25 17:38:27.634 OpenALStopStart[4264:907] Internal_InterruptionCallback: 1
2012-09-25 17:38:27.642 OpenALStopStart[4264:907] beginInterruption
2012-09-25 17:38:27.646 OpenALStopStart[4264:907] Already in interruption
2012-09-25 17:38:30.795 OpenALStopStart[4264:907] applicationDidBecomeActive:
2012-09-25 17:38:30.797 OpenALStopStart[4264:907] endInterruption
2012-09-25 17:38:30.799 OpenALStopStart[4264:907] ending interruption
AudioStreamBasicDescription: 2 ch, 44100 Hz, 'lpcm' (0x00000029) 32-bit little-endian float, deinterleaved
2012-09-25 17:38:33.338 OpenALStopStart[4264:907] Internal_InterruptionCallback: 1
2012-09-25 17:38:33.339 OpenALStopStart[4264:907] beginInterruption
2012-09-25 17:38:33.341 OpenALStopStart[4264:907] beginning interruption
2012-09-25 17:38:33.890 OpenALStopStart[4264:907] Internal_InterruptionCallback: 1
2012-09-25 17:38:33.893 OpenALStopStart[4264:907] beginInterruption
2012-09-25 17:38:33.897 OpenALStopStart[4264:907] Already in interruption
2012-09-25 17:39:06.558 OpenALStopStart[4264:907] Internal_InterruptionCallback: 0
2012-09-25 17:39:06.561 OpenALStopStart[4264:907] endInterruption
2012-09-25 17:39:06.563 OpenALStopStart[4264:907] ending interruption
This suggests to me that:
1) App Resigned Active (I suspend audio)
2) Get the Interruption callback (I do nothing because I already suspended audio)
I dismiss Siri
3) App Become Active (I resume audio)
4) Get the Interruption end callback (I do nothing because I already resumed audio)
5) ** Erroneously get 2 more BeginInterruption callbacks. (I now suspend audio when I shouldn't)
6) ** Eventually get an EndInterruption callback 30 seconds later. But audio still doesn't return because I think the audio system is hosed.
I filed bug 12022872 about the audio interruption API. Hitting this kind of bug AGAIN makes me think there is a problem with the API. Two things jumped out at me when dealing with this bug:
1) It's very difficult managing two different entry points for handling the audio system (interruptions and app delegate)
2) The Begin Interruptions come after the App Resign Active. Conversely, The App Becomes Active seems to come before the End Interruption. I think this call order is wrong/dangerous. I propose it should be:
Begin Interruption
App Resign Active
End Interruption
App Resume Active
The reason is I want to handle the audio system stuff in the audio handler, not the app delegate. From my other bugs, I learned from you guys that I need to treat app suspend/resume just like an Interruption (suspend OpenAL context). Because the Interruption API only calls me for very specific types of interruptions and not all of them, it is very complicated to manage the multiple entry points.
Furthermore, getting assurance that the audio system is handled before my app delegate stuff gives me assurances that I know the audio state. For end-interruption, the audio system is restored by the time my app resumes which is a good thing.
For begin-interruption, the problem is that since I have to handle both cases the same way, it seems more logical that the Begin Interruption is the "important one" I need to handle so it should come first. If you guys later tell me that they must be handled slightly differently, then I need the Begin Interruption first in order to not run my Resign Active code, otherwise it is already too late.
25-Sep-2012 06:20 PM Eric Wing:
'OpenALiOS6Siri.zip' was successfully uploaded
25-Sep-2012 07:16 PM Eric Wing:
In my test program, I added a usleep(1000*1000) at the top of my endInterruption. This seemed to work around the problem. But when I tried it in my real program, this didn't help. I'm hoping you might have some ideas on how I can work around the problem in for my real program.
- (void) endInterruption
{
NSLog(@"%@", NSStringFromSelector(_cmd));
if(true == [self isInInterruption])
{
NSLog(@"ending interruption");
usleep(1000*1000);
[self setAudioSessionActive:true];
ALmixer_EndInterruption();
[self setInInterruption:false];
ALmixer_ResumeChannel(-1);
}
else
{
NSLog(@"Already ended interruption");
}
}
25-Sep-2012 07:18 PM Eric Wing:
Forgot to mention, in the test app, I started seeing these Apple RemoteIO messages in the console after I added the sleep:
2012-09-25 18:29:53.812 OpenALStopStart[4416:907] applicationWillResignActive:
2012-09-25 18:29:53.814 OpenALStopStart[4416:907] beginInterruption
2012-09-25 18:29:53.817 OpenALStopStart[4416:907] beginning interruption2012-09-25 18:29:54.649 OpenALStopStart[4416:907] Internal_InterruptionCallback: 1
2012-09-25 18:29:54.650 OpenALStopStart[4416:1507] 18:29:54.650 <CAListenerProxy> shm_open failed: "AppleAURemoteIO.o.258d2" (23) flags=0x2 errno=2
2012-09-25 18:29:54.657 OpenALStopStart[4416:907] beginInterruption
2012-09-25 18:29:54.657 OpenALStopStart[4416:1507] 18:29:54.658 <CAListenerProxy> AURemoteIO::ChangeHardwareFormats: error 3
2012-09-25 18:29:54.658 OpenALStopStart[4416:907] Already in interruption
2012-09-25 18:29:55.589 OpenALStopStart[4416:907] applicationDidBecomeActive:
2012-09-25 18:29:55.593 OpenALStopStart[4416:907] endInterruption
2012-09-25 18:29:55.594 OpenALStopStart[4416:907] ending interruption
AudioStreamBasicDescription: 2 ch, 44100 Hz, 'lpcm' (0x00000029) 32-bit little-endian float, deinterleaved
(Test code uploaded at https://github.com/ewmailing/MyAppleBugs)
Comments
Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!