Receiving OpenGL errors with Google Cardboard enabled

Good day!

I’m receiving such error on android device with enabled cardboard vr support:
Error

02-16 17:41:36.781: E/Unity(2757): OPENGL NATIVE PLUG-IN ERROR: GL_OUT_OF_MEMORY: Not enough memory left to execute command
02-16 17:41:36.781: E/Unity(2757): 
02-16 17:41:36.781: E/Unity(2757): (Filename: ./Runtime/GfxDevice/opengles/GfxDeviceGLES.cpp Line: 363)
02-16 17:41:36.794: E/Unity(2757): [EGL] Failed to create window surface: EGL_BAD_ALLOC: EGL failed to allocate resources for the requested operation.
02-16 17:41:36.794: E/Unity(2757): 
02-16 17:41:36.794: E/Unity(2757): (Filename: ./Runtime/GfxDevice/egl/WindowContextEGL.cpp Line: 138)
02-16 17:41:36.798: I/Unity(2757): Skipped rendering frame because GfxDevice is in invalid state (device lost)

Unity: 5.6.0b8.
Android: 6.0.1.
SOC: Snapdragon 801, Adreno 330.
Google VR SDK: 1.20.

Is it Unity beta bug or Google VR SDK?

Best regards

This is a bug in the base level Android NDK from Google that we integrate. It will be fixed in a future release of the NDK though I am not sure which one exactly. The usual repro scenario is to flip in/out of a VR scene in the same application instance. Is this what you are doing and eventually seeing?

If that is the case, simply closing the application may fix it. If not you might have to reboot the phone to get the system to clean up the memory.

Thanks for response!

Next trouble:
Google vr app is crashing in moment, when VRSettings are set to true on Samsung Galaxy S5 (G900H) with Android 5.0. On device with Snapdragon 801 and Android 6.0.1 it may crash on second time scene loaded or show popup message Google VR failed to initialize.

Unity: 5.6.0b8
Google VR SDK: 1.20

Any solutions for this?

Best regards!

What does the crash log in logcat tell you?

Here is log 1 with tag “Unity”:
Log1

03-10 06:37:23.946: E/Unity(32615): Error trying to call delegated method unload. null
03-10 06:37:23.951: E/Unity(32615): loadGoogleVr:  Exception caught loading. Attempt to invoke virtual method 'java.lang.Object com.unity3d.player.l.a(java.lang.String, java.lang.Object[])' on a null object reference
03-10 06:37:24.066: E/Unity(32615): Google VR had a fatal issue while loading. VR will not be available.

And here is log 2 without any tags and more detailed:
Log2

03-10 07:20:33.397: I/Unity(23232): Before execute action. Time to wait: 5
03-10 07:20:33.397: I/Unity(23232): 
03-10 07:20:33.397: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:33.402: I/Unity(23232): Before load video. Current index: 0
03-10 07:20:33.402: I/Unity(23232): 
03-10 07:20:33.402: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:33.412: I/Unity(23232): Event handler. Event type: Closing errorCode: None
03-10 07:20:33.412: I/Unity(23232): 
03-10 07:20:33.412: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:33.412: V/MediaPlayer-JNI(23232): reset
03-10 07:20:33.412: V/MediaPlayer(23232): reset
03-10 07:20:33.427: I/Unity(23232): [AVProVideo] Opening jar:file:///data/app/com.rg.ZooGo-1/base.apk!/assets/VRMovie.mp4 (offset 0)
03-10 07:20:33.427: I/Unity(23232): 
03-10 07:20:33.427: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:33.432: V/MediaPlayer-JNI(23232): reset
03-10 07:20:33.432: V/MediaPlayer(23232): reset
03-10 07:20:33.432: V/MediaPlayer-JNI(23232): setDataSourceFD: fd 65
03-10 07:20:33.432: V/MediaPlayer(23232): setDataSource(65, 384700616, 117910753)
03-10 07:20:33.437: V/MediaPlayerService(3618): Create new client(121) from pid 23232, uid 10550,
03-10 07:20:33.437: V/MediaPlayerService(3618): setDataSource fd=36, offset=384700616, length=117910753
03-10 07:20:33.437: V/MediaPlayerService(3618): st_dev  = 66317
03-10 07:20:33.437: V/MediaPlayerService(3618): st_mode = 33188
03-10 07:20:33.437: V/MediaPlayerService(3618): st_uid  = 1000
03-10 07:20:33.437: V/MediaPlayerService(3618): st_gid  = 1000
03-10 07:20:33.437: V/MediaPlayerService(3618): st_size = 522720385
03-10 07:20:33.442: V/MediaPlayerService(3618): player type = 3
03-10 07:20:33.442: V/AwesomePlayer(3618): setDefault
03-10 07:20:33.442: V/AwesomePlayer(3618): constructor
03-10 07:20:33.442: V/AwesomePlayer(3618): setDefault
03-10 07:20:33.447: V/AwesomePlayer(3618): reset_l()
03-10 07:20:33.447: V/AwesomePlayer(3618): notifyListner_l() msg (8-MEDIA_STOPPED), ext1 (0), ext2 (0)
03-10 07:20:33.447: V/AwesomePlayer(3618): cancelPlayerEvents (keepNotifications=0)
03-10 07:20:33.447: V/AwesomePlayer(3618): mAudioTrackVector clear
03-10 07:20:33.447: V/AwesomePlayer(3618): reset_l() mAudioPlayer successfully deleted
03-10 07:20:33.447: V/AwesomePlayer(3618): mSecCapture clear
03-10 07:20:33.447: V/AwesomePlayer(3618): mSecMediaClock clear
03-10 07:20:33.447: V/StagefrightPlayer(3618): StagefrightPlayer
03-10 07:20:33.447: V/AwesomePlayer(3618): setListener
03-10 07:20:33.447: V/StagefrightPlayer(3618): initCheck
03-10 07:20:33.447: V/AwesomePlayer(3618): AwesomePlayer running on behalf of uid 10550
03-10 07:20:33.447: V/AudioSink(3618): AudioOutput(623)
03-10 07:20:33.447: V/AwesomePlayer(3618): setAudioSink
03-10 07:20:33.447: V/StagefrightPlayer(3618): setDataSource(36, 384700616, 117910753)
03-10 07:20:33.447: V/AwesomePlayer(3618): reset_l()
03-10 07:20:33.447: V/AwesomePlayer(3618): notifyListner_l() msg (8-MEDIA_STOPPED), ext1 (0), ext2 (0)
03-10 07:20:33.447: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 8, 0, 0)
03-10 07:20:33.447: V/MediaPlayer(23232): message received msg=8, ext1=0, ext2=0
03-10 07:20:33.447: V/AwesomePlayer(3618): cancelPlayerEvents (keepNotifications=0)
03-10 07:20:33.447: V/AwesomePlayer(3618): mAudioTrackVector clear
03-10 07:20:33.447: V/AwesomePlayer(3618): reset_l() mAudioPlayer successfully deleted
03-10 07:20:33.447: V/AwesomePlayer(3618): mSecCapture clear
03-10 07:20:33.447: V/AwesomePlayer(3618): mSecMediaClock clear
03-10 07:20:33.447: V/MediaPlayer(23232): notify(8, 0, 0) callback on disconnected mediaplayer
03-10 07:20:33.492: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onInitialize : 6560
03-10 07:20:33.492: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onSetOnInfoListener : add 6560
03-10 07:20:33.492: I/PrGenericPlugin(3617): [F] ENTER onInitialize : 0x19a0
03-10 07:20:33.492: I/PrGenericPlugin(3617): [F] LEAVE onInitialize : 0x19a0
03-10 07:20:33.497: E/SEC_DRM_PLUGIN_Omafl(3617): OmaPlugin::onOpenDecryptSession(fd)::smile:rm2IsDrmFileByExt::file is NOT DRM by extension
03-10 07:20:33.497: W/SEC_DRM_PLUGIN_Playready(3617): PlayreadyPlugIn: Function[DRM_ASFVerify_Context_Initialize]; Line[4453]; File type[0]
03-10 07:20:33.497: W/SEC_DRM_PLUGIN_Playready(3617): PlayReadyPlugIn: Function[onOpenDecryptSession]; Line[2571]; DRM Result[0x80004005]
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] ENTER onOpenDecryptSession : 0x19a0 uri = 15 fd = 15
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] ENTER onGetOriginalMimeType : 0x19a0
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] LEAVE onGetOriginalMimeType : 0x19a0
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] ENTER onCanHandle : 0x19a0
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] LEAVE onCanHandle : 0x19a0
03-10 07:20:33.497: E/PrGenericPlugin(3617): PrGenericPlugin::onOpenDecryptSession() onCanHandle error
03-10 07:20:33.497: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onTerminate : 6560
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] ENTER onTerminate : 0x19a0
03-10 07:20:33.497: I/PrGenericPlugin(3617): check context leak for (0) entries in conextMap.
03-10 07:20:33.497: I/PrGenericPlugin(3617): [F] LEAVE onTerminate : 0x19a0
03-10 07:20:33.497: I/(3618): [../../src/codec_checker.cpp:49]
03-10 07:20:33.497: I/(3618): [CHK] allocating for H264 mediatype
03-10 07:20:33.497: I/(3618): [../../src/codec_checker.cpp:85]
03-10 07:20:33.497: I/(3618): svid_check_codec : mt(104)
03-10 07:20:33.497: I/(3618): [../../src/codec_checker.cpp:91]
03-10 07:20:33.497: I/(3618): [SVID] mediatype = H264
03-10 07:20:33.497: I/(3618): [../../src/vid/chk_h264.cpp:379]
03-10 07:20:33.497: I/(3618): [vui_dec] Not supported yet -> Skip
03-10 07:20:33.497: I/(3618): [../../src/codec_checker.cpp:73]
03-10 07:20:33.497: I/(3618): [SVID CHK] free ctx
03-10 07:20:33.497: I/SampleTable(3618): There are reordered frames present.
03-10 07:20:33.497: D/MPEG4Extractor(3618): uuid box parsing enter
03-10 07:20:33.497: D/MPEG4Extractor(3618): 360 xmp parsed
03-10 07:20:33.502: D/MPEG4Extractor(3618): uuid box parsing enter
03-10 07:20:33.502: D/MPEG4Extractor(3618): 360 xmp parsed
03-10 07:20:33.502: V/AwesomePlayer(3618): track of type 'video/avc' does not publish bitrate
03-10 07:20:33.502: V/AwesomePlayer(3618): mBitrate = -1 bits/sec
03-10 07:20:33.502: V/AwesomePlayer(3618): current audio track index (1) is added to vector
03-10 07:20:33.502: V/AwesomePlayer(3618): setDataSource_l: Audio(1), Video(1)
03-10 07:20:33.502: I/AwesomePlayer(3618): checkRightsStatus is not necessary - AwesomePlayer::setDataSource_l
03-10 07:20:33.502: V/MediaPlayerService(3618): [121] setParameter(1604)
03-10 07:20:33.502: V/StagefrightPlayer(3618): setParameter(key=1604)
03-10 07:20:33.502: V/AwesomePlayer(3618): setParameter key (1604)
03-10 07:20:33.502: V/AwesomePlayer(3618): Current Contet PID : 23232
03-10 07:20:33.502: V/MediaPlayerService(3618): [121] getParameter(1700)
03-10 07:20:33.542: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onInitialize : 5394
03-10 07:20:33.542: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onSetOnInfoListener : add 5394
03-10 07:20:33.542: I/PrGenericPlugin(3617): [F] ENTER onInitialize : 0x1512
03-10 07:20:33.542: I/PrGenericPlugin(3617): [F] LEAVE onInitialize : 0x1512
03-10 07:20:33.547: D/WVMDrmPlugIn(3617): WVMDrmPlugin::onTerminate : 5394
03-10 07:20:33.547: I/PrGenericPlugin(3617): [F] ENTER onTerminate : 0x1512
03-10 07:20:33.547: I/PrGenericPlugin(3617): check context leak for (0) entries in conextMap.
03-10 07:20:33.547: I/PrGenericPlugin(3617): [F] LEAVE onTerminate : 0x1512
03-10 07:20:33.552: I/(23232): [../../src/codec_checker.cpp:49]
03-10 07:20:33.552: I/(23232): [CHK] allocating for H264 mediatype
03-10 07:20:33.552: I/(23232): [../../src/codec_checker.cpp:85]
03-10 07:20:33.552: I/(23232): svid_check_codec : mt(104)
03-10 07:20:33.552: I/(23232): [../../src/codec_checker.cpp:91]
03-10 07:20:33.552: I/(23232): [SVID] mediatype = H264
03-10 07:20:33.552: I/(23232): [../../src/vid/chk_h264.cpp:379]
03-10 07:20:33.552: I/(23232): [vui_dec] Not supported yet -> Skip
03-10 07:20:33.552: I/(23232): [../../src/codec_checker.cpp:73]
03-10 07:20:33.552: I/(23232): [SVID CHK] free ctx
03-10 07:20:33.552: I/SampleTable(23232): There are reordered frames present.
03-10 07:20:33.552: D/MPEG4Extractor(23232): uuid box parsing enter
03-10 07:20:33.552: D/MPEG4Extractor(23232): 360 xmp parsed
03-10 07:20:33.557: D/MPEG4Extractor(23232): uuid box parsing enter
03-10 07:20:33.557: D/MPEG4Extractor(23232): 360 xmp parsed
03-10 07:20:33.557: V/MediaPlayer(23232): setVideoSurfaceTexture
03-10 07:20:33.557: V/MediaPlayerService(3618): [121] setVideoSurfaceTexture(0xb0afe340)
03-10 07:20:33.557: V/StagefrightPlayer(3618): setVideoSurfaceTexture
03-10 07:20:33.557: V/MediaPlayer(23232): prepareAsync
03-10 07:20:33.557: V/MediaPlayerService(3618): [121] setAudioStreamType(3)
03-10 07:20:33.557: V/MediaPlayerService(3618): [121] prepareAsync
03-10 07:20:33.557: V/AwesomePlayer(3618): prepareAsync
03-10 07:20:33.557: V/MediaPlayer-JNI(23232): setLooping: 0
03-10 07:20:33.557: V/MediaPlayer(23232): MediaPlayer::setLooping
03-10 07:20:33.562: V/MediaPlayerService(3618): [121] setLooping(0)
03-10 07:20:33.562: V/StagefrightPlayer(3618): setLooping
03-10 07:20:33.562: V/AwesomePlayer(3618): setLooping (0)
03-10 07:20:33.562: V/AwesomePlayer(3618): onPrepareAsyncEvent
03-10 07:20:33.562: I/SecMediaClock(3618): SecMediaClock constructor
03-10 07:20:33.562: I/SecMediaClock(3618): reset
03-10 07:20:33.562: I/SecVideoCapture(3618): SecVideoCapture constructor
03-10 07:20:33.562: I/SecVideoCapture(3618): reset
03-10 07:20:33.562: V/AwesomePlayer(3618): initVideoDecoder flags=0x0
03-10 07:20:33.562: V/MediaPlayer-JNI(23232): setLooping: 0
03-10 07:20:33.562: V/MediaPlayer(23232): MediaPlayer::setLooping
03-10 07:20:33.562: V/MediaPlayerService(3618): [121] setLooping(0)
03-10 07:20:33.562: V/StagefrightPlayer(3618): setLooping
03-10 07:20:33.562: I/OMXCodec(3618): Attempting to allocate OMX node 'OMX.Exynos.avc.dec'
03-10 07:20:33.572: D/libexynosv4l2(3618): try node: /dev/video6
03-10 07:20:33.572: I/libexynosv4l2(3618): node found for device s5p-mfc-dec: /dev/video6
03-10 07:20:33.597: I/libexynosv4l2(3618): open video device /dev/video6
03-10 07:20:33.597: D/OMX(3618): SendBroadCasting VIDEO_PLAYBACK_START
03-10 07:20:33.602: I/OMXCodec(3618): Successfully allocated OMX node 'OMX.Exynos.avc.dec'
03-10 07:20:33.602: I/OMXCodec(3618): [OMX.Exynos.avc.dec] AVC profile = 77 (Main), level = 51
03-10 07:20:33.602: I/OMXCodec(3618): [OMX.Exynos.avc.dec] FrameRate (24)
03-10 07:20:33.602: I/OMX(3618): width (3840), height (2160), fps (24)
03-10 07:20:33.602: I/OMX(3618): width (3840), height (2160), fps (24)
03-10 07:20:33.602: I/OMXCodec(3618): [OMX.Exynos.avc.dec] video dimensions are 3840 x 2160
03-10 07:20:33.602: I/OMXCodec(3618): [OMX.Exynos.avc.dec] OMXCodec::start mState=1
03-10 07:20:33.602: W/MetaData(3618): MetaData::findData() - return false
03-10 07:20:33.602: I/OMXCodec(3618): [OMX.Exynos.avc.dec] allocating 5 buffers of size 12441600 on input port
03-10 07:20:33.697: I/OMXCodec(3618): [OMX.Exynos.avc.dec] minUndequeuedBufs : 2
03-10 07:20:33.697: I/OMXCodec(3618): [OMX.Exynos.avc.dec] OMX-buffers: min=2 actual=2 undeq=2+1
03-10 07:20:33.697: I/OMXCodec(3618): [OMX.Exynos.avc.dec] OMX-buffers: min=2 actual=7 undeq=5+1
03-10 07:20:33.697: I/OMXCodec(3618): [OMX.Exynos.avc.dec] allocating 7 buffers from a native window of size 12441600 on output port
03-10 07:20:33.932: D/BatteryService(4093): !@BatteryListener : batteryPropertiesChanged!
03-10 07:20:33.932: D/BatteryService(4093): level:23, scale:100, status:2, health:2, present:true, voltage: 3732, temperature: 320, technology: Li-ion, AC powered:false, USB powered:true, Wireless powered:false, icon:17303743, invalid charger:0
03-10 07:20:33.932: D/BatteryService(4093): online:4, current avg:450, charge type:1, power sharing:false, high voltage charger:false, capacity:280000
03-10 07:20:33.932: D/BatteryService(4093): Sending ACTION_BATTERY_CHANGED.
03-10 07:20:33.937: D/MotionRecognitionService(4093):   mReceiver.onReceive : ACTION_BATTERY_CHANGED
03-10 07:20:33.937: I/MotionRecognitionService(4093): Plugged
03-10 07:20:33.937: I/MotionRecognitionService(4093): setPowerConnected  = true
03-10 07:20:33.937: D/KeyguardUpdateMonitor(4446): received broadcast android.intent.action.BATTERY_CHANGED
03-10 07:20:33.937: D/KeyguardUpdateMonitor(4446): handleBatteryUpdate
03-10 07:20:33.947: D/STATUSBAR-PhoneStatusBar(4446):  mBrightnessEnablebySettings = true mBrightnessEnablebyBattery = true mBrightnessEnablebyDisableFlag = true mPmsBrightnessEnablebySettings = true
03-10 07:20:33.962: D/BatteryMeterView(4446): ACTION_BATTERY_CHANGED : level:23 status:2 health:2
03-10 07:20:33.962: D/BatteryMeterView(4446): ACTION_BATTERY_CHANGED : level:23 status:2 health:2
03-10 07:20:33.962: D/BatteryMeterView(4446): ACTION_BATTERY_CHANGED : level:23 status:2 health:2
03-10 07:20:33.977: D/libexynosv4l2(3618): try node: /dev/video6
03-10 07:20:33.977: I/libexynosv4l2(3618): node found for device s5p-mfc-dec: /dev/video6
03-10 07:20:33.997: I/libexynosv4l2(3618): open video device /dev/video6
03-10 07:20:33.997: I/OMXCodec(3618): [OMX.Exynos.avc.dec] Now Idle. Component sends idle done Event
03-10 07:20:33.997: V/AwesomePlayer(3618): initAudioDecoder
03-10 07:20:33.997: V/AwesomePlayer(3618): checkOffloadExceptions : VideoSource is not Null, return false
03-10 07:20:33.997: V/AwesomePlayer(3618): checkOffloadExceptions is false, disable offload
03-10 07:20:34.002: I/OMXCodec(3618): Attempting to allocate OMX node 'OMX.SEC.aac.dec'
03-10 07:20:34.007: I/OMXCodec(3618): Successfully allocated OMX node 'OMX.SEC.aac.dec'
03-10 07:20:34.007: I/OMXCodec(3618): OMXCodec::configureCodec 2 + 48000 ++
03-10 07:20:34.007: I/OMXCodec(3618): >>>UHQA OMXCodec::configureCodec : 78784000, 15000000
03-10 07:20:34.007: E/OMXNodeInstance(3618): getParameter(2130771976) ERROR: 0x8000101a
03-10 07:20:34.007: I/OMXCodec(3618): >>>UHQA initOutputFormat 16
03-10 07:20:34.007: I/AwesomePlayer(3618): Could not offload audio decode, try pcm offload
03-10 07:20:34.007: V/AudioPolicyManager(3618): isOffloadSupported: SR=48000, CM=0x3, Format=0x1, StreamType=3, BitRate=4294967295, duration=78784000 us, has_video=1
03-10 07:20:34.007: V/AudioPolicyManager(3618): isOffloadSupported: has_video == true, returning false
03-10 07:20:34.007: I/OMXCodec(3618): [OMX.SEC.aac.dec] OMXCodec::start mState=1
03-10 07:20:34.007: W/MetaData(3618): MetaData::findData() - return false
03-10 07:20:34.007: I/OMXCodec(3618): [OMX.SEC.aac.dec] allocating 5 buffers of size 1572864 on input port
03-10 07:20:34.007: I/OMXCodec(3618): [OMX.SEC.aac.dec] allocating 9 buffers of size 24576 on output port
03-10 07:20:34.012: I/SEC_BASE_COMP(3618): SEC_OMX_ComponentStateSet: Cur(1) -> Dest(2)
03-10 07:20:34.012: I/OMXCodec(3618): [OMX.SEC.aac.dec] Now Idle. Component sends idle done Event
03-10 07:20:34.012: I/SEC_BASE_COMP(3618): SEC_OMX_ComponentStateSet: Cur(2) -> Dest(3)
03-10 07:20:34.012: V/AwesomePlayer(3618): finishAsyncPrepare_l
03-10 07:20:34.012: V/AwesomePlayer(3618): kKeyIframeAvgInterval 948738
03-10 07:20:34.012: V/AwesomePlayer(3618): got crop rect 0, 0, 3839, 2159
03-10 07:20:34.012: V/AwesomePlayer(3618): notifyListner_l() msg (5-MEDIA_SET_VIDEO_SIZE), ext1 (3840), ext2 (2160)
03-10 07:20:34.012: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 5, 3840, 2160)
03-10 07:20:34.012: V/AwesomePlayer(3618): notifyListner_l() msg (1-MEDIA_PREPARED), ext1 (0), ext2 (0)
03-10 07:20:34.012: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 1, 0, 0)
03-10 07:20:34.012: V/AwesomePlayer(3618): setLooping (0)
03-10 07:20:34.012: V/MediaPlayer(23232): message received msg=5, ext1=3840, ext2=2160
03-10 07:20:34.012: V/MediaPlayer(23232): New video size 3840 x 2160
03-10 07:20:34.012: V/MediaPlayer(23232): getAudioStreamType
03-10 07:20:34.012: V/MediaPlayer(23232): callback application
03-10 07:20:34.012: V/MediaPlayer-JNI(23232): getAudioStreamType: 3 (streamtype)
03-10 07:20:34.012: V/MediaPlayer(23232): back from callback
03-10 07:20:34.012: V/MediaPlayer-JNI(23232): setVolume: left 1.000000  right 1.000000
03-10 07:20:34.012: V/MediaPlayer(23232): MediaPlayer::setVolume(1.000000, 1.000000)
03-10 07:20:34.012: V/MediaPlayer(23232): message received msg=1, ext1=0, ext2=0
03-10 07:20:34.017: V/MediaPlayerService(3618): [121] setVolume(1.000000, 1.000000)
03-10 07:20:34.017: V/AudioSink(3618): setVolume(1.000000, 1.000000)
03-10 07:20:34.017: V/MediaPlayer(23232): prepared
03-10 07:20:34.017: V/MediaPlayer(23232): callback application
03-10 07:20:34.017: V/MediaPlayer(23232): back from callback
03-10 07:20:34.017: V/MediaPlayer-JNI(23232): setVolume: left 1.000000  right 1.000000
03-10 07:20:34.017: V/MediaPlayer(23232): MediaPlayer::setVolume(1.000000, 1.000000)
03-10 07:20:34.017: V/MediaPlayerService(3618): [121] setVolume(1.000000, 1.000000)
03-10 07:20:34.017: V/AudioSink(3618): setVolume(1.000000, 1.000000)
03-10 07:20:34.017: I/Unity(23232): After load video. Current index: 0
03-10 07:20:34.017: I/Unity(23232): 
03-10 07:20:34.017: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:34.022: I/Unity(23232): After execute action. Time to wait: 5
03-10 07:20:34.022: I/Unity(23232): 
03-10 07:20:34.022: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:34.022: E/MediaPlayer(23232): Should have subtitle controller already set
03-10 07:20:34.022: V/MediaPlayer(23232): getDuration_l
03-10 07:20:34.022: V/MediaPlayerService(3618): getDuration
03-10 07:20:34.022: V/StagefrightPlayer(3618): getDuration
03-10 07:20:34.027: V/MediaPlayerService(3618): [121] getDuration = 78784
03-10 07:20:34.027: V/MediaPlayer-JNI(23232): getDuration: 78784 (msec)
03-10 07:20:34.027: V/MediaPlayer(23232): invoke 68
03-10 07:20:34.027: I/MediaPlayerService(3618): Client::invoke requestID=1
03-10 07:20:34.027: V/StagefrightPlayer(3618): invoke()
03-10 07:20:34.027: V/AwesomePlayer(3618): getTrackInfo
03-10 07:20:34.027: V/AwesomePlayer(3618): getTrackInfo index (0), mime (video/avc), lang (eng)
03-10 07:20:34.027: V/AwesomePlayer(3618): getTrackInfo index (1), mime (audio/mp4a-latm), lang (eng)
03-10 07:20:34.032: V/MediaPlayer(23232): invoke 68
03-10 07:20:34.032: I/MediaPlayerService(3618): Client::invoke requestID=1
03-10 07:20:34.032: V/StagefrightPlayer(3618): invoke()
03-10 07:20:34.032: V/AwesomePlayer(3618): getTrackInfo
03-10 07:20:34.032: V/AwesomePlayer(3618): getTrackInfo index (0), mime (video/avc), lang (eng)
03-10 07:20:34.032: V/AwesomePlayer(3618): getTrackInfo index (1), mime (audio/mp4a-latm), lang (eng)
03-10 07:20:34.032: V/MediaPlayer(23232): invoke 72
03-10 07:20:34.032: I/MediaPlayerService(3618): Client::invoke requestID=4
03-10 07:20:34.032: V/StagefrightPlayer(3618): invoke()
03-10 07:20:34.032: V/AwesomePlayer(3618): selectTrack: trackIndex = 1 and select=1
03-10 07:20:34.032: I/AwesomePlayer(3618): selectAudioTrack_l: trackIndex=1, mFlags=0x10
03-10 07:20:34.032: I/AwesomePlayer(3618): Track 1 is active. Does nothing.
03-10 07:20:34.032: V/MediaPlayer-JNI(23232): seekTo: 0(msec)
03-10 07:20:34.032: V/MediaPlayer(23232): seekTo 0
03-10 07:20:34.032: V/MediaPlayerService(3618): getDuration
03-10 07:20:34.032: V/StagefrightPlayer(3618): getDuration
03-10 07:20:34.032: V/MediaPlayerService(3618): [121] getDuration = 78784
03-10 07:20:34.032: V/MediaPlayerService(3618): [121] seekTo(0)
03-10 07:20:34.032: V/StagefrightPlayer(3618): seekTo 0.00 secs
03-10 07:20:34.032: V/AwesomePlayer(3618): seekTo, locked=1
03-10 07:20:34.032: V/AwesomePlayer(3618): seekTo timeUs (0)
03-10 07:20:34.032: V/AwesomePlayer(3618): seeking(1) while paused, sending SEEK_COMPLETE notification immediately.
03-10 07:20:34.032: V/AwesomePlayer(3618): notifyListner_l() msg (4-MEDIA_SEEK_COMPLETE), ext1 (0), ext2 (0)
03-10 07:20:34.032: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 4, 0, 0)
03-10 07:20:34.032: V/MediaPlayer(23232): message received msg=4, ext1=0, ext2=0
03-10 07:20:34.032: V/AwesomePlayer(3618): AwesomePlayer::onVideoEvent():: This is not a DRM content
03-10 07:20:34.032: V/AwesomePlayer(3618): seeking to 0 us (0.00 secs)
03-10 07:20:34.037: V/MediaPlayer(23232): Received seek complete
03-10 07:20:34.037: V/MediaPlayer(23232): All seeks complete - return to regularly scheduled program
03-10 07:20:34.037: V/MediaPlayer(23232): callback application
03-10 07:20:34.037: V/MediaPlayer(23232): back from callback
03-10 07:20:34.042: I/Unity(23232): Event handler. Event type: ReadyToPlay errorCode: None
03-10 07:20:34.042: I/Unity(23232): 
03-10 07:20:34.042: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] 0onCmdComplete  mState =  7
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] PORT_DISABLED(1)
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] video dimensions are 3840 x 2160
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] Crop rect is 3840 x 2160 @ (0, 0)
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] minUndequeuedBufs : 2
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] OMX-buffers: min=12 actual=12 undeq=2+1
03-10 07:20:34.067: I/OMXCodec(3618): [OMX.Exynos.avc.dec] OMX-buffers: min=12 actual=17 undeq=5+1
03-10 07:20:34.107: I/OMXCodec(3618): [OMX.Exynos.avc.dec] allocating 17 buffers from a native window of size 12441600 on output port
03-10 07:20:34.147: V/MediaPlayer-JNI(23232): setVolume: left 1.000000  right 1.000000
03-10 07:20:34.147: V/MediaPlayer(23232): MediaPlayer::setVolume(1.000000, 1.000000)
03-10 07:20:34.147: V/MediaPlayerService(3618): [121] setVolume(1.000000, 1.000000)
03-10 07:20:34.147: V/AudioSink(3618): setVolume(1.000000, 1.000000)
03-10 07:20:34.167: I/Unity(23232): [AVProVideo] Using playback path: MediaPlayer (3840x2160@24.00)
03-10 07:20:34.167: I/Unity(23232): 
03-10 07:20:34.167: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:34.167: I/Unity(23232): [AVProVideo] Texture ID: 25
03-10 07:20:34.167: I/Unity(23232): 
03-10 07:20:34.167: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:34.177: I/Unity(23232): Event handler. Event type: MetaDataReady errorCode: None
03-10 07:20:34.177: I/Unity(23232): 
03-10 07:20:34.177: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:35.112: V/AwesomePlayer(3618): initRenderer_l
03-10 07:20:35.112: V/AwesomePlayer(3618): notifyListner_l() msg (200-MEDIA_INFO), ext1 (3), ext2 (0)
03-10 07:20:35.112: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 200, 3, 0)
03-10 07:20:35.112: V/AwesomePlayer(3618): onVideoEvent - skip rendering
03-10 07:20:35.112: V/MediaPlayer(23232): message received msg=200, ext1=3, ext2=0
03-10 07:20:35.112: W/MediaPlayer(23232): info/warning (3, 0)
03-10 07:20:35.112: V/MediaPlayer(23232): callback application
03-10 07:20:35.117: V/MediaPlayer(23232): back from callback
03-10 07:20:35.157: I/Unity(23232): Event handler. Event type: FirstFrameReady errorCode: None
03-10 07:20:35.157: I/Unity(23232): 
03-10 07:20:35.157: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:37.177: D/StatusBar.NetworkController(4446): onSignalStrengthsChanged signalStrength=SignalStrength: 19 99 -19 -200 -19 -200 -1 99 2147483647 2147483647 2147483647 -1 2147483647 0x4 gsm|lte level=4
03-10 07:20:37.482: I/Unity(23232): Waiting seconds to execute: 0.75
03-10 07:20:37.482: I/Unity(23232): 
03-10 07:20:37.482: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.237: I/Unity(23232): Before execute action. Time to wait: 0.75
03-10 07:20:38.237: I/Unity(23232): 
03-10 07:20:38.237: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.242: I/Unity(23232): Enabling VR in unity settings
03-10 07:20:38.242: I/Unity(23232): 
03-10 07:20:38.242: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.302: I/SurfaceFlinger(3613): id=1766 Removed SurfaceView (5/8)
03-10 07:20:38.302: I/Unity(23232): Before play video. Current index: 0
03-10 07:20:38.302: I/Unity(23232): 
03-10 07:20:38.302: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.302: I/SurfaceFlinger(3613): id=1766 Removed SurfaceView (-2/8)
03-10 07:20:38.307: I/MediaPlayer(23232): sendBroadcast SMART_PAUSE_start()
03-10 07:20:38.312: W/MediaPlayer(23232): this is IMEDIA_PLAYER_VIDEO_EXIST
03-10 07:20:38.312: I/MediaPlayer(23232): sendBroadcast android.media.IMediaPlayer.videoexist
03-10 07:20:38.312: V/MediaPlayer-JNI(23232): start
03-10 07:20:38.312: V/MediaPlayer(23232): start
03-10 07:20:38.312: V/MediaPlayerService(3618): [121] setLooping(0)
03-10 07:20:38.312: V/StagefrightPlayer(3618): setLooping
03-10 07:20:38.312: V/AwesomePlayer(3618): setLooping (0)
03-10 07:20:38.317: V/MediaPlayerService(3618): [121] setVolume(1.000000, 1.000000)
03-10 07:20:38.317: V/AudioSink(3618): setVolume(1.000000, 1.000000)
03-10 07:20:38.317: V/MediaPlayerService(3618): [121] setAuxEffectSendLevel(0.000000)
03-10 07:20:38.317: V/AudioSink(3618): setAuxEffectSendLevel(0.000000)
03-10 07:20:38.317: V/MediaPlayerService(3618): [121] start
03-10 07:20:38.317: V/StagefrightPlayer(3618): setLooping
03-10 07:20:38.317: V/AwesomePlayer(3618): setLooping (0)
03-10 07:20:38.317: E/MediaPlayerService(3618): WFD client is not created
03-10 07:20:38.317: V/StagefrightPlayer(3618): start
03-10 07:20:38.317: V/AwesomePlayer(3618): play
03-10 07:20:38.317: V/AwesomePlayer(3618): set SecMediaClock
03-10 07:20:38.317: I/SecMediaClock(3618): reset
03-10 07:20:38.317: I/SecMediaClock(3618): setClockMargin mMinClockModificationCondition (70000), mMaxClockCorrection (30000)
03-10 07:20:38.317: I/SecMediaClock(3618): currentTimeLimit (0), requestTimeLimit (500000), currentTimeLimitCheck (0), requestTimeLimitCheck (1)
03-10 07:20:38.317: I/AudioPlayer(3618): setMediaClock() out
03-10 07:20:38.317: V/AwesomePlayer(3618): addBatteryData
03-10 07:20:38.327: I/Unity(23232): After play video. Current index: 0
03-10 07:20:38.327: I/Unity(23232): 
03-10 07:20:38.327: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.327: I/Unity(23232): After play video
03-10 07:20:38.327: I/Unity(23232): 
03-10 07:20:38.327: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.327: I/Unity(23232): After execute action. Time to wait: 0.75
03-10 07:20:38.327: I/Unity(23232): 
03-10 07:20:38.327: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.327: V/AwesomePlayer(3618): seeking to 0 us (0.00 secs)
03-10 07:20:38.332: E/BufferQueueProducer(3613): [SurfaceView] connect(P): BufferQueue has been abandoned
03-10 07:20:38.332: E/libEGL(23232): eglCreateWindowSurface: native_window_api_connect (win=0xaf364408) failed (0xffffffed) (already connected to another API?)
03-10 07:20:38.332: E/libEGL(23232): eglCreateWindowSurface:437 error 3003 (EGL_BAD_ALLOC)
03-10 07:20:38.332: E/Unity(23232): [EGL] Failed to create window surface: EGL_BAD_ALLOC: EGL failed to allocate resources for the requested operation.
03-10 07:20:38.332: E/Unity(23232): 
03-10 07:20:38.332: E/Unity(23232): (Filename: ./Runtime/GfxDevice/egl/WindowContextEGL.cpp Line: 138)
03-10 07:20:38.332: I/Unity(23232): Skipped rendering frame because GfxDevice is in invalid state (device lost)
03-10 07:20:38.332: I/Unity(23232): 
03-10 07:20:38.332: I/Unity(23232): (Filename:  Line: 762)
03-10 07:20:38.332: E/libEGL(23232): call to OpenGL ES API with no current context (logged once per thread)
03-10 07:20:38.357: W/libexynosv4l2(3618): failed to ioctl: VIDIOC_DQBUF (22 - Invalid argument)
03-10 07:20:38.362: I/SurfaceFlinger(3613): id=1771 createSurf (1920x1080),2 flag=404, SurfaceView
03-10 07:20:38.387: I/Unity(23232): Event handler. Event type: Started errorCode: None
03-10 07:20:38.387: I/Unity(23232): 
03-10 07:20:38.387: I/Unity(23232): (Filename: ./artifacts/generated/common/runtime/DebugBindings.gen.cpp Line: 51)
03-10 07:20:38.387: I/Unity(23232): Skipped rendering frame because GfxDevice is in invalid state (device lost)
03-10 07:20:38.387: I/Unity(23232): 
03-10 07:20:38.387: I/Unity(23232): (Filename:  Line: 762)
03-10 07:20:38.517: A/libc(23232): Fatal signal 11 (SIGSEGV), code 1, fault addr 0x24 in tid 23249 (UnityMain)
03-10 07:20:38.532: V/AwesomePlayer(3618): notifyListner_l() msg (9-MEDIA_SKIPPED), ext1 (0), ext2 (0)
03-10 07:20:38.532: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 9, 0, 0)
03-10 07:20:38.532: V/AwesomePlayer(3618): finishSeekIfNecessary: seeking audio to 41708 us (0.04 secs). (videoTS=41708 )
03-10 07:20:38.532: V/MediaPlayer(23232): message received msg=9, ext1=0, ext2=0
03-10 07:20:38.532: I/AudioPlayer(3618): seekTo time_us (41708), seekType (1)
03-10 07:20:38.537: I/SecMediaClock(3618): updateBasePosition (0)
03-10 07:20:38.537: V/AudioSink(3618): flush
03-10 07:20:38.537: V/AwesomePlayer(3618): startAudioPlayer_l, sendErrorNotification (1)
03-10 07:20:38.537: V/MediaPlayer(23232): unrecognized message: (9, 0, 0)
03-10 07:20:38.537: V/MediaPlayer(23232): callback application
03-10 07:20:38.537: V/MediaPlayer(23232): back from callback
03-10 07:20:38.542: I/SEC_AAC_DEC(3618):  AudioSpecificConfig 0x 11 90
03-10 07:20:38.547: I/SEC_AAC_DEC(3618):  AudioSpecificConfig 0x 11 90
03-10 07:20:38.552: I/AudioPlayer(3618): Audio channels(2)
03-10 07:20:38.552: I/AudioPlayer(3618): Audioplayer kKeyAudioPCMFormat:2, 1, 0
03-10 07:20:38.552: I/AudioPlayer(3618): Audioplayer kKeyAudioPCMFormat read fail(2, 1)
03-10 07:20:38.552: V/AudioSink(3618): open(48000, 2, 0x0, 0x1, 0, 4 0x26f)
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutput() device 2, stream 3, samplingRate 0, format 0, channelMask 0, flags 3
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutputsForDevice device 0002 -> 0002
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutput() returns output 2
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutput() device 2, stream 3, samplingRate 0, format 0, channelMask 0, flags 3
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutputsForDevice device 0002 -> 0002
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutput() returns output 2
03-10 07:20:38.552: V/AudioSink(3618): no track available to recycle
03-10 07:20:38.552: V/AudioSink(3618): creating new AudioTrack
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutputForAttr() usage=1, content=2, tag= flags=00000000
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutputForAttr() device 2, samplingRate 48000, format 1, channelMask 3, flags 40000
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutputsForDevice device 0002 -> 0002
03-10 07:20:38.552: V/AudioPolicyManager(3618): getOutput() returns output 2
03-10 07:20:38.557: V/AudioSink(3618): deleteRecycledTrack
03-10 07:20:38.557: V/AudioSink(3618): setVolume
03-10 07:20:38.557: V/AudioPolicyManager(3618): getOutputForAttr() usage=1, content=2, tag= flags=00000000
03-10 07:20:38.557: V/AudioPolicyManager(3618): getOutputForAttr() device 2, samplingRate 0, format 0, channelMask 3, flags 0
03-10 07:20:38.557: V/AudioPolicyManager(3618): getOutputsForDevice device 0002 -> 0002
03-10 07:20:38.557: V/AudioPolicyManager(3618): getOutput() returns output 2
03-10 07:20:38.557: V/AudioSink(3618): open() DONE status 0
03-10 07:20:38.557: I/SecMediaClock(3618): setLatency() prevLatencyUs (0), reqLatencyUs (160000)
03-10 07:20:38.557: V/AudioSink(3618): start
03-10 07:20:38.557: V/AudioPolicyManager(3618): startOutput() output 2, stream 3, session 623
03-10 07:20:38.557: V/AudioPolicyManager(3618): changeRefCount() stream 3, count 2
03-10 07:20:38.567: V/AwesomePlayer(3618): postAudioSeekComplete
03-10 07:20:38.567: V/AwesomePlayer(3618): updating TSdelta (5080779 => 0 change 5080779)
03-10 07:20:38.567: V/AwesomePlayer(3618): notifyListner_l() msg (6-MEDIA_STARTED), ext1 (0), ext2 (0)
03-10 07:20:38.567: V/MediaPlayerService(3618): [121] notify (0xaf112e00, 6, 0, 0)
03-10 07:20:38.567: V/MediaPlayer(23232): message received msg=6, ext1=0, ext2=0
03-10 07:20:38.572: I/AudioPlayer(3618): First fillBuffer call!!
03-10 07:20:38.572: I/AudioPlayer(3618): Play from audio DTS(42666). seektime was (41708)
03-10 07:20:38.572: I/SecMediaClock(3618): updateBasePosition (64000)
03-10 07:20:38.572: I/SecMediaClock(3618): SecMediaClock state RUNNING
03-10 07:20:38.572: V/MediaPlayer(23232): Received MEDIA_STARTED
03-10 07:20:38.572: V/MediaPlayer(23232): callback application
03-10 07:20:38.572: V/MediaPlayer(23232): back from callback
03-10 07:20:38.577: V/AwesomePlayer(3618): onCheckAudioStatus

The first log would imply that you didn’t even have the Unity Google integration compiled into your app, but that begs the question why it compiled.

The second log is just the same memory issue.

At this point there isn’t much I can tell you without a repro project to look at.

Ok, I will attach it a bit later. Thanks!

You say you are using 5.6, but the project you sent me there is GVR13. Can you please send me the correct project, preferably with only enough in it to reproduce the issues?

Here it is:
https://drive.google.com/open?id=0BwSH2reppuixUXpwaGQ3YmNSUUk

About version. In Unity console it logs:
Google VR SDK 1.20

But I may be wrong with GVR version and it could be GVR 13, as you mentioned before.

It seems, that it’s crashing, after VRSettings.enabled set to true.
It’s crashes also on google vr demo scene.

I can repro a crash and it looks like it is at the driver level through straight GL and not directly tied to VR. I’m not sure if that is truly your issue but I have asked the Android team to take a look and see if they can puzzle more out of this.

Ok, will be waiting your answer.

Any news?

2 Likes