Opened on 04/20/2018 at 06:00:35 AM

Closed on 05/18/2018 at 08:08:32 AM

#6600 closed defect (fixed)

Racy V8isolate unregistration

Reported by: asmirnov Assignee:
Priority: P2 Milestone:
Module: Adblock-Plus-for-Chromium Keywords:
Cc: sergz, jwangenheim Blocked By:
Blocking: Platform: Android
Ready: no Confidential: no
Tester: Unknown Verified working: no
Review URL(s):

​https://gitlab.com/eyeo/adblockplus/chromium/merge_requests/17

Description (last modified by asmirnov)

Environment

First time saw it after update to Chromium 65 (#6588).
libadblockplus holds references to V8isolateProvider instance and one the last instance reference is removed it get's destroyed. However it seems to happen in background thread (or in some unexpected conditions) so when the app is closed and V8Isolate destroyed i can see stacktrace without app crash.

How to reproduce

  1. Run the app (issue-6588 branch of AdblockChromium)
  2. Navigate to some URL
  3. close the tab
  4. see assertion failed in android log

Observed behaviour

i can see assertion failure in android log:

04-20 10:52:55.488 19701-19701 D/cr_tabmodel: [TabPersistentStore.java:883] Serializing tab lists; counts: 0, 0, 0
04-20 10:52:55.498 19701-19701 W/cr_ContextualSearch: Warning, the UNDEFINED state was aborted.
04-20 10:52:55.508 19701-19701 W/cr_ChromeTabbedActivity: onDestroyInternal()
04-20 10:52:55.508 19701-19701 W/cr_ChromeTabbedActivity: Adblock: deinitAdblock()
04-20 10:52:55.508 19701-19701 D/SingleInstanceEngineProvider: Waiting for ready in Thread[main,5,main]
04-20 10:52:55.508 19701-19701 D/SingleInstanceEngineProvider: Ready
04-20 10:52:55.508 19701-19701 W/SingleInstanceEngineProvider: Waiting for lock
04-20 10:52:55.508 19701-19701 W/SingleInstanceEngineProvider: Disposing adblock engine
04-20 10:52:55.508 19701-19701 W/AdblockEngine: Dispose
04-20 10:52:55.558 310-19309 I/AudioPolicyManager: getAudioPolicyConfig: audioParam;outDevice
04-20 10:52:55.568 19701-19701 A/chromium: [FATAL:memory_dump_manager.cc(467)] Check failed: (*mdp_iter)->task_runner && (*mdp_iter)->task_runner->RunsTasksInCurrentSequence(). MemoryDumpProvider "V8Isolate" attempted to unregister itself in a racy way. Please file a crbug.
                                           #00 0x9eabb7dd /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so+0x000a87dd
                                           #01 0x9eb0555b /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so+0x000f255b
                                           #02 0x9b159b51 /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so+0x00010b51
                                           #03 0x9b159b61 /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so+0x00010b61
                                           #04 0x9b156c5f /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so+0x0000dc5f
                                           #05 0x941717f5 /data/app/org.chromium.chrome-1/lib/arm/libchrome.cr.so+0x005447f5
                                           #06 0x94171839 /data/app/org.chromium.chrome-1/lib/arm/libchrome.cr.so+0x00544839
                                           #07 0x9af7de97 /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x0005be97
                                           #08 0x9af7de3b /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x0005be3b
                                           #09 0x9af77c61 /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x00055c61
                                           #10 0x9af82579 /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x00060579
                                           #11 0x9af83453 /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x00061453
                                           #12 0x9af70a17 /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so+0x0004ea17
04-20 10:52:55.568 19701-19701 A/libc: Fatal signal 6 (SIGABRT), code -6 in tid 19701 (chromium.chrome)
04-20 10:52:55.598 265-22792 I/SurfaceFlinger: id=78 Removed DhromeTabbe (7/10)
04-20 10:52:55.598 265-369 I/SurfaceFlinger: id=78 Removed DhromeTabbe (-2/10)
04-20 10:52:55.608 265-1025 I/SurfaceFlinger: id=79 Removed TurfaceView (6/9)
04-20 10:52:55.608 265-1649 I/SurfaceFlinger: id=79 Removed TurfaceView (-2/9)
04-20 10:52:55.658 310-19445 I/AudioPolicyManager: getAudioPolicyConfig: audioParam;outDevice
04-20 10:52:55.678 300-300 I/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
04-20 10:52:55.678 300-300 I/DEBUG: Build fingerprint: 'samsung/hltexx/hlte:5.0/LRX21V/N9005XXSGBPL7:user/release-keys'
04-20 10:52:55.678 300-300 I/DEBUG: Revision: '8'
04-20 10:52:55.678 300-300 I/DEBUG: ABI: 'arm'
04-20 10:52:55.678 300-300 I/DEBUG: pid: 19701, tid: 19701, name: chromium.chrome  >>> org.chromium.chrome <<<
04-20 10:52:55.678 300-300 I/DEBUG: signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------
04-20 10:52:55.738 300-300 I/DEBUG: Abort message: '[FATAL:memory_dump_manager.cc(467)] Check failed: (*mdp_iter)->task_runner && (*mdp_iter)->task_runner->RunsTasksInCurrentSequence(). MemoryDumpProvider "V8Isolate" attempted to unregister itself in a racy way. Please file a crbug.
                                    #00 0x9eabb7dd /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so+0x000a87dd
                                    #01 0x9eb0555b /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so+0x000f255b
                                    #02 0x9b159b51 /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so+0x00010b51
                                    #03 0x9b159b61 /data/app
04-20 10:52:55.738 300-300 I/DEBUG:     r0 00000000  r1 00004cf5  r2 00000006  r3 00000000
04-20 10:52:55.738 300-300 I/DEBUG:     r4 b6fad114  r5 00000006  r6 0000000b  r7 0000010c
04-20 10:52:55.738 300-300 I/DEBUG:     r8 9eb5f0b8  r9 9eb5fde0  sl bedce994  fp bedce998
04-20 10:52:55.738 300-300 I/DEBUG:     ip 00004cf5  sp bedce4c0  lr b6f36fd5  pc b6f5a4b0  cpsr 600f0010
04-20 10:52:55.738 300-300 I/DEBUG: backtrace:
04-20 10:52:55.738 300-300 I/DEBUG:     #00 pc 000374b0  /system/lib/libc.so (tgkill+12)
04-20 10:52:55.738 300-300 I/DEBUG:     #01 pc 00013fd1  /system/lib/libc.so (pthread_kill+52)
04-20 10:52:55.738 300-300 I/DEBUG:     #02 pc 00014bef  /system/lib/libc.so (raise+10)
04-20 10:52:55.738 300-300 I/DEBUG:     #03 pc 00011531  /system/lib/libc.so (__libc_android_abort+36)
04-20 10:52:55.738 300-300 I/DEBUG:     #04 pc 0000fcbc  /system/lib/libc.so (abort+4)
04-20 10:52:55.738 300-300 I/DEBUG:     #05 pc 00097105  /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so (base::debug::BreakDebugger()+20)
04-20 10:52:55.738 300-300 I/DEBUG:     #06 pc 000a89f3  /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so (logging::LogMessage::~LogMessage()+658)
04-20 10:52:55.738 300-300 I/DEBUG:     #07 pc 000f2559  /data/app/org.chromium.chrome-1/lib/arm/libbase.cr.so (base::trace_event::MemoryDumpManager::UnregisterDumpProviderInternal(base::trace_event::MemoryDumpProvider*, bool)+256)
04-20 10:52:55.738 300-300 I/DEBUG:     #08 pc 00010b4f  /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so
04-20 10:52:55.738 300-300 I/DEBUG:     #09 pc 00010b5f  /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so
04-20 10:52:55.738 300-300 I/DEBUG:     #10 pc 0000dc5f  /data/app/org.chromium.chrome-1/lib/arm/libgin.cr.so (gin::IsolateHolder::~IsolateHolder()+30)
04-20 10:52:55.738 300-300 I/DEBUG:     #11 pc 005447f3  /data/app/org.chromium.chrome-1/lib/arm/libchrome.cr.so
04-20 10:52:55.738 300-300 I/DEBUG:     #12 pc 00544837  /data/app/org.chromium.chrome-1/lib/arm/libchrome.cr.so
04-20 10:52:55.738 300-300 I/DEBUG:     #13 pc 0005be97  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so (AdblockPlus::JsEngine::~JsEngine()+76)
04-20 10:52:55.738 300-300 I/DEBUG:     #14 pc 0005be39  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so (std::__ndk1::__shared_ptr_pointer<AdblockPlus::JsEngine*, std::__ndk1::default_delete<AdblockPlus::JsEngine>, std::__ndk1::allocator<AdblockPlus::JsEngine> >::__on_zero_shared()+8)
04-20 10:52:55.738 300-300 I/DEBUG:     #15 pc 00055c61  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so (std::__ndk1::shared_ptr<AdblockPlus::JsEngine>::~shared_ptr()+44)
04-20 10:52:55.738 300-300 I/DEBUG:     #16 pc 00060577  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so (AdblockPlus::Platform::~Platform()+58)
04-20 10:52:55.738 300-300 I/DEBUG:     #17 pc 00061451  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so
04-20 10:52:55.738 300-300 I/DEBUG:     #18 pc 0004ea17  /data/app/org.chromium.chrome-1/lib/arm/libadblockplus-jni.so
04-20 10:52:55.738 300-300 I/DEBUG:     #19 pc 002462b9  /data/dalvik-cache/arm/data@app@org.chromium.chrome-1@base.apk@classes.dex
04-20 10:52:55.758 310-19337 I/AudioPolicyManager: getAudioPolicyConfig: audioParam;outDevice
04-20 10:52:55.798 762-4164 D/SSRM:n: SIOP:: AP = 410, PST = 399, CUR = 450
04-20 10:52:55.858 310-19443 I/AudioPolicyManager: getAudioPolicyConfig: audioParam;outDevice

Expected behaviour

there are no assertion failures in android log

Hints for testers

After the tab is closed there should be no assertion failures in android log.

Attachments (1)

android_log.txt​ (7.8 KB) - added by asmirnov on 04/20/2018 at 06:01:10 AM.

Download all attachments as: .zip

Change History (12)

Changed on 04/20/2018 at 06:01:10 AM by asmirnov

comment:1 Changed on 04/20/2018 at 06:02:41 AM by asmirnov

  • Description modified (diff)

comment:2 Changed on 04/20/2018 at 06:05:53 AM by asmirnov

probably it makes sense to check in what thread it happens in libadblockplus (releasing of last reference to V8IsolateProvider)

comment:3 Changed on 04/20/2018 at 10:04:52 AM by sergz

Do I correctly understand that the issue is that V8 isolate is being destroyed from a worker thread managed by that isolate instance?

It's destroyed in the same thread where AdblockPlus::Platform::~Platform is called, thus where Platform is destroyed. Is the destruction of the platform scheduled in a worker thread? Can it be that that V8 isolate is also used not only by libadblockplus but also by chromium?

comment:4 Changed on 04/20/2018 at 10:09:47 AM by asmirnov

Is the destruction of the platform scheduled in a worker thread?

no, in android code destroy is called in main thread (see pid = tid = 19701) in the log:

04-20 10:52:55.508 19701-19701 W/cr_ChromeTabbedActivity: onDestroyInternal()
04-20 10:52:55.508 19701-19701 W/cr_ChromeTabbedActivity: Adblock: deinitAdblock()
04-20 10:52:55.508 19701-19701 D/SingleInstanceEngineProvider: Waiting for ready in Thread[main,5,main]
04-20 10:52:55.508 19701-19701 D/SingleInstanceEngineProvider: Ready
04-20 10:52:55.508 19701-19701 W/SingleInstanceEngineProvider: Waiting for lock
04-20 10:52:55.508 19701-19701 W/SingleInstanceEngineProvider: Disposing adblock engine
04-20 10:52:55.508 19701-19701 W/AdblockEngine: Dispose

comment:5 Changed on 04/20/2018 at 10:10:12 AM by asmirnov

Can it be that that V8 isolate is also used not only by libadblockplus but also by chromium?

it's less likely as we don't pass v8isolate pointer anywhere else

comment:6 Changed on 04/20/2018 at 10:24:03 AM by sergz

I wonder whether the issue is that that isolate is created and destroyed in different threads. Could you please check in which thread the isolate is created and is it possible to create it in the main thread and pass to the worker one?

comment:7 Changed on 04/20/2018 at 10:26:27 AM by asmirnov

it's also created in main thread (pid = tid = 14058):

04-20 15:25:21.912 14058-14058 W/chromium: [WARNING:adblock_bridge.cc(387)] Adblock: creating isolate holder ...
04-20 15:25:21.912 14058-14058 W/chromium: [WARNING:adblock_bridge.cc(390)] Adblock: loading v8 snapshot & natives ...
04-20 15:25:21.912 14058-14058 W/chromium: [WARNING:adblock_bridge.cc(393)] Adblock: loaded v8 snapshot & natives
04-20 15:25:21.912 14058-14058 W/chromium: [WARNING:adblock_bridge.cc(396)] Adblock: initialize isolate holder
04-20 15:25:22.052 14058-14058 W/chromium: [WARNING:adblock_bridge.cc(411)] Adblock: returning (from adblock_bridge.cc) isolate provider 0x91cf8278
04-20 15:25:22.052 14058-14058 W/cr_ChromeTabbedActivity: Adblock: got isolate pointer = 2446295672 in thread Thread[main,5,main]

comment:8 Changed on 04/20/2018 at 11:00:32 AM by sergz

It's really difficult to guess the reason, there was an attempt in the repository to fix something what can be the reason of that bug (​https://github.com/adblockplus/v8-googlesource/commit/c2a6be0b16b9b1283892aafed75a0e756f45d013). Perhaps if it was not observed before and does not cause a crash, we should just wait and it will be resolved with the next update. FYI #6596.

comment:9 Changed on 04/22/2018 at 05:34:32 AM by asmirnov

Probably it can be solved by just releasing of V8Isolate in our task runner:
​https://gitlab.com/eyeo/adblockplus/chromium/blob/dev-65.0.3325.181/chrome/browser/android/adblock/adblock_bridge.cc#L59

comment:10 Changed on 05/07/2018 at 08:53:46 AM by asmirnov

  • Review URL(s) modified (diff)
  • Status changed from new to reviewing

comment:11 Changed on 05/18/2018 at 08:08:32 AM by asmirnov

  • Resolution set to fixed
  • Status changed from reviewing to closed

Add Comment

Modify Ticket

Change Properties
Action
as closed .
The resolution will be deleted. Next status will be 'reopened'.
to The owner will be changed from (none).
Attachments ↑ Description ↑
 
Note: See TracTickets for help on using tickets.