Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ARCore 1.6 is often crashing #666

Closed
lvonasek opened this issue Dec 7, 2018 · 5 comments
Closed

ARCore 1.6 is often crashing #666

lvonasek opened this issue Dec 7, 2018 · 5 comments

Comments

@lvonasek
Copy link

lvonasek commented Dec 7, 2018

2018-12-07 11:56:02.013 10653-10653/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2018-12-07 11:56:02.014 10653-10653/? A/DEBUG: Build fingerprint: 'asus/WW_ASUS_A002/ASUS_A002:7.0/NRD90M/14.1600.1805.51-20180626:user/release-keys'
2018-12-07 11:56:02.014 10653-10653/? A/DEBUG: Revision: '0'
2018-12-07 11:56:02.014 10653-10653/? A/DEBUG: ABI: 'arm'
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG: pid: 5726, tid: 5898, name: arcore3dscanner  >>> com.lvonasek.arcore3dscanner <<<
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG: signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG:     r0 00000000  r1 00000000  r2 eaa87880  r3 00000001
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG:     r4 00000000  r5 3f800000  r6 e0c69c48  r7 00000000
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG:     r8 e0c69c48  r9 e23833dc  sl 00000013  fp 3f800000
2018-12-07 11:56:02.015 10653-10653/? A/DEBUG:     ip 00000001  sp e2383358  lr 0000000d  pc ecf8e260  cpsr 60030030
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG: backtrace:
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #00 pc 00062260  /system/lib/libc.so (je_huge_salloc+7)
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #01 pc 000667cf  /system/lib/libc.so (ifree+242)
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #02 pc 00066b67  /system/lib/libc.so (je_free+74)
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #03 pc 00436761  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #04 pc 0043621b  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #05 pc 0043223d  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #06 pc 004315d7  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #07 pc 004312a5  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #08 pc 000d6c31  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #09 pc 0009bc93  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #10 pc 008061c3  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.025 10653-10653/? A/DEBUG:     #11 pc 0080724f  /data/app/com.google.ar.core-2/lib/arm/libarcore_c.so
2018-12-07 11:56:02.026 10653-10653/? A/DEBUG:     #12 pc 00046ff3  /system/lib/libc.so (_ZL15__pthread_startPv+22)
2018-12-07 11:56:02.026 10653-10653/? A/DEBUG:     #13 pc 00019ce9  /system/lib/libc.so (__start_thread+6)

My app is basically using the same AR functions like HelloAR. Additionally I am updating very often anchor:

    void ARCoreService::UpdateAnchor(ArPose* ar_pose) {
        ArAnchor *oldAnchor = ar_anchor_;
        int size = 0;
        ArHitResult* hit = 0;
        ArHitResultList* hits = 0;
        ArHitResult_create(ar_session_, &hit);
        ArHitResultList_create(ar_session_, &hits);
        ArFrame_hitTest(ar_session_, ar_frame_, renderer->width / 2, renderer->height / 2, hits);
        ArHitResultList_getSize(ar_session_, hits, &size);
        for (int i = 0; i < size; i++) {
            ArTrackable* trackable = 0;
            ArHitResultList_getItem(ar_session_, hits, i, hit);
            ArHitResult_acquireTrackable(ar_session_, hit, &trackable);
            ArTrackableType ar_trackable_type = AR_TRACKABLE_NOT_VALID;
            ArTrackable_getType(ar_session_, trackable, &ar_trackable_type);
            ArStatus ret = ArTrackable_acquireNewAnchor(ar_session_, trackable, ar_pose, &ar_anchor_);
            ArTrackable_release(trackable);
            if (ret != AR_SUCCESS)
                ar_anchor_ = 0;
            else {
                if (oldAnchor) {
                    ArAnchor_detach(ar_session_, oldAnchor);
                    ArAnchor_release(oldAnchor);
                }
                ArHitResultList_destroy(hits);
                ArHitResult_destroy(hit);
                return;
            }
        }
        ArHitResultList_destroy(hits);
        ArHitResult_destroy(hit);
        ar_anchor_ = oldAnchor;
    }
@inio
Copy link

inio commented Dec 7, 2018

Your stack trace indicates heap corruption, which could be caused just as easily by ARCore as by your own app.

Your code sample looks correct. Could you try forking HelloAR C, integrating this behavior, and seeing if you still get the crash? If so send me a link to the fork and We should be able to track down the issue quickly.

@lvonasek
Copy link
Author

I found one memory leak in my app, after it I am not able to reproduce issue on my device. Also I published an update on Google Play. However the Google Play Console indicates that the issue is still there.

@lvonasek
Copy link
Author

lvonasek commented Dec 29, 2018

I noticed that twice after this crash there was in the logcat E/mm-camera: <ISP ><ERROR>

2018-12-29 23:22:42.702 902-23357/? E/mm-camera: <ISP   ><ERROR> 2483: chk_adjacent_end_pix_roi_limitation: error: two roi ending on same pixel x 76 y 684 w 307 h 341
2018-12-29 23:22:42.788 902-23372/? E/mm-3a-core: PJrgb RGBSensor_DIT_(103, 68, 41, 660)
2018-12-29 23:22:43.080 23292-23330/com.lvonasek.arcore3dscanner A/libc: Fatal signal 11 (SIGSEGV), code 1, fault addr 0x82da64d0 in tid 23330 (tango_lp_0)
2018-12-29 23:22:43.083 902-23372/? E/mm-camera: <STATS_AEC ><ERROR> 2161: aec_port_callback: AEC_UPDATE_DBG: PORT_CB: WARNING: threading issue: SOF_ID:1949 OutputFrameId:1950 output_index=0 -> Debug
2018-12-29 23:22:43.156 24154-24154/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG: Build fingerprint: 'asus/WW_ASUS_A002/ASUS_A002:7.0/NRD90M/14.1600.1805.51-20180626:user/release-keys'
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG: Revision: '0'
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG: ABI: 'arm'
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG: pid: 23292, tid: 23330, name: tango_lp_0  >>> com.lvonasek.arcore3dscanner <<<
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG: signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x82da64d0
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG:     r0 82da64b0  r1 3ecf2d9d  r2 b8decd70  r3 c137d4a4
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG:     r4 3ecf2d9d  r5 82da64b0  r6 c4300ec0  r7 bf246c00
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG:     r8 b8c89380  r9 c116aad8  sl b8c89410  fp c2a7b8e0
2018-12-29 23:22:43.157 24154-24154/? A/DEBUG:     ip e85b6948  sp c4300d30  lr c49b5e29  pc c50debee  cpsr 60030030
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG: backtrace:
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #00 pc 008dcbee  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #01 pc 001b3e25  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #02 pc 001b43c1  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #03 pc 001b4a41  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #04 pc 00198411  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #05 pc 00156093  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #06 pc 0015562b  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #07 pc 00105d13  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.166 24154-24154/? A/DEBUG:     #08 pc 00105b77  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #09 pc 00107fdd  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #10 pc 001081a5  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #11 pc 0009bc93  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #12 pc 008061c3  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #13 pc 0080724f  /data/app/com.google.ar.core-1/lib/arm/libarcore_c.so
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #14 pc 00046ff3  /system/lib/libc.so (_ZL15__pthread_startPv+22)
2018-12-29 23:22:43.167 24154-24154/? A/DEBUG:     #15 pc 00019ce9  /system/lib/libc.so (__start_thread+6)
2018-12-29 23:22:43.438 902-23357/? E/mm-camera: <ISP   ><ERROR> 2483: chk_adjacent_end_pix_roi_limitation: error: two roi ending on same pixel x 76 y 684 w 307 h 341
2018-12-29 23:22:43.704 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.706 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.736 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.738 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.770 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.772 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.803 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.807 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.837 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.841 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.872 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.875 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.903 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.905 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.937 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.941 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:43.971 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:43.973 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:44.003 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:44.005 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:44.037 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:44.039 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:44.070 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:44.072 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:44.081 1391-24155/? W/ActivityManager:   Force finishing activity com.lvonasek.arcore3dscanner/.main.Main
2018-12-29 23:22:44.089 1391-1537/? I/BootReceiver: Copying /data/tombstones/tombstone_05 to DropBox (SYSTEM_TOMBSTONE)
2018-12-29 23:22:44.097 1391-24155/? D/ActivityTrigger: ActivityTrigger activityPauseTrigger 
2018-12-29 23:22:44.101 1391-1440/? W/BroadcastQueue: Permission Denial: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to ProcessRecord{da82b56 14559:com.teslacoilsw.notifier/u0a840} (pid=14559, uid=10840) requires android.permission.READ_LOGS due to sender android (uid 1000)
2018-12-29 23:22:44.103 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:44.107 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.
2018-12-29 23:22:44.119 1391-1440/? W/BroadcastQueue: Permission Denial: receiving Intent { act=android.intent.action.DROPBOX_ENTRY_ADDED flg=0x10 (has extras) } to ProcessRecord{da82b56 14559:com.teslacoilsw.notifier/u0a840} (pid=14559, uid=10840) requires android.permission.READ_LOGS due to sender android (uid 1000)
2018-12-29 23:22:44.121 2401-2447/? D/OpenedTimeAppInfoProvider: Update DB : number of affected records : 1
2018-12-29 23:22:44.122 2401-2401/? D/TaskWatcherService: pkgName: com.lvonasek.arcore3dscanner taskId: 74207
2018-12-29 23:22:44.123 2401-2401/? W/ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.startService:1397 android.content.ContextWrapper.startService:620 com.asus.powersaver.TaskWatcherService$IncomingHandler.handleMessage:-1 android.os.Handler.dispatchMessage:102 android.os.Looper.loop:159 
2018-12-29 23:22:44.127 2401-2401/? W/ContextImpl: Calling a method in the system process without a qualified user: android.app.ContextImpl.sendBroadcast:917 android.content.ContextWrapper.sendBroadcast:428 com.asus.powersaver.TaskWatcherService$IncomingHandler.handleMessage:-1 android.os.Handler.dispatchMessage:102 android.os.Looper.loop:159 
2018-12-29 23:22:44.131 1391-1441/? V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@8fef62f
2018-12-29 23:22:44.132 1391-1441/? V/BoostFramework: BoostFramework() : mPerf = com.qualcomm.qti.Performance@aeb543c
2018-12-29 23:22:44.136 2401-2401/? D/PowerSaverService: onStartCommand PowerSaverService
2018-12-29 23:22:44.138 2401-2401/? D/PowerSaverService: current package:com.lvonasek.arcore3dscanner;activity:com.lvonasek.arcore3dscanner.ui.FileManager
2018-12-29 23:22:44.138 2401-2401/? D/PowerSaverUtils: isLimitedCpuFrequency prop : 0 ; result : false
2018-12-29 23:22:44.138 902-23379/? E/mm-camera: <MCT   ><ERROR> 2322: mct_stream_get_metadata_buffer: Failed to get_buf - errno: Invalid argument!!!
2018-12-29 23:22:44.141 902-23379/? E/mm-camera: <MCT   ><ERROR> 811: mct_controller_proc_bus_msg_internal: Failed to issue SOF cmd to all modules.

@inio
Copy link

inio commented Jan 3, 2019

That's still a SIGSEGV which usually means heap corruption. I think we'd be seeing this from more developers if it were a bug in ARCore itself.

@lvonasek
Copy link
Author

lvonasek commented Jan 4, 2019

Thank you for your time, you are right.

I leave here a link to stackoverflow about heap corruption: https://stackoverflow.com/a/1504307/7795928

Closed because it is not an issue of ARCore

@lvonasek lvonasek closed this as completed Jan 4, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants