Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Double-free on Android #1596

Open
yutfa opened this issue Jan 25, 2022 · 10 comments
Open

Double-free on Android #1596

yutfa opened this issue Jan 25, 2022 · 10 comments
Labels

Comments

@yutfa
Copy link

yutfa commented Jan 25, 2022

AIR 33.1.1.731 crash on Android
--------- beginning of crash
01-25 14:56:18.734 1727 2136 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 2136 (Thread-35), pid 1727 (chy.jdzdDevelop)
01-25 14:56:19.090 3522 3522 F DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
01-25 14:56:19.090 3522 3522 F DEBUG : Build fingerprint: 'Xiaomi/star/star:12/SKQ1.211006.001/V13.0.5.0.SKACNXM:user/release-keys'
01-25 14:56:19.090 3522 3522 F DEBUG : Revision: '0'
01-25 14:56:19.090 3522 3522 F DEBUG : ABI: 'arm'
01-25 14:56:19.090 3522 3522 F DEBUG : Timestamp: 2022-01-25 14:56:18.860351552+0800
01-25 14:56:19.090 3522 3522 F DEBUG : Process uptime: 0s
01-25 14:56:19.090 3522 3522 F DEBUG : Cmdline: com.gameduchy.jdzdDevelop
01-25 14:56:19.090 3522 3522 F DEBUG : pid: 1727, tid: 2136, name: Thread-35 >>> com.gameduchy.jdzdDevelop <<<
01-25 14:56:19.090 3522 3522 F DEBUG : uid: 10456
01-25 14:56:19.090 3522 3522 F DEBUG : signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
01-25 14:56:19.090 3522 3522 F DEBUG : Abort message: 'Scudo ERROR: invalid chunk state when deallocating address 0xb545ccb0
01-25 14:56:19.090 3522 3522 F DEBUG : '
01-25 14:56:19.090 3522 3522 F DEBUG : r0 00000000 r1 00000858 r2 00000006 r3 a9e7fe68
01-25 14:56:19.090 3522 3522 F DEBUG : r4 a9e7fe7c r5 a9e7fe60 r6 000006bf r7 0000016b
01-25 14:56:19.090 3522 3522 F DEBUG : r8 a9e7fe68 r9 a9e7fe78 r10 a9e7fe98 r11 a9e7fe88
01-25 14:56:19.090 3522 3522 F DEBUG : ip 00000858 sp a9e7fe38 lr e9643f95 pc e9643fa8
01-25 14:56:19.090 3522 3522 F DEBUG : backtrace:
01-25 14:56:19.090 3522 3522 F DEBUG : #00 pc 00038fa8 /apex/com.android.runtime/lib/bionic/libc.so (abort+172) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #1 pc 0002d0c7 /apex/com.android.runtime/lib/bionic/libc.so (scudo::die()+2) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #2 pc 0002d565 /apex/com.android.runtime/lib/bionic/libc.so (scudo::ScopedErrorReport::~ScopedErrorReport()+16) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #3 pc 0002d6db /apex/com.android.runtime/lib/bionic/libc.so (scudo::reportInvalidChunkState(scudo::AllocatorAction, void*)+46) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #4 pc 0002e3c9 /apex/com.android.runtime/lib/bionic/libc.so (scudo::Allocator<scudo::AndroidConfig, &(scudo_malloc_postinit)>::deallocate(void*, scudo::Chunk::Origin, unsigned long, unsigned long)+156) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #5 pc 0002e31f /apex/com.android.runtime/lib/bionic/libc.so (scudo_free+18) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #6 pc 00167439 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #7 pc 0014324f /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #8 pc 002389ed /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #9 pc 0029d2e9 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #10 pc 0029fb53 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #11 pc 000e553b /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #12 pc 000e7b99 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #13 pc 000ea419 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #14 pc 0002d6bb /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/oat/arm/base.odex (art_jni_trampoline+50)
01-25 14:56:19.090 3522 3522 F DEBUG : #15 pc 0004554f /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/oat/arm/base.odex (com.adobe.air.customHandler.handleMessage+54)
01-25 14:56:19.090 3522 3522 F DEBUG : #16 pc 0044c889 /system/framework/arm/boot-framework.oat (android.os.Handler.dispatchMessage+152) (BuildId: 625436009cb7e9bcdaec00d6e5a61c75e1cc14dc)
01-25 14:56:19.090 3522 3522 F DEBUG : #17 pc 0044ed91 /system/framework/arm/boot-framework.oat (android.os.Looper.loopOnce+960) (BuildId: 625436009cb7e9bcdaec00d6e5a61c75e1cc14dc)
01-25 14:56:19.090 3522 3522 F DEBUG : #18 pc 0044e955 /system/framework/arm/boot-framework.oat (android.os.Looper.loop+460) (BuildId: 625436009cb7e9bcdaec00d6e5a61c75e1cc14dc)
01-25 14:56:19.090 3522 3522 F DEBUG : #19 pc 000eb35c /apex/com.android.art/lib/libart.so (nterp_helper+172) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #20 pc 000bd99e /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/oat/arm/base.vdex
01-25 14:56:19.090 3522 3522 F DEBUG : #21 pc 000f01d5 /apex/com.android.art/lib/libart.so (art_quick_invoke_stub_internal+68) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #22 pc 005098cb /apex/com.android.art/lib/libart.so (art_quick_invoke_stub+282) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #23 pc 00143a35 /apex/com.android.art/lib/libart.so (art::ArtMethod::Invoke(art::Thread*, unsigned int*, unsigned int, art::JValue*, char const*)+140) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #24 pc 004072a3 /apex/com.android.art/lib/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValuesart::ArtMethod*(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, art::ArtMethod*, jvalue const*)+366) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #25 pc 004073af /apex/com.android.art/lib/libart.so (art::JValue art::InvokeVirtualOrInterfaceWithJValues<_jmethodID*>(art::ScopedObjectAccessAlreadyRunnable const&, _jobject*, _jmethodID*, jvalue const*)+42) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #26 pc 002bbb25 /apex/com.android.art/lib/libart.so (art::JNI::CallVoidMethodA(_JNIEnv*, _jobject*, _jmethodID*, jvalue const*)+496) (BuildId: f661d7bd9157d74a48b0b38ff96424ff)
01-25 14:56:19.090 3522 3522 F DEBUG : #27 pc 000f14cf /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #28 pc 000f154b /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #29 pc 000f1523 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #30 pc 00140ec3 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #31 pc 00190ca9 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #32 pc 004c4f45 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #33 pc 004c7049 /data/app/~~rgFOHjarm5IV0LDRJCw7AA==/com.gameduchy.jdzdDevelop-ZQmuJtuhfH7mN7Zs5MphZQ==/lib/arm/libCore.so (BuildId: 0c4fb651185eb153bdfa0fd2e69744c362f5142b)
01-25 14:56:19.090 3522 3522 F DEBUG : #34 pc 00080f87 /apex/com.android.runtime/lib/bionic/libc.so (__pthread_start(void*)+40) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.090 3522 3522 F DEBUG : #35 pc 00039ed3 /apex/com.android.runtime/lib/bionic/libc.so (__start_thread+30) (BuildId: 58785c8a70449c8a3121178908640c6c)
01-25 14:56:19.109 3522 3522 E MIUINDBG: miui_native_debug_process_O
01-25 14:56:19.109 3522 3522 E MIUINDBG: unable to connect to mqsas native socket

@yutfa yutfa added the Bug label Jan 25, 2022
@yutfa
Copy link
Author

yutfa commented Jan 25, 2022

When we use the worker, it will crash, but not when we close the worker. It is suspected that it is a multi-threading problem.

@ajwfrost
Copy link
Collaborator

Are you using audio from the worker at all? this is a problem with an audio track which is being cleaned up (in this call stack, it's the primary thread that's just closing down the resources due to them not having been used for a while).

Looking at it, there shouldn't be multiple places where this is happening so it's a bit strange to see and somewhat difficult to prevent. If it really is a double-free, then we may be able to separately track the resources and ensure we don't call this..

Just wondering: is this fairly reproducible? If you can get us a build done with apk-debug or aab-debug, we can test it out with some additional debugging added, to find out where the delete-track calls are coming from..

thanks

@yutfa
Copy link
Author

yutfa commented Jan 25, 2022

Are you using audio from the worker at all? this is a problem with an audio track which is being cleaned up (in this call stack, it's the primary thread that's just closing down the resources due to them not having been used for a while).

Looking at it, there shouldn't be multiple places where this is happening so it's a bit strange to see and somewhat difficult to prevent. If it really is a double-free, then we may be able to separately track the resources and ensure we don't call this..

Just wondering: is this fairly reproducible? If you can get us a build done with apk-debug or aab-debug, we can test it out with some additional debugging added, to find out where the delete-track calls are coming from..

thanks

Yes, we use the worker to play audio, and it's easy to reproduce when doing certain operations. Is it related to the call of SoundChannel.stop()?

@ajwfrost
Copy link
Collaborator

Thanks @yutfa - yes I can see that some of the platform-specific audio handling may not be thread-safe if both the main thread (which owns the sound mixer) and a worker (which owns the sound channel) try to stop them both at the same time. Will look at the synchronisation of this (again .. last time I think we had tried to protect the creation/deletion of the Android track objects but ended up with deadlock...)

One of the team was just trying to put together a test case for this but if you were able to share an APK it would be good if we could use that to check it .. or alternatively if we can send you a new runtime library to try out which has more debug output (and a potential fix) in it?

thanks

@ajwfrost
Copy link
Collaborator

Hi again
Are you able to try with the attached please, to see if this helps? Note it's the armv8 runtime..
https://transfer.harman.com/message/f0k5MvRb2hzARc0ep5sLfa
thanks

@yutfa
Copy link
Author

yutfa commented Jan 26, 2022

@ajwfrost Thanks for the reply, we found this issue in a 32-bit build, just tried a 64-bit build and had the same issue. So, we rebuilt with the runtime you gave, and the issue is solved,but all text disappeared. Can you give us a 32-bit runtime (which has fixed this issue)

@ajwfrost
Copy link
Collaborator

Thanks @yutfa - so it's good to hear about the lack of crash; if you can share any logcat output I'd be interested to see it as we added some traces to find out what thread IDs were calling the 'delete track' method.

The text disappearing was because it was a build on top of some work-in-progress for the Android fonts problem; we're just finishing off some optimization on that, and then I'll kick off a 32-bit runtime build.

thanks

@ajwfrost
Copy link
Collaborator

Hi @yutfa - please see below
https://transfer.harman.com/message/uOokKv7FctQi4chRiGuaTx

thanks

@yutfa
Copy link
Author

yutfa commented Jan 27, 2022

Thanks @yutfa - so it's good to hear about the lack of crash; if you can share any logcat output I'd be interested to see it as we added some traces to find out what thread IDs were calling the 'delete track' method.

The text disappearing was because it was a build on top of some work-in-progress for the Android fonts problem; we're just finishing off some optimization on that, and then I'll kick off a 32-bit runtime build.

thanks

Hi,@ajwfrost, log here
log.txt

@ajwfrost
Copy link
Collaborator

Perfect, thanks @yutfa

01-27 15:32:30.772 22594 22821 D AdobeAIR: Creating audio track (mixer 0xb400007b5853a520) from thread 22821
...
01-27 15:34:54.989 22594 22594 D AdobeAIR: Destroying audio track (mixer 0xb400007b5853a520) from thread 22594
01-27 15:34:55.010 22594 22821 D AdobeAIR: Destroying audio track (mixer 0xb400007b5853a520) from thread 22821

So the pointers are the same i.e. it's the same "mixer" object that is being called; but the main thread is destroying the track that this holds as well as the worker thread. So if those two calls had happened very close together, it could have resulted in the crash we saw earlier: the code was roughly:

if (track) deleteTrack(track);
track = NULL;

so if the first thread had entered the deleteTrack() call but hadn't got as far as setting the pointer to null, and the second thread then got past the "if (track)" test, then we'd be double-deleting.

Thanks for finding this and for the log files! we didn't expect that two different threads would both be trying to access the mixer object...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants