Occasionally, Android SoundPool used with ScheduledExecutorService stops playing sounds

Question

This seems to happen about 1 in 15 times on my phone and on emulators. The SoundPool will play sounds for about 3 seconds and then stop. While I am playing sounds I repeatedly get this message, which I understand to just mean that low latency mode cannot be used. And when the sound stops, no more of these warnings are generated.

    W/AudioTrack: AUDIO_OUTPUT_FLAG_FAST denied by client

If I look at Android monitor for the whole phone, I always get this when the sound stops, and not otherwise. No exceptions are thrown.

    07-09 22:14:15.630 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7935
    07-09 22:14:15.630 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7928
    07-09 22:14:15.750 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7936
    07-09 22:14:15.750 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7937
    07-09 22:14:15.870 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7938
    07-09 22:14:16.130 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7939
    07-09 22:14:16.130 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7940
    07-09 22:14:16.250 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7941
    07-09 22:14:16.390 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7943
    07-09 22:14:16.390 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7944
    07-09 22:14:17.620 2601-2890/? I/AudioPolicyManager: stopOutput() output 2, stream 7, session 7942
    07-09 22:14:17.620 2601-2890/? I/AudioPolicyManager: getNewOutputDevice() selected device 0
    07-09 22:14:17.620 2601-2890/? I/AudioPolicyManager: setOutputDevice() output 2 device 0x0000 delayMs 40
    07-09 22:14:17.620 2601-2890/? I/AudioPolicyManager: setOutputDevice() prevDevice 0x0002
    07-09 22:14:17.620 2601-2890/? I/AudioPolicyManager: setOutputDevice() setting same device 0x0000 or null device for output 2

This is how I create the SoundPool:

    if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.LOLLIPOP) {
        clips = new SoundPool.Builder()
                .setMaxStreams(22)
                .setAudioAttributes(new AudioAttributes.Builder()
                        .setUsage(AudioAttributes.USAGE_ALARM)
                        .setContentType(AudioAttributes.CONTENT_TYPE_UNKNOWN)
                        .setFlags(AudioAttributes.FLAG_AUDIBILITY_ENFORCED)
                        .build())
                .build();
    } else {
        clips = new SoundPool(22, AudioManager.STREAM_ALARM, 0);
    }

The rest of my code is too large to post but I am loading and playing clips as follows:

ScheduledExecutorService trigger = Executors.newScheduledThreadPool(3);
int e1 = clips.load(this, noteFiles.getResourceId(0,0), 1);
int[] noteIDs = {e1};

playNote = new Runnable() {
        public void run() {
        clips.play(noteIDs[0], realTuneVol, realTuneVol, 1, 0, 1);
}
}

clips.setOnLoadCompleteListener(new SoundPool.OnLoadCompleteListener() {
        @Override
        public void onLoadComplete(SoundPool soundPool, int sampleId, int status) {
          if (savedInstanceState != null) {
               trigger.shutdown();
           } else {
               trigger.scheduleAtFixedRate(playNote, 0, 125, TimeUnit.MILLISECONDS);
                    }
                }
            }
        }
    });

I am playing a lot of clips simultaneously so I understand this could well be the issue, but I haven't noticed much correlation between the number of clips played and this error. However, what I have read and experienced is that if I try to play too many clips the SoundPool will just start skipping them, but it will not stop all together. So I wonder if this problem is unrelated to how many clips I am trying to play and actually related to the ScheduledExecutorService. When the sound stops, the Runnable appears to no longer be executed as I receive no new Log messages from it. Any help is greatly appreciated.

Answer 1

It turns out that the ScheduledExecutorService suppresses exceptions, as is mentioned here. http://code.nomad-labs.com/2011/12/09/mother-fk-the-scheduledexecutorservice/

So by wrapping the entire Runnable in a try catch block I was able to find out that an ArrayIndexOutOfBoundsException was occurring sometimes because of another part of the program, causing the problem.

playNote = new Runnable() {
    public void run() {
    try{
    clips.play(noteIDs[0], realTuneVol, realTuneVol, 1, 0, 1);
    }
    catch (Throwable th){
        Log.v("ErrorInRunnable", th.toString());
    }
    }
}