Filament: Android Filament update from 1.8.1 to 1.9.2 causes Fatal signal 11 (SIGSEGV) when setting irradiance

[zirman]

Describe the bug
This code causes a SIGSEGV when updating dependencies to Filament 1.9.2.

Commenting it out prevents the crash.
        // setting irradiance crashes
        filament.scene.indirectLight = IndirectLight
            .Builder()
            .irradiance(
                3,
                frame.lightEstimate.environmentalHdrAmbientSphericalHarmonics
                    .let { getEnvironmentalHdrSphericalHarmonics(it) }
            )
            .build(filament.engine)

To Reproduce
Sample code to reproduce crash is available here:
https://github.com/zirman/arcore-filament-example-app/tree/irradience

Expected behavior
N/A

Screenshots
N/A

Desktop (please complete the following information):
N/A

Smartphone (please complete the following information):

• Device: Pixel 3
• OS: Android 11

Additional context
```2020-09-29 13:11:03.002 7647-7647/com.example.app W/com.example.ap: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (greylist, reflection, allowed)
2020-09-29 13:11:03.002 7647-7647/com.example.app W/com.example.ap: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (greylist, reflection, allowed)
2020-09-29 13:11:03.071 7647-7647/com.example.app I/AdrenoGLES-0: QUALCOMM build : c9bef8a, Ie73904e3bd
Build Date : 06/26/20
OpenGL ES Shader Compiler Version: EV031.31.04.00
Local Branch : gfx-adreno.lnx.2.0
Remote Branch : quic/gfx-adreno.lnx.2.0
Remote Branch : NONE
Reconstruct Branch : NOTHING
2020-09-29 13:11:03.071 7647-7647/com.example.app I/AdrenoGLES-0: Build Config : C P 11.0.1 AArch64
2020-09-29 13:11:03.071 7647-7647/com.example.app I/AdrenoGLES-0: Driver Path : /vendor/lib64/egl/libGLESv2_adreno.so
2020-09-29 13:11:03.082 7647-7647/com.example.app I/AdrenoGLES-0: PFP: 0x016ee189, ME: 0x00000000
2020-09-29 13:11:03.085 7647-7647/com.example.app W/AdrenoUtils: : Failed to open /sys/class/kgsl/kgsl-3d0/gpu_model
2020-09-29 13:11:03.085 7647-7647/com.example.app W/AdrenoUtils: : Failed to read chip ID from gpu_model. Fallback to use the GSL path
2020-09-29 13:11:03.122 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/session_create.cc: Entering ArSession_createWithFeatures
2020-09-29 13:11:03.122 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: SDK build name: 1.19
2020-09-29 13:11:03.124 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: APK version code: 202550203
2020-09-29 13:11:03.133 7647-7647/com.example.app D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar
2020-09-29 13:11:03.173 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/session_create.cc: Dynamite load ok.
2020-09-29 13:11:03.174 7647-7647/com.example.app I/third_party/arcore/java/com/google/vr/dynamite/client/native/dynamite_client.cc: Attempting to load native library arcore_c from package com.google.ar.core
2020-09-29 13:11:03.203 7647-7647/com.example.app I/third_party/arcore/java/com/google/vr/dynamite/client/native/dynamite_client.cc: Dynamite::LoadNativeRemoteLibrary handle=3270391885326583399
2020-09-29 13:11:03.204 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore SDK: dynamite number_of_symbols_loaded=206
2020-09-29 13:11:03.204 7647-7647/com.example.app I/native: session_create_implementation.cc:194 Entering createImplementationWithFeaturesAndSettings. ARCore SDK version: [1.19.201750000].
2020-09-29 13:11:03.212 7647-7676/com.example.app V/third_party/redwood/infrastructure/jni_common/jni_helper.cc: JniHelper: attached thread (Called from line 363).
2020-09-29 13:11:03.222 7647-7647/com.example.app I/native: session_create_implementation_shared.cc:2076 Persistent online recalibration is enabled by Phenotype.
2020-09-29 13:11:03.225 7647-7647/com.example.app I/tflite: Initialized TensorFlow Lite runtime.
2020-09-29 13:11:03.225 7647-7647/com.example.app I/native: online_calibration_manager.cc:90 OnlineCalibrationManager: Could not open /data/user/0/com.example.app/cache/arcore-online-recalibration for reading.
2020-09-29 13:11:03.251 7647-7647/com.example.app W/ARCore-ContextUtils: The API key for use with the Google AR service could not be obtained!
2020-09-29 13:11:03.276 7647-7647/com.example.app I/native: session_create_implementation_shared.cc:904 Datasource will be created with timeout = 4s, should_wait = false, should_use_greedy_recovery = true
2020-09-29 13:11:03.276 7647-7647/com.example.app I/native: android_camera.cc:168 Camera start operation timeout set to 4000 ms.
2020-09-29 13:11:03.276 7647-7647/com.example.app I/native: android_camera.cc:1823 Initializing camera manager.
2020-09-29 13:11:03.289 7647-7647/com.example.app I/native: android_camera.cc:1849 Camera manager initialized successfully with 4 cameras.
2020-09-29 13:11:03.289 7647-7647/com.example.app I/native: session_create_implementation_shared.cc:1085 Datasource will be created with should_use_cameras_async = true
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:95 Using uncalibrated accelerometer.
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:123 Found IMU temperature sensor.
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:133 Using uncalibrated magnetometer.
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_LIGHT
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_PRESSURE
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_PROXIMITY
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_GRAVITY
2020-09-29 13:11:03.291 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_ROTATION_VECTOR
2020-09-29 13:11:03.292 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_GAME_ROTATION_VECTOR
2020-09-29 13:11:03.292 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_GEOMAGNETIC_ROTATION_VECTOR
2020-09-29 13:11:03.292 7647-7647/com.example.app I/native: android_sensors.cc:148 Using SENSOR_TYPE_STEP_DETECTOR
2020-09-29 13:11:03.293 7647-7647/com.example.app I/native: android_platform_checks.cc:194 IsZeroRotationLandscape = false
2020-09-29 13:11:03.293 7647-7647/com.example.app I/native: create_pursuit_tracker.cc:20 AugmentedRegion downsample mode from Phenotype: false
2020-09-29 13:11:03.294 7647-7647/com.example.app I/native: app_version_util.cc:50 Package name: com.google.ar.core App version: 1.20.202550203
2020-09-29 13:11:03.294 7647-7647/com.example.app I/native: logger.h:28 DataSourceMetrics: CamerasInit: 41.875us
2020-09-29 13:11:03.294 7647-7647/com.example.app I/native: session_create_implementation_shared.cc:1228 CPU Image enable frame delay to compensate delay: false
2020-09-29 13:11:03.303 7647-7647/com.example.app I/native: config_helpers.cc:396 Legacy IMU sigma values are used
2020-09-29 13:11:03.303 7647-7647/com.example.app I/native: config_helpers.cc:349 Failed to find IMU intrinsic covariance matrix in profile for id: 100
2020-09-29 13:11:03.303 7647-7647/com.example.app I/native: config_helpers.cc:107 Does not find camera intrinsic covariance matrix in profile for id 0
2020-09-29 13:11:03.303 7647-7647/com.example.app I/native: config_helpers.cc:180 Does not find extrinsic covariance matrix in profile for IMU id 100
2020-09-29 13:11:03.304 7647-7647/com.example.app I/native: feature_matcher_and_filter.cc:91 Enabled the robustification to large-sized and fast-moving objects on this mono-camera device.
2020-09-29 13:11:03.307 7647-7647/com.example.app I/native: pose_confidence_estimator.cc:220 Pose confidence model loaded successfully
2020-09-29 13:11:03.381 7647-7647/com.example.app I/native: asset_manager_util.cc:59 Created global reference to asset manager.
2020-09-29 13:11:03.381 7647-7647/com.example.app I/native: session_create_implementation_shared.cc:1255 Normal detector created.
2020-09-29 13:11:03.404 7647-7647/com.example.app I/native: planar_target_tracking_manager.h:114 Config of PlanarTargetTrackingManager:
-pose_refinement_with_detection_interval_ns: 0
-min_interval_between_detections_ns: 500000000
-filter_parallax: false
-filter_result: true
-multiple_targets: true
-mini_detection: true
-tracking_mode: 1
-camera_id: 0
2020-09-29 13:11:03.412 7647-7647/com.example.app E/native: camera_config_manager.cc:750 UpdateBugFixes on CameraConfigManager is unimplemented!
2020-09-29 13:11:03.412 7647-7647/com.example.app W/com.example.ap: Accessing hidden method Landroid/media/Image;->()V (greylist, linking, allowed)
2020-09-29 13:11:03.413 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/arimage_jni.cc: Loading AImage symbols
2020-09-29 13:11:03.414 7647-7647/com.example.app I/third_party/arcore/ar/core/android/sdk/image_metadata_jni.cc: Loading ACameraMetadata symbols
2020-09-29 13:11:03.418 7647-7647/com.example.app I/native: session.cc:480 Session::CheckAndWriteCurrentConfig returning OK.
2020-09-29 13:11:03.439 7647-7647/com.example.app I/Filament: FEngine (64 bits) created at 0x7728be3040 (threading is enabled)
2020-09-29 13:11:03.440 7647-7715/com.example.app D/Filament: Using ASurfaceTexture
2020-09-29 13:11:03.440 7647-7715/com.example.app D/Filament: FEngine resolved backend: OpenGL
2020-09-29 13:11:03.518 7647-7647/com.example.app I/native: session.cc:1081 Entering Session::Resume.
2020-09-29 13:11:03.519 7647-7647/com.example.app E/native: camera_config_manager.cc:750 UpdateBugFixes on CameraConfigManager is unimplemented!
2020-09-29 13:11:03.539 7647-7647/com.example.app I/CameraManagerGlobal: Connecting to camera service
2020-09-29 13:11:03.548 7647-7647/com.example.app I/native: android_sensors.cc:170 Starting thread.
2020-09-29 13:11:03.549 7647-7687/com.example.app I/native: android_camera.cc:762 [Camera=0; State=CLOSED] Reset cleanly got to CLOSED state.
2020-09-29 13:11:03.549 7647-7647/com.example.app I/native: cameras.cc:1142 Included camera stream {camera_id = "0", stream_index = 0} as feature extraction streams.
2020-09-29 13:11:03.549 7647-7647/com.example.app I/native: logger.h:28 DataSourceMetrics: kStartImageSubSystem: 1.064844ms
2020-09-29 13:11:03.549 7647-7647/com.example.app I/native: session.cc:1241 Session::ResumeWithAnalytics returning OK.
2020-09-29 13:11:03.550 7647-7722/com.example.app I/native: android_sensors.cc:43 Gyro min delay 2.5ms requesting 5ms
2020-09-29 13:11:03.579 7647-7722/com.example.app I/native: android_sensors.cc:43 Accel min delay 2.5ms requesting 5ms
2020-09-29 13:11:03.587 7647-7722/com.example.app I/native: android_sensors.cc:43 IMU Temperature min delay 200ms requesting 200ms
2020-09-29 13:11:03.600 7647-7670/com.example.app I/Gralloc4: mapper 4.x is not supported
2020-09-29 13:11:03.601 7647-7670/com.example.app W/Gralloc3: mapper 3.x is not supported
2020-09-29 13:11:03.609 7647-7670/com.example.app E/libc: Access denied finding property "vendor.gralloc.disable_ahardware_buffer"
2020-09-29 13:11:03.648 7647-7687/com.example.app I/native: logger.h:28 CameraMetrics: OpenCamera: 89.981884ms
2020-09-29 13:11:03.650 7647-7687/com.example.app I/native: camera_ndk_wrapper.cc:25 Loading Android NDK 28 symbols from libcamera2ndk.so
2020-09-29 13:11:03.651 7647-7687/com.example.app I/native: camera_ndk_wrapper.cc:45 Successfully loaded Android NDK 28 libcamera2ndk.so symbols.
2020-09-29 13:11:03.981 7647-7687/com.example.app I/native: logger.h:28 CameraMetrics: CreateCaptureSession: 330.649617ms
2020-09-29 13:11:03.983 7647-7687/com.example.app I/native: capture_request_utils.cc:142 This device does not support auto focus. Using fixed focus instead.
2020-09-29 13:11:03.983 7647-7687/com.example.app I/native: capture_request_utils.cc:206 Flash: ConfigureRequestFlashMode - OFF
2020-09-29 13:11:03.983 7647-7679/com.example.app I/native: cameras.cc:1313 Camera 0 changed state CLOSED->OPEN; Camera device opened successfully. i=0
2020-09-29 13:11:03.984 7647-7679/com.example.app I/native: cameras.cc:1313 Camera 0 changed state OPEN->CAPTURING; Started capture session. i=1
2020-09-29 13:11:03.984 7647-7687/com.example.app I/native: logger.h:28 DataSourceMetrics: kFirstGlCallback: 435.700356ms
2020-09-29 13:11:04.203 7647-7666/com.example.app W/Gralloc4: allocator 3.x is not supported
2020-09-29 13:11:04.204 7647-7666/com.example.app W/Gralloc3: allocator 3.x is not supported
2020-09-29 13:11:04.284 7647-7728/com.example.app I/native: logger.h:28 CameraMetrics: FirstCaptureComplete: 300.915707ms
2020-09-29 13:11:04.295 7647-7723/com.example.app I/native: timebase_helpers.cc:169 Timebase offset intialized to 0
2020-09-29 13:11:04.295 7647-7723/com.example.app I/native: logger.h:28 DataSourceMetrics: kFirstImageCallback: 747.137887ms
2020-09-29 13:11:04.309 7647-7701/com.example.app W/native: feature_matcher_and_filter_utils.cc:249 INVALID_ARGUMENT: integration window start at 0 Use identity R.

--------- beginning of crash

2020-09-29 13:11:04.349 7647-7647/com.example.app A/libc: Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x8 in tid 7647 (com.example.app), pid 7647 (com.example.app)
2020-09-29 13:11:04.723 7647-7698/com.example.app I/native: bundle_adjustment_initializer.cc:591 Deterministic initialization
2020-09-29 13:11:04.738 7647-7698/com.example.app I/native: bundle_adjustment_initializer.cc:171 Intrinsic vector size of the camera 0 is 7
2020-09-29 13:11:04.762 7647-7698/com.example.app I/native: bundle_adjustment_initializer.cc:360 Initializer did not converge: Maximum number of iterations reached. Number of iterations: 18.
2020-09-29 13:11:04.762 7647-7698/com.example.app I/native: ba_initialization_helpers.h:164 Number of measurements used in BA initialization for temporal landmarks: 300
2020-09-29 13:11:04.763 7647-7698/com.example.app I/native: ba_initialization_helpers.h:166 Number of good measurements (i.e., reprojection errors <= 3 pixels) in BA initialization for temporal landmarks: 299
2020-09-29 13:11:04.776 7647-7707/com.example.app E/libc: Access denied finding property "ro.hardware.chipname"
```

[bejado]

The crash doesn't look like its related to Filament.

Make sure you're supplying the correct number of float elements to irradiance (for 3 bands, you need 3² * 3 = 27 floats). If you do:

.irradiance(
        3,
        floatArrayOf(
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f,
        1.0f, 2.0f, 3.0f)
)

does it still crash?

[zirman]

@bejado It does supply a 27 element float. I tried it with the values given and still get the crash.

[bejado]

Interesting. I'll take a closer look

[romainguy]

Do you have more logs? Yours cutoff right when the crash dump starts.

[zirman]

Android studio was filtering them. Is this everything you need?

09-29 14:32:54.460 21701 21701 F libc    : Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x8 in tid 21701 (com.example.app), pid 21701 (com.example.app)
09-29 14:32:54.532 21860 21860 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
09-29 14:32:54.535   901   901 I tombstoned: received crash request for pid 21701
09-29 14:32:54.537 21860 21860 I crash_dump64: performing dump of process 21701 (target tid = 21701)
09-29 14:32:54.543 21701 21756 E native  : motion_tracking_context.cc:1030 Unable to find measurements corresponding to VIO status at timestamp 10654104898408.
09-29 14:32:54.548 21860 21860 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
09-29 14:32:54.548 21860 21860 F DEBUG   : Build fingerprint: 'google/blueline/blueline:11/RP1A.200720.009/6720564:user/release-keys'
09-29 14:32:54.548 21860 21860 F DEBUG   : Revision: 'MP1.0'
09-29 14:32:54.548 21860 21860 F DEBUG   : ABI: 'arm64'
09-29 14:32:54.551 21860 21860 F DEBUG   : Timestamp: 2020-09-29 14:32:54-0400
09-29 14:32:54.551 21860 21860 F DEBUG   : pid: 21701, tid: 21701, name: com.example.app  >>> com.example.app <<<
09-29 14:32:54.551 21860 21860 F DEBUG   : uid: 10697
09-29 14:32:54.551 21860 21860 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x8
09-29 14:32:54.551 21860 21860 F DEBUG   : Cause: null pointer dereference
09-29 14:32:54.551 21860 21860 F DEBUG   :     x0  0000007853a48ed0  x1  42c800000000077c  x2  0000000000000017  x3  0000000000000000
09-29 14:32:54.551 21860 21860 F DEBUG   :     x4  0000000000000010  x5  0000007fe62f7f27  x6  0000000000000030  x7  0000000000000030
09-29 14:32:54.551 21860 21860 F DEBUG   :     x8  0000007fe62f8150  x9  0000000000000000  x10 00000000b24ab3f0  x11 0000007a571cbf88
09-29 14:32:54.551 21860 21860 F DEBUG   :     x12 00000000000007c0  x13 0000000000000000  x14 0000007a55fc7d22  x15 0000000000000000
09-29 14:32:54.551 21860 21860 F DEBUG   :     x16 00000077582bca60  x17 0000007a571f2c4c  x18 0000007a59a14000  x19 00000078e3a61980
09-29 14:32:54.551 21860 21860 F DEBUG   :     x20 0000007fe62f8ce0  x21 0000007fe62f8f78  x22 0000007728be58f8  x23 00000078e3a619b0
09-29 14:32:54.551 21860 21860 F DEBUG   :     x24 0000007883a672d0  x25 0000007728be5040  x26 0000007853a48ed0  x27 0000000100000000
09-29 14:32:54.551 21860 21860 F DEBUG   :     x28 0000000000000001  x29 0000000000000001
09-29 14:32:54.551 21860 21860 F DEBUG   :     lr  0000007758228608  sp  0000007fe62f8150  pc  0000007758209334  pst 0000000080000000
09-29 14:32:54.552 21860 21860 F DEBUG   : backtrace:
09-29 14:32:54.552 21860 21860 F DEBUG   :       #00 pc 0000000000047334  /data/app/~~2hIPvskIXYCDD1TIKsBXgw==/com.example.app--H0ng98SL4ZrgSiFwKQCCg==/base.apk!libfilament-jni.so (offset 0x32000) (BuildId: 39c4c3709f6020a5f4fbeb249499a232081eefe0)
09-29 14:32:54.735 21701 21752 I native  : bundle_adjustment_initializer.cc:591 Deterministic initialization
09-29 14:32:54.737 21701 21752 I native  : bundle_adjustment_initializer.cc:171 Intrinsic vector size of the camera 0 is 7
09-29 14:32:54.756 21701 21752 I native  : ba_initialization_helpers.h:164 Number of measurements used in BA initialization for temporal landmarks: 300
09-29 14:32:54.756 21701 21752 I native  : ba_initialization_helpers.h:166 Number of good measurements (i.e., reprojection errors <= 3 pixels) in BA initialization for temporal landmarks: 299
09-29 14:32:54.765 21701 21760 E libc    : Access denied finding property "ro.hardware.chipname"

[romainguy]

It's better but the backtrace is still cutoff :) At least we know it's a null pointer somewhere now.

[zirman]

here is all of it:

09-29 14:38:19.344 29351 29351 I Finsky  : [2] aarq.a(1): Connecting InstallListener to SplitInstallService broadcaster...
09-29 14:38:19.352 29351 29351 I Finsky  : [2] rog.onTrimMemory(1): Memory trim requested to level 80
09-29 14:38:19.359 29351 30933 I Finsky  : [167] aasy.a(7): getSessionStates for package: com.facebook.lite
09-29 14:38:19.508   958  1031 I CHRE    : @ 10981.122: [AR] still: 42.352939
09-29 14:38:19.643 22492 22506 W JavaBinder: BinderProxy is being destroyed but the application did not call unlinkToDeath to unlink all of its death recipients beforehand.  Releasing leaked death recipient: X.1Ja
09-29 14:38:19.643 22492 22506 I BpBinder: onLastStrongRef automatically unlinking death recipients: <uncached descriptor>
09-29 14:38:19.807   958  1031 D VSC     : @ 10981.421: [WO] tilt angle 35
09-29 14:38:19.807   958  1031 D VSC     : @ 10981.421: [WO] isFlat() nearest_rotation: 0, flat_angle: 65
09-29 14:38:19.807   958  1031 D VSC     : @ 10981.421: [WO] orientation angle 2, orientation 0
09-29 14:38:20.838  1459  1511 E JobScheduler.Background: App com.google.android.gms became active but still in NEVER bucket
09-29 14:38:20.842  1459  1520 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
09-29 14:38:21.094 27110 27124 W System  : A resource failed to call close. 
09-29 14:38:21.094 27110 27124 E DataBuffer: Internal data leak within a DataBuffer object detected!  Be sure to explicitly call release() on all DataBuffer extending objects when you are done with them. (internal object: com.google.android.gms.common.data.DataHolder@125bc4c)
09-29 14:38:21.799  1459  1549 V DisplayPowerController: Brightness [0.05] reason changing to: 'automatic [ dim ]', previous reason: 'automatic'.
09-29 14:38:21.808   958  1031 D VSC     : @ 10983.422: [WO] tilt angle 37
09-29 14:38:21.808   958  1031 D VSC     : @ 10983.422: [WO] isFlat() nearest_rotation: 0, flat_angle: 65
09-29 14:38:21.808   958  1031 D VSC     : @ 10983.422: [WO] orientation angle 0, orientation 0
09-29 14:38:22.709   958  1031 I CHRE    : @ 10984.323: [AR] inconsistent: 41.176471
09-29 14:38:22.856  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
09-29 14:38:22.856  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
09-29 14:38:23.364  1459  1549 V DisplayPowerController: Brightness [0.22440796] reason changing to: 'automatic', previous reason: 'automatic [ dim ]'.
09-29 14:38:23.791  2105  2105 D RecentsOrientedState: current RecentsOrientedState: [this=RecentsOrientedState@3b04249 mOrientationHandler=PortraitPagedViewHandler@3b4a74e mDisplayRotation=0 mTouchRotation=0 mRecentsActivityRotation=0 isRecentsActivityRotationAllowed=false mSystemRotation=false mFlags=291]
09-29 14:38:23.792  2105  2105 I chatty  : uid=10033(com.google.android.apps.nexuslauncher) identical 2 lines
09-29 14:38:23.792  2105  2105 D RecentsOrientedState: current RecentsOrientedState: [this=RecentsOrientedState@3b04249 mOrientationHandler=PortraitPagedViewHandler@3b4a74e mDisplayRotation=0 mTouchRotation=0 mRecentsActivityRotation=0 isRecentsActivityRotationAllowed=false mSystemRotation=false mFlags=291]
09-29 14:38:23.806   958  1031 D VSC     : @ 10985.420: [WO] tilt angle 41
09-29 14:38:23.806   958  1031 D VSC     : @ 10985.421: [WO] isFlat() nearest_rotation: 0, flat_angle: 65
09-29 14:38:23.806   958  1031 D VSC     : @ 10985.421: [WO] orientation angle 5, orientation 0
09-29 14:38:25.519 22636 22638 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
09-29 14:38:25.631  1459  4411 I ActivityManager: Force stopping com.example.app appid=10697 user=0: from pid 22641
09-29 14:38:25.637 22641 22643 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
09-29 14:38:25.645  1459  2207 W ActivityManager: Permission Denial: Accessing service com.google.android.music/.dial.DialMediaRouteProviderService from pid=3128, uid=10013 that is not exported from uid 10102
09-29 14:38:25.647  2504 22644 I EuiccGoogle: [240] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: slotId = -1
09-29 14:38:25.649  3503  3503 D RegisteredNfcFServicesCache: Service unchanged, not updating
09-29 14:38:25.651  2504 22644 W EuiccGoogle: [240] EuiccServiceImpl.onGetEuiccProfileInfoList: slotId=-1. No eUICC is active. Return null.
09-29 14:38:25.741  1459  2207 I ActivityTaskManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 cmp=com.example.app/.aractivity.ArActivity} from uid 2000
09-29 14:38:25.742  1459  1514 D EventSequenceValidator: Transition from ACTIVITY_FINISHED to INTENT_STARTED
09-29 14:38:25.747  1081  1081 I perfetto: ing_service_impl.cc:758 Configured tracing session 49, #sources:1, duration:5000 ms, #buffers:1, total buffer size:4096 KB, total sessions:1, uid:1071 session name: ""
09-29 14:38:25.747  1079  1079 I perfetto: probes_producer.cc:230  Ftrace setup (target_buf=49)
09-29 14:38:25.753   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10697[I] (10)0x30000->*launch*[S] 
09-29 14:38:25.756  1079  1079 I perfetto: ftrace_procfs.cc:176    enabled ftrace
09-29 14:38:25.758 22648 22650 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
09-29 14:38:25.763  1459  1514 D CompatibilityChangeReporter: Compat change id reported: 135634846; UID 10697; state: DISABLED
09-29 14:38:25.765  1459  1521 D CompatibilityChangeReporter: Compat change id reported: 143937733; UID 10697; state: ENABLED
09-29 14:38:25.765  1459  1514 D EventSequenceValidator: Transition from INTENT_STARTED to ACTIVITY_LAUNCHED
09-29 14:38:25.781   922   922 D Zygote  : Forked child process 22656
09-29 14:38:25.786  1459  1521 I ActivityManager: Start proc 22656:com.example.app/u0a697 for pre-top-activity {com.example.app/com.example.app.aractivity.ArActivity}
09-29 14:38:25.786 22656 22656 I com.example.ap: Late-enabling -Xcheck:jni
09-29 14:38:25.802   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10262[I] (10)0x30000->*alarm*[S] 
09-29 14:38:25.805 22656 22656 I com.example.ap: Unquickening 12 vdex files!
09-29 14:38:25.806   958  1031 D VSC     : @ 10987.421: [WO] tilt angle 45
09-29 14:38:25.806   958  1031 D VSC     : @ 10987.421: [WO] isFlat() nearest_rotation: 4, flat_angle: 65
09-29 14:38:25.806   958  1031 D VSC     : @ 10987.421: [WO] orientation angle 357, orientation 4
09-29 14:38:25.809   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10262[I] (10)0x30000->*alarm*[S] 
09-29 14:38:25.810  1219  1266 I adbd    : jdwp connection from 22656
09-29 14:38:26.321 22656 22656 D NetworkSecurityConfig: No Network Security Config specified, using platform default
09-29 14:38:26.322 22656 22656 D NetworkSecurityConfig: No Network Security Config specified, using platform default
09-29 14:38:26.338 22656 22656 I TetheringManager: registerTetheringEventCallback:com.example.app
09-29 14:38:26.435 22656 22656 W com.example.ap: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (greylist, reflection, allowed)
09-29 14:38:26.436 22656 22656 W com.example.ap: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (greylist, reflection, allowed)
09-29 14:38:26.499 27110 13792 I native  : device_profile_database_helpers.cc:506 Found nothing for U78ORT
09-29 14:38:26.499 27110 13792 I native  : device_profile_database_helpers.cc:506 Found nothing for blueline/blueline
09-29 14:38:26.499 27110 13792 I native  : device_profile_database_helpers.cc:493 Considering ox1uFp:9
09-29 14:38:26.499 27110 13792 I native  : device_profile_database_helpers.cc:452 Device profile for google/blueline/blueline:11/RP1A.200720.009/6720564:user/release-keys: ox1uFp:9
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: QUALCOMM build                   : c9bef8a, Ie73904e3bd
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Build Date                       : 06/26/20
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: OpenGL ES Shader Compiler Version: EV031.31.04.00
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Local Branch                     : gfx-adreno.lnx.2.0
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Remote Branch                    : quic/gfx-adreno.lnx.2.0
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Remote Branch                    : NONE
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Reconstruct Branch               : NOTHING
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Build Config                     : C P 11.0.1 AArch64
09-29 14:38:26.503 22656 22656 I AdrenoGLES-0: Driver Path                      : /vendor/lib64/egl/libGLESv2_adreno.so
09-29 14:38:26.506 22656 22656 I AdrenoGLES-0: PFP: 0x016ee189, ME: 0x00000000
09-29 14:38:26.507 22656 22656 W AdrenoUtils: <ReadGpuID_from_sysfs:197>: Failed to open /sys/class/kgsl/kgsl-3d0/gpu_model
09-29 14:38:26.507 22656 22656 W AdrenoUtils: <ReadGpuID:221>: Failed to read chip ID from gpu_model. Fallback to use the GSL path
09-29 14:38:26.540 22656 22656 I third_party/arcore/ar/core/android/sdk/session_create.cc: Entering ArSession_createWithFeatures
09-29 14:38:26.540 22656 22656 I third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: SDK build name: 1.19
09-29 14:38:26.543 22656 22656 I third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore Version: APK version code: 202550203
09-29 14:38:26.549 22656 22656 D ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar
09-29 14:38:26.574 22656 22656 I third_party/arcore/ar/core/android/sdk/session_create.cc: Dynamite load ok.
09-29 14:38:26.574 22656 22656 I third_party/arcore/java/com/google/vr/dynamite/client/native/dynamite_client.cc: Attempting to load native library arcore_c from package com.google.ar.core
09-29 14:38:26.597 22656 22656 I third_party/arcore/java/com/google/vr/dynamite/client/native/dynamite_client.cc: Dynamite::LoadNativeRemoteLibrary handle=6484197039035110987
09-29 14:38:26.598 22656 22656 I third_party/arcore/ar/core/android/sdk/session_create.cc: ARCore SDK: dynamite number_of_symbols_loaded=206
09-29 14:38:26.598 22656 22656 I native  : session_create_implementation.cc:194 Entering createImplementationWithFeaturesAndSettings. ARCore SDK version: [1.19.201750000].
09-29 14:38:26.606 22656 22685 V third_party/redwood/infrastructure/jni_common/jni_helper.cc: JniHelper: attached thread (Called from line 363).
09-29 14:38:26.607 27110  8700 W ARCore-ContentProvider: No usable local profile
09-29 14:38:26.608 27110  8700 I native  : device_profile_database_helpers.cc:506 Found nothing for U78ORT
09-29 14:38:26.608 27110  8700 I native  : device_profile_database_helpers.cc:506 Found nothing for blueline/blueline
09-29 14:38:26.608 27110  8700 I native  : device_profile_database_helpers.cc:493 Considering ox1uFp:9
09-29 14:38:26.608 27110  8700 I native  : device_profile_database_helpers.cc:452 Device profile for google/blueline/blueline:11/RP1A.200720.009/6720564:user/release-keys: ox1uFp:9
09-29 14:38:26.609 27110  8700 W native  : helpers.cc:3248 Defaulting to persistent calibration file.
09-29 14:38:26.609 27110  8700 W native  : helpers.cc:3225 Property calibration_cad is not defined.
09-29 14:38:26.611 22656 22656 I native  : session_create_implementation_shared.cc:2076 Persistent online recalibration is enabled by Phenotype.
09-29 14:38:26.612 22656 22656 I tflite  : Initialized TensorFlow Lite runtime.
09-29 14:38:26.613 22656 22656 I native  : online_calibration_manager.cc:90 OnlineCalibrationManager: Could not open /data/user/0/com.example.app/cache/arcore-online-recalibration for reading.
09-29 14:38:26.636 22656 22656 W ARCore-ContextUtils: The API key for use with the Google AR service could not be obtained!
09-29 14:38:26.651 22656 22656 I native  : session_create_implementation_shared.cc:904 Datasource will be created with timeout = 4s, should_wait = false, should_use_greedy_recovery = true
09-29 14:38:26.651 22656 22656 I native  : android_camera.cc:168 Camera start operation timeout set to 4000 ms.
09-29 14:38:26.651 22656 22656 I native  : android_camera.cc:1823 Initializing camera manager.
09-29 14:38:26.652  1102  4307 W ServiceManager: Permission failure: android.permission.CAMERA_OPEN_CLOSE_LISTENER from uid=10697 pid=22656
09-29 14:38:26.656 22656 22656 I native  : android_camera.cc:1849 Camera manager initialized successfully with 4 cameras.
09-29 14:38:26.656 22656 22656 I native  : session_create_implementation_shared.cc:1085 Datasource will be created with should_use_cameras_async = true
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:95 Using uncalibrated accelerometer.
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:123 Found IMU temperature sensor.
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:133 Using uncalibrated magnetometer.
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_LIGHT
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_PRESSURE
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_PROXIMITY
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_GRAVITY
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_ROTATION_VECTOR
09-29 14:38:26.657 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_GAME_ROTATION_VECTOR
09-29 14:38:26.658 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_GEOMAGNETIC_ROTATION_VECTOR
09-29 14:38:26.658 22656 22656 I native  : android_sensors.cc:148 Using SENSOR_TYPE_STEP_DETECTOR
09-29 14:38:26.659 22656 22656 I native  : android_platform_checks.cc:194 IsZeroRotationLandscape = false
09-29 14:38:26.659 22656 22656 I native  : create_pursuit_tracker.cc:20 AugmentedRegion downsample mode from Phenotype: false
09-29 14:38:26.660 22656 22656 I native  : app_version_util.cc:50 Package name: com.google.ar.core App version: 1.20.202550203
09-29 14:38:26.660 22656 22656 I native  : logger.h:28 DataSourceMetrics: CamerasInit: 30.26us
09-29 14:38:26.660 22656 22656 I native  : session_create_implementation_shared.cc:1228 CPU Image enable frame delay to compensate delay: false
09-29 14:38:26.662  1459  3553 D CompatibilityChangeReporter: Compat change id reported: 136274596; UID 10697; state: ENABLED
09-29 14:38:26.663 27110 27110 W FeatureSplitService: Service bound
09-29 14:38:26.668 22656 22656 I native  : config_helpers.cc:396 Legacy IMU sigma values are used
09-29 14:38:26.668 22656 22656 I native  : config_helpers.cc:349 Failed to find IMU intrinsic covariance matrix in profile for id: 100
09-29 14:38:26.668 22656 22656 I native  : config_helpers.cc:107 Does not find camera intrinsic covariance matrix in profile for id 0
09-29 14:38:26.668 22656 22656 I native  : config_helpers.cc:180 Does not find extrinsic covariance matrix in profile for IMU id 100
09-29 14:38:26.669 22656 22656 I native  : feature_matcher_and_filter.cc:91 Enabled the robustification to large-sized and fast-moving objects on this mono-camera device.
09-29 14:38:26.671 22656 22656 I native  : pose_confidence_estimator.cc:220 Pose confidence model loaded successfully
09-29 14:38:26.739 22656 22656 I native  : asset_manager_util.cc:59 Created global reference to asset manager.
09-29 14:38:26.739 22656 22656 I native  : session_create_implementation_shared.cc:1255 Normal detector created.
09-29 14:38:26.754 22656 22656 I native  : planar_target_tracking_manager.h:114 Config of PlanarTargetTrackingManager:
09-29 14:38:26.754 22656 22656 I native  : -pose_refinement_with_detection_interval_ns: 0
09-29 14:38:26.754 22656 22656 I native  : -min_interval_between_detections_ns: 500000000
09-29 14:38:26.754 22656 22656 I native  : -filter_parallax: false
09-29 14:38:26.754 22656 22656 I native  : -filter_result: true
09-29 14:38:26.754 22656 22656 I native  : -multiple_targets: true
09-29 14:38:26.754 22656 22656 I native  : -mini_detection: true
09-29 14:38:26.754 22656 22656 I native  : -tracking_mode: 1
09-29 14:38:26.754 22656 22656 I native  : -camera_id: 0
09-29 14:38:26.757 22656 22656 E native  : camera_config_manager.cc:750 UpdateBugFixes on CameraConfigManager is unimplemented!
09-29 14:38:26.757 22656 22656 W com.example.ap: Accessing hidden method Landroid/media/Image;-><init>()V (greylist, linking, allowed)
09-29 14:38:26.757 22656 22656 I third_party/arcore/ar/core/android/sdk/arimage_jni.cc: Loading AImage symbols
09-29 14:38:26.758 22656 22656 I third_party/arcore/ar/core/android/sdk/image_metadata_jni.cc: Loading ACameraMetadata symbols
09-29 14:38:26.761 22656 22656 I native  : session.cc:480 Session::CheckAndWriteCurrentConfig returning OK.
09-29 14:38:26.763 27110 27110 W ARCore.Analytics: Log Source: PJgQUl1CRhj8-rGlwtloKA==
09-29 14:38:26.768  3128  5351 I PeopleChimeraService: onService. callbacks = yom@8ef6ad2, request = com.google.android.gms.common.internal.GetServiceRequest@e8a7a3
09-29 14:38:26.775 22656 22656 I Filament: FEngine (64 bits) created at 0x7728bde040 (threading is enabled)
09-29 14:38:26.775 22656 22723 D Filament: Using ASurfaceTexture
09-29 14:38:26.775 22656 22723 D Filament: FEngine resolved backend: OpenGL
09-29 14:38:26.776 27110 27110 W PeopleDeviceAccountsProvider: Processing 2 accounts
09-29 14:38:26.824 22656 22656 I native  : session.cc:1081 Entering Session::Resume.
09-29 14:38:26.825 22656 22656 E native  : camera_config_manager.cc:750 UpdateBugFixes on CameraConfigManager is unimplemented!
09-29 14:38:26.839 22656 22656 I CameraManagerGlobal: Connecting to camera service
09-29 14:38:26.841  1102  4307 W ServiceManager: Permission failure: android.permission.CAMERA_OPEN_CLOSE_LISTENER from uid=10697 pid=22656
09-29 14:38:26.843 22656 22656 I native  : android_sensors.cc:170 Starting thread.
09-29 14:38:26.843 22656 22696 I native  : android_camera.cc:762 [Camera=0; State=CLOSED] Reset cleanly got to CLOSED state.
09-29 14:38:26.843 22656 22656 I native  : cameras.cc:1142 Included camera stream {camera_id = "0", stream_index = 0} as feature extraction streams.
09-29 14:38:26.843 22656 22656 I native  : logger.h:28 DataSourceMetrics: kStartImageSubSystem: 119.583us
09-29 14:38:26.843 22656 22656 I native  : session.cc:1241 Session::ResumeWithAnalytics returning OK.
09-29 14:38:26.845 22656 22729 I native  : android_sensors.cc:43 Gyro min delay 2.5ms requesting 5ms
09-29 14:38:26.845   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope_uncalibrated/161, period=200000000, max_latency=0
09-29 14:38:26.845   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope_uncalibrated/161, period=200000000, max_latency=0 request completed
09-29 14:38:26.845   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope_uncalibrated/161 en=1
09-29 14:38:26.845   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.846   958   958 D Diag_Lib:  Diag_LSM_Init: Failed to open handle to diag driver, error = 13
09-29 14:38:26.842   958   958 W [email protected]: type=1400 audit(0.0:962): avc: denied { read write } for name="diag" dev="tmpfs" ino=12790 scontext=u:r:hal_sensors_default:s0 tcontext=u:object_r:diag_device:s0 tclass=chr_file permissive=0
09-29 14:38:26.846   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.847  1102  4307 I CameraService: CameraService::connect call (PID -1 "", camera ID 0) for HAL version default and Camera API version 2
09-29 14:38:26.847   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope_uncalibrated/161 en=1 completed
09-29 14:38:26.847   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope_uncalibrated/161, period=5000000, max_latency=0
09-29 14:38:26.847   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope_uncalibrated/161, period=5000000, max_latency=0 request completed
09-29 14:38:26.848 22656 22729 I native  : android_sensors.cc:43 Accel min delay 2.5ms requesting 5ms
09-29 14:38:26.848  1102  4307 I Camera2ClientBase: Camera 0: Opened. Client:  (PID 22656, UID 10697)
09-29 14:38:26.848  1102  4307 I CameraDeviceClient: CameraDeviceClient 0: Opened
09-29 14:38:26.848   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.accelerometer_uncalibrated/351, period=200000000, max_latency=0
09-29 14:38:26.848   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.accelerometer_uncalibrated/351, period=200000000, max_latency=0 request completed
09-29 14:38:26.848   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.accelerometer_uncalibrated/351 en=1
09-29 14:38:26.848   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.846   958   958 W [email protected]: type=1400 audit(0.0:963): avc: denied { read write } for name="diag" dev="tmpfs" ino=12790 scontext=u:r:hal_sensors_default:s0 tcontext=u:object_r:diag_device:s0 tclass=chr_file permissive=0
09-29 14:38:26.849   958   958 D Diag_Lib:  Diag_LSM_Init: Failed to open handle to diag driver, error = 13
09-29 14:38:26.849   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.849  1102  4307 I CameraService: onTorchStatusChangedLocked: Torch status changed for cameraId=0, newStatus=0
09-29 14:38:26.850  1102  4307 I CameraProviderManager: Camera device [email protected]/legacy/0 torch status is now NOT_AVAILABLE
09-29 14:38:26.850  1102  4307 I CameraService: onTorchStatusChangedLocked: Torch status changed for cameraId=0, newStatus=0
09-29 14:38:26.850  2234  2234 D GRIL-S  : [0216]> UPDATE_DEVICE_STATE DeviceState: Usb:1, Wifi: 1, Wifi AP: 0, Earpiece: 0, Bluetooth: 1, Wireless charging: 0, Screen: 1, Camera: 1, 0, 0, 0, Motion: 1, Bluetooth tethering: 0, Voice: 0, Wifi 2.4G: 0, Radio: 1, Bluetooth connected: 0, Bluetooth media: 0
09-29 14:38:26.850   940 27240 D CameraThermalHAL: Starting Thermal HAL polling thread
09-29 14:38:26.851   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.accelerometer_uncalibrated/351 en=1 completed
09-29 14:38:26.852   940 27240 D CameraThermalHAL: Started thermal polling thread successfully
09-29 14:38:26.852   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.accelerometer_uncalibrated/351, period=5000000, max_latency=0
09-29 14:38:26.852   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.accelerometer_uncalibrated/351, period=5000000, max_latency=0 request completed
09-29 14:38:26.852 22656 22729 I native  : android_sensors.cc:43 IMU Temperature min delay 200ms requesting 200ms
09-29 14:38:26.852   940 27240 E FMQ     : grantorIdx must be less than 3
09-29 14:38:26.852   940 27240 E FMQ     : grantorIdx must be less than 3
09-29 14:38:26.853   958   958 I sensors-hal: batch_physical_sensor:285, com.google.sensor.gyro_temperature/11021, period=200000000, max_latency=0
09-29 14:38:26.853   958   958 I sensors-hal: batch_physical_sensor:296, com.google.sensor.gyro_temperature/11021, period=200000000, max_latency=0 request completed
09-29 14:38:26.853  1102  4307 E FMQ     : grantorIdx must be less than 3
09-29 14:38:26.853   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.gyro_temperature/11021 en=1
09-29 14:38:26.853  1102  4307 E FMQ     : grantorIdx must be less than 3
09-29 14:38:26.853   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.854   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.gyro_temperature/11021 en=1 completed
09-29 14:38:26.854  2234  3081 D GRIL-S  : [0216]< UPDATE_DEVICE_STATE 
09-29 14:38:26.854 22656 22696 I native  : logger.h:28 CameraMetrics: OpenCamera: 8.221512ms
09-29 14:38:26.855 22656 22696 I native  : camera_ndk_wrapper.cc:25 Loading Android NDK 28 symbols from libcamera2ndk.so
09-29 14:38:26.856 22656 22696 I native  : camera_ndk_wrapper.cc:45 Successfully loaded Android NDK 28 libcamera2ndk.so symbols.
09-29 14:38:26.857  1102  6845 W CameraDeviceClient: createSurfaceFromGbp: Camera 0 with consumer usage flag: 256: Forcing asynchronous mode for stream
09-29 14:38:26.857  1102  6845 W CameraDeviceClient: createSurfaceFromGbp: Camera 0: Overriding format 0x1 to IMPLEMENTATION_DEFINED
09-29 14:38:26.857   958 22734 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.857   958 22743 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.859  1156  1156 I EaselThermalMonitor: Cooling Device: mnh cur_state 0 max_state 4
09-29 14:38:26.859   940 27240 I CHIUSECASE: Google usecase selected
09-29 14:38:26.860   940 27240 I CHIUSECASE: LogClassifiedStream: Camera 0 preview stream type = 0 format = 34 width = 1920 height = 1080
09-29 14:38:26.860   940 27240 I CHIUSECASE: LogClassifiedStream: Camera 0 yuv stream type = 0 format = 35 width = 640 height = 480
09-29 14:38:26.860   940 27240 I CHIUSECASE: Use preview aspect ratio as dummy stream
09-29 14:38:26.861  1156  1156 I EaselThermalMonitor: Cooling Device: mnh cur_state 0 max_state 4
09-29 14:38:26.861   940 27240 I CHIUSECASE: CreatePipelines: Creating pipelines for CHI usecase: UsecaseGooglePhoto1
09-29 14:38:26.861   940 27240 I CHIUSECASE: GoogleUsecasePipeline: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:26.861   958 22738 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.861   940 27240 D CHIUSECASE: Initialize: RDI resolution: 4032x3024
09-29 14:38:26.861   940 27240 D CHIUSECASE: [Offline HDR+ Pipeline] CreateChiPipeline: Creating the CHI pipeline.
09-29 14:38:26.862   940 27240 E GOOGLE_CHINODE_HDRPLUS: CHINODECAPSINFO is smaller than expected
09-29 14:38:26.862   940 27240 I CHIUSECASE: CameraID: 0, SelectedMode W=4032, H=3024, FPS:30, NumBatchedFrames:1, modeIndex:0
09-29 14:38:26.862   940 27240 I CHIUSECASE: Initialize: mGcamMinPayloadFrames: 2
09-29 14:38:26.863   940 27240 I CHIUSECASE: Create: Created a GoogleUsecaseOfflineHdrplusPipeline for camera 0
09-29 14:38:26.863   940 27240 I CHIUSECASE: GoogleUsecasePipeline: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:26.864   940 27240 D CHIUSECASE: Initialize: RDI resolution: 4032x3024
09-29 14:38:26.864   940 27240 D CHIUSECASE: [Realtime ZSL Pipeline] CreateChiPipeline: Creating the CHI pipeline.
09-29 14:38:26.864   940 22757 E CameraMetadataUtils: InitializeLensGcamGeometricCalibration: 335: distortion is NULL.
09-29 14:38:26.864   940 22757 W CameraMetadataUtils: Create: Initializing GCAM geometric calibration metadata failed: No such file or directory (-2)
09-29 14:38:26.864   940 22757 I native  : gcam.cc:365 Writing AP timing log to /data/camera/ap_3pa.timing
09-29 14:38:26.864   940 27240 I goog_warping: Create
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.debug is set to 0
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.enable is set to 1
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.vcmdelay is set to 0
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.usegyrodirect is set to 0
09-29 14:38:26.864   940 22757 I native  : gcam.cc:371 Creating IpuServiceReferenceThirdPartyIdle
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.usegyropoll is set to 1
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.fdinfo is set to 1
09-29 14:38:26.864   940 27240 D goog_warping: persist.camera.warping.ftmethod is set to 1
09-29 14:38:26.864   940 22757 I native  : easel_service_control.cc:275 SuspendReferenceCountIncrement suspend_reference_count_=2
09-29 14:38:26.864   940 22757 I native  : ipu_wake_lock.cc:69 IpuWakeLock::Request:0x719c67c4d8:1
09-29 14:38:26.864   940 22757 I native  : easel_service_control.cc:326 RunReferenceCountIncrement run_reference_count_=1
09-29 14:38:26.864   940 22757 I native  : easel_service_control.cc:705 COMMAND_PROCESSOR_3PA: ResumeAsync
09-29 14:38:26.864   940 27240 I goog_warping: Warping node in photo mode. No crop is used.
09-29 14:38:26.864   940 22757 I native  : ipu_wake_lock.cc:69 IpuWakeLock::Request:0x7103f69118:9
09-29 14:38:26.865   940 22757 I native  : easel_service_control.cc:485 COMMAND_PROCESSOR_3PA: WaitUntilRunning
09-29 14:38:26.865   940 22758 I native  : easel_service_control.cc:710 COMMAND_PROCESSOR_3PA: EaselManager::Resume
09-29 14:38:26.865  1156  1156 I EaselThermalMonitor: Cooling Device: mnh cur_state 0 max_state 4
09-29 14:38:26.868   958 22747 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.868   940 27240 I GoogleFDNode: Initialize: GoogleFDNode created ensemble detector successfully.
09-29 14:38:26.868   940 27240 I GoogleFDNode: Initialize: GoogleFDNode uses dedicated thread for Ensemble.
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceSkipFrame to 804f000e
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.count to 804f000f
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.ids to 804f0010
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.xy to 804f0011
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.depth to 804f0012
09-29 14:38:26.869   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceOrientation to 804f0014
09-29 14:38:26.869   940 27240 E CamX    : [ERROR][PPROC  ] camxipenode.cpp:2293 ProcessingNodeFinalizeInputRequirement() NonConformant AspectRatio:1.333333 Change Width 852 using AR:1.777778
09-29 14:38:26.869   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:26.869   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:26.869   940 27240 E CamX    : [ERROR][PPROC  ] camxipenode.cpp:2293 ProcessingNodeFinalizeInputRequirement() NonConformant AspectRatio:1.333333 Change Width 852 using AR:1.777778
09-29 14:38:26.869   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:26.869   940 27240 I CHIUSECASE: CameraID: 0, SelectedMode W=4032, H=3024, FPS:30, NumBatchedFrames:1, modeIndex:0
09-29 14:38:26.869   940 27240 I CHIUSECASE: Create: Created a GoogleUsecaseRealtimeZslPipeline for camera 0
09-29 14:38:26.869   940 27240 I CHIUSECASE: Build: building a session with pipeline for camera id 0
09-29 14:38:26.879   710   738 I BpBinder: onLastStrongRef automatically unlinking death recipients: <uncached descriptor>
09-29 14:38:26.881   669   669 I hwservicemanager: getTransport: Cannot find entry [email protected]::IMapper/default in either framework or device manifest.
09-29 14:38:26.882 22656 22679 I Gralloc4: mapper 4.x is not supported
09-29 14:38:26.882   669   669 I hwservicemanager: getTransport: Cannot find entry [email protected]::IMapper/default in either framework or device manifest.
09-29 14:38:26.882 22656 22679 W Gralloc3: mapper 3.x is not supported
09-29 14:38:26.883   958 22754 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.884   958  1031 D ASH     : @ 10988.499: SensorType 1 resampler quality 1
09-29 14:38:26.884   958  1031 D ASH     : @ 10988.499: SensorType 195 resampler quality 1
09-29 14:38:26.884   958  1031 D CHRE    : @ 10988.500: SensorType 195 resampler quality 1
09-29 14:38:26.885 22656 22679 E libc    : Access denied finding property "vendor.gralloc.disable_ahardware_buffer"
09-29 14:38:26.888   940 27240 I [email protected]_64: [GOOG_STATS] PDLibData already assigned
09-29 14:38:26.888   940 27240 I [email protected]_64: [GOOG_STATS] Calling CreatePDLib in QC library
09-29 14:38:26.894  1963  1963 I Elmyra/ElmyraService: Gated by NavigationBarVisibility [mIsNavigationHidden -> true; mExceptions -> [DismissTimer [mReceiverRegistered -> true], SnoozeAlarm [mReceiverRegistered -> true], SilenceCall [mSilenceSettingEnabled -> true], SettingsAction]; mIsNavigationGestural -> true; isActiveAssistantNga() -> false]
09-29 14:38:26.895  1459  1514 D EventSequenceValidator: Transition from ACTIVITY_LAUNCHED to ACTIVITY_FINISHED
09-29 14:38:26.895   943   943 V ContextHubHal: sendMessageToHub
09-29 14:38:26.896  1459  1519 D ArtManagerInternalImpl: /data/misc/iorapd/com.example.app/13/com.example.app.aractivity.ArActivity/compiled_traces/compiled_trace.pb doesn't exist
09-29 14:38:26.897   958  1031 D CHRE    : @ 10988.512: Parsed nanoapp message from host: app ID 0x476f6f676c00100e, endpoint 0x1, msgType 201, payload size 0
09-29 14:38:26.898   958  1031 D CHRE    : @ 10988.513: Elmyra/Nanoapp Recognizer stopped
09-29 14:38:26.898  1459  1519 I ActivityTaskManager: Displayed com.example.app/.aractivity.ArActivity: +1s153ms
09-29 14:38:26.909  1459  2170 E JavaBinder: *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
09-29 14:38:26.909  1459  2170 E JavaBinder: java.lang.RuntimeException: android.os.RemoteException: Couldn't get ApplicationInfo for package [email protected]::ISensorManager
09-29 14:38:26.909  1459  2170 E JavaBinder:    at android.os.Parcel.writeException(Parcel.java:2158)
09-29 14:38:26.909  1459  2170 E JavaBinder:    at android.os.Binder.execTransactInternal(Binder.java:1178)
09-29 14:38:26.909  1459  2170 E JavaBinder:    at android.os.Binder.execTransact(Binder.java:1123)
09-29 14:38:26.909  1459  2170 E JavaBinder: Caused by: android.os.RemoteException: Couldn't get ApplicationInfo for package [email protected]::ISensorManager
09-29 14:38:26.909  1459  2170 E JavaBinder:    at com.android.server.pm.PackageManagerService$PackageManagerNative.getTargetSdkVersionForPackage(PackageManagerService.java:23939)
09-29 14:38:26.909  1459  2170 E JavaBinder:    at android.content.pm.IPackageManagerNative$Stub.onTransact(IPackageManagerNative.java:255)
09-29 14:38:26.909  1459  2170 E JavaBinder:    at android.os.Binder.execTransactInternal(Binder.java:1159)
09-29 14:38:26.909  1459  2170 E JavaBinder:    ... 1 more
09-29 14:38:26.910   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope/41, period=5000000, max_latency=0
09-29 14:38:26.910   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope/41, period=5000000, max_latency=0 request completed
09-29 14:38:26.911   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope/41 en=1
09-29 14:38:26.912   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.909   958   958 W [email protected]: type=1400 audit(0.0:964): avc: denied { read write } for name="diag" dev="tmpfs" ino=12790 scontext=u:r:hal_sensors_default:s0 tcontext=u:object_r:diag_device:s0 tclass=chr_file permissive=0
09-29 14:38:26.912   958   958 D Diag_Lib:  Diag_LSM_Init: Failed to open handle to diag driver, error = 13
09-29 14:38:26.913   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:26.913   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope/41 en=1 completed
09-29 14:38:26.916   958 22768 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.916  3357  3357 I GoogleInputMethodService: GoogleInputMethodService.onFinishInput():3184 
09-29 14:38:26.917  3357  3357 I GoogleInputMethodService: GoogleInputMethodService.onStartInput():1830 
09-29 14:38:26.917   958 22772 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:26.933   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10697[I] (10)0x30000->*launch*[S] 
09-29 14:38:26.952  3964  4426 W SearchServiceCore: Abort, client detached.
09-29 14:38:26.953  3964  4426 I StreamController: cleanUpControllerScope(nowcards-15-a22ad0-3dc9)
09-29 14:38:26.954  3964 20483 I PBSessionCacheImpl: Deleted sessionId[17435457763768896] from persistence.
09-29 14:38:26.959  1156  1156 I EaselPowerBlue: [TIME_LOGGER] resume took 93 ms
09-29 14:38:26.960   940 22758 I native  : easel_manager_callback.cc:34 COMMAND_PROCESSOR_3PA on easel started
09-29 14:38:26.960   940 22757 I native  : session.cc:71 SetEaselPortId:13
09-29 14:38:26.961   940 22757 I native  : ipu_wake_lock.cc:95 IpuWakeLock::WaitAcquire:0x7103f69118:0
09-29 14:38:26.961   940 22757 I native  : easel_service_control.cc:326 RunReferenceCountIncrement run_reference_count_=2
09-29 14:38:26.961   940 22757 I native  : ipu_wake_lock.cc:69 IpuWakeLock::Request:0x71cc652318:2
09-29 14:38:26.961   940 22757 I native  : session.cc:71 SetEaselPortId:13
09-29 14:38:26.961   940 22757 I native  : ipu_wake_lock.cc:95 IpuWakeLock::WaitAcquire:0x71cc652318:0
09-29 14:38:26.961   940 27248 I native  : ipu_keepalive.cc:85 IpuKeepAliveThread: PING (sync)
09-29 14:38:26.961   940 22757 I native  : ipu_wake_lock.cc:75 IpuWakeLock::Release:0x7103f69118
09-29 14:38:26.961   940 22757 I native  : easel_service_control.cc:345 RunReferenceCountDecrement run_reference_count_=1
09-29 14:38:26.961   940 22757 I native  : gcam.cc:402 Gcam thread id = 22757
09-29 14:38:26.962   940 22757 I libgcam : [gcam.cc:441]: Initializing camera 0: device blueline, device code 97df6696b247a2aed6addb76c879acdc, sensor ID 0.
09-29 14:38:26.962   940 22757 I native  : gcam.cc:462 halide_ipu_set_timeout=2s
09-29 14:38:26.962   940 22757 I native  : easel_service_control.cc:326 RunReferenceCountIncrement run_reference_count_=2
09-29 14:38:26.963   940 22757 I native  : ipu_wake_lock.cc:69 IpuWakeLock::Request:0x7103f69278:9
09-29 14:38:26.963   940 22757 I native  : session.cc:71 SetEaselPortId:13
09-29 14:38:26.963   940 22757 I native  : ipu_wake_lock.cc:95 IpuWakeLock::WaitAcquire:0x7103f69278:0
09-29 14:38:26.963   940 22757 I native  : imx_fine_grain_client.cc:47 Acquire ImxSession Reference. reference_count_=2
09-29 14:38:26.963   940 22757 I native  : ipu_wake_lock.cc:75 IpuWakeLock::Release:0x7103f69278
09-29 14:38:26.963   940 22757 I native  : easel_service_control.cc:345 RunReferenceCountDecrement run_reference_count_=1
09-29 14:38:26.964   940 22757 I libgcam : [gcam.cc:557]: Gcam initialized.
09-29 14:38:26.964   940 22757 I HdrplusProcessing: InitializeGcam: Initialized GCAM.
09-29 14:38:26.968   940 27240 E CamX    : [ERROR][STATS_AEC] aec_set.cpp:1586: aec_set_init_chromatix_sensor aec_set_init_chromatix_sensor is called before LoadTuning
09-29 14:38:26.968   940 27240 E CamX    : [ERROR][STATS_AEC] aec_get.cpp:575: aec_get_param Wrong sequence! Get exposure before AE init idx=-1
09-29 14:38:26.968   940 27240 E CamX    : [ERROR][STATS_AEC] camxae.cpp:1801: AecGetStartExposure aec get parameter failed
09-29 14:38:26.968   940 27240 E CamX    : [ERROR][STATS_AEC] camxcaecstatsprocessor.cpp:1757 PopulatePropPoolFrameControl() Invalid exposure parameters: gain: 0.000000, exposureTime: 0
09-29 14:38:26.970  1156  1183 I EaselThermalMonitor: (Low) mnh_cpu: 35.11, mnh_ipu1: 37.33, mnh_ipu2: 36.08, mnh_lpddr: 34.84
09-29 14:38:26.970  1156  1183 I EaselThermalMonitor: Cooling Device: mnh cur_state 0 max_state 4
09-29 14:38:26.970  1156  1183 I EaselManagerServer: Old thermal condition: 4, new thermal condition: 0
09-29 14:38:26.970  1156  1156 I EaselThermalMonitor: Cooling Device: mnh cur_state 0 max_state 4
09-29 14:38:26.970  1156  1183 I EaselPowerBlue: [TIME_LOGGER] setClockMode took 0 ms
09-29 14:38:26.981   940 27240 D CamX    : [DEBUG][STATS_AWB] camxcawbstatsprocessor.cpp:749 SetOperationModetoAlgo() Mode set to Algo: 1
09-29 14:38:26.985   958   958 I sensors-hal: flush_physical_sensor:328, android.sensor.gyroscope/41
09-29 14:38:26.985   958   958 I sensors-hal: flush_physical_sensor:336, android.sensor.gyroscope/41 completed
09-29 14:38:26.988   958  1031 I VSC     : @ 10988.604: {Fusion} configure fusion 9 19230us 0us.
09-29 14:38:26.988   958  1031 D VSC     : @ 10988.604: [Gravity Sensor] Request accel, interval 19.2 ms, latency 0.0 ms
09-29 14:38:26.996   958  1031 D VSC     : @ 10988.605: [Gravity Sensor] Request gyro, interval 5.0 ms, latency 0.0 ms
09-29 14:38:26.996   958  1031 D ASH     : @ 10988.612: SensorType 1 resampler quality 2
09-29 14:38:27.006   940  1541 I [email protected]_64: [GOOG_STATS] PDAF wrapper is successfully initialized
09-29 14:38:27.006   940  1541 I [email protected]_64: [GOOG_STATS] PDAF infinity DAC = -315, macro DAC = 455, image bits = 8
09-29 14:38:27.006   940  1541 I [email protected]_64: [GOOG_STATS] doDefaultPDProcess = 0
09-29 14:38:27.006   940  1541 I [email protected]_64: [GOOG_STATS] Calling QC PDLibInitialize: run on sparse PD = 0
09-29 14:38:27.012   940 22785 I native  : flicker_wrapper.cc:82 FlickerCreate
09-29 14:38:27.013   940 22785 I native  : flicker_wrapper.cc:87 Using default flicker parameters.
09-29 14:38:27.040   940 27240 I GoogSensorSync: GoogSensorSync 67 Sensor sync camera ID: 0
09-29 14:38:27.041   940 27240 I GoogSensorSync: GetSensorHandle 109 handle for 0 is found.
09-29 14:38:27.043   958   958 I sensors-hal: batch_physical_sensor:285, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0
09-29 14:38:27.043   958   958 I sensors-hal: batch_physical_sensor:296, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0 request completed
09-29 14:38:27.043   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.camera_vsync/11051 en=1
09-29 14:38:27.043   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:27.044   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.camera_vsync/11051 en=1 completed
09-29 14:38:27.044   940 27240 I CHIUSECASE: Build: building a session with pipeline for camera id 0
09-29 14:38:27.054   940 27240 I GoogSensorSync: GoogSensorSync 67 Sensor sync camera ID: 0
09-29 14:38:27.055   940 27240 I GoogSensorSync: GetSensorHandle 109 handle for 0 is found.
09-29 14:38:27.057   940 27240 I CHIUSECASE: UpdateBufferManagementSupportVersion: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:27.057   940 27240 I CHIUSECASE: InitializeStreamBufferCacheManager: Creating stream buffer cache manager for stream 0x720c772b78.
09-29 14:38:27.057   940 27240 I CHIUSECASE: StreamBufferCache: reserved buffer will be allocated during signaled stream configured. 
09-29 14:38:27.058   940 27240 I CHIUSECASE: StreamBufferCache: StreamBufferCache successfully created for stream 0x720c772b78 capacity 1
09-29 14:38:27.058   940 27240 I CHIUSECASE: InitializeStreamBufferCacheManager: Creating stream buffer cache manager for stream 0x720c678568.
09-29 14:38:27.058   940 27240 I CHIUSECASE: StreamBufferCache: reserved buffer will be allocated during signaled stream configured. 
09-29 14:38:27.060   940 27240 I CHIUSECASE: StreamBufferCache: StreamBufferCache successfully created for stream 0x720c678568 capacity 1
09-29 14:38:27.060   940 27240 D CHIUSECASE: Create: Initialized Google use case successfully.
09-29 14:38:27.062  1102  6845 D Camera3-Device: Set real time priority for request queue thread (tid 22753)
09-29 14:38:27.062 22656 22696 I native  : logger.h:28 CameraMetrics: CreateCaptureSession: 205.75752ms
09-29 14:38:27.062 22656 22696 I native  : capture_request_utils.cc:142 This device does not support auto focus. Using fixed focus instead.
09-29 14:38:27.062 22656 22696 I native  : capture_request_utils.cc:206 Flash: ConfigureRequestFlashMode - OFF
09-29 14:38:27.063 22656 22696 I native  : logger.h:28 DataSourceMetrics: kFirstGlCallback: 219.713876ms
09-29 14:38:27.063 22656 22688 I native  : cameras.cc:1313 Camera 0 changed state CLOSED->OPEN; Camera device opened successfully. i=0
09-29 14:38:27.063 22656 22688 I native  : cameras.cc:1313 Camera 0 changed state OPEN->CAPTURING; Started capture session. i=1
09-29 14:38:27.064   940 27240 D CHIUSECASE: ExtensionModule::TeardownOverrideSession Enter
09-29 14:38:27.064   940 27240 D CHIUSECASE: Usecase::DestroyObject 0x736c7a6260
09-29 14:38:27.064   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:353 Destroy() Destroying session 0x710befe040
09-29 14:38:27.064   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:302 Flush() flush is happening for session 0x710befe040; we will wait till all results are available
09-29 14:38:27.064   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:338 Flush() Flush is done
09-29 14:38:27.065   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:537 Destroy() Done destroying the session
09-29 14:38:27.065   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:88 ~Session() Session::~Session 0x710befe040
09-29 14:38:27.065   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope/41, period=5000000, max_latency=0
09-29 14:38:27.065   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope/41, period=5000000, max_latency=0 request completed
09-29 14:38:27.071   958  1031 D VSC     : @ 10988.682: [Gravity Sensor] Stop accel
09-29 14:38:27.074   958  1031 D VSC     : @ 10988.684: [Gravity Sensor] Stop gyro
09-29 14:38:27.075   958   958 I sensors-hal: batch_physical_sensor:285, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0
09-29 14:38:27.075   958   958 I sensors-hal: batch_physical_sensor:296, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0 request completed
09-29 14:38:27.075   940 27240 I GoogSensorSync: ~GoogSensorSync 72 Total failure/sync for camera 0: 0/0
09-29 14:38:27.080   940 22785 I native  : flicker_wrapper.cc:108 FlickerDestroy
09-29 14:38:27.080   940 22785 I native  : timer_utils.cc:191 Thread ID: 27928
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 27910
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.041000 ms, count: 1, average: 0.041000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 28362
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 7778
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.098000 ms, count: 1, average: 0.098000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 27481
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 12630
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 17086
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10768
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.074000 ms, count: 1, average: 0.074000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10750
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 21508
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10225
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10243
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 7796
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.018000 ms, count: 1, average: 0.018000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 27265
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 20994
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.041000 ms, count: 1, average: 0.041000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 21012
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 16569
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.063000 ms, count: 1, average: 0.063000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.174000 ms, count: 4, average: 0.043500 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.078000 ms, count: 4, average: 0.019500 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 17104
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 16323
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.047000 ms, count: 1, average: 0.047000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.065000 ms, count: 1, average: 0.065000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 22429
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.038000 ms, count: 1, average: 0.038000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 22447
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 9972
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 9954
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 22785
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10567
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.044000 ms, count: 1, average: 0.044000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 10549
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 8637
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.038000 ms, count: 1, average: 0.038000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 8619
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.204000 ms, count: 1, average: 0.204000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 16303
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.076000 ms, count: 1, average: 0.076000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 16551
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.042000 ms, count: 1, average: 0.042000 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 11310
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.173000 ms, count: 1, average: 0.173000 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect RunFFT total: 1.336000 ms, count: 26, average: 0.051385 ms
09-29 14:38:27.080   940 22785 I native  : FlickerDetect ComputePeaks total: 0.538000 ms, count: 26, average: 0.020692 ms
09-29 14:38:27.080   940 22785 I native  : 
09-29 14:38:27.080   940 22785 I native  : Thread ID: 9674
09-29 14:38:27.080   940 22785 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 
09-29 14:38:27.080   940 22785 I native  : flicker_wrapper.cc:111 flicker_obj deleted.
09-29 14:38:27.081   940 27240 I [email protected]_64: [GOOG_STATS] Calling PDLibDestroy in QC library
09-29 14:38:27.084   940 27240 I goog_warping: Destroy
09-29 14:38:27.084   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope/41 en=0
09-29 14:38:27.085   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope/41 en=0 completed
09-29 14:38:27.085   940 22763 I GoogleFDNode: EnsembleStateLoop: [FD] Closing Ensemble in Google FD Node.
09-29 14:38:27.203   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:353 Destroy() Destroying session 0x7103653040
09-29 14:38:27.203   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:302 Flush() flush is happening for session 0x7103653040; we will wait till all results are available
09-29 14:38:27.203   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:338 Flush() Flush is done
09-29 14:38:27.203   940 22783 I GOOGLE_CHINODE_HDRPLUS: MonitorEaselThermalState: Closing Easel monitor thread.
09-29 14:38:27.205   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:537 Destroy() Done destroying the session
09-29 14:38:27.205   940 27240 D CamX    : [DEBUG][CORE   ] camxsession.cpp:88 ~Session() Session::~Session 0x7103653040
09-29 14:38:27.205   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.camera_vsync/11051 en=0
09-29 14:38:27.206   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.camera_vsync/11051 en=0 completed
09-29 14:38:27.206   940 27240 I GoogSensorSync: ~GoogSensorSync 72 Total failure/sync for camera 0: 0/0
09-29 14:38:27.209   940 27240 I native  : easel_service_control.cc:326 RunReferenceCountIncrement run_reference_count_=2
09-29 14:38:27.209   940 27240 I native  : ipu_wake_lock.cc:69 IpuWakeLock::Request:0x70eeca41b8:9
09-29 14:38:27.209   940 27240 I native  : session.cc:71 SetEaselPortId:13
09-29 14:38:27.209   940 27240 I native  : ipu_wake_lock.cc:95 IpuWakeLock::WaitAcquire:0x70eeca41b8:0
09-29 14:38:27.209   940 27240 I native  : imx_fine_grain_client.cc:68 Release ImxSession Reference. reference_count_=1
09-29 14:38:27.209   940 27240 I native  : ipu_wake_lock.cc:75 IpuWakeLock::Release:0x719c67c4d8
09-29 14:38:27.209   940 27240 I native  : easel_service_control.cc:291 SuspendReferenceCountDecrement suspend_reference_count_=1
09-29 14:38:27.209   940 27240 I native  : ipu_wake_lock.cc:75 IpuWakeLock::Release:0x70eeca41b8
09-29 14:38:27.209   940 27240 I native  : easel_service_control.cc:345 RunReferenceCountDecrement run_reference_count_=1
09-29 14:38:27.209   940 27248 I native  : ipu_keepalive.cc:75 IpuKeepAliveThread: Releasing run reference since no Gcam objects are left.
09-29 14:38:27.209   940 27248 I native  : ipu_wake_lock.cc:75 IpuWakeLock::Release:0x71cc652318
09-29 14:38:27.209   940 27248 I native  : easel_service_control.cc:345 RunReferenceCountDecrement run_reference_count_=0
09-29 14:38:27.209   940 27248 I native  : easel_service_control.cc:352 EaselServiceControl Suspend
09-29 14:38:27.209   940 27248 I native  : easel_service_control.cc:652 COMMAND_PROCESSOR_3PA: SuspendInternal
09-29 14:38:27.213   940 22789 I CHIUSECASE: DumpState: ==== Dumping StreamBufferCacheManager Begin ====
09-29 14:38:27.213   940 22789 I CHIUSECASE: DumpState: == SBC[stream: 0x720c678568] reserved: 0x0 cache size: 0
09-29 14:38:27.213   940 22789 I CHIUSECASE: DumpState: == SBC[stream: 0x720c772b78] reserved: 0x0 cache size: 0
09-29 14:38:27.213   940 22789 I CHIUSECASE: DumpState: ==== Dumping StreamBufferCacheManager End ====
09-29 14:38:27.213   940 22789 I CHIUSECASE: RefillReturnThreadLoop: RefillReturnThreadLoop exits.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: ===== Dumping PendingResultDispatcher State Begin =====
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: shutter frameNum queue len = 0 | result queue len = 0.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: metadata frameNum queue len = 0 | result queue len = 0.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: outputStream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: outputStream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: inputstream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:27.213   940 27240 I CHIUSECASE: DumpQueueState: ===== Dumping PendingResultDispatcher State End =====
09-29 14:38:27.213   940 27240 D CHIUSECASE: ExtensionModule::TeardownOverrideSession Exit
09-29 14:38:27.213   940 27240 D CHIUSECASE: IsStreamConfigHdrplusCompatible: the fps is over hdr plus support.
09-29 14:38:27.213   940 27240 I CHIUSECASE: Google usecase selected
09-29 14:38:27.213   940 27240 I CHIUSECASE: LogClassifiedStream: Camera 0 preview stream type = 0 format = 34 width = 1920 height = 1080
09-29 14:38:27.213   940 27240 I CHIUSECASE: LogClassifiedStream: Camera 0 yuv stream type = 0 format = 35 width = 640 height = 480
09-29 14:38:27.213   940 27240 I CHIUSECASE: Use preview aspect ratio as dummy stream
09-29 14:38:27.213   940 27240 D CHIUSECASE: IsStreamConfigHdrplusCompatible: the fps is over hdr plus support.
09-29 14:38:27.213   940 27240 I CHIUSECASE: CreatePipelines: Creating pipelines for CHI usecase: UsecaseGooglePhoto1
09-29 14:38:27.213   940 27240 I CHIUSECASE: GoogleUsecasePipeline: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:27.213   940 27240 D CHIUSECASE: [Realtime] CreateChiPipeline: Creating the CHI pipeline.
09-29 14:38:27.214   940 27240 I goog_warping: Create
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.debug is set to 0
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.enable is set to 1
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.vcmdelay is set to 0
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.usegyrodirect is set to 0
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.usegyropoll is set to 1
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.fdinfo is set to 1
09-29 14:38:27.214   940 27240 D goog_warping: persist.camera.warping.ftmethod is set to 1
09-29 14:38:27.215   940 27240 I goog_warping: Warping node in photo mode. No crop is used.
09-29 14:38:27.218   940 27240 I GoogleFDNode: Initialize: GoogleFDNode created ensemble detector successfully.
09-29 14:38:27.218   940 27240 I GoogleFDNode: Initialize: GoogleFDNode uses dedicated thread for Ensemble.
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceSkipFrame to 804f000e
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.count to 804f000f
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.ids to 804f0010
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.xy to 804f0011
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceLandmark.depth to 804f0012
09-29 14:38:27.219   940 27240 I GoogleFDNode: QueryBufferInfo: [FD] Google FD Node publishing com.google.nexus.experimental2018 | faceOrientation to 804f0014
09-29 14:38:27.219   940 27240 E CamX    : [ERROR][PPROC  ] camxipenode.cpp:2293 ProcessingNodeFinalizeInputRequirement() NonConformant AspectRatio:1.333333 Change Width 852 using AR:1.777778
09-29 14:38:27.219   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:27.219   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:27.219   940 27240 E CamX    : [ERROR][PPROC  ] camxipenode.cpp:2293 ProcessingNodeFinalizeInputRequirement() NonConformant AspectRatio:1.333333 Change Width 852 using AR:1.777778
09-29 14:38:27.219   940 27240 D CamX    : [DEBUG][PPROC  ] camxipenode.cpp:2360 ProcessingNodeFinalizeInputRequirement() IPE video dimension: 0 x 0
09-29 14:38:27.219   940 27240 I CHIUSECASE: CameraID: 0, SelectedMode W=2016, H=1512, FPS:60, NumBatchedFrames:1, modeIndex:3
09-29 14:38:27.219   940 27240 I CHIUSECASE: Create: Created a GoogleUsecaseRealtimePipeline for camera 0
09-29 14:38:27.219   940 27240 I CHIUSECASE: Build: building a session with pipeline for camera id 0
09-29 14:38:27.234   940 27240 I [email protected]_64: [GOOG_STATS] PDLibData already assigned
09-29 14:38:27.234   940 27240 I [email protected]_64: [GOOG_STATS] Calling CreatePDLib in QC library
09-29 14:38:27.238  1459  1537 E JavaBinder: *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
09-29 14:38:27.238  1459  1537 E JavaBinder: java.lang.RuntimeException: android.os.RemoteException: Couldn't get ApplicationInfo for package [email protected]::ISensorManager
09-29 14:38:27.238  1459  1537 E JavaBinder:    at android.os.Parcel.writeException(Parcel.java:2158)
09-29 14:38:27.238  1459  1537 E JavaBinder:    at android.os.Binder.execTransactInternal(Binder.java:1178)
09-29 14:38:27.238  1459  1537 E JavaBinder:    at android.os.Binder.execTransact(Binder.java:1123)
09-29 14:38:27.238  1459  1537 E JavaBinder: Caused by: android.os.RemoteException: Couldn't get ApplicationInfo for package [email protected]::ISensorManager
09-29 14:38:27.238  1459  1537 E JavaBinder:    at com.android.server.pm.PackageManagerService$PackageManagerNative.getTargetSdkVersionForPackage(PackageManagerService.java:23939)
09-29 14:38:27.238  1459  1537 E JavaBinder:    at android.content.pm.IPackageManagerNative$Stub.onTransact(IPackageManagerNative.java:255)
09-29 14:38:27.238  1459  1537 E JavaBinder:    at android.os.Binder.execTransactInternal(Binder.java:1159)
09-29 14:38:27.238  1459  1537 E JavaBinder:    ... 1 more
09-29 14:38:27.238   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope/41, period=5000000, max_latency=0
09-29 14:38:27.238   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope/41, period=5000000, max_latency=0 request completed
09-29 14:38:27.238   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope/41 en=1
09-29 14:38:27.239   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:27.239   958   958 D Diag_Lib:  Diag_LSM_Init: Failed to open handle to diag driver, error = 13
09-29 14:38:27.240   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:27.236   958   958 W [email protected]: type=1400 audit(0.0:965): avc: denied { read write } for name="diag" dev="tmpfs" ino=12790 scontext=u:r:hal_sensors_default:s0 tcontext=u:object_r:diag_device:s0 tclass=chr_file permissive=0
09-29 14:38:27.240   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope/41 en=1 completed
09-29 14:38:27.242   958 22796 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:27.244   958 22800 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:27.249   940 27240 E CamX    : [ERROR][STATS_AEC] aec_set.cpp:1586: aec_set_init_chromatix_sensor aec_set_init_chromatix_sensor is called before LoadTuning
09-29 14:38:27.249   940 27240 E CamX    : [ERROR][STATS_AEC] aec_get.cpp:575: aec_get_param Wrong sequence! Get exposure before AE init idx=-1
09-29 14:38:27.249   940 27240 E CamX    : [ERROR][STATS_AEC] camxae.cpp:1801: AecGetStartExposure aec get parameter failed
09-29 14:38:27.249   940 27240 E CamX    : [ERROR][STATS_AEC] camxcaecstatsprocessor.cpp:1757 PopulatePropPoolFrameControl() Invalid exposure parameters: gain: 0.000000, exposureTime: 0
09-29 14:38:27.249   940 27240 D CamX    : [DEBUG][STATS_AWB] camxcawbstatsprocessor.cpp:749 SetOperationModetoAlgo() Mode set to Algo: 1
09-29 14:38:27.251   940  1542 I [email protected]_64: [GOOG_STATS] PDAF wrapper is successfully initialized
09-29 14:38:27.251   940  1542 I [email protected]_64: [GOOG_STATS] PDAF infinity DAC = -315, macro DAC = 455, image bits = 8
09-29 14:38:27.251   940  1542 I [email protected]_64: [GOOG_STATS] doDefaultPDProcess = 0
09-29 14:38:27.251   940  1542 I [email protected]_64: [GOOG_STATS] Calling QC PDLibInitialize: run on sparse PD = 0
09-29 14:38:27.253   958   958 I sensors-hal: flush_physical_sensor:328, android.sensor.gyroscope/41
09-29 14:38:27.253   958   958 I sensors-hal: flush_physical_sensor:336, android.sensor.gyroscope/41 completed
09-29 14:38:27.256   958  1031 I VSC     : @ 10988.872: {Fusion} configure fusion 9 19230us 0us.
09-29 14:38:27.256   958  1031 D VSC     : @ 10988.872: [Gravity Sensor] Request accel, interval 19.2 ms, latency 0.0 ms
09-29 14:38:27.256   940 22803 I native  : flicker_wrapper.cc:82 FlickerCreate
09-29 14:38:27.256   940 22803 I native  : flicker_wrapper.cc:87 Using default flicker parameters.
09-29 14:38:27.260  1156  1156 I EaselPowerBlue: [TIME_LOGGER] suspend took 49 ms
09-29 14:38:27.260   940 27248 I native  : easel_service_control.cc:655 COMMAND_PROCESSOR_3PA: SuspendInternal complete
09-29 14:38:27.260   940 27248 I native  : easel_service_control.cc:644 COMMAND_PROCESSOR_3PA: Suspend complete
09-29 14:38:27.265   958  1031 D VSC     : @ 10988.874: [Gravity Sensor] Request gyro, interval 5.0 ms, latency 0.0 ms
09-29 14:38:27.265   958  1031 D ASH     : @ 10988.881: SensorType 1 resampler quality 2
09-29 14:38:27.286   940 27240 I GoogSensorSync: GoogSensorSync 67 Sensor sync camera ID: 0
09-29 14:38:27.287   940 27240 I GoogSensorSync: GetSensorHandle 109 handle for 0 is found.
09-29 14:38:27.288   958   958 I sensors-hal: batch_physical_sensor:285, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0
09-29 14:38:27.289   958   958 I sensors-hal: batch_physical_sensor:296, com.google.sensor.camera_vsync/11051, period=5000000, max_latency=0 request completed
09-29 14:38:27.289   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.camera_vsync/11051 en=1
09-29 14:38:27.289   958   958 I sensors-hal: get_qmi_debug_flag:233, support_qmi_debug : false
09-29 14:38:27.290   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.camera_vsync/11051 en=1 completed
09-29 14:38:27.290   940 27240 I CHIUSECASE: UpdateBufferManagementSupportVersion: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:27.290   940 27240 I CHIUSECASE: InitializeStreamBufferCacheManager: Creating stream buffer cache manager for stream 0x720c772b78.
09-29 14:38:27.290   940 27240 I CHIUSECASE: StreamBufferCache: reserved buffer will be allocated during signaled stream configured. 
09-29 14:38:27.291   940 27240 I CHIUSECASE: StreamBufferCache: StreamBufferCache successfully created for stream 0x720c772b78 capacity 1
09-29 14:38:27.291   940 27240 I CHIUSECASE: InitializeStreamBufferCacheManager: Creating stream buffer cache manager for stream 0x720c678568.
09-29 14:38:27.291   940 27240 I CHIUSECASE: StreamBufferCache: reserved buffer will be allocated during signaled stream configured. 
09-29 14:38:27.292   940 27240 I CHIUSECASE: StreamBufferCache: StreamBufferCache successfully created for stream 0x720c678568 capacity 1
09-29 14:38:27.292   940 27240 D CHIUSECASE: Create: Initialized Google use case successfully.
09-29 14:38:27.292  1102 22753 D Camera3-Device: Set real time priority for request queue thread (tid 22753)
09-29 14:38:27.293   940 27240 I CHIUSECASE: UpdateBufferManagementSupportVersion: ANDROID_INFO_SUPPORTED_BUFFER_MANAGEMENT_VERSION = 0
09-29 14:38:27.293   940 27240 I CHIUSECASE: SignalStreamConfigured: StreamBufferCacheManager allocated reserved buffer for stream 0x720c772b78.
09-29 14:38:27.293   940 27240 I CHIUSECASE: ExecuteCaptureRequest: stream 0x720c772b78 first request arrived. Signal for stream configuration complete.
09-29 14:38:27.293   940 27240 I CHIUSECASE: SignalStreamConfigured: StreamBufferCacheManager allocated reserved buffer for stream 0x720c678568.
09-29 14:38:27.293   940 27240 I CHIUSECASE: ExecuteCaptureRequest: stream 0x720c678568 first request arrived. Signal for stream configuration complete.
09-29 14:38:27.293   940 27240 I CHIUSECASE: SubmitRequest: ActivatePipeline camera id 0
09-29 14:38:27.293   669   669 I hwservicemanager: getTransport: Cannot find entry [email protected]::IAllocator/default in either framework or device manifest.
09-29 14:38:27.293 22656 22676 W Gralloc4: allocator 3.x is not supported
09-29 14:38:27.293   669   669 I hwservicemanager: getTransport: Cannot find entry [email protected]::IAllocator/default in either framework or device manifest.
09-29 14:38:27.294 22656 22676 W Gralloc3: allocator 3.x is not supported
09-29 14:38:27.303   940  1538 E CamX    : [ERROR][STATS_AF] camxafstatemachine.cpp:238 HandleAFStateTransition() Cause 3 not handled in state 0
09-29 14:38:27.303   940  1540 E CamX    : [ERROR][STATS  ] camxae.cpp:2290 AECLoadTuning() Not supported combination (0,3,0)
09-29 14:38:27.303   940  1540 D CamX    : [DEBUG][STATS  ] camxae.cpp:2297 AECLoadTuning() load tuning(cameraID,SensorMode,Usecase)=(0,3,0),opMode=2, name:IMX363 2x2 60fps
09-29 14:38:27.306   958 22805 I sensors-hal: handle_indication_realtime:451,  SCHED_FIFO(10) for qmi_cbk
09-29 14:38:27.357   940  1539 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.369   710   737 E SurfaceFlinger: setDesiredDisplayConfigSpecs: failed to call setDesiredDisplayConfigSpecs: -22
09-29 14:38:27.369  1459  1514 E SurfaceFlinger: setDesiredDisplayConfigSpecs failed to transact: -22
09-29 14:38:27.372   940  1538 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.374   940  1541 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.374 22656 22739 I native  : logger.h:28 CameraMetrics: FirstCaptureComplete: 311.977323ms
09-29 14:38:27.384 22656 22730 I native  : timebase_helpers.cc:169 Timebase offset intialized to 0
09-29 14:38:27.384 22656 22730 I native  : logger.h:28 DataSourceMetrics: kFirstImageCallback: 540.738336ms
09-29 14:38:27.388   940  1539 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.392   940  1540 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.395 22656 22710 W native  : feature_matcher_and_filter_utils.cc:249 INVALID_ARGUMENT: integration window start at 0 Use identity R.
09-29 14:38:27.405   940  1541 E CamX    : [ERROR][STATS_AF] camxcafioutil.cpp:3866 PopulateGoogGravityData() No samples read from Gravity sensor
09-29 14:38:27.505 22656 22711 E native  : motion_tracking_context.cc:1030 Unable to find measurements corresponding to VIO status at timestamp 10987074642118.
09-29 14:38:27.763 22656 22656 F libc    : Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x8 in tid 22656 (com.example.app), pid 22656 (com.example.app)
09-29 14:38:27.828 22656 22707 I native  : bundle_adjustment_initializer.cc:591 Deterministic initialization
09-29 14:38:27.828 22810 22810 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone
09-29 14:38:27.828   901   901 I tombstoned: received crash request for pid 22656
09-29 14:38:27.829 22810 22810 I crash_dump64: performing dump of process 22656 (target tid = 22656)
09-29 14:38:27.831 22656 22707 I native  : bundle_adjustment_initializer.cc:171 Intrinsic vector size of the camera 0 is 7
09-29 14:38:27.839 22810 22810 F DEBUG   : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
09-29 14:38:27.839 22810 22810 F DEBUG   : Build fingerprint: 'google/blueline/blueline:11/RP1A.200720.009/6720564:user/release-keys'
09-29 14:38:27.839 22810 22810 F DEBUG   : Revision: 'MP1.0'
09-29 14:38:27.839 22810 22810 F DEBUG   : ABI: 'arm64'
09-29 14:38:27.842 22810 22810 F DEBUG   : Timestamp: 2020-09-29 14:38:27-0400
09-29 14:38:27.842 22810 22810 F DEBUG   : pid: 22656, tid: 22656, name: com.example.app  >>> com.example.app <<<
09-29 14:38:27.842 22810 22810 F DEBUG   : uid: 10697
09-29 14:38:27.842 22810 22810 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x8
09-29 14:38:27.842 22810 22810 F DEBUG   : Cause: null pointer dereference
09-29 14:38:27.842 22810 22810 F DEBUG   :     x0  0000007853a503d0  x1  42c800000000077c  x2  0000000000000017  x3  0000000000000000
09-29 14:38:27.842 22810 22810 F DEBUG   :     x4  0000000000000010  x5  0000007fe62f7f27  x6  0000000000000030  x7  0000000000000030
09-29 14:38:27.842 22810 22810 F DEBUG   :     x8  0000007fe62f8150  x9  0000000000000000  x10 00000000b24ab3f0  x11 0000007a571cbf88
09-29 14:38:27.842 22810 22810 F DEBUG   :     x12 00000000000007c0  x13 0000000000000000  x14 0000007a55fc7d22  x15 0000000000000000
09-29 14:38:27.842 22810 22810 F DEBUG   :     x16 00000077582bda60  x17 0000007a571f2c4c  x18 0000007a59a14000  x19 00000078e3a5c7a0
09-29 14:38:27.842 22810 22810 F DEBUG   :     x20 0000007fe62f8ce0  x21 0000007fe62f8f78  x22 0000007728bde8f8  x23 00000078e3a5c7d0
09-29 14:38:27.842 22810 22810 F DEBUG   :     x24 0000007883a676f0  x25 0000007728bde040  x26 0000007853a503d0  x27 0000000100000000
09-29 14:38:27.842 22810 22810 F DEBUG   :     x28 0000000000000001  x29 0000000000000001
09-29 14:38:27.842 22810 22810 F DEBUG   :     lr  0000007758229608  sp  0000007fe62f8150  pc  000000775820a334  pst 0000000080000000
09-29 14:38:27.842 22810 22810 F DEBUG   : backtrace:
09-29 14:38:27.842 22810 22810 F DEBUG   :       #00 pc 0000000000047334  /data/app/~~2hIPvskIXYCDD1TIKsBXgw==/com.example.app--H0ng98SL4ZrgSiFwKQCCg==/base.apk!libfilament-jni.so (offset 0x32000) (BuildId: 39c4c3709f6020a5f4fbeb249499a232081eefe0)
09-29 14:38:27.846   958  1031 D VSC     : @ 10989.460: [WO] tilt angle 46
09-29 14:38:27.846   958  1031 D VSC     : @ 10989.460: [WO] isFlat() nearest_rotation: 4, flat_angle: 65
09-29 14:38:27.846   958  1031 D VSC     : @ 10989.460: [WO] orientation angle 352, orientation 4
09-29 14:38:27.854 22656 22707 I native  : bundle_adjustment_initializer.cc:360 Initializer did not converge: Maximum number of iterations reached. Number of iterations: 18.
09-29 14:38:27.854 22656 22707 I native  : ba_initialization_helpers.h:164 Number of measurements used in BA initialization for temporal landmarks: 300
09-29 14:38:27.854 22656 22707 I native  : ba_initialization_helpers.h:166 Number of good measurements (i.e., reprojection errors <= 3 pixels) in BA initialization for temporal landmarks: 289
09-29 14:38:27.865  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5682538 ms. Complete trace: # bmjb@169f34c8
09-29 14:38:27.865  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.865  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.865  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.865  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5800991 ms. Complete trace: # bmjb@44510df5
09-29 14:38:27.865  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.865  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.865  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.866  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5741492 ms. Complete trace: # bmjb@d6c21410
09-29 14:38:27.866  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.866  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.866  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.867  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5819387 ms. Complete trace: # bmjb@27439149
09-29 14:38:27.867  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.867  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.867  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5953582 ms. Complete trace: # bmjb@f837eab1
09-29 14:38:27.868  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5772597 ms. Complete trace: # bmjb@a0d0fb18
09-29 14:38:27.868  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5659742 ms. Complete trace: # bmjb@a4877a08
09-29 14:38:27.868  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.868  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.869  2562 22094 E bmir    : Trace gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery timed out after 5704942 ms. Complete trace: # bmjb@5106d2d6
09-29 14:38:27.869  2562 22094 E bmir    : bmjf: 
09-29 14:38:27.869  2562 22094 E bmir    :  at tk_trace.scheduler_cancel(Started After:0)
09-29 14:38:27.869  2562 22094 E bmir    :  at tk_trace.gcm-SchedulerPackageIntentOperation_onHandleIntentWithRedelivery(Started After:0)
09-29 14:38:27.885 22656 22715 E libc    : Access denied finding property "ro.hardware.chipname"
09-29 14:38:27.909 22656 22707 I native  : vio_fault_detector.cc:409 VIO did not use vision constraints.
09-29 14:38:28.206   901   901 E tombstoned: Tombstone written to: /data/tombstones/tombstone_15
09-29 14:38:28.207  1459 22819 I DropBoxManagerService: add tag=data_app_native_crash isTagEnabled=true flags=0x2
09-29 14:38:28.207  1459 22818 W ActivityTaskManager:   Force finishing activity com.example.app/.aractivity.ArActivity
09-29 14:38:28.213  1459  1547 I BootReceiver: Copying /data/tombstones/tombstone_15 to DropBox (SYSTEM_TOMBSTONE)
09-29 14:38:28.219  1459  1547 I DropBoxManagerService: add tag=SYSTEM_TOMBSTONE isTagEnabled=true flags=0x2
09-29 14:38:28.227   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10697[I] (10)0x30000->*launch*[S] 
09-29 14:38:28.234  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
09-29 14:38:28.234  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
09-29 14:38:28.239  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.stats.service.DropBoxEntryAddedReceiver
09-29 14:38:28.239  1459  1520 W BroadcastQueue: Background execution not allowed: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to com.google.android.gms/.chimera.GmsIntentOperationService$PersistentTrustedReceiver
09-29 14:38:28.267  1459  2207 I WindowManager: WIN DEATH: Window{a5d0998 u0 com.example.app/com.example.app.aractivity.ArActivity}
09-29 14:38:28.267  1459  2207 W InputDispatcher: Attempted to unregister already unregistered input channel 'a5d0998 com.example.app/com.example.app.aractivity.ArActivity (server)'
09-29 14:38:28.267  1102 27270 E Camera3-OutputStream: getBufferLockedCommon: Stream 1: Can't dequeue next output buffer: Broken pipe (-32)
09-29 14:38:28.267  1102 12577 E Surface : queueBuffer: error queuing buffer to SurfaceTexture, -32
09-29 14:38:28.267  1102 12577 E Camera3-OutputStream: returnBufferCheckedLocked: Stream 1: Error queueing buffer to native window: Broken pipe (-32)
09-29 14:38:28.267   940 22807 W CHIUSECASE: RequestStreamBufferFromFwk: request failed due to error: 4
09-29 14:38:28.267   940 22807 W CHIUSECASE: RequestStreamBufferFromFwk: buffer_ret[0] error: 3
09-29 14:38:28.267   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 marked as abandoned.
09-29 14:38:28.268  1102 27270 E Camera3-OutputStream: getBufferLockedCommon: Stream 0: Can't dequeue next output buffer: Broken pipe (-32)
09-29 14:38:28.268   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope_uncalibrated/161 en=0
09-29 14:38:28.268   922   922 I Zygote  : Process 22656 exited due to signal 11 (Segmentation fault)
09-29 14:38:28.268   940 22807 W CHIUSECASE: RequestStreamBufferFromFwk: request failed due to error: 4
09-29 14:38:28.268   940 22807 W CHIUSECASE: RequestStreamBufferFromFwk: buffer_ret[0] error: 3
09-29 14:38:28.268   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 marked as abandoned.
09-29 14:38:28.268   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.268   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.269   940  1541 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.269   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.269   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.270   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope_uncalibrated/161 en=0 completed
09-29 14:38:28.271   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.accelerometer_uncalibrated/351 en=0
09-29 14:38:28.272  1102 12577 E Surface : queueBuffer: error queuing buffer to SurfaceTexture, -32
09-29 14:38:28.273  1459  2672 W WindowManager: Cannot find window which accessibility connection is added to
09-29 14:38:28.273   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.accelerometer_uncalibrated/351 en=0 completed
09-29 14:38:28.273   940  1541 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.273   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.273   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.274  1459  4379 I ActivityManager: Process com.example.app (pid 22656) has died: prcp TOP 
09-29 14:38:28.274   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.gyro_temperature/11021 en=0
09-29 14:38:28.274  1459  1531 I libprocessgroup: Successfully killed process cgroup uid 10697 pid 22656 in 0ms
09-29 14:38:28.275   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.gyro_temperature/11021 en=0 completed
09-29 14:38:28.277   940  1539 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.277   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.277   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.277   940  1539 E CamX    : [ERROR][CSL    ] camxcslhwinternal.cpp:2741 CSLHwInternalDefaultIoctl2() Ioctl returned -1, failed for device /dev/video1 (Type:CSLHwRequestManager, FD:9, Index:-1)with error reason Operation already in progress
09-29 14:38:28.278   940  1539 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.278   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.278   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.278   940  1539 E CamX    : [ERROR][CSL    ] camxcslhwinternal.cpp:2741 CSLHwInternalDefaultIoctl2() Ioctl returned -1, failed for device /dev/video1 (Type:CSLHwRequestManager, FD:9, Index:-1)with error reason Operation already in progress
09-29 14:38:28.282   940  1540 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.282   920   925 E statsd  : Predicate 5980654721335871649 dropping data for dimension key (10)0x2010101->10697[I] (10)0x30000->*launch*[S] 
09-29 14:38:28.282   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.282   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.283   940  1540 E CamX    : [ERROR][CSL    ] camxcslhwinternal.cpp:2741 CSLHwInternalDefaultIoctl2() Ioctl returned -1, failed for device /dev/video1 (Type:CSLHwRequestManager, FD:9, Index:-1)with error reason Operation already in progress
09-29 14:38:28.284   940  1540 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.284   940  1540 E CamX    : [ERROR][CSL    ] camxcslhwinternal.cpp:2741 CSLHwInternalDefaultIoctl2() Ioctl returned -1, failed for device /dev/video1 (Type:CSLHwRequestManager, FD:9, Index:-1)with error reason Operation already in progress
09-29 14:38:28.284   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.284   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.285   958  1031 D ASH     : @ 10989.899: SensorType 195 resampler quality 2
09-29 14:38:28.285   958  1031 D CHRE    : @ 10989.899: SensorType 195 resampler quality 1
09-29 14:38:28.285   958  1031 D ASH     : @ 10989.900: SensorType 1 resampler quality 3
09-29 14:38:28.297  1963  1978 W System  : A resource failed to call release. 
09-29 14:38:28.300  1459 22818 W ActivityManager: Ignoring remove of inactive process: ProcessRecord{d37a5cb 0:com.example.app/u0a697}
09-29 14:38:28.301  1459  1514 W ActivityManager: setHasOverlayUi called on unknown pid: 22656
09-29 14:38:28.302 29351 29351 I Finsky  : [2] rog.onTrimMemory(1): Memory trim requested to level 80
09-29 14:38:28.307 20097 20097 I OnTrimMemoryDispatcher: Dispatching onTrimMemory(40)
09-29 14:38:28.314  1963  1963 I Elmyra/ElmyraService: Unblocked; current action: LaunchOpa [mIsGestureEnabled -> true; mIsOpaEnabled -> true]
09-29 14:38:28.315   943   943 V ContextHubHal: sendMessageToHub
09-29 14:38:28.316   958  1031 D CHRE    : @ 10989.932: Parsed nanoapp message from host: app ID 0x476f6f676c00100e, endpoint 0x1, msgType 200, payload size 10
09-29 14:38:28.317   958  1031 D CHRE    : @ 10989.933: Elmyra/Nanoapp Recognizer started
09-29 14:38:28.318   940  1541 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.318   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.318   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.318   940  1541 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.318   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.318   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.321 13011 13011 W BaseNSApplication: Trimming memory to level 80
09-29 14:38:28.321  3357  3357 I AppBase : AppBase.onTrimMemory():639 onTrimMemory(): 5
09-29 14:38:28.322  3357  3380 I DeferredObjectPersisterWrapper: DeferredObjectPersisterWrapper$1.onTrimMemory():46 Received on trim memory notification with level 5, flush data from memory to disk.
09-29 14:38:28.323  3357  3357 I GoogleInputMethodService: GoogleInputMethodService.onTrimMemory():4344 onTrimMemory(): 5
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: QUALCOMM build                   : c9bef8a, Ie73904e3bd
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Build Date                       : 06/26/20
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: OpenGL ES Shader Compiler Version: EV031.31.04.00
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Local Branch                     : gfx-adreno.lnx.2.0
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Remote Branch                    : quic/gfx-adreno.lnx.2.0
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Remote Branch                    : NONE
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Reconstruct Branch               : NOTHING
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Build Config                     : C P 11.0.1 AArch64
09-29 14:38:28.332  3964  4593 I AdrenoGLES-0: Driver Path                      : /vendor/lib64/egl/libGLESv2_adreno.so
09-29 14:38:28.335   940  1538 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.335   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.335   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.335   940  1538 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.335   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.335   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.340  3964  4593 I AdrenoGLES-0: PFP: 0x016ee189, ME: 0x00000000
09-29 14:38:28.351   940  1539 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c678568
09-29 14:38:28.352   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.352   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.352   940  1539 I CHIUSECASE: RequestStreamBuffers: dummy buffer returned for stream 0x720c772b78
09-29 14:38:28.354   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c678568 has been abandoned. Can not refill cache any more.
09-29 14:38:28.354   940 22807 I CHIUSECASE: Refill: StreamBufferCache for stream 0x720c772b78 has been abandoned. Can not refill cache any more.
09-29 14:38:28.358  3964  3964 I MemoryTrimmer: Trimming objects from memory, since app is in the background.
09-29 14:38:28.367   940  1543 I CHIUSECASE: UpdateResultAndInflightRequests: all inflight requests have been processed. Notify stream buffer cache manager to flush.
09-29 14:38:28.369  1102  6845 I Camera3-Device: disconnectImpl: E
09-29 14:38:28.369  1102  6845 I CameraLatencyHistogram: ProcessCaptureRequest latency histogram (58) samples:
09-29 14:38:28.369  1102  6845 I CameraLatencyHistogram:        40     80    120    160    200    240    280    320    360    inf (max ms)
09-29 14:38:28.369  1102  6845 I CameraLatencyHistogram:      96.55   3.45   0.00   0.00   0.00   0.00   0.00   0.00   0.00   0.00 (%)
09-29 14:38:28.369   940  1546 D CHIUSECASE: ExtensionModule::ExtendClose
09-29 14:38:28.370   940  1546 D CameraThermalHAL: Stopping Thermal HAL Polling thread
09-29 14:38:28.370   940 22750 D CameraThermalHAL: Thermal HAL thread exiting ...
09-29 14:38:28.370   940  1546 D CHIUSECASE: ExtensionModule::TeardownOverrideSession Enter
09-29 14:38:28.370   940  1546 D CHIUSECASE: Usecase::DestroyObject 0x736c7a6260
09-29 14:38:28.370   940  1546 D CamX    : [DEBUG][CORE   ] camxsession.cpp:353 Destroy() Destroying session 0x710befe040
09-29 14:38:28.370   940  1546 D CamX    : [DEBUG][CORE   ] camxsession.cpp:302 Flush() flush is happening for session 0x710befe040; we will wait till all results are available
09-29 14:38:28.370   940  1546 D CamX    : [DEBUG][CORE   ] camxsession.cpp:338 Flush() Flush is done
09-29 14:38:28.379  3964  4317 W ThreadPoolDumper: Queue length for executor EventBus is now 11. Perhaps some tasks are too long, or the pool is too small.
09-29 14:38:28.379  3357  3357 I GoogleInputMethodService: GoogleInputMethodService.onFinishInput():3184 
09-29 14:38:28.380  3357  3357 I GoogleInputMethodService: GoogleInputMethodService.onStartInput():1830 
09-29 14:38:28.385   940  1546 D CamX    : [DEBUG][CORE   ] camxsession.cpp:537 Destroy() Done destroying the session
09-29 14:38:28.385   940  1546 D CamX    : [DEBUG][CORE   ] camxsession.cpp:88 ~Session() Session::~Session 0x710befe040
09-29 14:38:28.386   958   958 I sensors-hal: batch_physical_sensor:285, android.sensor.gyroscope/41, period=5000000, max_latency=0
09-29 14:38:28.386   958   958 I sensors-hal: batch_physical_sensor:296, android.sensor.gyroscope/41, period=5000000, max_latency=0 request completed
09-29 14:38:28.387   958  1031 D VSC     : @ 10990.003: [Gravity Sensor] Stop accel
09-29 14:38:28.392   958  1031 D VSC     : @ 10990.005: [Gravity Sensor] Stop gyro
09-29 14:38:28.393  1459  4554 I ActivityManager: Force stopping com.example.app appid=10697 user=0: from pid 22829
09-29 14:38:28.393   958   958 I sensors-hal: activate_physical_sensor:220, com.google.sensor.camera_vsync/11051 en=0
09-29 14:38:28.394   958   958 I sensors-hal: activate_physical_sensor:233, com.google.sensor.camera_vsync/11051 en=0 completed
09-29 14:38:28.394   940  1546 I GoogSensorSync: ~GoogSensorSync 72 Total failure/sync for camera 0: 0/58
09-29 14:38:28.395   958  1031 D ASH     : @ 10990.010: SensorType 1 resampler quality 0
09-29 14:38:28.397  3964  4426 I StreamController: registerScope: nowcards-15-a22ad0-3dc9
09-29 14:38:28.398 22829 22831 I cmd     : oneway function results will be dropped but finished with status OK and parcel size 4
09-29 14:38:28.404  1459  3552 W ActivityManager: Permission Denial: Accessing service com.google.android.music/.dial.DialMediaRouteProviderService from pid=3128, uid=10013 that is not exported from uid 10102
09-29 14:38:28.405  3503  3503 D RegisteredNfcFServicesCache: Service unchanged, not updating
09-29 14:38:28.405   958  1031 D ASH     : @ 10990.020: SensorType 195 resampler quality 2
09-29 14:38:28.405   958  1031 D CHRE    : @ 10990.020: SensorType 195 resampler quality 0
09-29 14:38:28.405  2504 22227 I EuiccGoogle: [237] EuiccServiceImpl.onGetEuiccProfileInfoList: onGetEuiccProfileInfoList: slotId = -1
09-29 14:38:28.408  2504 22227 W EuiccGoogle: [237] EuiccServiceImpl.onGetEuiccProfileInfoList: slotId=-1. No eUICC is active. Return null.
09-29 14:38:28.421  3964  3964 I BgTaskExecutorImpl: Starting EXCLUSIVE background task TNG_MINUS_ONE_SYNC.
09-29 14:38:28.421  3964  3964 I BgTaskExecutorImpl: Starting EXCLUSIVE background task TNG_VOICE_SEARCH_SYNC.
09-29 14:38:28.421  3964  4316 E MDD     : DownloadProgressMonitor: Can't find file for uri: android://com.google.android.googlequicksearchbox/files/sharedminusonemodule/shared/SharedMinusOneData.pb.tmp
09-29 14:38:28.423  3964  4426 I TngMinusOneSync: Syncing TNG:-1
09-29 14:38:28.423  3964  4426 I TngVoiceSearchSync: Syncing TNG:VoiceSearch
09-29 14:38:28.426   940 22803 I native  : flicker_wrapper.cc:108 FlickerDestroy
09-29 14:38:28.426   940 22803 I native  : timer_utils.cc:191 Thread ID: 27928
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 27910
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.041000 ms, count: 1, average: 0.041000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 28362
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 7778
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.098000 ms, count: 1, average: 0.098000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 27481
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 12630
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 17086
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10768
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.074000 ms, count: 1, average: 0.074000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10750
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 21508
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10225
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10243
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 7796
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.018000 ms, count: 1, average: 0.018000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 27265
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 20994
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.041000 ms, count: 1, average: 0.041000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 21012
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 16569
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.063000 ms, count: 1, average: 0.063000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.174000 ms, count: 4, average: 0.043500 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.078000 ms, count: 4, average: 0.019500 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 17104
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 16323
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.047000 ms, count: 1, average: 0.047000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.065000 ms, count: 1, average: 0.065000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 22429
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.038000 ms, count: 1, average: 0.038000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 22447
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average: 0.043000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 9972
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 9954
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 22785
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.039000 ms, count: 1, average: 0.039000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10567
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.044000 ms, count: 1, average: 0.044000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.017000 ms, count: 1, average: 0.017000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 10549
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.040000 ms, count: 1, average: 0.040000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 8637
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.038000 ms, count: 1, average: 0.038000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 8619
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.204000 ms, count: 1, average: 0.204000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 16303
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.076000 ms, count: 1, average: 0.076000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 16551
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.042000 ms, count: 1, average: 0.042000 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 11310
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.173000 ms, count: 1, average: 0.173000 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect RunFFT total: 1.336000 ms, count: 26, average: 0.051385 ms
09-29 14:38:28.426   940 22803 I native  : FlickerDetect ComputePeaks total: 0.538000 ms, count: 26, average: 0.020692 ms
09-29 14:38:28.426   940 22803 I native  : 
09-29 14:38:28.426   940 22803 I native  : Thread ID: 22803
09-29 14:38:28.426   940 22803 I native  : FlickerDetect Initialize total: 0.043000 ms, count: 1, average:
09-29 14:38:28.426   940 22803 I native  : flicker_wrapper.cc:111 flicker_obj deleted.
09-29 14:38:28.431   940  1546 I [email protected]_64: [GOOG_STATS] Calling PDLibDestroy in QC library
09-29 14:38:28.434   940  1546 I goog_warping: Destroy
09-29 14:38:28.435   958   958 I sensors-hal: activate_physical_sensor:220, android.sensor.gyroscope/41 en=0
09-29 14:38:28.436   958   958 I sensors-hal: activate_physical_sensor:233, android.sensor.gyroscope/41 en=0 completed
09-29 14:38:28.436   940 22794 I GoogleFDNode: EnsembleStateLoop: [FD] Closing Ensemble in Google FD Node.
09-29 14:38:28.554   940 22807 I CHIUSECASE: DumpState: ==== Dumping StreamBufferCacheManager Begin ====
09-29 14:38:28.554   940 22807 I CHIUSECASE: DumpState: == SBC[stream: 0x720c678568] reserved: 0x723c639010 cache size: 0
09-29 14:38:28.554   940 22807 I CHIUSECASE: DumpState: == SBC[stream: 0x720c772b78] reserved: 0x723c722830 cache size: 0
09-29 14:38:28.554   940 22807 I CHIUSECASE: DumpState: ==== Dumping StreamBufferCacheManager End ====
09-29 14:38:28.554   940 22807 I CHIUSECASE: RefillReturnThreadLoop: RefillReturnThreadLoop exits.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: ===== Dumping PendingResultDispatcher State Begin =====
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: shutter frameNum queue len = 0 | result queue len = 0.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: metadata frameNum queue len = 0 | result queue len = 0.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: outputStream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: outputStream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: inputstream frameNum queue len = 0 | result queue len = 0.
09-29 14:38:28.554   940  1546 I CHIUSECASE: DumpQueueState: ===== Dumping PendingResultDispatcher State End =====
09-29 14:38:28.554   940  1546 D CHIUSECASE: ExtensionModule::TeardownOverrideSession Exit
09-29 14:38:28.554  1102  6845 I CameraProviderManager: Camera device [email protected]/legacy/0 torch status is now AVAILABLE_OFF
09-29 14:38:28.554  1102  6845 I CameraService: onTorchStatusChangedLocked: Torch status changed for cameraId=0, newStatus=1
09-29 14:38:28.556  1102  6845 W Camera3-OutputStream: disconnectLocked: While disconnecting stream 0 from native window, the native window died from under us
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram: Stream 0 dequeueBuffer latency histogram (53) samples:
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram:         5     10     15     20     25     30     35     40     45    inf (max ms)
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram:      100.00   0.00   0.00   0.00   0.00   0.00   0.00   0.00   0.00   0.00 (%)
09-29 14:38:28.556  1102  6845 W Camera3-OutputStream: disconnectLocked: While disconnecting stream 1 from native window, the native window died from under us
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram: Stream 1 dequeueBuffer latency histogram (53) samples:
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram:         5     10     15     20     25     30     35     40     45    inf (max ms)
09-29 14:38:28.556  1102  6845 I CameraLatencyHistogram:      94.34   3.77   0.00   0.00   0.00   0.00   0.00   0.00   1.89   0.00 (%)
09-29 14:38:28.556  1102  6845 I Camera3-Device: disconnectImpl: X
09-29 14:38:28.557  1102  6845 I CameraService: disconnect: Disconnected client for camera 0 for PID 22656
09-29 14:38:28.557  1102  6845 I Camera3-Device: disconnectImpl: E
09-29 14:38:28.557  1102  6845 I Camera2ClientBase: Closed Camera 0. Client was: com.example.app (PID 22656, UID 10697)
09-29 14:38:28.557  1102  6845 I Camera3-Device: disconnectImpl: E
09-29 14:38:28.557  1102  6845 E CameraService: binderDied: Java client's binder died, removing it from the list of active clients
09-29 14:38:28.558  2234  2234 D GRIL-S  : [0217]> UPDATE_DEVICE_STATE DeviceState: Usb:1, Wifi: 1, Wifi AP: 0, Earpiece: 0, Bluetooth: 1, Wireless charging: 0, Screen: 1, Camera: 0, 0, 0, 0, Motion: 1, Bluetooth tethering: 0, Voice: 0, Wifi 2.4G: 0, Radio: 1, Bluetooth connected: 0, Bluetooth media: 0
09-29 14:38:28.561  2234  3081 D GRIL-S  : [0217]< UPDATE_DEVICE_STATE 
09-29 14:38:28.708  1459  1514 W ActivityTaskManager: Activity top resumed state loss timeout for ActivityRecord{250689a u0 com.example.app/.aractivity.ArActivity t-1 f}}
09-29 14:38:29.141   958  1031 I CHRE    : @ 10990.756: [AR] still: 51.372547
09-29 14:38:29.887   958  1031 D VSC     : @ 10991.501: [WO] tilt angle 45
09-29 14:38:29.887   958  1031 D VSC     : @ 10991.501: [WO] isFlat() nearest_rotation: 4, flat_angle: 65
09-29 14:38:29.887   958  1031 D VSC     : @ 10991.501: [WO] orientation angle 350, orientation 4
09-29 14:38:30.753  1079  1079 I perfetto: probes_producer.cc:329  Producer stop (id=49)
09-29 14:38:30.756  1079  1079 I perfetto: ftrace_procfs.cc:183    disabled ftrace
09-29 14:38:30.767  1081  1081 I perfetto: ng_service_impl.cc:1948 Tracing session 49 ended, total sessions:0
09-29 14:38:30.881  1120 22652 I iorapd  : Perfetto TraceBuffer saved to file: /data/misc/iorapd/com.example.app/13/com.example.app.aractivity.ArActivity/raw_traces/1601404710874571702.perfetto_trace.pb
09-29 14:38:31.038  2284  2389 I QImsService: ImsSenderRxr : [UNSL]< UNSOL_VOPS_CHANGED true[SUB0]
09-29 14:38:31.047  2284  2284 I QImsService: ImsServiceSubHandler : Message received: what = 25
09-29 14:38:31.097  3038  3038 D StateService: Country ISO: us
09-29 14:38:31.097  3038  3038 D StateService: Regulatory domain: US > US
09-29 14:38:31.099  2181  2283 I QCNEJ/CndHalConnector: -> SND notifyWwanSubtypeChanged(13)
09-29 14:38:31.100  2181  2283 I QCNEJ/CndHalConnector: -> SND notifyMobileDataEnabledChanged(true)
09-29 14:38:31.103  2284  2284 D ServiceStateProvider: subId=1
09-29 14:38:31.103  2994  2994 I CarrierServices: [2] ImsRegistrationNetworkSelector.onCellStateChanged:341 OnCellStateChanged for subId: 2147483647
09-29 14:38:31.114  1459  1864 D Nat464Xlat: clatd running, updating NAI for v4-rmnet_data2
09-29 14:38:31.122 14605 14605 D CellBroadcastReceiver: onReceive Intent { act=android.intent.action.SERVICE_STATE flg=0x1000010 cmp=com.google.android.cellbroadcastreceiver/com.android.cellbroadcastreceiver.CellBroadcastReceiver (has extras) }
09-29 14:38:31.124  2284  2434 W TelephonyPermissions: reportAccessDeniedToReadIdentifiers:com.google.android.apps.tycho:getSubscriptionInfoList:-1
09-29 14:38:31.127  3038  3038 I TelephonySignalStrength: TelephonySignalStrength()
09-29 14:38:31.142  2994  2994 I CarrierServices: [2] ServiceStateReceiver.onReceive:16 Received SERVICE_STATE intent, clearing cached cell info
09-29 14:38:31.143  2284  2284 I Telephony: isRttCurrentlySupported -- regular acct, hasVoiceAvailability: true
09-29 14:38:31.143  2284  2284 I Telephony:  isRttSupported: false
09-29 14:38:31.143  2284  2284 I Telephony:  isRoaming: false
09-29 14:38:31.143  2284  2284 I Telephony:  isOnWfc: false
09-29 14:38:31.148  2284  2284 D TelephonyProvider: Using old permission behavior for telephony provider compat
09-29 14:38:31.148  2284  2284 D TelephonyProvider: subIdString = 1 subId = 1
09-29 14:38:31.156  2284  2591 W TelephonyPermissions: reportAccessDeniedToReadIdentifiers:com.google.android.apps.tycho:getSubscriptionInfoList:-1
09-29 14:38:31.162  2284  2284 D TelephonyProvider: Using old permission behavior for telephony provider compat
09-29 14:38:31.162  2284  2284 D TelephonyProvider: subIdString = 1 subId = 1
09-29 14:38:31.171  2621  5337 I Tycho.ejw: Setting flaky count. LTE session ended: false
09-29 14:38:31.171  2621  5337 I Tycho.elo: Successfully updated LTE flakiness count, current count is 0.000000
09-29 14:38:31.181  2621  5337 I Tycho.eja: Ignoring duplicate service state event: service state In service; voice network type LTE; country: US.
09-29 14:38:31.889   958  1031 D VSC     : @ 10993.502: [WO] tilt angle 58
09-29 14:38:31.889   958  1031 D VSC     : @ 10993.503: [WO] isFlat() nearest_rotation: 4, flat_angle: 65
09-29 14:38:31.889   958  1031 D VSC     : @ 10993.503: [WO] orientation angle 319, orientation 4
09-29 14:38:31.889   958  1031 D VSC     : @ 10993.503: [WO] rejected by isOrientationAngleAcceptable
09-29 14:38:33.348 27110 27124 W System  : A resource failed to call close. 
09-29 14:38:33.348 27110 27124 E DataBuffer: Internal data leak within a DataBuffer object detected!  Be sure to explicitly call release() on all DataBuffer extending objects when you are done with them. (internal object: com.google.android.gms.common.data.DataHolder@e86ec29)
09-29 14:38:33.889   958  1031 D VSC     : @ 10995.503: [WO] tilt angle 85
09-29 14:38:35.548   958  1031 I CHRE    : @ 10997.162: [AR] inconsistent: 41.176471
09-29 14:38:35.889   958  1031 D VSC     : @ 10997.502: [WO] tilt angle 85
09-29 14:38:35.996  2994  2994 I CarrierServices: [2] ImsRegistrationNetworkSelector.onCellStateChanged:341 OnCellStateChanged for subId: 2147483647
09-29 14:38:37.891   958  1031 D VSC     : @ 10999.504: [WO] tilt angle 85
09-29 14:38:38.792   958  1031 I CHRE    : @ 11000.406: [AR] still: 59.607841
09-29 14:38:39.129   958  1031 D VSC     : @ 11000.743: [Step Counter] Request motion_detect, interval 18446744027136.0 ms, latency 0.0 ms
09-29 14:38:39.131   958  1031 D VSC     : @ 11000.745: [Step Counter] Stop accel
09-29 14:38:39.886   958  1031 D VSC     : @ 11001.501: [WO] tilt angle 85
09-29 14:38:41.889   958  1031 D VSC     : @ 11003.502: [WO] tilt angle 84
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: connected
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: Sending [1] HTTP transactions.
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: Sending [0] HTTP errors.
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: Sending [0] activity traces.
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: Sending [0] session attributes.
09-29 14:38:42.876 21078 21136 I com.newrelic.android: Harvester: Sending [0] analytics events.
09-29 14:38:43.889   958  1031 D VSC     : @ 11005.502: [WO] tilt angle 85
09-29 14:38:44.385  1459  4554 I Telecom : PhoneAccountRegistrar: getSimCallManager: SimCallManager for subId 1 queried, returning: ComponentInfo{com.google.android.ims/com.google.android.ims.call.DialerConnectionService}, ***, UserHandle{0}: TSI.gSCM@BWU
09-29 14:38:44.404  1459  4554 I Telecom : PhoneAccountRegistrar: getSimCallManager: SimCallManager for subId 1 queried, returning: ComponentInfo{com.google.android.ims/com.google.android.ims.call.DialerConnectionService}, ***, UserHandle{0}: TSI.gSCM@BWc

[bejado]

If I run the app with a locally-built debug version of Filament, I see a assertion "mThreadId == std::this_thread::get_id() assert fired:

2020-09-29 13:20:30.340 19110-19110/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2020-09-29 13:20:30.340 19110-19110/? A/DEBUG: Build fingerprint: 'google/sunfish/sunfish:11/RP1A.201005.005/6787072:user/release-keys'
2020-09-29 13:20:30.340 19110-19110/? A/DEBUG: Revision: 'MP1.0'
2020-09-29 13:20:30.340 19110-19110/? A/DEBUG: ABI: 'arm64'
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG: Timestamp: 2020-09-29 12:20:30-0700
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG: pid: 18910, tid: 19106, name: RxCachedThreadS  >>> com.example.app <<<
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG: uid: 10000
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG: signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG: Abort message: '../../filament/backend/include/private/backend/CommandStream.h:303: void *filament::backend::CommandStream::allocateCommand(size_t): assertion "mThreadId == std::this_thread::get_id()" failed'
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x0  0000000000000000  x1  0000000000004aa2  x2  0000000000000006  x3  0000007283dd3f40
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x4  0000000000000000  x5  0000000000000000  x6  0000000000000000  x7  0000000000000040
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x8  00000000000000f0  x9  5cc6ac66f51cc83c  x10 0000000000000000  x11 ffffffc0fffffbdf
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x12 0000000000000001  x13 00000c28f01c313b  x14 000b210bfe467b31  x15 000000000151d0d0
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x16 00000075ba243c80  x17 00000075ba2253b0  x18 0000007283062000  x19 00000000000049de
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x20 0000000000004aa2  x21 00000000ffffffff  x22 0000007283dd8000  x23 b40000749a155a18
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x24 000000730dce7980  x25 0000007283dd8000  x26 000000000000000b  x27 0000000000000004
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     x28 0000007283dd5dd0  x29 0000007283dd3fc0
2020-09-29 13:20:30.341 19110-19110/? A/DEBUG:     lr  00000075ba1d8e20  sp  0000007283dd3f20  pc  00000075ba1d8e4c  pst 0000000000000000
2020-09-29 13:20:30.348 19110-19110/? A/DEBUG: backtrace:
2020-09-29 13:20:30.348 19110-19110/? A/DEBUG:       #00 pc 000000000004de4c  /apex/com.android.runtime/lib64/bionic/libc.so (abort+164) (BuildId: 03452a4a418e14ff93948f26561eace6)
2020-09-29 13:20:30.348 19110-19110/? A/DEBUG:       #01 pc 000000000004e214  /apex/com.android.runtime/lib64/bionic/libc.so (__assert2+36) (BuildId: 03452a4a418e14ff93948f26561eace6)
2020-09-29 13:20:30.348 19110-19110/? A/DEBUG:       #02 pc 0000000000262220  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::backend::CommandStream::allocateCommand(unsigned long)+112) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.348 19110-19110/? A/DEBUG:       #03 pc 000000000025e4e4  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::backend::CommandStream::createUniformBuffer(unsigned long, filament::backend::BufferUsage)+164) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #04 pc 00000000002c844c  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::FMaterialInstance::initDefaultInstance(filament::FEngine&, filament::FMaterial const*)+204) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #05 pc 00000000002b9eb0  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::FMaterial::FMaterial(filament::FEngine&, filament::Material::Builder const&)+2800) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #06 pc 00000000002ac5d4  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::FMaterial* utils::Arena<utils::HeapAllocator, utils::Mutex, utils::TrackingPolicy::DebugAndHighWatermark>::make<filament::FMaterial, 8ul, filament::FEngine&, filament::Material::Builder const&>(filament::FEngine&, filament::Material::Builder const&)+148) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #07 pc 0000000000285bdc  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::FMaterial* filament::FEngine::create<filament::FMaterial>(filament::ResourceList<filament::FMaterial, utils::LockingPolicy::NoLock>&, filament::FMaterial::Builder const&)+44) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #08 pc 00000000002806f8  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::FEngine::createMaterial(filament::Material::Builder const&)+40) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #09 pc 00000000002b91dc  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libfilament-jni.so (offset 0xe65000) (filament::Material::Builder::build(filament::Engine&)+556) (BuildId: 2316b93fbe6fb9cc913f3052f852f547455609fd)
2020-09-29 13:20:30.349 19110-19110/? A/DEBUG:       #10 pc 00000000001796ec  /data/app/~~a-gqayyt8WPhqstn4URPZw==/com.example.app-0hb8Uxz17sxszZsMbcttOA==/base.apk!libgltfio-jni.so (offset 0x15cd000) (BuildId: ccd8f549005ff009d7f23970c1bb8bb85a685be1)

[romainguy]

@zirman This asset means you are invoking Filament from the wrong thread.

[zirman]

Strange. It's on the main thread. I double checked by doing logging

Looper.myLooper() == Looper.getMainLooper()

Which returns true.

[romainguy]

Was the engine also created on the main thread?

[zirman]

Yes, all of this is initialized on the main thread.

    val engine: Engine = Engine.create(arCore.eglContext)
    val renderer: Renderer = engine.createRenderer().apply { clearOptions }
    val scene: Scene = engine.createScene()

[romainguy]

@bejado I wonder if this could be related to the recent change Mathias made in how we track the initialization thread? https://github.com/google/filament/pull/3031

[bejado]

@romainguy I can try reverting that change and see if it still crashes.

[bejado]

I think the mThreadId assertion is unrelated. I commented out the assertion and was able to get a symbolicated stack trace:

09-29 13:55:03.565 25705 25705 F DEBUG   : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0xebebebebebebebf3
09-29 13:55:03.565 25705 25705 F DEBUG   :     x0  0000007fd6c0de54  x1  ebebebebebebebf3  x2  0000000000000004  x3  0000000000000009
09-29 13:55:03.565 25705 25705 F DEBUG   :     x4  ebebebebebebebf7  x5  0000007fd6c0de58  x6  400000003f800000  x7  4040000040000000
09-29 13:55:03.565 25705 25705 F DEBUG   :     x8  0000007fd6c0de54  x9  ebebebebebebebeb  x10 0000000000000008  x11 0000000000000330
09-29 13:55:03.565 25705 25705 F DEBUG   :     x12 000000000000007c  x13 00000000000007c8  x14 00000075ba246d22  x15 0000007fd6c0dea8
09-29 13:55:03.565 25705 25705 F DEBUG   :     x16 00000072b82f1f78  x17 00000075ba1d4e40  x18 00000075c0100000  x19 b400007499c9d7b0
09-29 13:55:03.565 25705 25705 F DEBUG   :     x20 0000000000000000  x21 b400007499c9d7b0  x22 00000075bf275000  x23 b400007499c9d868
09-29 13:55:03.565 25705 25705 F DEBUG   :     x24 000000730dbd3e48  x25 00000075bf275000  x26 0000000000000037  x27 0000000000000004
09-29 13:55:03.565 25705 25705 F DEBUG   :     x28 0000007fd6c0f8f0  x29 0000007fd6c0dc50
09-29 13:55:03.565 25705 25705 F DEBUG   :     lr  00000072b7e439a8  sp  0000007fd6c0dc20  pc  00000075ba1d4d44  pst 0000000080001000
09-29 13:55:03.571 25705 25705 F DEBUG   : backtrace:
09-29 13:55:03.571 25705 25705 F DEBUG   :       #00 pc 0000000000049d44  /apex/com.android.runtime/lib64/bionic/libc.so (__memcpy+116) (BuildId: 03452a4a418e14ff93948f26561eace6)
09-29 13:55:03.571 25705 25705 F DEBUG   :       #01 pc 00000000002b79a4  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FTexture::getHwHandle() const+36) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #02 pc 00000000002b6b9c  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FIndirectLight::getReflectionHwHandle() const+28) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #03 pc 00000000003348c0  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FView::prepareLighting(filament::FEngine&, filament::backend::CommandStream&, utils::ArenaScope<utils::Arena<utils::LinearAllocator, utils::LockingPolicy::NoLock, utils::TrackingPolicy::DebugAndHighWatermark> >&, filament::Viewport const&)+656) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #04 pc 00000000003355a4  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FView::prepare(filament::FEngine&, filament::backend::CommandStream&, utils::ArenaScope<utils::Arena<utils::LinearAllocator, utils::LockingPolicy::NoLock, utils::TrackingPolicy::DebugAndHighWatermark> >&, filament::Viewport const&, filament::math::details::TVec4<float> const&)+2036) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #05 pc 00000000002f1af4  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FRenderer::renderJob(utils::ArenaScope<utils::Arena<utils::LinearAllocator, utils::LockingPolicy::NoLock, utils::TrackingPolicy::DebugAndHighWatermark> >&, filament::FView&)+916) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #06 pc 00000000002f16f4  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::FRenderer::render(filament::FView const*)+388) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #07 pc 00000000002f4fac  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (filament::Renderer::render(filament::View const*)+60) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.572 25705 25705 F DEBUG   :       #08 pc 0000000000244578  /data/app/~~ZEKzlV2xbzUL6l_78_BQ2A==/com.example.app-3n7_wk7_dZvKiegH5EidDA==/base.apk!libfilament-jni.so (offset 0x1ddd000) (Java_com_google_android_filament_Renderer_nRender+48) (BuildId: b289fcfd5b9677f03c14b14f5e95c0225172c679)
09-29 13:55:03.573 25460 25562 I native  : distribute.cc:79 No keypoints to prune.
09-29 13:55:03.578 25460 25582 W native

Looks like the crash is happening in FIndirectLight::getReflectionHwHandle.

[bejado]

@prideout

I think https://github.com/google/filament/commit/732a6c08dea774379d8d092050c35fe4b977b03a is the offending commit.

mReflectionsTexture is uninitialized in IndirectLight.h and is only set if the indirect light is initialized with a reflection map (here). If no reflection map is provided, we dereference an invalid pointer when we do FIndirectLight::getReflectionHwHandle.

I can fix it by initializing mReflectionsTexture, but I'm not sure what getReflectionHwHandle should return if mReflectionsTexture is null.

[zirman]

In a related note, do you have an example of how to generate a reflections texture from the following:
https://developers.google.com/ar/reference/java/com/google/ar/core/LightEstimate#acquireEnvironmentalHdrCubeMap()
The docs say to use cmgen but this needs to be done programmatically. Any help is appreciated.

[romainguy]

@zirman Yes, it's actually fairly easy, you just need to create the cubemap texture and then call Texture.generatePrefilterMipmap(). This will do what cmgen does, except at runtime.

[Sheng-Xuan]

Might be a relevant issue on my side. I have this error thrown on filament 1.80 and 1.81:

2020-09-30 10:37:29.067 27172-27172/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: Build fingerprint: 'google/coral/coral:11/RP1A.200720.009/6720564:user/release-keys'
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: Revision: 'MP1.0'
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: ABI: 'arm64'
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: Timestamp: 2020-09-30 10:37:29+0800
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: pid: 24778, tid: 24937, name: Thread-15  >>> com.demoapp.demo <<<
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: uid: 10482
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x10
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG: Cause: null pointer dereference
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x0  0000007b7c37dbe0  x1  0000000000000000  x2  0000000000000000  x3  0000000000000040
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x4  0000000000000010  x5  0000007b5c545580  x6  0000000000000002  x7  0000007b8c46dbc0
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x8  0000000000000000  x9  0000000000000000  x10 ffffffffffffffff  x11 0000000000000000
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x12 0000000000000000  x13 0000007b3ffab168  x14 0000000000000002  x15 0000000000000000
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x16 0000007b3efd44e8  x17 0000007dee7c281c  x18 0000007adbb56000  x19 0000007c9c30b0a0
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x20 0000007b7c37dbe0  x21 0000007ada532b00  x22 0000007b4bfb1860  x23 0000007b6c3322f0
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x24 0000007b6c332300  x25 0000007adc92bcc0  x26 0000007adc92bff8  x27 00000000000fc000
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     x28 0000007adc833000  x29 0000007adc92bc70
2020-09-30 10:37:29.068 27172-27172/? A/DEBUG:     lr  0000007b4c93e26c  sp  0000007adc92ba70  pc  0000007b4c93e298  pst 0000000080000000
2020-09-30 10:37:29.076 27172-27172/? A/DEBUG: backtrace:
2020-09-30 10:37:29.076 27172-27172/? A/DEBUG:       #00 pc 000000000007c298  /data/app/~~t27Pxmnhq1GWIKs95aJJ0A==/com.demoapp.demo-CUy9IZCED50XnpdbqBp5XA==/base.apk!libfilament-jni.so (offset 0x70f000) (BuildId: 97d04aece5bbc0c8d3e71a6ba0c02cdff1dc7f29)

It seems only happen after I upgrade my pixel 4 to Android 11, was stable before the os upgrade.
Have not tried 1.92 as I need to rebuild all the .metc files.
I can't see more detailed error log in Android studio except for this.

[bejado]

@Sheng-Xuan 732a6c0 is only present in Filament 1.9.0 and up, so I suspect that crash is unrelated.

[Sheng-Xuan]

@zirman Hi, could you tell me how did you manage to get the full backtrace in Android Studio?

[zirman]

@Sheng-Xuan I used adb logcat: https://developer.android.com/studio/command-line/logcat

[pixelflinger]

ebebebeb indicates uninitialized memory.