google-ar / arcore-ios-sdk

ARCore SDK for iOS
https://developers.google.com/ar/
Apache License 2.0
283 stars 85 forks source link

AugmentedFacesExample getting EXC_BAD_ACCESS when run for a moment #32

Closed Bersaelor closed 3 years ago

Bersaelor commented 4 years ago

The unchanged example app will get a EXC_BAD_ACCESS in FacesVIewController.swift: 231 after running for a moment..

Screen Shot 2020-04-03 at 17 08 58

It's pretty much 100% reproducible (Tried on an iPad Pro 11", an iPhone X and an iPhone 6S). Takes up to 5 mins in my tests. I just left the app running with debugger attached while I working on something else, with my face still in the frame.

I'm assuming noone actually tested this framework this long, so it wasn't noticed before?

(iOS 13.3.1 and iOS 13.4, ARCore 1.16.0 )

Crash Stack:

#0  0x000000018b54efc0 in objc_msgSend ()
#1  0x000000018b56d278 in objc_retain ()
#2  0x0000000102990b8c in FacesViewController.renderer(_:updateAtTime:) at /Users/konrad/Downloads/arcore-ios-sdk-master/Examples/AugmentedFacesExample/AugmentedFacesExample/FacesViewController.swift:231
#3  0x0000000102991564 in @objc FacesViewController.renderer(_:updateAtTime:) ()
#4  0x000000019ff449d4 in -[SCNRenderer _update:] ()
#5  0x000000019ff4719c in -[SCNRenderer _drawSceneWithNewRenderer:] ()
#6  0x000000019ff47778 in -[SCNRenderer _drawScene:] ()
#7  0x000000019ff47b24 in -[SCNRenderer _drawAtTime:] ()
#8  0x000000019ffe6724 in -[SCNView _drawAtTime:] ()
#9  0x000000019fea30b8 in __69-[NSObject(SCN_DisplayLinkExtensions) SCN_setupDisplayLinkWithQueue:]_block_invoke ()
#10 0x000000019ffb0614 in __36-[SCNDisplayLink _callbackWithTime:]_block_invoke ()
#11 0x0000000103b1727c in _dispatch_client_callout ()
#12 0x0000000103b26058 in _dispatch_lane_barrier_sync_invoke_and_complete ()
#13 0x000000019ffb0598 in -[SCNDisplayLink _callbackWithTime:] ()
#14 0x0000000103d18208 in -[DYDisplayLinkInterposer forwardDisplayLinkCallback:] ()
#15 0x00000001922bff24 in CA::Display::DisplayLink::dispatch_items(unsigned long long, unsigned long long, unsigned long long) ()
#16 0x000000019238e608 in display_timer_callback(__CFMachPort*, void*, long, void*) ()
#17 0x000000018b78bdac in __CFMachPortPerform ()
#18 0x000000018b7b67c4 in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE1_PERFORM_FUNCTION__ ()
#19 0x000000018b7b5e90 in __CFRunLoopDoSource1 ()
#20 0x000000018b7b0ac8 in __CFRunLoopRun ()
#21 0x000000018b7aff40 in CFRunLoopRunSpecific ()
#22 0x000000018baf5340 in -[NSRunLoop(NSRunLoop) runMode:beforeDate:] ()
#23 0x000000019fea34c0 in __71-[SCNView(SCNDisplayLink) _initializeDisplayLinkWithCompletionHandler:]_block_invoke ()
#24 0x000000019fea3730 in __SCNRenderThread_start__ ()
#25 0x000000018b543840 in _pthread_start ()

I believe this must be a run-conditioning happening somewhere between the threads. And it doesn't happen deterministically, thats why the app has to be left open for a while.

Bersaelor commented 4 years ago

After some more testing it seems the problem is inside the ARCore framework, potentially introduced in Version 1.16.0.

I rearranged the example code to the following:

    let projectionSIMD = frame.projectionMatrix(
        forViewportSize: sceneBounds,
        presentationOrientation: .portrait,
        mirrored: false,
        zNear: 0.05,
        zFar: 100
    )
    let projectionM = SCNMatrix4.init(projectionSIMD)
    // Set the scene camera's transform to the projection matrix for this frame.
    DispatchQueue.main.sync {
      sceneCamera.projectionTransform = projectionM
    }

The crash always happens during the frame.projectionMatrix() call.

As far as I understand, EXC_BAD_ACCESS in objc_msgSend means that the frame object was already released when the frame.projectionMatrix call is sent. Thats why I tried saving the result of the call and only using the result in the Dispatch.sync call. Unfortunately it's still crashing, so its maybe an internal ARCore issue.

Screen Shot 2020-04-03 at 17 58 18
rsfuller commented 4 years ago

Thanks for this bug report!

The fix will likely be switching the sceneView.bounds.size call (UI API) to cameraImageLayer.bounds.size (which is safe to call on a bg thread), and not dispatching the block to the main queue.

Bersaelor commented 4 years ago

@rsfuller thanks for answering, I thought about that, thats why in the above example I saved the bounds under:

    private var sceneBounds: CGSize = .zero

in

    public override func viewDidLayoutSubviews() {
        super.viewDidLayoutSubviews()

        sceneBounds = sceneView.bounds.size
    }

and then read the instance var when calling projectionMatrix. Unfortunately that didn't make a difference it still crashed (as you can see in the screenshot of my previous comment).

The next thing I did was moving the code before the face-block, like so:

  public func renderer(_ renderer: SCNSceneRenderer, updateAtTime time: TimeInterval) {
    guard let frame = faceSession?.currentFrame else { return }

    let projectionSIMD = frame.projectionMatrix(
        forViewportSize: sceneBounds,
        presentationOrientation: .portrait,
        mirrored: false,
        zNear: 0.05,
        zFar: 100
    )

    if let face = frame.face {

and at least for the last 13mins it's running crash free. But that isn't really a fix, since it shouldn't matter in which line of your method we call a method, I guess?

rsfuller commented 4 years ago

Yes, I would expect your alteration to not crash either, because you're not dispatching to the main queue. [It is not clear to me why the frame is sporadically not retained in the closure. I would have to dig more into that.]

The Augmented Faces example app previously had the scene camera's transform updated on a callback from the ARCore API, but we switched to a pull model (calling .currentFrame) in the example app for simplicity in 1.16, and now everything is updated in sync.

However, on reading this bug I realized there is no good reason for using the sceneView bounds as it is tied to the view bounds (and hence the cameraImageLayer bounds (see line #87). So we may prefer to simply switch to that and not dispatch to the main queue.

Bersaelor commented 4 years ago

Agreed (not not using the sceneView bounds).

I just let it run for another 30mins, with my changes (had a magazine with a person on the cover sitting in front of the ipad while I had dinner). And it crashed again with a released frame.

It seems that the currentFrame is released before the renderer( method is finished, if I move the projectionMatrix earlier in the method, I still get the crash, just this time on frame.capturedImage:

Screen Shot 2020-04-03 at 19 13 44
rsfuller commented 4 years ago

Ahh, okay. You appear to have found a deeper issue in the SDK. I will keep this open for tracking.

In the meantime, if you'd like something more stable, I would suggest switching to the push model (delegate callback). You can look at previous releases to see how that's done in the sample app.

Thanks for finding this and reporting it so thoroughly!

Bersaelor commented 4 years ago

Thank you for believing me! (since the whole reproduction of the problem always takes a few minutes to crashand other people I worked with would have just said "Oh, it's working for me")

Using the delegate-call works flawlessly, here's the method in case someone else wants to copy-paste:

// MARK: - Face Session delegate

extension FacesViewController : GARAugmentedFaceSessionDelegate {

    public func didUpdate(_ frame: GARAugmentedFaceFrame) {
        if let face = frame.face {
            faceTextureNode.geometry = faceMeshConverter.geometryFromFace(face)
            faceTextureNode.geometry?.firstMaterial = faceTextureMaterial
            faceOccluderNode.geometry = faceTextureNode.geometry?.copy() as? SCNGeometry
            faceOccluderNode.geometry?.firstMaterial = faceOccluderMaterial

            faceNode.simdWorldTransform = face.centerTransform
            updateTransform(face.transform(for: .nose), for: noseTipNode)
            updateTransform(face.transform(for: .foreheadLeft), for: foreheadLeftNode)
            updateTransform(face.transform(for: .foreheadRight), for: foreheadRightNode)
        }

        // Set the scene camera's transform to the projection matrix for this frame.
        sceneCamera.projectionTransform = SCNMatrix4.init(
            frame.projectionMatrix(
                forViewportSize: sceneView.bounds.size,
                presentationOrientation: .portrait,
                mirrored: false,
                zNear: 0.05,
                zFar: 100)
        )

        // Update the camera image layer's transform to the display transform for this frame.
        cameraImageLayer.contents = frame.capturedImage as CVPixelBuffer
        cameraImageLayer.setAffineTransform(
            frame.displayTransform(
                forViewportSize: cameraImageLayer.bounds.size,
                presentationOrientation: .portrait,
                mirrored: true
            )
        )

        // Only show AR content when a face is detected.
        sceneView.scene?.rootNode.isHidden = frame.face == nil
    }

}
yinglieng commented 4 years ago

Bersaelor, can you still reproduce the crash with the latest version v1.19.0?

I just tested the version v1.19.0

Test device: iPhone 6s Plus iOS 13.3.1

Run XCode to install the app on the device. Let the app run with the debugger attached. The face is in the frame. The app ran for 12 min, without crash. Then I stopped the experiment.

It would be appreciated with your new test. Thanks!

Bersaelor commented 4 years ago

Unfortunately it looks like I got the same result:

(I let the demo running while it looks at a picture of a person, so it gets a face at every frame)

(iPhone X, iOS 13.7 Xcode 11.7)

Screen Shot 2020-09-15 at 14 17 57
kapsyst commented 3 years ago

Is there any update on this? I'm experiencing a very similar issue. While I'm working on a more complex application, the general usage pattern is identical to the example app. I get an EXC_BAD_ACCESS error on the render thread, especially for debug builds, and/or after running for some time.

The crash seems to occur when performing more work on the render thread (hence debug builds). As @Bersaelor mentioned, this could indicate AR Frame memory is being released too soon.

Any help appreciated.

Dev environment: iPhone X (iOS 14.2) Xcode Version 12.4 (12D4e) AR Augmented Faces 1.23.0 (occurs in earlier versions too)

kapsyst commented 3 years ago

Also just to confirm, the source code for AR Augmented Faces is not available, correct?

All I can find is: https://dl.google.com/dl/cpdc/f3dd4e97ce621828/ARCore-1.23.0.tar.gz

Which contains precompiled frameworks.

kapsyst commented 3 years ago

Hi @rsfuller, @Bersaelor I just wanted to give you a quick update.

Since my last post I've tried the following:

Here is a screen shot, and the crash log: gar_crash AugmentedFacesExample 2021-04-20 14-32.txt

Dev environment: iPhone 8 (iOS 14.2) Xcode Version 12.4 (12D4e) AR Augmented Faces 1.23.0

It's worth noting that it occurs more frequently in debug builds, and on lower spec devices (iPhone 8 in particular). The location of the EXC_BAD_ACCESS changes when the stack composition is changed too.

At this stage it's fairly safe to say that GAR is the cause of the crash, as far as I can see. Since releasing our application, we've had about 12000 occurrences, so any help or updates would be very much appreciated.

andy-at commented 3 years ago

Would be great to have some priority or acknowledgement of this issue. Our app also crashes in the same conditions detailed by @kapsyst.

JamieHeatherZozoNZ commented 3 years ago

Any updates on this? I'm getting the same problem :(

jrullman commented 3 years ago

A fix for this will be in the 1.25 release of ARCore, anticipated in mid-June.

jrullman commented 3 years ago

Until then, a workaround would be to use the delegate to get frames, instead of using currentFrame.

kapsyst commented 3 years ago

Thanks for the update @jrullman -- very much looking forward to trying out the fix.

Until then, a workaround would be to use the delegate to get frames, instead of using currentFrame.

FYI we did try using the didUpdate function in GARAugmentedFaceSessionDelegate.

We would convert GAR meshes to SceneKit meshes (copying), and save them with video frames and camera matrices in a sync'd ring buffer. They would then get read from the render thread as they became available. In other words, we weren't directly accessing GARFrames from the render thread. However, this still crashed in the same manner as before.

We also tried saving the results of this ring buffer on disk, and "playing" them back without any calls GAR, which worked without crashing.

jrullman commented 3 years ago

My suggestion is simpler: have your own currentFrame property, which is protected by a lock. Set this property in the delegate method and get it where the code is currently using session.currentFrame. Locking is necessary to prevent the issue.

kapsyst commented 3 years ago

Thanks @jrullman, although I'm not quite sure I understand what you mean - could you provide an example?

kapsyst commented 3 years ago

Hi @jrullman, I just saw there was an update for 1.25 -- have yet to test with our application but looking forward to trying it out.

FWIW, here is the relevant code for a fix we attempted using a semaphore for locking. I'm not sure if this is what you had in mind. If not, any guidance would be appreciated.

We tested this version and were still able to recreate the crash in question.

class ViewController: UIViewController {

    fileprivate var updateGARSemaphore = DispatchSemaphore(value: 0)
    fileprivate var lastGARFrame: GARAugmentedFaceFrame?
}

extension ViewController: SCNSceneRendererDelegate {

    public func renderer(_ renderer: SCNSceneRenderer, updateAtTime time: TimeInterval) {

        guard let frame = self.lastGARFrame else {
            self.updateGARSemaphore.signal()
            return
        }

        // Use the frame here.

        self.updateGARSemaphore.signal()
    }
}

extension ViewController: GARAugmentedFaceSessionDelegate {

    public func didUpdate(_ frame: GARAugmentedFaceFrame) {

        // Don't wait more than a frame, in case the render update takes too long.
        let result = self.updateGARSemaphore.wait(timeout: (DispatchTime.now() + Double(1.0/60.0)))
        if (result == .success) {
            self.lastGARFrame = frame
        }
    }
}
cpsauer commented 3 years ago

FWIW, I'm not seeing this crash running the sample app for 1.25 (1.26 broken per #47).

How about you all? Are you still seeing the issue, or no?