segfault in MWActivity onDestroy()

[scar20]

As I was trying to extend the example from AppCompatActivity, I noticed the app crash on rotation. It seem there is some difference of behavior with AppCompat; screenSize attibute must be added to android:configChanges="orientation|keyboardHidden" in the manifest to get the same behavior as the original app - not restart the app on rotation. But before I find this attribute, I've put some more log in the lifecycle method of MWEngineActivity and MWEngine and proceeded to provoque a call to destroy() by hitting the "Home" button then swipe off the app from the screen. Here's what I find:

The log at the end of destroy() never get called although flushSong() and _engine.dispose() do get called but it doesn't get out of the last. Instead it crash with a segfault - which is not very noticeable since you just get rid of the app but will be if the app is to be recreated inside a configChange.

Also in MWEngine.dispose() method, there seem to be redondancy with _isRunning = false; variable since .stop() already set this to false (and we can presume that stop() have been called before destroy), then stop() get called which will only return. So that is looking odd to me, unless I miss something.

Anyhow, just to make sure I didn't introduce myself a bug, I tried again with the original app - just run, hit Home button and swipe; same result. As it seem to originate from MWEngine, I though it could be of concern.

Below is the full "run" log from the original app:

11/30 16:30:56: Launching 'mwengine_example' on Google Pixel 3a XL. Install successfully finished in 1 s. $ adb shell am start -n "nl.igorski.mwengine.example/nl.igorski.mwengine.example.MWEngineActivity" -a android.intent.action.MAIN -c android.intent.category.LAUNCHER Connected to process 11106 on device 'google-pixel_3a_xl-934AX04CSF'. Capturing and displaying logcat messages from application. This behavior can be disabled in the "Logcat output" section of the "Debugger" settings page. D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar D/NetworkSecurityConfig: No Network Security Config specified, using platform default D/NetworkSecurityConfig: No Network Security Config specified, using platform default D/MWENGINE: initing MWEngineActivity W/wengine.example: type=1400 audit(0.0:579): avc: denied { read } for name="cpus" dev="cgroup" ino=99 scontext=u:r:untrusted_app_27:s0:c223,c256,c512,c768 tcontext=u:object_r:cgroup:s0 tclass=file permissive=0 app=nl.igorski.mwengine.example W/wengine.example: type=1400 audit(0.0:580): avc: denied { read } for name="cpus" dev="cgroup" ino=45 scontext=u:r:untrusted_app_27:s0:c223,c256,c512,c768 tcontext=u:object_r:cgroup:s0 tclass=file permissive=0 app=nl.igorski.mwengine.example V/MWENGINE: About to parse data for WAV file '/data/user/0/nl.igorski.mwengine.example/cache/tmp' File size : 45092 Audio format : 1 Channel amount : 2 Sample rate : 44100 Bytes per second : 176400 Block align : 4 Bits per sample : 16 V/MWENGINE: About to parse data for WAV file '/data/user/0/nl.igorski.mwengine.example/cache/tmp' V/MWENGINE: File size : 92582 Audio format : 1 Channel amount : 1 Sample rate : 48000 Bytes per second : 96000 Block align : 2 Bits per sample : 16 W/wengine.example: type=1400 audit(0.0:581): avc: denied { read } for name="cpus" dev="cgroup" ino=27 scontext=u:r:untrusted_app_27:s0:c223,c256,c512,c768 tcontext=u:object_r:cgroup:s0 tclass=file permissive=0 app=nl.igorski.mwengine.example D/MWENGINE: starting native audio rendering thread @ 48000 Hz using 96 samples per buffer V/MWENGINE: STARTING engine STARTED engine V/MWENGINE: DriverAdapter::initializing AAudio driver I/AAudio: AAudioStreamBuilder_openStream() called ---------------------------------------- I/AudioStreamBuilder: rate = 0, channels = 2, format = 5, sharing = EX, dir = OUTPUT device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0 usage = 0, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0 privacy sensitive = false D/wengine.exampl: PlayerBase::PlayerBase() D/AudioStreamInternal_Client: open() original HW burst = 48, minMicros = 2000 => SW burst = 96 D/AAudioStream: setState(s#1) from 0 to 2 I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#1 ---------------- V/MWENGINE: AAudio_IO::Setting buffer size to 96 I/AAudio: AAudioStreamBuilder_openStream() called ---------------------------------------- I/AudioStreamBuilder: rate = 48000, channels = 1, format = 5, sharing = EX, dir = INPUT device = 0, sessionId = -1, perfMode = 12, callback: OFF with frames = 0 usage = 0, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0 privacy sensitive = false D/wengine.exampl: PlayerBase::PlayerBase() D/AudioStreamInternal_Client: open() original HW burst = 48, minMicros = 2000 => SW burst = 96 D/AAudioStream: setState(s#2) from 0 to 2 I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#2 ---------------- D/AAudio: AAudioStream_requestStart(s#2) called -------------- D/AAudioStream: setState(s#2) from 2 to 3 I/AdrenoGLES-0: QUALCOMM build : c9bef8a, Ie73904e3bd Build Date : 06/26/20 OpenGL ES Shader Compiler Version: EV031.31.04.00 Local Branch : gfx-adreno.lnx.2.0 Remote Branch : quic/gfx-adreno.lnx.2.0 Remote Branch : NONE Reconstruct Branch : NOTHING Build Config : C P 11.0.1 AArch64 Driver Path : /vendor/lib64/egl/libGLESv2_adreno.so I/AdrenoGLES-0: PFP: 0x016ee189, ME: 0x00000000 W/AdrenoUtils: : Failed to open /sys/class/kgsl/kgsl-3d0/gpu_model

: Failed to read chip ID from gpu_model. Fallback to use the GSL path I/Gralloc4: mapper 4.x is not supported W/Gralloc3: mapper 3.x is not supported D/MWENGINE: window focus changed for MWEngineActivity, has focus > true D/wengine.exampl: PlayerBase::start() from IPlayer D/AAudio: AAudioStream_requestStart(s#2) returned 0 --------- AAudioStream_requestStart(s#1) called -------------- D/AAudioStream: setState(s#1) from 2 to 3 D/wengine.exampl: PlayerBase::start() from IPlayer D/AAudio: AAudioStream_requestStart(s#1) returned 0 --------- D/AudioStreamInternalPlay_Client: callbackLoop() entering >>>>>>>>>>>>>>> V/MWENGINE: Binding to current CPU ID 7 for thread 11175 V/MWENGINE: AAudio_IO::Error calculating latency: AAUDIO_ERROR_INVALID_STATE D/AudioStreamInternal_Client: onEventFromServer - AAUDIO_SERVICE_EVENT_VOLUME 0.055739 D/AudioStreamInternalPlay_Client: doSetVolume() mStreamVolume * duckAndMuteVolume = 0.055739 * 1.000000 = 0.055739 D/AudioStreamInternal_Client: onEventFromServer - AAUDIO_SERVICE_EVENT_VOLUME 0.055739 D/AudioStreamInternalPlay_Client: doSetVolume() mStreamVolume * duckAndMuteVolume = 0.055739 * 1.000000 = 0.055739 D/AudioStreamInternal_Client: onEventFromServer - got AAUDIO_SERVICE_EVENT_STARTED D/AAudioStream: setState(s#1) from 3 to 4 D/AudioStreamInternal_Client: onEventFromServer - AAUDIO_SERVICE_EVENT_VOLUME 0.055739 D/AudioStreamInternalPlay_Client: doSetVolume() mStreamVolume * duckAndMuteVolume = 0.055739 * 1.000000 = 0.055739 V/MWENGINE: AAudio_IO::Error calculating latency: AAUDIO_ERROR_INVALID_STATE D/MWENGINE: window focus changed for MWEngineActivity, has focus > false V/MWENGINE: STOPPING engine STOPPED engine D/AAudio: AAudioStream_requestStop(s#1) called D/AudioStreamInternalPlay_Client: callbackLoop() exiting, result = 96, isActive() = 1 <<<<<<<<<<<<<< D/IsochronousClockModel: stop(nanos = 258932869077579) max lateness = 1230 micros D/AAudioStream: setState(s#1) from 4 to 9 D/wengine.exampl: PlayerBase::stop() from IPlayer D/AAudio: AAudioStream_close(s#1) called --------------- D/AAudioStream: setState(s#1) from 9 to 11 D/AAudioStream: setState(s#1) from 11 to 11 E/AAudioStream: setState(1) tried to set to 11 but already CLOSING D/AAudioStream: setState(s#1) from 11 to 12 D/AAudio: AAudioStream_close(s#1) returned 0 --------- AAudioStream_requestStop(s#2) called D/IsochronousClockModel: stop(nanos = 258933018162855) max lateness = 0 micros D/AAudioStream: setState(s#2) from 3 to 9 D/wengine.exampl: PlayerBase::stop() from IPlayer D/AAudio: AAudioStream_close(s#2) called --------------- D/AAudioStream: setState(s#2) from 9 to 11 D/AAudioStream: setState(s#2) from 11 to 11 E/AAudioStream: setState(2) tried to set to 11 but already CLOSING D/AAudioStream: setState(s#2) from 11 to 12 D/wengine.exampl: PlayerBase::~PlayerBase() D/AAudio: AAudioStream_close(s#2) returned 0 --------- A/libc: Fatal signal 11 (SIGSEGV), code 2 (SEGV_ACCERR), fault addr 0x79f1ab9000 in tid 11106 (wengine.example), pid 11106 (wengine.example)

[scar20]

Commenting out the line <!-- android:configChanges="orientation|keyboardHidden">--> in the manifest allow more convenient debugging since it call onDestroy() on rotation.

The bug is inside flushSong(), at the _synth2.delete(); line. Suspecting _delay, I commented out _synth2.getAudioChannel().getProcessingChain().addProcessor( _delay ); in setupSong(). Indeed it fixed it. So instead of commenting out, I added _delay.delete() just before _synth2.delete(); and it is OK now.

Which make me wonder, I though I saw something about this in the Wiki about the order of deletion of processors and their associated instruments - but can't find it now. But from the comments in the code:

// calling 'delete()' on all instruments invokes the native layer destructor
// (and frees memory allocated to their resources, e.g. AudioChannels, Processors)

seems to indicate that it should be fine. So it is something wrong with _delay? The others instruments aren't affected even though they have processors in their processingChain. So processor.delete() before instrument.delete() or not?

[igorski]

I have been looking at this, I'm not sure whether it's the delay processor per se. When looking at issue https://github.com/igorski/MWEngine/issues/139 I uncovered some issues related to the SynthEvent (and thus related SynthInstrument) destructor sequence. Can you pull the latest changes and verify whether that addressed your issue ?

[scar20]

I pulled your changes in master of my working dir, then push to my origin to keep in sync. I merged master to the test branch "configChange" and tried again. Unfortunately, it still crash at the same place if I comment out the added _delay.delete() at line 344 of the modified MWEngineActivity with added log on overloaded lifecycle method. But for the rest, its the same file. Commenting out force the app to be destroyed and recreated on rotation, showing the bug.

I pushed the branch on my rep: https://github.com/scar20/MWEngine/tree/configChange if you want to take a look. I have limited skill in debugging techniques (mostly kinda primitive sprintf() guy...) and it seem there is a wall from Java to C++ that I can't get trough. Commenting out line 344 _delay.delete() and rotate device will make it crash. Sorry not to be more useful.

[igorski]

Alright, found the issue and addressed it in f7a25c14ac9c6d1cd614059a551020fb82176a36

Basically the destructor of the ProcessingChain was modifying the active processor list while at the same time recursively calling a method to individually remove processors, which would do the same. The Delay wasn't the issue specifically, but it was the only processor for synth2 and would make this conflicting cleanup apparent. Can you verify whether this addresses your issue ?

As you mentioned, the android:configChanges attribute is outdated and should now be configured as android:configChanges="orientation|screenSize|screenLayout|keyboardHidden. I will update the example activity shortly using androidx/AppCompatActivity to get with the times :)

[scar20]

I have "Pull into Current Using Rebase" from upstream into local (and puch to origin) using the little menu down right. Fast check - removing manifest line to force destroy on rotation - and it did not crash. So fixed, great! Thx

I think however you forgot to add the gradle.properties file which contain those line:

# AndroidX package structure to make it clearer which packages are bundled with the
# Android operating system, and which are packaged with your app"s APK
# https://developer.android.com/topic/libraries/support-library/androidx-rn
android.useAndroidX=true
# Automatically convert third-party libraries to use AndroidX
android.enableJetifier=true

I cant tell for sure if it was there or not since I added unversioned one in the project tree to test appCompat. I cant see it on github. It could be generated from others settings perhaps. But it wont compile if useAndroidX is not set.

[igorski]

Phew, good news, glad the crashing is tackled.

It's true that gradle.properties wasn't part of the commit I mentioned above, it was added at a later stage in 9c01fd19ee897cb7311e4002649dc992f14d5bbe though. It is possible that during rebase it got lost since you had a local copy. Anyways, the contents of those are exactly the same :)

[scar20]

OK, I was just afraid I've introduced it by accident. So I have now a pristine master with the latest commit, cool... I have safely deleted configChange branch in local and origin so to not keep dirt. I leave you the liberty of closing this thread if you have nothing else to add.