New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 647291 link

Starred by 5 users

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Dec 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug



Sign in to add a comment

Strict mode violation in startChromiumLocked

Reported by kmans...@gmail.com, Sep 15 2016

Issue description

Steps to reproduce the problem:
Follow-up to  issue #628627 

Seeing this in my app called AquaMail.

Strict mode violation (file not closed, triggering CloseGuard) and - with my strict mode settings - app process to abort.

1. Create a dummy file that forces the app into "debug" mode: 

AquaMail-autosetup.xml

at the root of the phone's internal

2. Install a mail app called AquaMail from Play

3. Set up an account

4. Check mail

5. Try to open a message -> boom

09-15 12:10:12.219 E/StrictMode(24516): java.lang.Throwable: Explicit termination method 'close' not called
09-15 12:10:12.219 E/StrictMode(24516): 	at dalvik.system.CloseGuard.open(CloseGuard.java:180)
09-15 12:10:12.219 E/StrictMode(24516): 	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:127)
09-15 12:10:12.219 E/StrictMode(24516): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startChromiumLocked(WebViewChromiumFactoryProvider.java:16107)
09-15 12:10:12.219 E/StrictMode(24516): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.ensureChromiumStartedLocked(WebViewChromiumFactoryProvider.java:334)
09-15 12:10:12.219 E/StrictMode(24516): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startYourEngines(WebViewChromiumFactoryProvider.java:417)
09-15 12:10:12.219 E/StrictMode(24516): 	at com.android.webview.chromium.WebViewChromium.init(WebViewChromium.java:162)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.webkit.WebView.<init>(WebView.java:618)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.webkit.WebView.<init>(WebView.java:554)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.webkit.WebView.<init>(WebView.java:537)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.webkit.WebView.<init>(WebView.java:524)
09-15 12:10:12.219 E/StrictMode(24516): 	at org.kman.AquaMail.view.MessageWebView.<init>(MessageWebView.java:34)
09-15 12:10:12.219 E/StrictMode(24516): 	at org.kman.AquaMail.view.MessageDisplayWebView.<init>(MessageDisplayWebView.java:34)
09-15 12:10:12.219 E/StrictMode(24516): 	at java.lang.reflect.Constructor.newInstance(Native Method)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.createView(LayoutInflater.java:631)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:776)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:716)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:847)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:810)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:855)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:810)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:527)
09-15 12:10:12.219 E/StrictMode(24516): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:429)

My strict mode setup:

StrictMode.VmPolicy.Builder builder = new StrictMode.VmPolicy.Builder();

builder.detectLeakedClosableObjects();

^^^ This triggers on a file left open

builder.penaltyLog();
builder.penaltyDeath();

^^^ This causes the app's process to terminate

StrictMode.VmPolicy policy = builder.build();
StrictMode.setVmPolicy(policy);

What is the expected behavior?
No strict mode violation

What went wrong?
Strict mode violation

Crashed report ID: No

How much crashed? Whole browser

Is it a problem with a plugin? No 

Did this work before? Yes Broke in 54.0.2840.25, can't be more specific, sorry

Chrome version: 54.0.2840.25  Channel: beta
OS Version: 6.0.1
Flash Version: N/A

Seeing this on a Huawei Honor 5C and a Samsung S7 Edge, but I don't think the devices matter.

The stack trace is the same on both.

Both have Android 6, not sure if this matters, should happen from 4.4 onward.
 

Comment 1 by torne@chromium.org, Sep 15 2016

Components: Mobile>WebView

Comment 2 by torne@chromium.org, Sep 15 2016

This stack trace looks very weird: it's referring to a line number in WebViewChromiumFactoryProvider that definitely doesn't exist (line 16107 in a file that only has 700-800 lines depending on version), and we don't use RandomAccessFile from there.

The only place where we *do* use RandomAccessFile in non-test code that I can find is in AwBrowserProcess.tryObtainingDataDirLockOrDie. The file there is indeed not closed, but this is intentional as it's a lock file that has an active file lock held on it, and I would expect this to not generate a strict mode warning. Also, this code has not changed whatsoever for a very long time, and so would not cause a new regression in M54.

There is a known problem with a number of Huawei devices that they don't actually *use* our webview, and instead use Huawei's own customised version that does not receive updates at all. That might conceivably explain why this happens on a Huawei device, if it's one of those, since the customised code might well introduce strict mode violations, but if that's the case then 1) we can't fix it, because the device doesn't use our updates anyway and 2) I'm very surprised to hear that the same stack would happen on a Samsung S7 Edge, because we're not aware of Samsung having ever done this.

So, we should try to repro this, but also, a couple of questions for the reporter:

1) Is the stack on the Samsung device really *exactly* the same, including the line numbers? If it's even a tiny bit different, can you attach that as well?

2) Can we get a full bugreport from the Huawei device? This will allow us to confirm whether it's using our webview or not.

3) Does it definitely stop happening if you revert to the previous version of WebView? If so, what version is that?

Comment 3 by kmans...@gmail.com, Sep 15 2016

1 - Yes, same exact stack trace, same line numbers as far as I can tell, please see below.

2 - Yes, uploaded to Google Drive, please contact me if you're unable to access it:

https://drive.google.com/drive/folders/0ByN0LdMzTK27flZXd0RDQVh2ZlVNeEFsSTREYlF3Rmw1QU81OUhvNkxmcENyNF9tdndzVWM?usp=sharing

3 - I have a Sony Z3 Compact which had not been powered up for a while (I just came back from vacation).

Booted it up, no violation with WebView 53.0.2785.90.

Updated to 54.0.2840.25 -> boom.

Same exact stack trace, same line numbers as on the Huawei 5C and the Samsung S7 Edge.

------

Huawei Honor 5C

09-15 19:57:08.905 E/StrictMode(19782): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
09-15 19:57:08.905 E/StrictMode(19782): java.lang.Throwable: Explicit termination method 'close' not called
09-15 19:57:08.905 E/StrictMode(19782): 	at dalvik.system.CloseGuard.open(CloseGuard.java:180)
09-15 19:57:08.905 E/StrictMode(19782): 	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:127)
09-15 19:57:08.905 E/StrictMode(19782): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startChromiumLocked(WebViewChromiumFactoryProvider.java:16107)
09-15 19:57:08.905 E/StrictMode(19782): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.ensureChromiumStartedLocked(WebViewChromiumFactoryProvider.java:334)
09-15 19:57:08.905 E/StrictMode(19782): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startYourEngines(WebViewChromiumFactoryProvider.java:417)
09-15 19:57:08.905 E/StrictMode(19782): 	at com.android.webview.chromium.WebViewChromium.init(WebViewChromium.java:162)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.webkit.WebView.<init>(WebView.java:606)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.webkit.WebView.<init>(WebView.java:542)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.webkit.WebView.<init>(WebView.java:525)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.webkit.WebView.<init>(WebView.java:512)
09-15 19:57:08.905 E/StrictMode(19782): 	at org.kman.AquaMail.view.MessageWebView.<init>(MessageWebView.java:34)
09-15 19:57:08.905 E/StrictMode(19782): 	at org.kman.AquaMail.view.MessageDisplayWebView.<init>(MessageDisplayWebView.java:34)
09-15 19:57:08.905 E/StrictMode(19782): 	at java.lang.reflect.Constructor.newInstance(Native Method)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.createView(LayoutInflater.java:641)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:791)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:731)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:862)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:825)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:865)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:825)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:537)
09-15 19:57:08.905 E/StrictMode(19782): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:437)

Samsung S7 Edge

09-15 19:59:13.599 E/StrictMode(27172): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
09-15 19:59:13.599 E/StrictMode(27172): java.lang.Throwable: Explicit termination method 'close' not called
09-15 19:59:13.599 E/StrictMode(27172): 	at dalvik.system.CloseGuard.open(CloseGuard.java:180)
09-15 19:59:13.599 E/StrictMode(27172): 	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:127)
09-15 19:59:13.599 E/StrictMode(27172): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startChromiumLocked(WebViewChromiumFactoryProvider.java:16107)
09-15 19:59:13.599 E/StrictMode(27172): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.ensureChromiumStartedLocked(WebViewChromiumFactoryProvider.java:334)
09-15 19:59:13.599 E/StrictMode(27172): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startYourEngines(WebViewChromiumFactoryProvider.java:417)
09-15 19:59:13.599 E/StrictMode(27172): 	at com.android.webview.chromium.WebViewChromium.init(WebViewChromium.java:162)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.webkit.WebView.<init>(WebView.java:618)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.webkit.WebView.<init>(WebView.java:554)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.webkit.WebView.<init>(WebView.java:537)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.webkit.WebView.<init>(WebView.java:524)
09-15 19:59:13.599 E/StrictMode(27172): 	at org.kman.AquaMail.view.MessageWebView.<init>(MessageWebView.java:34)
09-15 19:59:13.599 E/StrictMode(27172): 	at org.kman.AquaMail.view.MessageDisplayWebView.<init>(MessageDisplayWebView.java:34)
09-15 19:59:13.599 E/StrictMode(27172): 	at java.lang.reflect.Constructor.newInstance(Native Method)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.createView(LayoutInflater.java:631)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:776)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:716)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:847)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:810)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:855)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:810)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:527)
09-15 19:59:13.599 E/StrictMode(27172): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:429)


Sony Z3 Compact

Before: 53.0.2785.90 - no crash

Updated to: 54.0.2840.25

09-15 20:09:36.571 E/StrictMode(25964): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
09-15 20:09:36.571 E/StrictMode(25964): java.lang.Throwable: Explicit termination method 'close' not called
09-15 20:09:36.571 E/StrictMode(25964): 	at dalvik.system.CloseGuard.open(CloseGuard.java:180)
09-15 20:09:36.571 E/StrictMode(25964): 	at java.io.RandomAccessFile.<init>(RandomAccessFile.java:127)
09-15 20:09:36.571 E/StrictMode(25964): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startChromiumLocked(WebViewChromiumFactoryProvider.java:16107)
09-15 20:09:36.571 E/StrictMode(25964): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.ensureChromiumStartedLocked(WebViewChromiumFactoryProvider.java:334)
09-15 20:09:36.571 E/StrictMode(25964): 	at com.android.webview.chromium.WebViewChromiumFactoryProvider.startYourEngines(WebViewChromiumFactoryProvider.java:417)
09-15 20:09:36.571 E/StrictMode(25964): 	at com.android.webview.chromium.WebViewChromium.init(WebViewChromium.java:162)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.webkit.WebView.<init>(WebView.java:606)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.webkit.WebView.<init>(WebView.java:542)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.webkit.WebView.<init>(WebView.java:525)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.webkit.WebView.<init>(WebView.java:512)
09-15 20:09:36.571 E/StrictMode(25964): 	at org.kman.AquaMail.view.MessageWebView.<init>(MessageWebView.java:34)
09-15 20:09:36.571 E/StrictMode(25964): 	at org.kman.AquaMail.view.MessageDisplayWebView.<init>(MessageDisplayWebView.java:34)
09-15 20:09:36.571 E/StrictMode(25964): 	at java.lang.reflect.Constructor.newInstance(Native Method)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.createView(LayoutInflater.java:619)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:764)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:704)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:835)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:798)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.rInflate(LayoutInflater.java:838)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.rInflateChildren(LayoutInflater.java:798)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:515)
09-15 20:09:36.571 E/StrictMode(25964): 	at android.view.LayoutInflater.inflate(LayoutInflater.java:423)

I've verified that this happens on a Nexus device as well with WebView 54 (and doesn't repro with 53) :/

The only CL I can see that has been poking around in that specific code since 53 is https://codereview.chromium.org/2076623002 but that shouldn't affect this..?

Comment 5 by torne@chromium.org, Sep 16 2016

OK, so I think the weird looking stack is caused by proguard optimisation, which was recently enabled - I suspect it's inlining methods, which would cause the frames in-between to be missing, and might also mangle the line numbers. I think it's supposed to be possible to demangle the stack back to its original state using the mapping table that proguard emits at build time, but I'm not sure 1) whether we keep those around for builds 2) how to do it 3) whether it even works for optimisation, or only for obfuscation.

I still can't see any place where we use RandomAccessFile other than the data directory lock, which doesn't appear to have changed in 54 (it's never called close(), so if that specific case triggers CloseGuard it should have done so in 53 as well).

I wonder if proguard's optimisation has actually broken it. I'm not sure in what revision we started allowing proguard to optimise webview code but it was pretty recently..

Comment 6 by kmans...@gmail.com, Sep 16 2016

Re: ProGuard - sounds plausible. The process of optimizing does leave around map files that can be used to un-mangle, but..

If/when you have any test builds that you'd like me to try -- be it with a real fix, or with ProGuard disabled -- I'll be happy to.

Comment 7 by torne@chromium.org, Sep 23 2016

Cc: smaier@chromium.org
smaier@, do you know how we can demangle this stack trace to find where the caller really is, per my comment 5?

We can repro it on official builds but not locally on tip of tree, and we're confused by this since the code hasn't changed, so either we're mistaken about where it's coming from or we don't understand under what circumstances proguard optimisations are turned on..
ping

Comment 9 by boliu@chromium.org, Oct 13 2016

smaier has left google already I think, in case you are still waiting for a reply
Oooooh, thanks Bo :P
Is there any update on this issue? I see the stack trace and strict mode violation from comment 1 when initializing the IMA SDK (see https://developers.google.com/interactive-media-ads/docs/sdks/android/). Thanks.
Owner: gsennton@chromium.org
Status: Assigned (was: Unconfirmed)
Whoopsie, not really, I can take a look again. I think the last time I looked this occurred flakily.

Comment 13 by kmans...@gmail.com, Oct 31 2016

I'm pretty sure it happens every time on my 6.0 phone --

-- every time *once* per fresh restart of the app, i.e. per new app process.

Which makes sense since it's in the code that loads the Chrome machinery, and this only happens once per new app process.

You can use Aqua Mail in Google Play, and create a dummy file called "AquaMail-autosetup.xml" at the root of the phone's "large built-in storage" to enable strict mode checks.
Alright, this consistently reproduces for me now (with a custom test app). And it reproduces on ToT, wuhuu!
Cc: torne@chromium.org
Hmm, I'm a bit confused by the way the file and the file lock are used - it looks like the finalizer of the RandomAccessFile closes the RandomAccessFile so IIUC we should really be holding on to that object (the RandomAccessFile) rather than letting it be garbage collected. But my understanding of file locks is very limited :)

Maybe in 53 and before we didn't gc the RandomAccessFile for a loooong time?
We should be able to solve this by just holding a reference to the RandomAccessFile for as long as we hold a reference to the file lock - however - to not hit this strictmode violation on shutdown I think we will have to explicitly close the file at some time during shutdown (not sure how we can do that).

I wonder why we don't hit this case in the AwStrictModeTest.
Right, we probably just don't have time to call finalize on the RandomAccessFile during the test...
To clarify my comments from yesterday: we know how to fix this, and I'll upload a CL soon. We would however like to add a test to ensure this doesn't regress in the future - but there usually isn't a reliable way to cause the JVM to GC / call finalizers at a certain time to repro this issue in a test.
Project Member

Comment 19 by bugdroid1@chromium.org, Nov 1 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7c1c15a67b2a3523ff4380cd7845a96331438326

commit 7c1c15a67b2a3523ff4380cd7845a96331438326
Author: gsennton <gsennton@chromium.org>
Date: Tue Nov 01 14:12:22 2016

[Android WebView] Keep a reference to the exclusive data dir lock file.

RandomAccessFile has a CloseGuard which causes a StrictMode violation
during RandomAccessFile.finalize(), i.e. when a RandomAccessFile is
garbage collected. We sometimes hit this StrictMode violation, meaning
that we sometimes close the corresponding file and its file lock
(because the finalizer also closes the actual file).

Instead of throwing away the reference to the data dir lock file, store
it until process termination to ensure we never unlock the file lock
(and to ensure we don't hit the StrictMode violation).

BUG= 647291 

Review-Url: https://codereview.chromium.org/2465203003
Cr-Commit-Position: refs/heads/master@{#428994}

[modify] https://crrev.com/7c1c15a67b2a3523ff4380cd7845a96331438326/android_webview/java/src/org/chromium/android_webview/AwBrowserProcess.java

For anyone interested in whether this now works:
AFAICT the fix in #19 is included in 56.0.2907.0 which is the current version of Chrome Canary available on the Play Store.

In Android Nougat we added the ability to use Chrome as your WebView implementation so: 
If you have a device running Android Nougat you can download Chrome Canary from the Play Store onto that device and then change the WebView implementation setting (Settings -> Developer options -> WebView implementation) to "Chrome Canary".

Your app should then not be crashing with the StrictMode violation reported in this bug :).  
Hmmm, I'm still trying to find out why I can't hit this violation in a chromium instrumentation test - in a CTS test I can hit the violation reliably by running a GC during the test, but during the instrumentation test I run GC 15 times and the RandomAccessFile finalizer is never called..
An update on this:
After looking at the Android code in master it looks like RandomAccessFile passes a reference to itself to FileChannelImpl (which is returned by RandomAccessFile.getChannel()).

When calling FileChannel.tryLock() the FileChannelImpl passes a reference of itself to FileLockImpl which holds on to that reference.
That FileLockImpl is what we are referencing through AwBrowserProcess.sExclusiveFileLock - so by keeping sExclusiveFileLock we should still hold onto the RandomAccessFile, and the file itself should never close.

Here is the output I get from a heap dump analyzer:

Class Name                                                                                                         | Shallow Heap | Retained Heap
--------------------------------------------------------------------------------------------------------------------------------------------------
class org.chromium.android_webview.AwBrowserProcess @ 0x12d26160 System Class                                      |           24 |            56
|- <class> class java.lang.Class @ 0x6f8fe478 System Class                                                         |           32 |           664
|- <classloader> dalvik.system.PathClassLoader @ 0x12c98670 Native Stack                                           |           40 |         2,368
|- TAG java.lang.String @ 0x12cdc760 Unknown                                                                       |           24 |            72
|- PRIVATE_DATA_DIRECTORY_SUFFIX java.lang.String @ 0x12ce29a0 Unknown                                             |           24 |            56
|- EXCLUSIVE_LOCK_FILE java.lang.String @ 0x12cfa388 Unknown                                                       |           24 |            72
|- $classOverhead byte[16] @ 0x12d26161  ................                                                          |           32 |            32
|- sExclusiveFileLock sun.nio.ch.FileLockImpl @ 0x12d5a420                                                         |           40 |            40
|  |- <class>, shadow$_klass_ class sun.nio.ch.FileLockImpl @ 0x6f946b40 System Class                              |            8 |           368
|  |- channel sun.nio.ch.FileChannelImpl @ 0x12d56350                                                              |           56 |           152
|  |  |- <class>, shadow$_klass_ class sun.nio.ch.FileChannelImpl @ 0x6f84d8a0 System Class                        |           48 |           520
|  |  |- closeLock java.lang.Object @ 0x12caae08                                                                   |            8 |             8
|  |  |- positionLock java.lang.Object @ 0x12caae10                                                                |            8 |             8
|  |  |- nd sun.nio.ch.FileDispatcherImpl @ 0x12caae18                                                             |            8 |             8
|  |  |- path java.lang.String @ 0x12d17b30                                                                        |           24 |           192
|  |  |- fd java.io.FileDescriptor @ 0x12d39d40                                                                    |           16 |            16
|  |  |- fileLockTable sun.nio.ch.SharedFileLockTable @ 0x12d39d70                                                 |           16 |            16
|  |  |- threads sun.nio.ch.NativeThreadSet @ 0x12d57568                                                           |           24 |            56
|  |  |- parent org.chromium.android_webview.AwBrowserProcess$2 @ 0x12d5a3d0                                       |           40 |           448
|  |  |  |- <class>, shadow$_klass_ class org.chromium.android_webview.AwBrowserProcess$2 @ 0x12d59400 System Class|            8 |           480
|  |  |  |- closeLock java.lang.Object @ 0x12caae00                                                                |            8 |             8
|  |  |  |- path java.lang.String @ 0x12d17b30                                                                     |           24 |           192
|  |  |  |- guard dalvik.system.CloseGuard @ 0x12d39d30                                                            |           16 |           376
|  |  |  |- fd java.io.FileDescriptor @ 0x12d39d40                                                                 |           16 |            16
|  |  |  |- channel sun.nio.ch.FileChannelImpl @ 0x12d56350                                                        |           56 |           152
|  |  |  |- scratch byte[8] @ 0x12d57550  ........                                                                 |           24 |            24
|  |  |  '- Total: 7 entries                                                                                       |              |              
|  |  '- Total: 9 entries                                                                                          |              |              
|  '- Total: 2 entries                                                                                             |              |              
--------------------------------------------------------------------------------------------------------------------------------------------------


AFAICT the object labeled

"parent org.chromium.android_webview.AwBrowserProcess$2 @ 0x12d5a3d0"

is the RandomAccessFile - so it is indeed referenced from sExclusiveFileLock.

This should mean that my CL
https://codereview.chromium.org/2465203003/
(explicitly storing the RandomAccessFile in AwBrowserProcess) shouldn't actually fix this bug.

I'll have to investigate further :)
I tested 56.0.2907.0 with my test-app - and added a call to Runtime.getRuntime().gc() which then causes the StrictMode violation - I guess I've just added one more layer of references before the finalizer is called.

I'm a bit confused now - it seems like this would imply that the class loader that loaded the static variables in AwBrowserProcess is gc'd?
So we figured this out: Gustav's CL is not actually necessary, and doesn't help. The problem is that Proguard optimises away the sExclusiveFileLock field because it's never read (the optimisation is field/removal/writeonly) and this causes the file lock, and thus the file, to become eligible for GC immediately. Trying to save the file in a static field doesn't help, because that field is *also* removed by the proguard optimisation.

Proguard's optimisation here is non-semantically-equivalent in the case where the value stored in the field has a finaliser or enqueued weak/phantom reference that will trigger a side effect upon it becoming eligible for GC.

While this is a pretty obscure edge case, I'm tempted to suggest that we try disabling field/removal/writeonly and see what the dex size impact is; if it's miniscule, we can probably just leave it off to avoid this case anyway.

Also, it seems like fields which are only written to and not read could be detected by a linter (or findbugs), and then we could simply fix the source code instead of "optimising" the compiled bytecode, which would enable us to flag this field as an ignored case..
Thanks for the update! (I'm the original reporter).

Alright!

I have some numbers for the size of classes.dex with and without the 'field/removal/writeonly' optimization:

Chrome:  (unzip -v apks/Chrome.apk | grep classes)
Uncompressed
opt removed:     5714496
opt still there: 5670532
diff: 43964

Compressed
opt removed:     2512376
opt still there: 2491927
diff: 20449


WebView  (unzip -v apks/SystemWebViewGoogle.apk | grep classes)
Uncompressed
opt removed:     1005192
opt still there: 999208
diff: 5984

Compressed
opt removed:     434089
opt still there: 430871
diff: 3218
Also verified that the proguard change fixes the StrictMode CTS I created to check this kind of error (including running Runtime.getRuntime().gc() five times), and verified that
AwBrowserProcess.sExclusiveFileLock
AwBrowserProcess.sLockFile
are in a heap dump collected during the CTS test after AwBrowserProcess.start() was called.
I think the main reason the proguard optimization exists, is that many fields become write-only only after dead code is eliminated.

Would storing the reference in an AtomicReference<>, or in native via JNI work around this?

Also - for future reference, instructions for de-mangling java stacks is here: 
https://chromium.googlesource.com/chromium/src/+/master/docs/android_debugging_instructions.md#Deobfuscating-Stack-Traces-Java

The .mapping files are archived alongside official builds (googler-only access). However, when this bug was hit, there was a bug with archiving where some .mapping files were slightly off :(. 

Comment 29 by torne@chromium.org, Nov 10 2016

Storing it in an AtomicReference won't be guaranteed to help. Storing it in native would work. It's probably sufficient to just -keep the field in the webview proguard config though; we'll try that first. That should prevent the optimiser from deleting it (on the assumption that, say, it's accessed by reflection it can't see).
The real fix for this is now in https://codereview.chromium.org/2489333003/

Note to self: we can revert the patch in comment #19 given that that CL doesn't solve this bug. 
Project Member

Comment 31 by bugdroid1@chromium.org, Nov 11 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/d7730964c696db73bde4cc1ea6d07d3f09f85765

commit d7730964c696db73bde4cc1ea6d07d3f09f85765
Author: gsennton <gsennton@chromium.org>
Date: Fri Nov 11 13:46:22 2016

WebView Proguard: Keep AwBrowserProcess.sExclusiveFileLock.

Static fields in Java are often assumed to stay alive throughout the
runtime of the entire program. However, the proguard
field/removal/writeonly optimization removes even static fields that are
only written to. This breaks some WebView code that relies on static
fields to hold onto a file-lock which prevents file-access from other
processes.

In this CL we explicitly tell proguard to keep
AwBrowserProcess.sExclusiveFileLock.

BUG= 647291 

Review-Url: https://codereview.chromium.org/2489333003
Cr-Commit-Position: refs/heads/master@{#431556}

[modify] https://crrev.com/d7730964c696db73bde4cc1ea6d07d3f09f85765/android_webview/apk/java/proguard.flags

Note to self: the fix (in comment 31) went into 56.0.2917.0, I've only kept this bug open because it might be a good idea to ensure we don't run into this in the future again (but that would require either running release-built instrumentation tests, or running some StrictMode CTS tests with release-built WebViews. 

Comment 33 by kmans...@gmail.com, Dec 16 2016

Checked 56.0.2924.23, yes "tentatively" looks good to me. I'll keep an eye on it.

There is a new "error" in the logcat though.

Is this related? Unrelated but legit? Should I file a new bug?

chromium  E  [ERROR:interface_registry.cc(210)] Failed to locate a binder for interface: autofill::mojom:
   :PasswordManagerDriver requested by: content_renderer exposed by: content_browser via Interf
   aceProviderSpec "navigation:frame".
E  InterfaceRegistry(navigation:frame):
E  Owned by:
E    content_browser@ run as: e12dde29-690a-49b0-a804-f9a61b44bce6
E    Providing:
E      capability: renderer containing interfaces:
E        autofill::mojom::AutofillDriver
E        autofill::mojom::PasswordManagerDriver
E        blink::mojom::MediaSessionService
E        blink::mojom::PermissionService
E        blink::mojom::PresentationService
E        blink::mojom::SensitiveInputVisibilityService
E        blink::mojom::ShapeDetection
E        blink::mojom::WebBluetoothService
E        blink::mojom::WebSocket
E        content::mojom::BrowserTarget
E        device::VibrationManager
E        device::mojom::GeolocationService
E        device::mojom::SensorProvider
E        device::mojom::VRService
E        device::mojom::WakeLockService
E        device::nfc::mojom::NFC
E        device::usb::DeviceManager
E        media::mojom::InterfaceFactory
E        media::mojom::RemoterFactory
E        media::mojom::Renderer
E        mojom::MediaDevicesDispatcherHost
E        payments::mojom::PaymentRequest
E        web_restrictions::mojom::WebRestrictions
E    Requiring:
E      From: content_renderer:
E        browser
E  Bound to:
E    content_renderer@2_1 run as: e12dde29-690a-49b0-a804-f9a61b44bce6
E    Providing:
E      capability: browser containing interfaces:
E        autofill::mojom::AutofillAgent
E        autofill::mojom::PasswordAutofillAgent
E        autofill::mojom::PasswordGenerationAgent
E        blink::mojom::AppBannerController
E        content::mojom::ImageDownloader
E        mojom::MediaDevicesListener
E    Requiring:
E      From: content_browser:
E        renderer
E  Binders registered for:
E   * autofill::mojom::AutofillDriver
E   * blink::mojom::MediaSessionService
E   * blink::mojom::PermissionService
E   * blink::mojom::PresentationService
E   * blink::mojom::ShapeDetection
E   * blink::mojom::WebBluetoothService
E   * blink::mojom::WebSocket
E   * device::VibrationManager
E   * device::mojom::GeolocationService
E   * device::mojom::VRService
E   * device::mojom::WakeLockService
E   * device::nfc::mojom::NFC
E   * media::mojom::InterfaceFactory
E   * mojom::MediaDevicesDispatcherHost
E   * web_restrictions::mojom::WebRestrictions
E   * - denotes an interface exposed to remote per policy.

That kind of mojo error is indeed unrelated to this bug.
Also, that 'error' is not an actual error as per  crbug.com/662040#c50 

Comment 35 by boliu@chromium.org, Dec 16 2016

But dumping that into the logcat is not ok. Yes, please file another bug with the webview template.
Status: Fixed (was: Assigned)
I'm closing this since the actual bug is fixed.
For tasks related to ensuring strictmode doesn't cause crashes we have  crbug.com/655167  

Sign in to add a comment