New issue
Advanced search Search tips

Issue 692816 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Apr 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 3
Type: Bug
Proj-XR
Proj-XR-VR



Sign in to add a comment

Instrumentation tests failed due to StrictMode policy violation

Project Member Reported by leilei@chromium.org, Feb 15 2017

Issue description

Chrome Version: Latest build from trunk
OS: Android 7.1.2
Device: Pixel XL
VR Service: 1.2.146064240

What steps will reproduce the problem?
(1) Prepare the device:
    Install vr service from play store
    Install Daydream app from play store and set up daydream app
(2) build chrome and test apk
    ninja -C out/Debug -j 50 chrome
    ninja -C out/Debug -j 50 chrome_public_test_vr_apk
(3) Run instrumentation tests with following command:
   ./out/Debug/bin/run_chrome_public_test_vr_apk  -v

What is the expected result?
All the tests pass

What happens instead?
All the tests failed with the following error message:
I   43.164s run_tests_on_device(HT67R0200128)  detected failure in org.chromium.chrome.browser.vr_shell.WebVrTest#testPoseDataUnfocusedTab. raw output:
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: numtests=1
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: stream=
I   43.165s run_tests_on_device(HT67R0200128)    org.chromium.chrome.browser.vr_shell.WebVrTest:
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: id=InstrumentationTestRunner
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: test=testPoseDataUnfocusedTab
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: class=org.chromium.chrome.browser.vr_shell.WebVrTest
I   43.165s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: current=1
I   43.166s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS_CODE: 1
I   43.166s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: test=testPoseDataUnfocusedTab
I   43.166s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: class=org.chromium.chrome.test.ChromeActivityTestCaseBase$ChromeUncaughtExceptionHandler
I   43.166s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS: stack=android.os.StrictMode$StrictModeViolation: policy=18153503 violation=2
I   43.166s run_tests_on_device(HT67R0200128)    	at android.os.StrictMode.executeDeathPenalty(StrictMode.java:1539)
I   43.166s run_tests_on_device(HT67R0200128)    	at android.os.StrictMode.-wrap3(StrictMode.java)
I   43.166s run_tests_on_device(HT67R0200128)    	at android.os.StrictMode$AndroidBlockGuardPolicy.handleViolation(StrictMode.java:1532)
I   43.166s run_tests_on_device(HT67R0200128)    	at android.os.StrictMode$AndroidBlockGuardPolicy$1.run(StrictMode.java:1410)
I   43.167s run_tests_on_device(HT67R0200128)    	at android.os.Handler.handleCallback(Handler.java:751)
I   43.167s run_tests_on_device(HT67R0200128)    	at android.os.Handler.dispatchMessage(Handler.java:95)
I   43.167s run_tests_on_device(HT67R0200128)    	at android.os.Looper.loop(Looper.java:154)
I   43.167s run_tests_on_device(HT67R0200128)    	at android.app.ActivityThread.main(ActivityThread.java:6119)
I   43.167s run_tests_on_device(HT67R0200128)    	at java.lang.reflect.Method.invoke(Native Method)
I   43.167s run_tests_on_device(HT67R0200128)    	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
I   43.167s run_tests_on_device(HT67R0200128)    	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)
I   43.167s run_tests_on_device(HT67R0200128)    
I   43.168s run_tests_on_device(HT67R0200128)    Search logcat for "StrictMode policy violation" for full stack.
I   43.168s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_STATUS_CODE: -1
I   43.168s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_RESULT: shortMsg=Process crashed.
I   43.168s run_tests_on_device(HT67R0200128)    INSTRUMENTATION_CODE: 0

See the detailed log in logcat.txt in the attachment

 
logcat.txt
373 KB View Download

Comment 1 by leilei@chromium.org, Feb 15 2017

Labels: -Proj-VR-

Comment 2 by leilei@chromium.org, Feb 16 2017

Status: WontFix (was: Untriaged)
This issue happens only when headset is set to default, it works when headset is set either to daydream view or cardboard.
Status: Unconfirmed (was: WontFix)
Default is a valid value (i.e. the user has not configured a headset). Is this an issue with the tests or in Chrome? Either way, we should probably fix it, even if that means failing another way.
Owner: bsheedy@chromium.org
This appears to be something out of our control. Looking at the original logcat dump, some of the lines in the stack trace were obfuscated due to Proguard despite it being disabled for Chrome. I installed a slightly older (but still v1.2) Dogfood VRCore build I had lying around, which has the Proguard obfuscation disabled, and got the following trace:

02-16 13:52:07.401 23720 23720 D StrictMode: StrictMode policy violation; ~duration=177 ms: android.os.StrictMode$StrictModeDiskReadViolation: policy=22347807 violation=2
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.StrictMode$AndroidBlockGuardPolicy.onReadFromDisk(StrictMode.java:1293)
02-16 13:52:07.401 23720 23720 D StrictMode:    at java.io.UnixFileSystem.getSpace(UnixFileSystem.java:358)
02-16 13:52:07.401 23720 23720 D StrictMode:    at java.io.File.getTotalSpace(File.java:1669)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.storage.StorageManager.getStorageLowBytes(StorageManager.java:1041)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.storage.VolumeInfo.buildStorageVolume(VolumeInfo.java:362)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.android.server.MountService.getVolumeList(MountService.java:3069)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.storage.IMountService$Stub.onTransact(IMountService.java:1826)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Binder.execTransact(Binder.java:565)
02-16 13:52:07.401 23720 23720 D StrictMode: # via Binder call with stack:
02-16 13:52:07.401 23720 23720 D StrictMode: android.os.StrictMode$LogStackTrace
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.StrictMode.readAndHandleBinderCallViolations(StrictMode.java:1954)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Parcel.readExceptionCode(Parcel.java:1665)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Parcel.readException(Parcel.java:1634)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.storage.IMountService$Stub$Proxy.getVolumeList(IMountService.java:790)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.storage.StorageManager.getVolumeList(StorageManager.java:981)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Environment$UserEnvironment.getExternalDirs(Environment.java:87)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Environment.getExternalStorageDirectory(Environment.java:444)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.cardboard.ConfigUtils.getConfigFile(ConfigUtils.java:219)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.cardboard.ConfigUtils.readFromExternalStorage(ConfigUtils.java:247)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.cardboard.ConfigUtils.readDeviceParamsFromExternalStorage(ConfigUtils.java:74)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.cardboard.LegacyVrParamsProvider.readDeviceParams(LegacyVrParamsProvider.java:20)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.settings.n.readDeviceParams(VrSettings.java:580)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.daydream.da.b(VrSessionManager.java:4298)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.daydream.da.a(VrSessionManager.java:688)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.daydream.e.a(DaydreamManagerImpl.java:19632)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.common.a.g.onTransact(IDaydreamManager.java:103)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Binder.execTransact(Binder.java:565)
02-16 13:52:07.401 23720 23720 D StrictMode: # via Binder call with stack:
02-16 13:52:07.401 23720 23720 D StrictMode: android.os.StrictMode$LogStackTrace
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.StrictMode.readAndHandleBinderCallViolations(StrictMode.java:1954)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Parcel.readExceptionCode(Parcel.java:1665)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Parcel.readException(Parcel.java:1634)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.vrcore.common.api.IDaydreamManager$Stub$Proxy.prepareVr(SourceFile:332)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.google.vr.ndk.base.VrCoreSdkClient$1.onServiceConnected(SourceFile:408)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Handler.handleCallback(Handler.java:751)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.os.Looper.loop(Looper.java:154)
02-16 13:52:07.401 23720 23720 D StrictMode:    at android.app.ActivityThread.main(ActivityThread.java:6121)
02-16 13:52:07.401 23720 23720 D StrictMode:    at java.lang.reflect.Method.invoke(Native Method)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
02-16 13:52:07.401 23720 23720 D StrictMode:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)

From the looks of that, the violation is happening without any call from Chrome, so we can't just wrap a function call with a more lenient StrictMode policy like we've done in the past. If this is going to be fixed, it'll require a change on Daydream's side.
It should also be noted that StrictMode violations don't have an effect unless they're set up to be fatal like they are for automated tests. From a normal user's perspective, they'd only know if they looked at the logcat output.
Status: Assigned (was: Unconfirmed)
Labels: -Restrict-View-Google
Labels: Pri-3 Type-Bug
Status: ExternalDependency (was: Assigned)
FYI, this is indeed a problem that's only fixable on VRCore's side. It's being tracked at b/35628570.

In the meantime, it's possible to run instrumentation tests with "--strict-mode off" or "--strict-mode flash". The off option makes StrictMode violations do nothing, while flash will cause the screen to flash when they occur, although they will not cause a fatal exception.

Comment 10 by bshe@chromium.org, Feb 28 2017

Is there a way to ignore these StrictMode violation for testing? Given that it is originated from VrCore, we should probably have a way to ignore these violations. 
Yes, command line arguments to do so are in comment 9.
This is now also happening when the viewer is Daydream view, although the stack trace is slightly different. Still not fixable from Chrome.

03-09 14:22:45.596 25402 25402 D StrictMode: StrictMode policy violation; ~duration=92 ms: android.os.StrictMode$StrictModeDiskReadViolation: policy=22347807 violation=2
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.StrictMode$AndroidBlockGuardPolicy.onReadFromDisk(StrictMode.java:1293)
03-09 14:22:45.596 25402 25402 D StrictMode:    at libcore.io.BlockGuardOs.open(BlockGuardOs.java:183)
03-09 14:22:45.596 25402 25402 D StrictMode:    at libcore.io.IoUtils.canOpenReadOnly(IoUtils.java:163)
03-09 14:22:45.596 25402 25402 D StrictMode:    at dalvik.system.DexPathList$Element.findNativeLibrary(DexPathList.java:550)
03-09 14:22:45.596 25402 25402 D StrictMode:    at dalvik.system.DexPathList.findLibrary(DexPathList.java:480)
03-09 14:22:45.596 25402 25402 D StrictMode:    at dalvik.system.BaseDexClassLoader.findLibrary(BaseDexClassLoader.java:84)
03-09 14:22:45.596 25402 25402 D StrictMode:    at java.lang.Runtime.loadLibrary0(Runtime.java:978)
03-09 14:22:45.596 25402 25402 D StrictMode:    at java.lang.System.loadLibrary(System.java:1562)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.daydream.cs.b(TransitionalHeadTracker.java:114)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.daydream.cs.a(TransitionalHeadTracker.java:84)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.daydream.DaydreamManagerImpl.a(DaydreamManagerImpl.java:735)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.daydream.e.a(DaydreamManagerImpl.java:4524)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.daydream.e.a(DaydreamManagerImpl.java:447)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.common.a.g.onTransact(IDaydreamManager.java:103)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Binder.execTransact(Binder.java:565)
03-09 14:22:45.596 25402 25402 D StrictMode: # via Binder call with stack:
03-09 14:22:45.596 25402 25402 D StrictMode: android.os.StrictMode$LogStackTrace
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.StrictMode.readAndHandleBinderCallViolations(StrictMode.java:1954)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Parcel.readExceptionCode(Parcel.java:1665)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Parcel.readException(Parcel.java:1634)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.vrcore.common.api.IDaydreamManager$Stub$Proxy.prepareVr(SourceFile:332)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.google.vr.ndk.base.VrCoreSdkClient$1.onServiceConnected(SourceFile:408)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Handler.handleCallback(Handler.java:751)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Handler.dispatchMessage(Handler.java:95)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.os.Looper.loop(Looper.java:154)
03-09 14:22:45.596 25402 25402 D StrictMode:    at android.app.ActivityThread.main(ActivityThread.java:6121)
03-09 14:22:45.596 25402 25402 D StrictMode:    at java.lang.reflect.Method.invoke(Native Method)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:889)
03-09 14:22:45.596 25402 25402 D StrictMode:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:779)
Project Member

Comment 13 by bugdroid1@chromium.org, Apr 8 2017

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

commit e2a2e605169bf31e451e1dc3f8e3e245c6fc18e5
Author: bsheedy <bsheedy@chromium.org>
Date: Sat Apr 08 01:15:36 2017

Re-enable StrictMode for VR e2e tests

The upgrade to VRCore 1.4 seems to have resolved the StrictMode violations
on their end, so re-enable StrictMode checking to check for legitimate browser
violations.

BUG= 692816 

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

[modify] https://crrev.com/e2a2e605169bf31e451e1dc3f8e3e245c6fc18e5/testing/buildbot/chromium.fyi.json

Closing this since this seems to have been fixed with VrCore 1.4
Status: Fixed (was: ExternalDependency)

Sign in to add a comment