Open Radar

 
06-Sep-2011 04:02 PM Eric Wing:
'OpenALSuspendResume.zip' was successfully uploaded

06-Sep-2011 04:02 PM Eric Wing:
Summary:

I believe I have found a race condition in the OpenAL implementation with respect to pausing and resuming 
(playing) on a source. This seems to occur for me when I am dealing with an application suspend and resume on iOS. This is what I do:

On App Suspend:
1) I pause my playing OpenAL source
2) I set the current OpenAL context to NULL
3) I set the audio session to inactive

On App Resume
1) I set the audio session to active
2) I make the OpenAL context current
3) I resume playing my OpenAL source

Sometimes, my source does not resume playing. I get no OpenAL errors. I discovered that when I check the OpenAL state right after I resume it, the source claims it is playing. But in the case where the source fails to play even though the OpenAL state says it was playing, if I check the OpenAL state again a few seconds later, it says it is paused.

This suggests there is some kind of race condition or internal bug that is ignoring or resetting my paused state.

With some additional experimentation, I disabled the code that set the current context to NULL and back. When I do this, I can not reproduce this problem. However, I don't consider this a workaround because I also use this suspend/resume code for handling audio interruption events. So this race condition must get fixed because setting/restoring the OpenAL context is required to properly handle interruption events.


Steps to Reproduce:
Attached is a simple sample project that isolates the the problem. It uses my open source ALmixer which wraps OpenAL to make playback a little easier to setup in less code. Ultimately, the ALmixer_PauseChannel and ALmixer_ResumeChannel just call alSourcePause and alSourcePlay. Don't let the scary code fool you. This particular case is not complex, and you probably don't need to worry too much about scrutinizing this code.

I added some addition printf statements in ALmixer for checking the pause and resume-playing states. The specific lines of the most interest are around 2842 in ALmixer.c:

				alGetSourcei(
							 ALmixer_Channel_List[channel].alsource,
							 AL_SOURCE_STATE, &state
							 );
				if(state != AL_PAUSED)
				{
					fprintf(stderr, "Internal_PauseChannel assertion failed: not paused %x, source=%d\n", state, ALmixer_Channel_List[channel].alsource);
					
				}
				else
				{
					fprintf(stderr, "Internal_ResumeChannel assertion passed: paused %x, source=%d\n", state, ALmixer_Channel_List[channel].alsource);
					
				}

The assertion always passes for me. So to catch the bad race condition, I added additional code in AppDelegate.m in:
- (void)applicationDidBecomeActive:(UIApplication *)application

After I resume everything, I schedule a callback function to fire in 2 seconds:
	[self performSelector:@selector(checkSourceState:) withObject:nil afterDelay:2];

The code checks the state one more time and prints the result:

- (void) checkSourceState:(id)object
{
	ALint source_state = 0;
	alGetSourcei(ALmixer_GetSource(0), AL_SOURCE_STATE, &source_state);
	if(AL_PLAYING != source_state)
	{
		NSLog(@"Assertion failure in checkSourceState. Should be AL_PLAYING, but is %x", source_state);
	}
	else
	{
		NSLog(@"checkSourceState passed; is AL_PLAYING, %x", source_state);		
	}
}

So to reproduce, build and run the app. (Make sure the application does not exit on suspend in the Info.plist.) Keep suspending and resuming the app. Watch the console and wait for the debugging messages to fire after the 2 second period. When the audio finally fails to come back, when the 2 second callback fires, you should see the assertion failure message. I usually only need to suspend and resume 2-5 times before I encounter this problem.


My failure log output looks like:
2011-09-06 14:10:01.862 OpenALSuspendResume[1466:707] applicationWillResignActive:
Internal_ResumeChannel assertion passed: paused 1013, source=2400
2011-09-06 14:10:01.869 OpenALSuspendResume[1466:707] Error setting audio session active to 0! '!ini'
2011-09-06 14:10:04.591 OpenALSuspendResume[1466:707] applicationDidBecomeActive:
2011-09-06 14:10:04.592 OpenALSuspendResume[1466:707] Error setting audio session active to 1! '!ini'
AudioStreamBasicDescription:  2 ch,  44100 Hz, 'lpcm' (0x00000C2C) 8.24-bit little-endian signed integer, deinterleaved
Internal_ResumeChannel assertion passed: playing 1012, source=2400
2011-09-06 14:10:06.610 OpenALSuspendResume[1466:707] Assertion failure in checkSourceState. Should be AL_PLAYING, but is 1013



Expected Results:
Audio should not fail to resume playing. State should be PLAYING.

Actual Results:
Audio sometimes does not resume playing. State changes from PLAYING to PAUSED.



Notes:
I also added a #define which disables my OpenAL context NULL/restore code. At the top of ALmixer.c, you will see a commented out line:
//#define DONT_SUSPEND_APPLE_OPENAL_CONTEXT

Uncomment this line to bypass my setting of the OpenAL context to NULL and back on suspend/resume. When I do this, I don't seem to encounter the race condition problem.



06-Sep-2011 06:22 PM Eric Wing:
I did some testing on an iPad 1 running 4.3.5 and was not able to reproduce the problem. I have a report complaining about 4.3 on iPad 2 so I'm thinking the problem  iPad 2 regardless of OS version. I definitely have the problem on iPad 2 running iOS 5 beta.


07-Sep-2011 11:45 AM Eric Wing:
I got reports that suggest this same race condition may also exist in the Mac implementation. I have not directly verified, but my new workaround which bypasses setting the OpenAL context to NULL and back seems to avoid any problem on the Mac.