google-ar / sceneform-android-sdk

Sceneform SDK for Android
https://developers.google.com/sceneform/develop/
Apache License 2.0
1.23k stars 604 forks source link

SessionPausedException -- hellosceneform #230

Closed alexbagg03 closed 6 years ago

alexbagg03 commented 6 years ago

Hello Google AR Devs,

I've been developing an app using the 1.3 sceneform sdk, but just saw that the sdk was updated to 1.4 and so I tried updating my app to use 1.4. After doing so, I found that the app crashes immediately on startup. The app is set up in a very similar way to the hellosceneform sample app in that it uses an ArFragment in the MainActivity.

I also tried to run the hellosceneform sample app (now using sceneform 1.4) and get the same crash/exception -- here's the full log:

08-03 10:11:18.477 25917-25917/? I/zygote64: Late-enabling -Xcheck:jni
08-03 10:11:18.529 25917-25924/? I/zygote64: Debugger is no longer active
08-03 10:11:18.681 25917-25917/? I/InstantRun: starting instant run server: is main process
08-03 10:11:18.851 25917-25917/? I/Adreno: QUALCOMM build                   : 2941438, I916dfac403
    Build Date                       : 10/03/17
    OpenGL ES Shader Compiler Version: EV031.21.02.00
    Local Branch                     : O18A
    Remote Branch                    : 
    Remote Branch                    : 
    Reconstruct Branch               : 
08-03 10:11:18.854 25917-25917/? I/Adreno: PFP: 0x005ff087, ME: 0x005ff063
08-03 10:11:18.858 25917-25917/? I/zygote64: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
08-03 10:11:18.863 25917-25917/? I/Filament: FEngine (64 bits) created at 0x7317400000
08-03 10:11:18.971 25917-25917/? I/third_party/arcore/ar/core/android/sdk/session_create.cc: Entering ArSession_create
08-03 10:11:18.976 25917-25917/? I/third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: APK version code: 180716066
08-03 10:11:18.998 25917-25917/? W/native: commandlineflags.cc:1311 Ignoring RegisterValidateFunction() for flag pointer 0x7315011818: no flag found at that address
08-03 10:11:18.999 25917-25917/? I/native: version_check.cc:23 ARCore Version: APK version:1.4.180716066
    version_check.cc:24 ARCore Version: emulated SDK version:1.4.180626000
08-03 10:11:18.999 25917-25917/? I/third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: SDK build name: 1.4
    Dynamite load ok.
08-03 10:11:19.014 25917-25917/? W/native: commandlineflags.cc:1311 Ignoring RegisterValidateFunction() for flag pointer 0x7314f592e8: no flag found at that address
08-03 10:11:19.017 25917-25917/? I/native: session_create_implementation.cc:49 Entering ArSession_createImplementation. ARCore SDK version: [1.4.180626000].
08-03 10:11:19.017 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 20.)
    ~JniHelper: did not need to detach thread. (Called from line 703.)
    JniHelper: about to attach thread. (Called from line 90.)
    JniHelper: thread already attached. (Called from line 90.)
08-03 10:11:19.018 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 90.)
08-03 10:11:19.035 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 448.)
08-03 10:11:19.035 25917-25917/? I/native: device_profile_conversions.cc:140 used_active_calibration: 2
08-03 10:11:19.036 25917-25917/? I/native: device_profile_conversions.cc:140 used_active_calibration: 2
08-03 10:11:19.037 25917-25917/? I/native: android_sensors.cc:51 Using uncalibrated accelerometer.
08-03 10:11:19.039 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: about to attach thread. (Called from line 68.)
    JniHelper: thread already attached. (Called from line 68.)
08-03 10:11:19.039 25917-25953/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: about to attach thread. (Called from line 188.)
08-03 10:11:19.039 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 68.)
08-03 10:11:19.040 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 69.)
08-03 10:11:19.040 25917-25953/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: attached thread. (Called from line 188.)
08-03 10:11:19.040 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: about to attach thread. (Called from line 137.)
    JniHelper: thread already attached. (Called from line 137.)
08-03 10:11:19.043 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 137.)
    JniHelper: about to attach thread. (Called from line 114.)
    JniHelper: thread already attached. (Called from line 114.)
08-03 10:11:19.046 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 114.)
08-03 10:11:19.047 25917-25917/? I/native: performance_manager.cc:22 Processor data: Num processors 4
    Processor type: LittleBig
    Num small cores 2
    Max frequency 1593600
    Min frequency 307200
    Small cores 0 1
    Num big cores 2
    Max frequency 2150400
    Min frequency 307200
    Big cores 2 3
08-03 10:11:19.048 25917-25917/? I/native: device_provider.cc:1124 Identified device type: kSailfish
08-03 10:11:19.086 25917-25917/? I/native: vio_helper.cc:48 Use calibrated IMU scale factors.
    vio_helper.cc:60 Use calibrated IMU misalignment factors.
08-03 10:11:19.172 25917-25917/? W/AnchorServiceClientFactory: The API key for use with the Google AR service could not be obtained!
08-03 10:11:19.180 25917-25917/? D/NetworkSecurityConfig: No Network Security Config specified, using platform default
08-03 10:11:19.199 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 343.)
08-03 10:11:19.200 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 209.)
08-03 10:11:19.202 25917-25917/? I/native: android_camera.cc:1117 Initializing camera manager.
08-03 10:11:19.204 25917-25917/? I/native: android_camera.cc:1133 Camera manager initialized successfully with 2 cameras.
    device_profile_conversions.cc:140 used_active_calibration: 2
08-03 10:11:19.214 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: about to attach thread. (Called from line 44.)
    JniHelper: thread already attached. (Called from line 44.)
08-03 10:11:19.216 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: ~JniHelper: did not need to detach thread. (Called from line 44.)
08-03 10:11:19.216 25917-25917/? I/native: session_create_implementation.cc:189 ArSession_createImplementation returning OK.
08-03 10:11:19.218 25917-25917/? I/third_party/arcore/ar/core/android/sdk/arimage_jni.cc: Loading AImage symbols
08-03 10:11:19.220 25917-25917/? I/third_party/arcore/ar/core/android/sdk/image_metadata_jni.cc: Loading ACameraMetadata symbols
08-03 10:11:19.245 25917-25917/? I/native: session.cc:543 Entering Session::Resume.
08-03 10:11:19.245 25917-25917/? V/third_party/redwood/base/jni_common/jni_helper.cc: JniHelper: about to attach thread. (Called from line 44.)
    JniHelper: thread already attached. (Called from line 44.)
    ~JniHelper: did not need to detach thread. (Called from line 44.)
08-03 10:11:19.245 25917-25917/? I/native: android_sensors.cc:94 Starting thread.
    cameras.cc:579 Selected camera 0 stream 0 as feature extraction stream.
08-03 10:11:19.245 25917-25917/? E/NdkImageReader: AImageReader_getWindow
08-03 10:11:19.246 25917-25968/? I/native: android_sensors.cc:140 Gyro min delay 2.5ms requesting 5ms
08-03 10:11:19.255 25917-25968/? I/native: android_sensors.cc:157 Accel min delay 2.5ms requesting 5ms
08-03 10:11:21.972 25917-25917/com.google.ar.sceneform.samples.hellosceneform E/ACameraManager: openCamera: connect camera device failed: Status(-8): '8: connectHelper:1305: Cannot open camera 0 for "" (PID -1): Too many other clients connecting'
08-03 10:11:21.973 25917-25917/com.google.ar.sceneform.samples.hellosceneform E/native: android_camera.cc:632 Reset: Resetting camera 0 from an ERROR state, best effort clean-up commencing
08-03 10:11:21.973 25917-25917/com.google.ar.sceneform.samples.hellosceneform I/native: android_data_source.cc:279 Failed to start cameras.
08-03 10:11:21.979 25917-25917/com.google.ar.sceneform.samples.hellosceneform W/native: session.cc:584 Session::Resume returning ArStatusErrorSpace::AR_ERROR_CAMERA_NOT_AVAILABLE: .
08-03 10:11:21.979 25917-25917/com.google.ar.sceneform.samples.hellosceneform E/native: status.cc:155 ArStatusErrorSpace::AR_ERROR_CAMERA_NOT_AVAILABLE: 
08-03 10:11:21.990 25917-25984/com.google.ar.sceneform.samples.hellosceneform D/OpenGLRenderer: HWUI GL Pipeline
08-03 10:11:22.087 25917-25917/com.google.ar.sceneform.samples.hellosceneform I/Choreographer: Skipped 186 frames!  The application may be doing too much work on its main thread.
08-03 10:11:22.108 25917-25917/com.google.ar.sceneform.samples.hellosceneform E/native: status.cc:155 ArStatusErrorSpace::AR_ERROR_SESSION_PAUSED: Could not update frame, session is paused.
08-03 10:11:22.109 25917-25917/com.google.ar.sceneform.samples.hellosceneform D/AndroidRuntime: Shutting down VM

    --------- beginning of crash
08-03 10:11:22.110 25917-25917/com.google.ar.sceneform.samples.hellosceneform E/AndroidRuntime: FATAL EXCEPTION: main
    Process: com.google.ar.sceneform.samples.hellosceneform, PID: 25917
    com.google.ar.core.exceptions.SessionPausedException
        at com.google.ar.core.V.a(Unknown Source:2)
        at com.google.ar.core.Session.throwExceptionFromArStatus(Unknown Source:4)
        at com.google.ar.core.Session.nativeUpdate(Native Method)
        at com.google.ar.core.Session.update(Unknown Source:12)
        at com.google.ar.sceneform.ArSceneView.onBeginFrame(Unknown Source:10)
        at com.google.ar.sceneform.SceneView.doFrame(Unknown Source:16)
        at android.view.Choreographer$CallbackRecord.run(Choreographer.java:909)
        at android.view.Choreographer.doCallbacks(Choreographer.java:723)
        at android.view.Choreographer.doFrame(Choreographer.java:655)
        at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:897)
        at android.os.Handler.handleCallback(Handler.java:790)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6494)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

I'm trying to run on a Pixel (8.1.0). I'll probably stick with using sceneform 1.3 for now, but wanted to make you aware of this issue.

Thanks!

malik-at-work commented 6 years ago

We are looking into this. We will update when we have more info.

alexbagg03 commented 6 years ago

Awesome, thanks. Also, I just found that the issue was still occurring for any apps I ran that were using sceneform 1.3. I rebooted my device and it seemed to fix the issue, but have no clue how or why the problem started. Anyhow, that said, it seems that it wasn't just a version-specific issue but an underlying bug related to the AR Session. I can now run apps with sceneform 1.4 👍

malik-at-work commented 6 years ago

Glad it is resolved.

Our response is that based on the log it seems that multiple sessions are open and trying to connect to the same camera at the same time, or possibly there is an app in the background attempting to control the camera. Our recommendation would have been to restart to phone to make sure there isn't a bad app holding onto the camera.

Based on your post I think that confirms it. Closing the issue.

syedtarique786 commented 6 years ago

Hi Google Ar Devs,

I'm trying to run a sample of AR from https://github.com/google-ar/arcore-android-sdk/tree/master/samples/ But keep getting following error. Tried with modifying Scene images in using Camera option & Restarting the Emulator. But nothing seems to work.

09-07 16:07:01.346 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.347 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.418 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.419 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.494 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.495 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.570 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.571 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.646 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.646 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.681 1481-4329/? E/Camera3-Stream: getBuffer: wait for output buffer return timed out after 3000ms (max_buffers 3) 09-07 16:07:01.682 1481-4329/? E/Camera3-Device: RequestThread: Can't get output buffer, skipping request: Connection timed out (-110) 09-07 16:07:01.682 4263-4282/com.raywenderlich.whacardroid D/ACameraDevice: Device error received, code 3, frame number 1103, request ID 0, subseq ID 0 09-07 16:07:01.682 4263-4323/com.raywenderlich.whacardroid E/native: android_camera.cc:1096 Camera capture failed! frame: 1103 reason: 1 09-07 16:07:01.722 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.723 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.799 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.801 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.878 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.879 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270) 09-07 16:07:01.955 4263-4285/com.raywenderlich.whacardroid E/BackgroundRenderer: Draw: glError 1282 09-07 16:07:01.956 4263-4285/com.raywenderlich.whacardroid E/HelloArActivity: Exception on the OpenGL thread java.lang.RuntimeException: Draw: glError 1282 at com.android.arsample.render.ShaderUtil.checkGLError(ShaderUtil.java:60) at com.android.arsample.render.BackgroundRenderer.draw(BackgroundRenderer.java:169) at com.android.arsample.main.HelloArActivity.onDrawFrame(HelloArActivity.java:279) at android.opengl.GLSurfaceView$GLThread.guardedRun(GLSurfaceView.java:1571) at android.opengl.GLSurfaceView$GLThread.run(GLSurfaceView.java:1270)

I'm running it on Emulator (with Pixel 2 XL API 27) & ArCore has been updated with ARCore_1_4_x86_for_emulator.apk, manually. Please help to resolve this.

Thanks

chnouman commented 5 years ago
com.google.ar.core.exceptions.SessionPausedException
    at java.lang.reflect.Constructor.newInstance0(Native Method)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:343)
    at com.google.ar.core.Session.throwExceptionFromArStatus(Session.java:145)
    at com.google.ar.core.Session.nativeCreateAnchor(Native Method)
    at com.google.ar.core.Session.createAnchor(Session.java:93)
    at com.xyz.xyz.main.arloop.main.ARNode.setImage(ARNode.kt:142)
    at com.xyz.xyz.main.arloop.main.MainActivity$onUpdateFrame$2.run(MainActivity.kt:184)
    at android.os.Handler.handleCallback(Handler.java:883)
    at android.os.Handler.dispatchMessage(Handler.java:100)
    at android.os.Looper.loop(Looper.java:214)
    at android.app.ActivityThread.main(ActivityThread.java:7116)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:925)