Android Crash 2

[kiranb47]

• axmol version:
• devices test on:
• developing environments
  • NDK version: r19c
  • Xcode version: 12.4
  • Visual Studio:
    • VS version: 2019 (16.11), 2022 (17.4)
    • MSVC version: 1929, 1934
    • Windows SDK version: 10.0.22621.0
  • cmake version:
    Steps to Reproduce:

We have migrated our Match Animal game to Axmol from Cocos2dx V3 latest yesterday. Getting this crash now. How to fix this issue?

terminating with uncaught exception of type al::backend_exception: Failed to stop stream: ErrorClosed

  #00  pc 0x00000000000534d4  /apex/com.android.runtime/lib64/bionic/libc.so (abort+164)
  #01  pc 0x00000000000d1fcc  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libc++_shared.so (abort_message+76)
  #02  pc 0x00000000000d2180  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libc++_shared.so (demangling_terminate_handler()+62)
  #03  pc 0x00000000000e6e80  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libc++_shared.so (std::__terminate(void (*)())+59)
  #04  pc 0x00000000000e6e18  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libc++_shared.so (std::terminate()+88)
  #05  pc 0x00000000000986b0  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libopenal.so (alcDestroyContext+3423)
  #06  pc 0x000000000068c2b8  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libMatchAnimal.so (ax::AudioEngineImpl::~AudioEngineImpl()+293)
  #07  pc 0x000000000068c4a0  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libMatchAnimal.so (ax::AudioEngineImpl::~AudioEngineImpl()+280)
  #08  pc 0x00000000006868bc  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libMatchAnimal.so (ax::AudioEngine::end()+147)
  #09  pc 0x000000000063bc50  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libMatchAnimal.so (ax::Director::reset()+977)
  #10  pc 0x000000000063ca08  /data/app/~~KcRhAtDu_ohUoG7_ckyt2Q==/games.spearmint.matchanimal-Yg0b8aD7s5klY_lpCbdbfA==/split_config.arm64_v8a.apk!libMatchAnimal.so (ax::Director::mainLoop()+1044)
  #11  pc 0x000000000004f2e0  /data/dalvik-cache/arm64/data@app@~~KcRhAtDu_ohUoG7_ckyt2Q==@games.spearmint.matchanimal-Yg

[rh101]

Was this running on a real device or emulator?

Was it connected to a debugger at the time it crashed? I've only ever seen this when running the app on a device connected to a debugger, such as what is described in #1195

If it is reproducible, then why not just put a breakpoint on ax::AudioEngine::end() and trace the execution of the code from there?

[kiranb47]

Hey @rh101 The issue is not reproducible in any of our test devices. Crash logs are from Google Play live users.

[aismann]

The issue is not reproducible in any of our test devices. Crash logs are from Google Play live users.

Is this a sporadic issue (only some devices/users), right?
Or a general issue on all same devices?

[rh101]

@kiranb47 Are you by any chance calling AudioEngine::end() anywhere in your own code?

For example, in the Cocos2d CPP template, there is this section in AppDelegate.cpp:

AppDelegate::~AppDelegate() 
{
    AudioEngine::end();
}

[halx99]

@kiranb47 Are you by any chance calling AudioEngine::end() anywhere in your own code?

For example, in the Cocos2d CPP template, there is this section in AppDelegate.cpp:

AppDelegate::~AppDelegate() 
{
    AudioEngine::end();
}

User don't needs to invoke AudioEngine::end, see this issue: #550

[rh101]

I just had an idea and tested it out, and managed to reproduce this issue consistently.

1. Load the app
2. Make or receive a phone call

This causes the audio section to throw an error, which closes the stream. Audio in the app no longer works, and eventually it will crash because of 2 different issues.

• One would be something like Fail to play Sounds/AudioFile.mp3 cause by limited max instance of AudioEngine
  OR
• The other would be what is posted above by @kiranb47, which would generally happen when a user exits the app: terminating with uncaught exception of type al::backend_exception: Failed to stop stream: ErrorClosed

When I received a phone call, I saw this in logcat:

2023-05-25 16:56:35.361 25517-25533 localhost.test          com.localhost.test                D  PlayerBase::setVolume() from IPlayer
2023-05-25 16:56:35.361 25517-25533 AAudioStream            com.localhost.test                D  setDuckAndMuteVolume() to 0.000000
2023-05-25 16:56:35.361 25517-25533 AudioStrea...lay_Client com.localhost.test                D  doSetVolume() mStreamVolume * duckAndMuteVolume = 1.000000 * 0.000000 = 0.000000
2023-05-25 16:56:39.181 25517-25517 AxmolActivity           com.localhost.test                D  onPause()
2023-05-25 16:56:39.259 25517-25517 AxmolActivity           com.localhost.test                D  onWindowFocusChanged() hasFocus=false
2023-05-25 16:56:39.514 25517-25693 AudioStrea...nal_Client com.localhost.test                D  onEventFromServer - got AAUDIO_SERVICE_EVENT_STOPPED
2023-05-25 16:56:39.517 25517-25693 AAudioStream            com.localhost.test                D  setState(s#2) from 4 to 13
2023-05-25 16:56:39.517 25517-25693 AudioStrea...nal_Client com.localhost.test                W  onEventFromServer - AAUDIO_SERVICE_EVENT_DISCONNECTED - FIFO cleared
2023-05-25 16:56:39.519 25517-25693 AudioStrea...lay_Client com.localhost.test                D  callbackLoop() exiting, result = -899, isActive() = 0 <<<<<<<<<<<<<<
2023-05-25 16:56:39.522 25517-25914 OboeAudio               com.localhost.test                D  oboe_aaudio_error_thread_proc(,-899) - entering >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
2023-05-25 16:56:39.522 25517-25914 AAudio                  com.localhost.test                D  AAudioStream_requestStop(s#2) called
2023-05-25 16:56:39.531 25517-25914 AAudioStream            com.localhost.test                D  joinThread_l() pthread_join succeeded
2023-05-25 16:56:39.531 25517-25914 IsochronousClockModel   com.localhost.test                D  stop(nanos = 15325857903817) max lateness = 74 micros
2023-05-25 16:56:39.531 25517-25914 AAudioStream            com.localhost.test                D  setState(s#2) from 13 to 9
2023-05-25 16:56:39.531 25517-25914 AAudioStream            com.localhost.test                W  setState(2) tried to set to 9 but already DISCONNECTED
2023-05-25 16:56:39.532 25517-25914 AAudio                  com.localhost.test                D  AAudioStream_requestStop(s#2) called
2023-05-25 16:56:39.532 25517-25914 AAudioStream            com.localhost.test                D  joinThread() - but has no thread or already join()ed
2023-05-25 16:56:39.532 25517-25914 AudioStrea...nal_Client com.localhost.test                W  requestStop_l() stop callback returned -895, returning early
2023-05-25 16:56:39.542 25517-25914 AAudio                  com.localhost.test                D  AAudioStream_close(s#2) called ---------------
2023-05-25 16:56:39.542 25517-25914 AudioStrea...nal_Client com.localhost.test                D  release_l(): mServiceStreamHandle = 0x00000034
2023-05-25 16:56:39.542 25517-25914 AAudioStream            com.localhost.test                D  joinThread() - but has no thread or already join()ed
2023-05-25 16:56:39.542 25517-25914 AudioStrea...nal_Client com.localhost.test                W  requestStop_l() stop callback returned -895, returning early
2023-05-25 16:56:39.542 25517-25914 AAudioStream            com.localhost.test                D  setState(s#2) from 13 to 11
2023-05-25 16:56:39.645 25517-25914 AAudioStream            com.localhost.test                D  setState(s#2) from 11 to 11
2023-05-25 16:56:39.645 25517-25914 AAudioStream            com.localhost.test                D  setState(s#2) from 11 to 12
2023-05-25 16:56:39.645 25517-25914 AudioStrea...nal_Client com.localhost.test                D  ~AudioStreamInternal() 0xb400007a7a173c80 called
2023-05-25 16:56:39.645 25517-25914 AAudioStream            com.localhost.test                D  ~AudioStream(s#2) mPlayerBase strongCount = 2
2023-05-25 16:56:39.645 25517-25914 AAudio                  com.localhost.test                D  AAudioStream_close(s#2) returned 0 ---------
2023-05-25 16:56:39.645 25517-25914 OboeAudio               com.localhost.test                D  oboe_aaudio_error_thread_proc() - exiting <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
2023-05-25 16:56:41.255 25517-25890 FA                      com.localhost.test                I  Application backgrounded at: timestamp_millis: 1684997799249
2023-05-25 16:56:42.911 25517-25517 AxmolActivity           com.localhost.test                D  onResume()
2023-05-25 16:56:42.933 25517-25658 OpenGLRenderer          com.localhost.test                E  Unable to match the desired swap behavior.
2023-05-25 16:56:42.937 25517-25675 GLSurfaceView           com.localhost.test                W  Warning, !readyToDraw() but waiting for draw finished! Early reporting draw finished.
2023-05-25 16:56:42.969 25517-25517 AxmolActivity           com.localhost.test                D  onWindowFocusChanged() hasFocus=true

oboe_aaudio_error_thread_proc() was definitely called there, which closes the stream.

@halx99 This shouldn't be happening, right? I've never tested this scenario before, but this causes the same issue described in #1195

[kiranb47]

@rh101 @halx99 We are not invoking AudioEngine::end()

[kiranb47]

@aismann 5.2% users affected

[halx99]

I create a PR to switch default audio backend to opensl, plz update and check.

[rh101]

I create a PR to switch default audio backend to opensl, plz update and check.

I'll merge the PR in locally and test it now

[rh101]

@halx99 Using OpenSL, everything is working fine, with no errors or crashes at all. Making and receiving phone calls resulted in this logcat output, which looks normal, with no errors:

2023-05-25 18:37:37.477  6655-6859  localhost.test          com.localhost.test                D  PlayerBase::setVolume() from IPlayer
2023-05-25 18:37:42.083  6655-6655  AxmolActivity           com.localhost.test                D  onPause()
2023-05-25 18:37:42.117  6655-6655  AxmolActivity           com.localhost.test                D  onWindowFocusChanged() hasFocus=false
2023-05-25 18:37:44.167  6655-7826  FA                      com.localhost.test                I  Application backgrounded at: timestamp_millis: 1685003862161
2023-05-25 18:37:44.623  6655-6655  AxmolActivity           com.localhost.test                D  onResume()
2023-05-25 18:37:44.649  6655-6847  OpenGLRenderer          com.localhost.test                E  Unable to match the desired swap behavior.
2023-05-25 18:37:44.651  6655-6857  GLSurfaceView           com.localhost.test                W  Warning, !readyToDraw() but waiting for draw finished! Early reporting draw finished.
2023-05-25 18:37:44.651  6655-6655  SurfaceSyncer           com.localhost.test                E  Failed to find sync for id=1
2023-05-25 18:37:44.678  6655-6655  AxmolActivity           com.localhost.test                D  onWindowFocusChanged() hasFocus=true
2023-05-25 18:37:45.746  6655-6859  localhost.test          com.localhost.test                D  PlayerBase::setVolume() from IPlayer

The app audio worked fine after the phone call terminated. Also, no more audio issues or crashes when using a debugger and breakpoints as described in #1195.