This website uses cookies. By clicking Accept, you consent to the use of cookies. Click Here to learn more about how we use cookies.
Accept
Reject
Help
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 

Oculus Go intermittent segfault on UE 4.19 build - VrDriver.apk

SuperManualChar
Honored Guest

‎10-18-2018 05:30 PM

Hello all. I have a UE 4.19 project that I am trying to ship specifically for the Oculus Go. It's a museum installation piece that is designed to run 24/7.

The application runs at nearby 60fps on CPU2/GPU4 occaisionally dropping down the GPU3 when occlusion is doing it's work. The scene is about 60k tris and 44 draw calls so everything in the correct ranges. Vertex fogging is on, MSAA x4 and mobile multi view direct etc but other than that, all set up according to the docs.

After 5 - 120 seconds run time, I start seeing large black planes over the mid ground geometry. They only appear for a few frames and eventually the app will crash when one of the black planes is visible. Here is the best debug info I can get out of logcat just before and after the crash. Any help appreciated!

10-19 11:17:18.424: D/VrApi(11120): setSystemPerformance cpu: 3 gpu: 4
10-19 11:17:18.425: D/VrApiService(594): CPU_CLUSTER_0: Client 11120 sends freq request [13, 13]
10-19 11:17:18.425: D/VrApiService(594): CPU_CLUSTER_0: Next Perf Level = (13, 13)
10-19 11:17:18.425: D/VrApiService(594): CPU_CLUSTER_1: Client 11120 sends freq request [13, 13]
10-19 11:17:18.425: D/VrApiService(594): CPU_CLUSTER_1: Next Perf Level = (13, 13)
10-19 11:17:18.426: D/VrApiService(594): CPUBW: Client 11120 sends freq request [8, 11]
10-19 11:17:18.426: D/VrApiService(594): CPUBW: Next Perf Level = (8, 11)
10-19 11:17:18.427: D/VrApiService(594): GPUBW: Client 11120 sends freq request [9, 11]
10-19 11:17:18.427: D/VrApiService(594): GPUBW: Next Perf Level = (9, 11)
10-19 11:17:18.427: D/VrApiService(594): GPU: Client 11120 sends freq request [4, 4]
10-19 11:17:18.427: D/VrApiService(594): GPU: Next Perf Level = (4, 4)
10-19 11:17:18.428: I/Clocks(11120): LockClocks( cpu=3, gpu=4 ) - end (4.4 ms)
10-19 11:17:18.796: I/VrApi(11120): FPS=60,Prd=58ms,Tear=0,Early=0,Stale=0,VSnc=1,Lat=1,Fov=3,CPU2/GPU=4/4,1286/510MHz,OC=F,TA=E/C/C,SP=N/N/N,Mem=1554MHz,Free=1200MB,PSM=0,PLS=0,Temp=27.0C/25.0C,TW=1.17ms,App=15.01ms
10-19 11:17:18.882: I/UtilPoller(11120): GPU Util 0.994339 / CPU Util 0.833333 (avg 0.752715)
10-19 11:17:18.994: W/Adreno-GSL(11120): <gsl_ldd_control:548>: ioctl fd 53 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 71 Protocol error
10-19 11:17:18.994: W/Adreno-GSL(11120): <log_gpu_snapshot:457>: panel.gpuSnapshotPath is not set.not generating user snapshot
10-19 11:17:19.379: W/Adreno-GSL(11120): <gsl_ldd_control:548>: ioctl fd 53 code 0xc040094a (IOCTL_KGSL_GPU_COMMAND) failed: errno 35 Resource deadlock would occur
10-19 11:17:19.379: W/Adreno-GSL(11120): <log_gpu_snapshot:457>: panel.gpuSnapshotPath is not set.not generating user snapshot
10-19 11:17:19.380: W/Adreno-GSL(11120): <gsl_ldd_control:548>: ioctl fd 53 code 0xc0140933 (IOCTL_KGSL_TIMESTAMP_EVENT) failed: errno 22 Invalid argument
10-19 11:17:19.380: W/Adreno-GSL(11120): <ioctl_kgsl_syncobj_create:4125>: (36, 3a, 2884) fail 22 Invalid argument
10-19 11:17:19.554: E/cnss-daemon(586): Stale or unreachable neighbors, ndm state: 4
10-19 11:17:19.768: I/VrApi(11120): FPS=60,Prd=59ms,Tear=0,Early=0,Stale=0,VSnc=1,Lat=1,Fov=3,CPU2/GPU=3/4,1286/214MHz,OC=F,TA=E/C/C,SP=N/N/N,Mem=1554MHz,Free=1199MB,PSM=0,PLS=0,Temp=27.0C/25.0C,TW=1.16ms,App=15.99ms
10-19 11:17:19.768: I/VrApi(11120): --------- beginning of crash
10-19 11:17:19.882: A/libc(11120): Fatal signal 11 (SIGSEGV), code 1, fault addr 0xd68ec20 in tid 12318 (OVR::UtilPoller)
10-19 11:17:19.886: E/SettingsProxyService(986): Failed to get crash reports setting
10-19 11:17:19.886: E/SettingsProxyService(986): android.provider.Settings$SettingNotFoundException: crash_reports_enabled
10-19 11:17:19.886: E/SettingsProxyService(986): at android.provider.Settings$Secure.getIntForUser(Settings.java:4463)
10-19 11:17:19.886: E/SettingsProxyService(986): at android.provider.Settings$Secure.getInt(Settings.java:4448)
10-19 11:17:19.886: E/SettingsProxyService(986): at oculus.internal.services.SettingsProxyServiceImpl.getCrashReportsEnabled(SettingsProxyServiceImpl.java:32)
10-19 11:17:19.886: E/SettingsProxyService(986): at oculus.internal.ISettingsProxy$Stub.onTransact(ISettingsProxy.java:48)
10-19 11:17:19.886: E/SettingsProxyService(986): at android.os.Binder.execTransact(Binder.java:565)
10-19 11:17:19.891: I/crash-reporter(11120): failed to capture minidump crash
10-19 11:17:19.893: W/(6332): debuggerd: handling request: pid=11120 uid=10077 gid=10077 tid=12318
10-19 11:17:19.995: A/DEBUG(12355): *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
10-19 11:17:19.996: A/DEBUG(12355): Build fingerprint: 'oculus/vr_pacific/pacific:7.1.2/N2G48H/139090.3070.0:user/release-keys'
10-19 11:17:19.996: A/DEBUG(12355): Revision: '0'
10-19 11:17:19.996: A/DEBUG(12355): ABI: 'arm'
10-19 11:17:19.996: A/DEBUG(12355): pid: 11120, tid: 12318, name: OVR::UtilPoller  >>> com.visitor.mephisto <<<
10-19 11:17:19.996: A/DEBUG(12355): signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xd68ec20
10-19 11:17:19.996: A/DEBUG(12355):     r0 00000001  r1 b0f017f0  r2 a8e1caed  r3 00000004
10-19 11:17:19.996: A/DEBUG(12355):     r4 b3608d30  r5 0d68ec28  r6 b7dfdc00  r7 e799d19c
10-19 11:17:19.996: A/DEBUG(12355):     r8 00000000  r9 b7dfdc40  sl b0f017e0  fp b0f01830
10-19 11:17:19.996: A/DEBUG(12355):     ip d90101db  sp 0d68ec20  lr d8f7ef37  pc b3596b04  cpsr 800f0010
10-19 11:17:20.002: A/DEBUG(12355): backtrace:
10-19 11:17:20.002: A/DEBUG(12355):     #00 pc 00039b04  /system/priv-app/VrDriver/VrDriver.apk (offset 0xb07000)
10-19 11:17:20.002: A/DEBUG(12355):     #01 pc 00038b78  /system/priv-app/VrDriver/VrDriver.apk (offset 0xb07000)
10-19 11:17:20.002: A/DEBUG(12355):     #02 pc 000386fc  /system/priv-app/VrDriver/VrDriver.apk (offset 0xb07000)
10-19 11:17:20.002: A/DEBUG(12355):     #03 pc 0003af80  /system/priv-app/VrDriver/VrDriver.apk (offset 0xb07000)
10-19 11:17:20.002: A/DEBUG(12355):     #04 pc 00047923  /system/lib/libc.so (_ZL15__pthread_startPv+22)
10-19 11:17:20.002: A/DEBUG(12355):     #05 pc 0001a035  /system/lib/libc.so (__start_thread+6)
10-19 11:17:20.935: I/AudioFlinger(562): BUFFER TIMEOUT: remove(4103) from active list on thread 0xebf837c0
10-19 11:17:20.935: I/AudioFlinger(562): BUFFER TIMEOUT: remove(4104) from active list on thread 0xebf837c0
10-19 11:17:21.346: D/VRPowerManagerService(1252): processing message: sensor changed
10-19 11:17:21.346: I/VRPowerManagerService(1252): transition from HEADSET_MOUNTED to HEADSET_UNMOUNTED
10-19 11:17:21.350: W/VRLifecycleSessionManager(1586): No apps were active so skipping session.
10-19 11:17:21.350: W/VRLifecycleManager(1586): onHeadsetUnmounted
10-19 11:17:21.351: D/VRPowerManagerClient(1232): Headset state: 3
10-19 11:17:21.351: V/ControllerNotifications(1232): Handling unmount notification
10-19 11:17:21.353: D/TrackingService(1279): Received transition to STANDBY current is RUNNING 
10-19 11:17:21.353: D/TrackingService(1279): Setting power state to STANDBY
10-19 11:17:21.355: D/audio_hw_primary(562): adev_set_mic_mute state 0
10-19 11:17:21.356: I/PlatformPluginManager(1586): setHeadsetMountState: false
10-19 11:17:21.357: I/OVRPlatform(1586): [AudioManager] SetHeadsetMounted: false
10-19 11:17:21.357: I/OVRPlatform(1586): [AudioManager] Current headsetMounted_ false
10-19 11:17:21.357: I/OVRPlatform(1586): [AudioManager] Current headphoneStatus_: DISCONNECTED
10-19 11:17:21.357: I/OVRPlatform(1586): [PartyChat] Setting connection MicrophoneMutedState MUTED
10-19 11:17:21.357: W/VRLifecycleManager(1586): onHeadsetUnmounted
10-19 11:17:21.357: I/OVRPlatform(1586): [PartyChat] Updating playback mode to 0
10-19 11:17:22.632: W/ActivityManager(986):   Force finishing activity com.visitor.mephisto/com.epicgames.ue4.GameActivity
10-19 11:17:22.643: D/ActivityTrigger(986): ActivityTrigger activityPauseTrigger 
10-19 11:17:22.643: E/SettingsProxyService(986): Failed to get crash reports setting
10-19 11:17:22.643: E/SettingsProxyService(986): android.provider.Settings$SettingNotFoundException: crash_reports_enabled
10-19 11:17:22.643: E/SettingsProxyService(986): at android.provider.Settings$Secure.getIntForUser(Settings.java:4463)
10-19 11:17:22.643: E/SettingsProxyService(986): at android.provider.Settings$Secure.getInt(Settings.java:4448)
10-19 11:17:22.643: E/SettingsProxyService(986): at oculus.internal.services.SettingsProxyServiceImpl.getCrashReportsEnabled(SettingsProxyServiceImpl.java:32)
10-19 11:17:22.643: E/SettingsProxyService(986): at oculus.internal.ISettingsProxy$Stub.onTransact(ISettingsProxy.java:48)
10-19 11:17:22.643: E/SettingsProxyService(986): at android.os.Binder.execTransact(Binder.java:565)
10-19 11:17:22.644: D/crash-reporter(1442): user has disabled crash reports, not uploading crashes
10-19 11:17:22.651: I/VrAppLoader(986): VrApi Loader Version: 1.1.15.0-0-0 Jun 11 2018 11:32:55 
10-19 11:17:22.654: I/BootReceiver(986): Copying /data/tombstones/tombstone_05 to DropBox (SYSTEM_TOMBSTONE)
10-19 11:17:22.654: V/VrDriver(986): Loading 64-bit VrDriver.
10-19 11:17:22.655: I/DriverLoader(986): *Adding Layer: Rage
10-19 11:17:22.655: I/DriverLoader(986): *Adding Layer: PowerLevelSwitcher
10-19 11:17:22.655: I/DriverLoader(986): *Adding Layer: UtilPoller
10-19 11:17:22.655: I/DriverLoader(986): *Adding Layer: VrIntegrationLayer
10-19 11:17:22.655: I/DriverLoader(986): About to call StartLayer in vrapilayers.VrIntegrationLayer
10-19 11:17:22.655: D/VrIntegrationLayerJava(986): VrIntegrationLayer StartLayer: Loading libvrintegrationlayer.so
10-19 11:17:22.656: I/VrApiLayers(986): Initializing VrApiLayer
10-19 11:17:22.656: I/DriverLoader(986): VrapiLayer VrIntegrationLayer started
10-19 11:17:22.656: I/DriverLoader(986): About to call StartLayer in vrapilayers.UtilPoller
10-19 11:17:22.656: D/UtilPollerJava(986): UtilPoller StartLayer: Loading utilpoller.so
10-19 11:17:22.656: I/VrApiLayers(986): Initializing VrApiLayer
10-19 11:17:22.656: I/DriverLoader(986): VrapiLayer UtilPoller started
10-19 11:17:22.656: I/DriverLoader(986): About to call StartLayer in vrapilayers.PowerLevelSwitcher
10-19 11:17:22.656: D/PowerLevelSwitcherJava(986): PowerLevelSwitcher StartLayer: Loading powerlevelswitcher.so
10-19 11:17:22.657: I/VrApiLayers(986): Initializing VrApiLayer
10-19 11:17:22.657: I/DriverLoader(986): VrapiLayer PowerLevelSwitcher started
10-19 11:17:22.657: I/DriverLoader(986): About to call StartLayer in vrapilayers.Rage
10-19 11:17:22.659: W/(6332): debuggerd: resuming target 11120
10-19 11:17:22.659: I/Rage(986): nativeStartLayer: Starting Rage Detection
10-19 11:17:22.659: I/VrApiLayers(986): Initializing VrApiLayer
10-19 11:17:22.659: I/DriverLoader(986): VrapiLayer Rage started
10-19 11:17:22.659: I/Rage(986): -----dev_vrapi_Initialize------

0 Kudos
2 REPLIES 2

SuperManualChar
Honored Guest

‎10-22-2018 11:13 PM

Thank-you @imperativity - yes understood that running the unit 24/7 is not supported. The installation is actually designed to be run for 7 hours at a stretch.

Also I have narrowed down the cause of this crash to a single material in Unreal Engine. I am trying to located the shader instruction that is causing this. Will fill in more details as they come to hand.

Rehago
Honored Guest

‎09-10-2019 08:11 AM

Hi @SuperManualCharles, did you figure out, what exactly caused the problem? We also have a game that suddenly started to crash randomly. It would be very helpful to know, where to look for the error, as no debugging tool seems to be of much help.
Cheers
0 Kudos