facebookarchive / AsyncDisplayKit

Smooth asynchronous user interfaces for iOS apps.
http://asyncdisplaykit.org
Other
13.4k stars 2.2k forks source link

[Core Data] Document AsyncDisplayKit's threading model (needed by Core Data apps to ensure against deadlocks) #1208

Closed smyrgl closed 7 years ago

smyrgl commented 8 years ago

So the latest code is causing a consistent deadlock for me when dealing with sections. There was actually an intermittent deadlock that seems like it was introduced a few weeks ago but now it is 100% reproducible as of the last pull.

To explain better I have a serial queue which processes batch update operations that is shown below. This batch update operation has worked fine for the most part for quite some time and it continues to work with my ASCollectionViews that use only a single section, but when dealing with multiple sections I get a consistent deadlock.

You can see the stack trace below and where the collection update operation factors in but the deadlock seems to be on the getter for isNodeLoaded and the mutex lock that surrounds it.

I'm also including the code for the base view controller which is managing this process. As I said this is the same abstract view controller that is used for both my collection views that use sections and the ones that don't and only the section ones seem to be deadlocking.

Stacktrace

screen shot 2016-02-09 at 12 20 35 pm

Update Operations

final class UpdateAsyncTableCollectionViewOperation: GroupOperation {
    var animated = true

    weak var tableView: ASTableView?
    weak var collectionView: ASCollectionView?

    let attemptUpdateNode: AttemptUpdateNodeBlock?
    var update: TLIndexPathUpdates

    let managedObjectContext: NSManagedObjectContext

    init(update: TLIndexPathUpdates, context: NSManagedObjectContext, attemptUpdateNode: AttemptUpdateNodeBlock? = nil) {
        self.update = update
        self.managedObjectContext = context
        self.attemptUpdateNode = attemptUpdateNode
        super.init(operations: [])
    }

    override func execute() {
        var suboperations = [Operation]()
        DDLogInfo("Update table operation starting")
        let submitUpdateOp = BlockOperation( block: { [weak self] continuation in
            guard let strongSelf = self else { continuation(error: nil); return }
            dispatch_async(dispatch_get_main_queue(), { () -> Void in
                DDLogInfo("Starting submit updates")
                if let tableView = strongSelf.tableView {
                    tableView.beginUpdates()
                    let update = strongSelf.update
                    if update.insertedSectionNames.count > 0 {
                        let indexSet = NSMutableIndexSet()
                        for sectionName in update.insertedSectionNames {
                            let section = update.updatedDataModel!.sectionForSectionName(sectionName)
                            indexSet.addIndex(section)
                        }
                        tableView.insertSections(indexSet, withRowAnimation: .Automatic)
                    }

                    if update.deletedSectionNames.count > 0 {
                        let indexSet = NSMutableIndexSet()
                        for sectionName in update.deletedSectionNames {
                            let section = update.oldDataModel!.sectionForSectionName(sectionName)
                            indexSet.addIndex(section)
                        }
                        tableView.deleteSections(indexSet, withRowAnimation: .Automatic)
                    }

                    if update.movedSectionNames.count > 0 {
                        for sectionName in update.movedSectionNames {
                            let oldSection = update.oldDataModel!.sectionForSectionName(sectionName)
                            let newSection = update.updatedDataModel!.sectionForSectionName(sectionName)
                            tableView.moveSection(oldSection, toSection: newSection)
                        }
                    }

                    if update.insertedItems.count > 0 {
                        var indexPaths = [NSIndexPath]()
                        for item in update.insertedItems {
                            let indexPath = update.updatedDataModel!.indexPathForItem(item)
                            indexPaths.append(indexPath!)
                        }
                        tableView.insertRowsAtIndexPaths(indexPaths, withRowAnimation: .Automatic)
                    }
                    if update.deletedItems.count > 0 {
                        var indexPaths = [NSIndexPath]()
                        for item in update.deletedItems {
                            let indexPath = update.oldDataModel!.indexPathForItem(item)
                            indexPaths.append(indexPath!)
                        }
                        tableView.deleteRowsAtIndexPaths(indexPaths, withRowAnimation: .Automatic)
                    }

                    if update.movedItems.count > 0 {
                        for item in update.movedItems {
                            let oldIndexPath = update.oldDataModel!.indexPathForItem(item)!
                            let newIndexPath = update.updatedDataModel!.indexPathForItem(item)!
                            let oldSectionName = update.oldDataModel!.sectionNameForSection(oldIndexPath.section)
                            let newSectionName = update.updatedDataModel!.sectionNameForSection(newIndexPath.section)
                            let oldSectionDeleted = update.deletedSectionNames.contains(oldSectionName)
                            let newSectionInserted = update.insertedSectionNames.contains(newSectionName)

                            if oldSectionDeleted && newSectionInserted {
                                // No-op
                            } else if oldSectionDeleted {
                                tableView.insertRowsAtIndexPaths([newIndexPath], withRowAnimation: .Automatic)
                            } else if newSectionInserted {
                                tableView.deleteRowsAtIndexPaths([oldIndexPath], withRowAnimation: .Automatic)
                                tableView.insertRowsAtIndexPaths([newIndexPath], withRowAnimation: .Automatic)
                            } else {
                                tableView.moveRowAtIndexPath(oldIndexPath, toIndexPath: newIndexPath)
                            }
                        }
                    }
                    tableView.endUpdatesAnimated(strongSelf.animated, completion: { finished in
                        continuation(error: nil)
                    })
                } else if let collectionView = self?.collectionView {
                    DDLogInfo("Collection View Update:\nSection Inserts: \(strongSelf.update.insertedSectionNames.count)\nSection Deletes: \(strongSelf.update.deletedSectionNames.count)\nSection Moves: \(strongSelf.update.movedSectionNames.count)\nInsertedItems: \(strongSelf.update.insertedItems.count)\nDeleted Items: \(strongSelf.update.deletedItems.count)\nModified Items: \(strongSelf.update.modifiedItems.count)\nMoved Items: \(strongSelf.update.movedItems.count)")
                    collectionView.performBatchAnimated(strongSelf.animated, updates: {
                        let update = strongSelf.update
                        if update.insertedSectionNames.count > 0 {
                            let indexSet = NSMutableIndexSet()
                            for sectionName in update.insertedSectionNames {
                                let section = update.updatedDataModel!.sectionForSectionName(sectionName)
                                indexSet.addIndex(section)
                            }
                            collectionView.insertSections(indexSet)
                        }

                        if update.deletedSectionNames.count > 0 {
                            let indexSet = NSMutableIndexSet()
                            for sectionName in update.deletedSectionNames {
                                let section = update.oldDataModel!.sectionForSectionName(sectionName)
                                indexSet.addIndex(section)
                            }
                            collectionView.deleteSections(indexSet)
                        }

                        if update.movedSectionNames.count > 0 {
                            for sectionName in update.movedSectionNames {
                                let oldSection = update.oldDataModel!.sectionForSectionName(sectionName)
                                let newSection = update.updatedDataModel!.sectionForSectionName(sectionName)
                                collectionView.moveSection(oldSection, toSection: newSection)
                            }
                        }

                        if update.insertedItems.count > 0 {
                            var indexPaths = [NSIndexPath]()
                            for item in update.insertedItems {
                                let indexPath = update.updatedDataModel!.indexPathForItem(item)
                                indexPaths.append(indexPath!)
                            }
                            collectionView.insertItemsAtIndexPaths(indexPaths)
                        }
                        if update.deletedItems.count > 0 {
                            var indexPaths = [NSIndexPath]()
                            for item in update.deletedItems {
                                let indexPath = update.oldDataModel!.indexPathForItem(item)
                                indexPaths.append(indexPath!)
                            }
                            collectionView.deleteItemsAtIndexPaths(indexPaths)
                        }

                        if update.modifiedItems.count > 0 {
                            for item in update.modifiedItems {
                                if let indexPath = update.oldDataModel!.indexPathForItem(item) {
                                    collectionView.nodeForItemAtIndexPath(indexPath).fetchData()
                                }
                            }
                        }

                        if update.movedItems.count > 0 {
                            for item in update.movedItems {
                                let oldIndexPath = update.oldDataModel!.indexPathForItem(item)!
                                let newIndexPath = update.updatedDataModel!.indexPathForItem(item)!
                                let oldSectionName = update.oldDataModel!.sectionNameForSection(oldIndexPath.section)
                                let newSectionName = update.updatedDataModel!.sectionNameForSection(newIndexPath.section)
                                let oldSectionDeleted = update.deletedSectionNames.contains(oldSectionName)
                                let newSectionInserted = update.insertedSectionNames.contains(newSectionName)

                                if oldSectionDeleted && newSectionInserted {
                                    // No-op
                                } else if oldSectionDeleted {
                                    collectionView.insertItemsAtIndexPaths([newIndexPath])
                                } else if newSectionInserted {
                                    collectionView.deleteItemsAtIndexPaths([oldIndexPath])
                                    collectionView.insertItemsAtIndexPaths([newIndexPath])
                                } else {
                                    collectionView.moveItemAtIndexPath(oldIndexPath, toIndexPath: newIndexPath)
                                }
                            }
                        }
                        }, completion: { finished in
                            continuation(error: nil)
                    })
                } else {
                    continuation(error: nil)
                }
            })
        })
        suboperations.append(submitUpdateOp)
        submitUpdateOp.name = "Submit update"
        for (operation, nextOperation) in zip(suboperations, suboperations[1..<suboperations.count]) {
            nextOperation.addDependency(operation)
        }
        for operation in sub operations {
            addOperation(operation)
        }
        super.execute()
    }
}

Base Collection View Controller

let InfiniteScrollItemIdentifier = "InfiniteScrollItemIdentifier"

class AsyncCollectionViewController: ASViewController, ASCollectionDataSource, ASCollectionDelegate, CoreDataSourceProviderDelegate, CellNodeDelegate, BaseFlowLayoutDatasource {

    private let dataSourceGroup = dispatch_group_create()
    var newIndicatorText = "New"
    lazy var infiniteScrollSpinner: GetMoreNode = {
        let spinner = GetMoreNode(placeholderText: nil)
        return spinner
    }()

    let tableUpdateOpQueue: OperationQueue = {
        let queue = OperationQueue()
        queue.maxConcurrentOperationCount = 1
        queue.qualityOfService = .UserInteractive
        return queue
    }()

    let collectionNode: ASCollectionNode
    var focusItemIdentifier: String?
    var collectionView: ASCollectionView { return collectionNode.view }
    private var isInitialLoad = true

    var dataModel: TLIndexPathDataModel { return self.dataSource.model }
    lazy var dataSource: CoreDataSourceProvider = {
        var source = self.buildDataSource()
        source.delegate = self
        source.processChangesAutomatically = false
        return source
    }()
    private var baseFlowLayout: BaseFlowLayout? {
        return collectionView.collectionViewLayout as? BaseFlowLayout
    }

    // MARK: - UIViewController

    init(layout: UICollectionViewLayout) {
        let colNode = ASCollectionNode(collectionViewLayout: layout)
        colNode.autoresizingMask = [.FlexibleHeight, .FlexibleWidth]
        self.collectionNode = colNode
        super.init(node: colNode)
        self.baseFlowLayout?.dataSource = self
    }

    required init?(coder aDecoder: NSCoder) {
        fatalError("init(coder:) has not been implemented")
    }

    override func viewDidLoad() {
        super.viewDidLoad()
        collectionView.asyncDelegate = self
        collectionView.asyncDataSource = self
        collectionView.backgroundColor = UIColor.groupTableViewBackgroundColor()
        collectionView.leadingScreensForBatching = 2.0
        collectionView.contentInset = UIEdgeInsetsMake(5, 0, 5, 0)
        dataSource.fetchData()
        NSNotificationCenter.defaultCenter().addObserver(self, selector: "blocklistUpdated", name: CloudStoreBlockListDidChangeNotification, object: nil)
    }

    override func viewWillAppear(animated: Bool) {
        super.viewWillAppear(animated)
    }

    override func viewWillDisappear(animated: Bool) {
        super.viewWillDisappear(animated)
    }

    override func viewDidAppear(animated: Bool) {
        super.viewDidAppear(animated)
    }

    deinit {
        NSNotificationCenter.defaultCenter().removeObserver(self)
    }

    // MARK: - Subclass methods

    func buildDataSource() -> CoreDataSourceProvider {
        fatalError("buildDataSource() has not been implemented, override in a subclass")
    }

    func collectionViewBatchUpdateComplete() {
        DDLogInfo("Collection view batch update complete")
    }

    // MARK: - ASCollectionViewDataSource

    func collectionView(collectionView: ASCollectionView, constrainedSizeForNodeAtIndexPath indexPath: NSIndexPath) -> ASSizeRange {
        return ASSizeRangeMake(CGSizeMake(view.bounds.width, 1), CGSizeMake(view.bounds.width, 10000))
    }

    func numberOfSectionsInCollectionView(collectionView: UICollectionView) -> Int {
        return dataModel.sections.count
    }

    func collectionView(collectionView: UICollectionView, numberOfItemsInSection section: Int) -> Int {
        return dataModel.numberOfRowsInSection(section)
    }

    func collectionView(collectionView: ASCollectionView, nodeForItemAtIndexPath indexPath: NSIndexPath) -> ASCellNode {
        return ASCellNode()
    }

    // MARK: - ASCollectionViewDelegate

    func shouldBatchFetchForCollectionView(collectionView: ASCollectionView) -> Bool {
        return true
    }

    func collectionViewLockDataSource(collectionView: ASCollectionView) {
        DDLogDebug("Locking data source")
        MustBeMainThread()
        dispatch_group_enter(self.dataSourceGroup)
    }

    func collectionViewUnlockDataSource(collectionView: ASCollectionView) {
        DDLogDebug("Unlocking data source")
        MustBeMainThread()
        dispatch_group_leave(self.dataSourceGroup)
    }

    func collectionView(collectionView: UICollectionView, didSelectItemAtIndexPath indexPath: NSIndexPath) {
        // Override in subclasses
    }

    func scrollViewDidEndDecelerating(scrollView: UIScrollView) {
        let visiblePaths = collectionView.indexPathsForVisibleItems()
        for indexPath in visiblePaths {
            if let item = dataModel.itemAtIndexPath(indexPath) as? ActivitySet {
                if item.seen?.boolValue == false {
                    let node = collectionView.nodeForItemAtIndexPath(indexPath)
                    if CGRectContainsRect(view.bounds, node.frame) {
                        item.seen = true
                    }
                }
            }
        }
    }

    func scrollViewWillBeginDragging(scrollView: UIScrollView) {
        focusItemIdentifier = nil
    }

    // MARK: - Loading

    func startInfiniteScrolling() {
        RunOnMainThread { [weak self] in
            guard let strongSelf = self else { return }
            strongSelf.infiniteScrollSpinner.startLoading()
        }
    }

    func endInfiniteScrolling() {
        RunOnMainThread { [weak self] in
            guard let strongSelf = self else { return }
            strongSelf.infiniteScrollSpinner.stopLoading()
        }
    }

    // MARK: - CoreDataSourceProviderDelegate

    func dataSourceWillUpdate(datasource: CoreDataSourceProvider, oldModel: TLIndexPathDataModel, newModel: TLIndexPathDataModel) -> TLIndexPathDataModel {
        defer {
            dispatch_group_notify(self.dataSourceGroup, dispatch_get_main_queue()) { () -> Void in
                if let baseFlowLayout = self.baseFlowLayout {
                    if let focusItemIdentifier = self.focusItemIdentifier {
                        if let item = self.dataModel.itemForIdentifier(focusItemIdentifier) {
                            if let indexPath = self.dataModel.indexPathForIdentifier(focusItemIdentifier) {
                                baseFlowLayout.targetItem = item
                            }
                        }
                    } else if let focusIndexPath = self.collectionView.indexPathsForVisibleItems().sort({ $0.compare($1) == .OrderedAscending }).first {
                        baseFlowLayout.targetItem = self.dataModel.itemAtIndexPath(focusIndexPath)
                        if let attributes = baseFlowLayout.layoutAttributesForItemAtIndexPath(focusIndexPath) {
                            baseFlowLayout.targetYOffset = self.collectionView.contentOffset.y - attributes.frame.origin.y
                        }

                    }
                }
                datasource.processChanges()
            }
        }
        if let newModel = newModel as? TLTreeDataModel {
            var items: [AnyObject] = newModel.treeItems
            items.append(TLIndexPathTreeItem(identifier: InfiniteScrollItemIdentifier, sectionName: nil, cellIdentifier: InfiniteScrollItemIdentifier, data: nil, andChildItems: []))
            return TLTreeDataModel(treeItems: items, collapsedNodeIdentifiers: newModel.collapsedNodeIdentifiers)
        }
        guard !isInitialLoad else {
            if newModel.items.count == 0 {
                return newModel
            } else if newModel.items.count <= 5 {
                return newModel
            } else {
                let upToIndex = newModel.items.count <= 5 ? newModel.items.count - 1 : 4
                if let newModel = newModel as? TLTreeDataModel {
                    let treeItems = Array(newModel.treeItems[0..<upToIndex])
                    return TLTreeDataModel(treeItems: treeItems, collapsedNodeIdentifiers: newModel.collapsedNodeIdentifiers)
                } else {
                    return TLIndexPathDataModel(items: Array(newModel.items[0..<upToIndex]))
                }
            }
        }
        var items: [AnyObject] = newModel.items
        items.append(TLIndexPathItem(identifier: InfiniteScrollItemIdentifier, sectionName: nil, cellIdentifier: InfiniteScrollItemIdentifier, data: nil))
        return TLIndexPathDataModel(items: items)
    }

    func dataSourceDidUpdate(datasource: CoreDataSourceProvider, updates: TLIndexPathUpdates) {
        DDLogInfo("Datasource model updated")
        dispatch_group_enter(dataSourceGroup)
        (collectionView.collectionViewLayout as? BaseFlowLayout)?.autoAdjustContentOffset = !isInitialLoad
        if isViewLoaded() && view.window != nil && !isInitialLoad {
            let op = UpdateAsyncTableCollectionViewOperation(update: updates, context: NSManagedObjectContext.mainContext)
            op.collectionView = self.collectionView
            op.completionBlock = {
                DDLogInfo("Batch updates Complete")
                dispatch_group_leave(self.dataSourceGroup)
                RunOnMainThread { [weak self] in
                    guard let strongSelf = self else { return }
                    strongSelf.collectionViewBatchUpdateComplete()
                }
            }
            tableUpdateOpQueue.addOperation(op)
        } else {
            guard updates.hasChanges else { dispatch_group_leave(dataSourceGroup); return }
            collectionView.reloadDataWithCompletion({ () -> Void in
                let oldInitialLoad = self.isInitialLoad
                if updates.updatedDataModel?.items.isEmpty == false {
                    self.isInitialLoad = false
                }
                dispatch_group_leave(self.dataSourceGroup)
                if oldInitialLoad != self.isInitialLoad {
                    self.dataSource.fetchData()
                }
            })
        }
    }

    // MARK: - ASCellNodeLayoutDelegate

    func nestingLevelsForNode(node: ASCellNode, completion: (previous: Int?, next: Int?) -> ()) {
        var previous: Int?
        var next: Int?
        MainContext().performBlockAndWait { [weak self] () -> Void in
            guard let strongSelf = self else {
                completion(previous: nil, next: nil)
                return
            }
            var previousItem: TLIndexPathTreeItem?
            var nextItem: TLIndexPathTreeItem?
            let indexPath = strongSelf.collectionView.indexPathForNode(node)
            if indexPath.row > 0 {
                previousItem = strongSelf.dataModel.itemAtIndexPath(NSIndexPath(forRow: indexPath.row - 1, inSection: indexPath.section)) as? TLIndexPathTreeItem
            }
            if strongSelf.dataModel.numberOfRowsInSection(indexPath.section) > indexPath.row - 1 {
                nextItem = strongSelf.dataModel.itemAtIndexPath(NSIndexPath(forRow: indexPath.row + 1, inSection: indexPath.section)) as? TLIndexPathTreeItem
            }
            previous = (previousItem?.data as? Post)?.nestCount
            next = (nextItem?.data as? Post)?.nestCount
        }
        completion(previous: previous, next: next)
    }

    func cellDidClickURL(url: NSURL) {
        if DeepLinkRouter.canHandleURL(url) {
            DeepLinkRouter.handleURL(url, handlingViewController: navigationController)
        } else {
            presentBrowser(url, thread: nil)
        }
    }

    func quoteNodeWasTapped(quoteNode: QuoteNode) {
        if let thread = quoteNode.quotePost?.thread {
            navigationController?.showDiscussion(thread, animateToPost: quoteNode.quotePost)
        }
    }

    func quoteNodeDidChangeState(quoteNode: QuoteNode, newState: QuoteNodeState) {

    }

    func quoteNodeShouldAllowExpansion(quoteNode: QuoteNode) -> Bool {
        return false
    }

    func quoteNodeWillChangeState(quoteNode: QuoteNode, newState: QuoteNodeState) {

    }

    // MARK: - BaseFlowLayoutDatasource

    func baseLayoutIndexPathForItem(item: AnyObject) -> NSIndexPath? {
        return dataModel.indexPathForItem(item)
    }

    // MARK: - Notifications

    func blocklistUpdated() {
        DDLogInfo("Blocklist updated")
    }

}

class NetworkCollectionViewController: AsyncCollectionViewController {
    let bounceView: UIView = {
        let bounceWidth = UIScreen.mainScreen().applicationFrame.width
        let view = UIView(frame: CGRectMake(0, -300, bounceWidth, 300))
        view.autoresizingMask = [.FlexibleWidth]
        view.backgroundColor = UIColor.groupTableViewBackgroundColor()
        return view
    }()
    private var refreshFetchOp: Operation?
    private var moreDataFetchOp: Operation?

    // MARK: - UIViewController 

    override func viewDidLoad() {
        super.viewDidLoad()
        collectionView.addSubview(bounceView)
        collectionView.addPullToRefresh { () -> Void in
            self.fetchLatestData({ () -> () in
                self.collectionView.pullToRefreshView?.stopAnimating()
            })
        }
    }

    override func viewWillAppear(animated: Bool) {
        super.viewWillAppear(animated)
        NSNotificationCenter.defaultCenter().addObserver(self, selector: "appDidBecomeActive", name: UIApplicationDidBecomeActiveNotification, object: nil)
        guard UIApplication.sharedApplication().applicationState == .Active else { return }
        fetchLatestData()
    }

    override func viewWillDisappear(animated: Bool) {
        super.viewWillDisappear(animated)
        refreshFetchOp?.cancel()
        moreDataFetchOp?.cancel()
        NSNotificationCenter.defaultCenter().removeObserver(self)
    }

    deinit {
        NSNotificationCenter.defaultCenter().removeObserver(self)
    }

    // MARK: - Data fetching

    func refreshFetchOperation() -> ResourceSyncOperation? {
        fatalError("refreshFetchOperation() has not been implemented, override in a subclass")
    }

    func moreDataFetchOperation() -> ResourceSyncOperation? {
        fatalError("moreDataFetchOperation() has not been implemented, override in a subclass")
    }

    func fetchLatestData(completion: AsyncTableFetchCompletionBlock? = nil) {
        guard refreshFetchOp == nil else { return }
        guard let syncOp = refreshFetchOperation() else { return }
        refreshFetchOp = syncOp
        SyncManager.manager.addSyncOperation(syncOp) { [weak self] (success, error) -> () in
            guard let strongSelf = self else { return }
            strongSelf.dataSource.fetchData()
            completion?()
        }
    }

    func fetchMoreData(completion: AsyncTableFetchCompletionBlock? = nil) {
        guard moreDataFetchOp == nil else { return }
        guard let syncOp = moreDataFetchOperation() else { return }
        startInfiniteScrolling()
        moreDataFetchOp = syncOp
        SyncManager.manager.addSyncOperation(syncOp) { [weak self] (success, error) -> () in
            guard let strongSelf = self else { return }
            strongSelf.endInfiniteScrolling()
            strongSelf.dataSource.fetchData()
            completion?()
        }
    }

    // MARK: - Notifications

    func appDidBecomeActive() {
        fetchLatestData()
    }
}
appleguy commented 8 years ago

@smyrgl @binl @nguyenhuy is this addressed by https://github.com/facebook/AsyncDisplayKit/pull/1207 ?

smyrgl commented 8 years ago

@appleguy I just tried manually using that change and there is no change to this behavior.

appleguy commented 8 years ago

@smyrgl thank you for confirming that, unfortunately I was in a rush when I last commented and did not realize the nature of this issue. Since it is related to Display node locking, indeed I doubt that change will help. Thanks for all the detail you included here, as it should allow me to fix this in the next day or two.

appleguy commented 8 years ago

@smyrgl just realized there doesn't seem to be a full, all thread backtrace included. Can you upload a text file of the output from "bt all"? Thanks!

appleguy commented 8 years ago

@smyrgl one more thing that I can think of the moment. What revision were you on previously, and what revision did you update to when this became fully reproducible? Likewise, do you remember or have the ability to check the revisions involved when you first saw it occur?

Feel free to email me details at asyncdisplaykit@gmail.com / send me your iMessage so we can coordinate faster, especially tomorrow as I will prioritize investigating this in the middle part of the day or the evening. I may already have yours, but don't remember for sure...

appleguy commented 8 years ago

@Adlai-Holler -- to be honest, the initial signs indicate that the best fix for this might be illuminating thread affinity. Thread affinity is the only reason why there is a check for whether or not the node is loaded in the data controller layout pass, and it is definitely suboptimal.

@levi ultimately this also relates to your work, in that we will want the notion of the "pending layout" that we discussed today, in order to gracefully support asynchronous measurement for nodes that have already been loaded and even are currently onscreen.

@rahul-malik I think the modifications we made it in you're awesome diff to add support for node blocks caused the recent change in behavior, but don't worry; that change is overall much more important for the framework, and in the amazingly fast progress the community is making towards 2.0, I feel we should fix forward with the equally significant patches on their way in from Levi and Adlai.

appleguy commented 8 years ago

@smyrgl I just landed the change that I think will fix your issue. Please test it out and let me know if that is the case, but even if so, I am very interested in the full backtrace and any other thoughts or discoveries you have about this issue.

I haven't exhaustively reviewed your code, but I want to understand the specific scenario of usage on the thread besides main that led to this deadlock over the same node instance. We have some pretty extensive usage of the framework at Pinterest, in at least 20 quite complex views, and we also do things like diffing model object responses to break into UIKit edit operations.

However, clearly we may not quite be triggering something that otherwise could very easily be hit, and indeed may not have quite as sophisticated and architecture in this area as your app does. So especially before launching the recent changes that likely introduced this, I want to make sure the fix is not merely plausible, but evaluate what additional changes are necessary to ensure this is almost impossible for third-party code to trigger.

smyrgl commented 8 years ago

@appleguy On the info you wanted, here is the full backtrace.

warning: could not load any Objective-C class information. This will significantly reduce the quality of type information available.
* thread #1: tid = 0x5b825d, 0x000000010f2b1ee2 libsystem_kernel.dylib`__psynch_mutexwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x000000010f2b1ee2 libsystem_kernel.dylib`__psynch_mutexwait + 10
    frame #1: 0x000000010f279a49 libsystem_pthread.dylib`_pthread_mutex_lock_wait + 89
    frame #2: 0x000000010f279c17 libsystem_pthread.dylib`_pthread_mutex_lock_slow + 300
    frame #3: 0x00000001093c0a25 AsyncDisplayKit`ASDN::Mutex::lock(this=0x00007f93e45f4d98) + 37 at ASThread.h:124
    frame #4: 0x00000001093c09f3 AsyncDisplayKit`ASDN::Locker<ASDN::Mutex>::Locker(this=0x00007fff58117168, l=0x00007f93e45f4d98) + 35 at ASThread.h:69
    frame #5: 0x00000001093bcfdd AsyncDisplayKit`ASDN::Locker<ASDN::Mutex>::Locker(this=0x00007fff58117168, l=0x00007f93e45f4d98) + 29 at ASThread.h:68
    frame #6: 0x0000000109438daa AsyncDisplayKit`-[ASDisplayNode isNodeLoaded](self=0x00007f93e45f4d30, _cmd="isNodeLoaded") + 42 at ASDisplayNode.mm:580
    frame #7: 0x0000000109407010 AsyncDisplayKit`__58-[ASDataController layoutLoadedNodes:ofKind:atIndexPaths:]_block_invoke(.block_descriptor=0x00007fff581173b0, indexPath=0xc000000000200016, idx=0, stop=NO) + 192 at ASDataController.mm:131
    frame #8: 0x000000010de8570d CoreFoundation`__53-[__NSArrayI enumerateObjectsWithOptions:usingBlock:]_block_invoke + 77
    frame #9: 0x000000010de855b6 CoreFoundation`-[__NSArrayI enumerateObjectsWithOptions:usingBlock:] + 166
    frame #10: 0x0000000109406e50 AsyncDisplayKit`-[ASDataController layoutLoadedNodes:ofKind:atIndexPaths:](self=0x00007f93e409ebc0, _cmd="layoutLoadedNodes:ofKind:atIndexPaths:", nodes=0x00007f93e47616e0, kind=0x00000001095220f0, indexPaths=0x00007f93e4685760) + 736 at ASDataController.mm:129
    frame #11: 0x0000000109408c16 AsyncDisplayKit`__64-[ASDataController _layoutNodes:ofKind:atIndexPaths:completion:]_block_invoke102(.block_descriptor=<unavailable>) + 182 at ASDataController.mm:195
    frame #12: 0x0000000109476446 AsyncDisplayKit`__30-[ASMainSerialQueue runBlocks]_block_invoke(.block_descriptor=<unavailable>) + 310 at ASMainSerialQueue.mm:54
    frame #13: 0x000000010947656d AsyncDisplayKit`__30-[ASMainSerialQueue runBlocks]_block_invoke16(.block_descriptor=<unavailable>) + 29 at ASMainSerialQueue.mm:62
    frame #14: 0x000000010ef1de5d libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #15: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #16: 0x000000010ef262af libdispatch.dylib`_dispatch_main_queue_callback_4CF + 1738
    frame #17: 0x000000010dea3d09 CoreFoundation`__CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 9
    frame #18: 0x000000010de652c9 CoreFoundation`__CFRunLoopRun + 2073
    frame #19: 0x000000010de64828 CoreFoundation`CFRunLoopRunSpecific + 488
    frame #20: 0x0000000111293ad2 GraphicsServices`GSEventRunModal + 161
    frame #21: 0x000000010bbc5610 UIKit`UIApplicationMain + 171
    frame #22: 0x0000000107fa4a6d Disqus`main + 1053 at main.swift:17
    frame #23: 0x000000010ef7292d libdyld.dylib`start + 1

  thread #2: tid = 0x5b8282, 0x000000010f2b2fde libsystem_kernel.dylib`kevent64 + 10, queue = 'com.apple.libdispatch-manager'
    frame #0: 0x000000010f2b2fde libsystem_kernel.dylib`kevent64 + 10
    frame #1: 0x000000010ef2d4c8 libdispatch.dylib`_dispatch_mgr_invoke + 260
    frame #2: 0x000000010ef2d262 libdispatch.dylib`_dispatch_mgr_thread + 54

  thread #3: tid = 0x5b8283, 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10, queue = 'com.apple.root.default-qos'
    frame #0: 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010ef29b1a libdispatch.dylib`_dispatch_thread_semaphore_wait + 16
    frame #2: 0x000000010ef2296c libdispatch.dylib`_dispatch_barrier_sync_f_slow + 830
    frame #3: 0x0000000109bd978c CoreData`-[NSManagedObjectContext performBlockAndWait:] + 252
    frame #4: 0x0000000107e4edab Disqus`Disqus.AsyncCollectionViewController.nestingLevelsForNode (node=0x00007f93e70438b0, completion=(Disqus`partial apply forwarder for Disqus.DiscussionPostNode.(fetchData (Disqus.DiscussionPostNode) -> () -> ()).(closure #1) at DiscussionPostNode.swift), self=0x00007f93e5837200)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () + 747 at AsyncCollectionViewController.swift:273
    frame #5: 0x0000000107e5122b Disqus`protocol witness for Disqus.DiscussionPostNodeDelegate.nestingLevelsForNode <A where A: Disqus.DiscussionPostNodeDelegate> (A)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () in conformance Disqus.AsyncCollectionViewController : Disqus.DiscussionPostNodeDelegate in Disqus + 91 at AsyncCollectionViewController.swift:254
    frame #6: 0x000000010806e94d Disqus`Disqus.DiscussionPostNode.fetchData (self=0x00007f93e7043bc0)() -> () + 6509 at DiscussionPostNode.swift:210
    frame #7: 0x000000010806eb42 Disqus`@objc Disqus.DiscussionPostNode.fetchData (Disqus.DiscussionPostNode)() -> () + 34 at DiscussionPostNode.swift:0
    frame #8: 0x000000010944b480 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e7043bc0, _cmd="recursivelyFetchData") + 576 at ASDisplayNode.mm:1826
    frame #9: 0x000000010944b3c7 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e70438b0, _cmd="recursivelyFetchData") + 391 at ASDisplayNode.mm:1824
    frame #10: 0x0000000108092df5 Disqus`Disqus.CellNode.layoutSpecThatFits (constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000)), self=0x00007f93e70438b0)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 117 at CellNode.swift:114
    frame #11: 0x000000010809315f Disqus`@objc Disqus.CellNode.layoutSpecThatFits (Disqus.CellNode)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 95 at CellNode.swift:0
    frame #12: 0x0000000109448daa AsyncDisplayKit`-[ASDisplayNode calculateLayoutThatFits:](self=0x00007f93e70438b0, _cmd="calculateLayoutThatFits:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 586 at ASDisplayNode.mm:1674
    frame #13: 0x0000000109439c64 AsyncDisplayKit`-[ASDisplayNode measureWithSizeRange:](self=0x00007f93e70438b0, _cmd="measureWithSizeRange:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 916 at ASDisplayNode.mm:647
    frame #14: 0x000000010940731e AsyncDisplayKit`-[ASDataController _layoutNode:withConstrainedSize:](self=0x00007f93e409ebc0, _cmd="_layoutNode:withConstrainedSize:", node=0x00007f93e70438b0, constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 142 at ASDataController.mm:143
    frame #15: 0x0000000109408e9c AsyncDisplayKit`__64-[ASDataController _layoutNodes:ofKind:atIndexPaths:completion:]_block_invoke108(.block_descriptor=<unavailable>) + 252 at ASDataController.mm:205
    frame #16: 0x000000010ef1de5d libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #17: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #18: 0x000000010ef26bef libdispatch.dylib`_dispatch_root_queue_drain + 1829
    frame #19: 0x000000010ef264c5 libdispatch.dylib`_dispatch_worker_thread3 + 111
    frame #20: 0x000000010f27668f libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #21: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #4: tid = 0x5b8284, 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10, queue = 'NSOperationQueue 0x7f93e2751ea0 :: NSOperation 0x7f93e27988f0 (QOS: UTILITY)'
    frame #0: 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010ef29b1a libdispatch.dylib`_dispatch_thread_semaphore_wait + 16
    frame #2: 0x000000010ef2296c libdispatch.dylib`_dispatch_barrier_sync_f_slow + 830
    frame #3: 0x000000010b7d4eaf SDWebImage`__69-[SDWebImageManager downloadImageWithURL:options:progress:completed:]_block_invoke100(.block_descriptor=0x00007f93e4535ea0, downloadedImage=0x00007f93e473afe0, data=0x00007f93e2788bd0, error=0x0000000000000000, finished=YES) + 3487 at SDWebImageManager.m:241
    frame #4: 0x000000010b7caf54 SDWebImage`__72-[SDWebImageDownloader downloadImageWithURL:options:progress:completed:]_block_invoke93(.block_descriptor=0x00007f93e2781a20, image=0x00007f93e473afe0, data=0x00007f93e2788bd0, error=0x0000000000000000, finished=YES) + 1044 at SDWebImageDownloader.m:163
    frame #5: 0x000000010b7cfc02 SDWebImage`-[SDWebImageDownloaderOperation connectionDidFinishLoading:](self=0x00007f93e27988f0, _cmd="connectionDidFinishLoading:", aConnection=0x00007f93e4254ea0) + 1794 at SDWebImageDownloaderOperation.m:398
    frame #6: 0x0000000109816a88 CFNetwork`__65-[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:]_block_invoke + 69
    frame #7: 0x0000000109816a2c CFNetwork`-[NSURLConnectionInternal _withConnectionAndDelegate:onlyActive:] + 199
    frame #8: 0x0000000109816b81 CFNetwork`-[NSURLConnectionInternal _withActiveConnectionAndDelegate:] + 48
    frame #9: 0x0000000109684fbe CFNetwork`___ZN27URLConnectionClient_Classic26_delegate_didFinishLoadingEU13block_pointerFvvE_block_invoke + 104
    frame #10: 0x0000000109772965 CFNetwork`___ZN27URLConnectionClient_Classic18_withDelegateAsyncEPKcU13block_pointerFvP16_CFURLConnectionPK33CFURLConnectionClientCurrent_VMaxE_block_invoke_2 + 100
    frame #11: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #12: 0x000000010ef2054b libdispatch.dylib`_dispatch_block_invoke + 716
    frame #13: 0x00000001096711ac CFNetwork`RunloopBlockContext::_invoke_block(void const*, void*) + 24
    frame #14: 0x000000010de42ee4 CoreFoundation`CFArrayApplyFunction + 68
    frame #15: 0x00000001096710a5 CFNetwork`RunloopBlockContext::perform() + 137
    frame #16: 0x0000000109670f5e CFNetwork`MultiplexerSource::perform() + 282
    frame #17: 0x0000000109670d80 CFNetwork`MultiplexerSource::_perform(void*) + 72
    frame #18: 0x000000010de6fa31 CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ + 17
    frame #19: 0x000000010de6595c CoreFoundation`__CFRunLoopDoSources0 + 556
    frame #20: 0x000000010de64e13 CoreFoundation`__CFRunLoopRun + 867
    frame #21: 0x000000010de64828 CoreFoundation`CFRunLoopRunSpecific + 488
    frame #22: 0x000000010df17f11 CoreFoundation`CFRunLoopRun + 97
    frame #23: 0x000000010b7ccfec SDWebImage`-[SDWebImageDownloaderOperation start](self=0x00007f93e27988f0, _cmd="start") + 1868 at SDWebImageDownloaderOperation.m:117
    frame #24: 0x000000010a861b9b Foundation`__NSOQSchedule_f + 194
    frame #25: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #26: 0x000000010ef248ec libdispatch.dylib`_dispatch_queue_drain + 2215
    frame #27: 0x000000010ef23e0d libdispatch.dylib`_dispatch_queue_invoke + 601
    frame #28: 0x000000010ef26a56 libdispatch.dylib`_dispatch_root_queue_drain + 1420
    frame #29: 0x000000010ef264c5 libdispatch.dylib`_dispatch_worker_thread3 + 111
    frame #30: 0x000000010f27668f libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #31: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #6: tid = 0x5b8289, 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'WebThread'
    frame #0: 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x000000010f2ab7c7 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x000000010de65b64 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x000000010de64fbf CoreFoundation`__CFRunLoopRun + 1295
    frame #4: 0x000000010de64828 CoreFoundation`CFRunLoopRunSpecific + 488
    frame #5: 0x000000011288ff65 WebCore`RunWebThread(void*) + 469
    frame #6: 0x000000010f276c13 libsystem_pthread.dylib`_pthread_body + 131
    frame #7: 0x000000010f276b90 libsystem_pthread.dylib`_pthread_start + 168
    frame #8: 0x000000010f274375 libsystem_pthread.dylib`thread_start + 13

  thread #7: tid = 0x5b828b, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #8: tid = 0x5b828c, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #10: tid = 0x5b8297, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #12: tid = 0x5b8299, 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'AVAudioSession Notify Thread'
    frame #0: 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x000000010f2ab7c7 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x000000010de65b64 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x000000010de64fbf CoreFoundation`__CFRunLoopRun + 1295
    frame #4: 0x000000010de64828 CoreFoundation`CFRunLoopRunSpecific + 488
    frame #5: 0x0000000115d7c5e7 libAVFAudio.dylib`GenericRunLoopThread::Entry(void*) + 189
    frame #6: 0x0000000115d52034 libAVFAudio.dylib`CAPThread::Entry(CAPThread*) + 80
    frame #7: 0x000000010f276c13 libsystem_pthread.dylib`_pthread_body + 131
    frame #8: 0x000000010f276b90 libsystem_pthread.dylib`_pthread_start + 168
    frame #9: 0x000000010f274375 libsystem_pthread.dylib`thread_start + 13

  thread #13: tid = 0x5b829a, 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.NSURLConnectionLoader'
    frame #0: 0x000000010f2ac386 libsystem_kernel.dylib`mach_msg_trap + 10
    frame #1: 0x000000010f2ab7c7 libsystem_kernel.dylib`mach_msg + 55
    frame #2: 0x000000010de65b64 CoreFoundation`__CFRunLoopServiceMachPort + 212
    frame #3: 0x000000010de64fbf CoreFoundation`__CFRunLoopRun + 1295
    frame #4: 0x000000010de64828 CoreFoundation`CFRunLoopRunSpecific + 488
    frame #5: 0x00000001097023c4 CFNetwork`+[NSURLConnection(Loader) _resourceLoadLoop:] + 412
    frame #6: 0x000000010a958dfb Foundation`__NSThread__start__ + 1198
    frame #7: 0x000000010f276c13 libsystem_pthread.dylib`_pthread_body + 131
    frame #8: 0x000000010f276b90 libsystem_pthread.dylib`_pthread_start + 168
    frame #9: 0x000000010f274375 libsystem_pthread.dylib`thread_start + 13

  thread #14: tid = 0x5b829c, 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10, queue = 'com.apple.root.default-qos'
    frame #0: 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010ef29b1a libdispatch.dylib`_dispatch_thread_semaphore_wait + 16
    frame #2: 0x000000010ef2296c libdispatch.dylib`_dispatch_barrier_sync_f_slow + 830
    frame #3: 0x0000000109bd978c CoreData`-[NSManagedObjectContext performBlockAndWait:] + 252
    frame #4: 0x0000000107e4edab Disqus`Disqus.AsyncCollectionViewController.nestingLevelsForNode (node=0x00007f93e45f4d30, completion=(Disqus`partial apply forwarder for Disqus.DiscussionPostNode.(fetchData (Disqus.DiscussionPostNode) -> () -> ()).(closure #1) at DiscussionPostNode.swift), self=0x00007f93e5837200)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () + 747 at AsyncCollectionViewController.swift:273
    frame #5: 0x0000000107e5122b Disqus`protocol witness for Disqus.DiscussionPostNodeDelegate.nestingLevelsForNode <A where A: Disqus.DiscussionPostNodeDelegate> (A)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () in conformance Disqus.AsyncCollectionViewController : Disqus.DiscussionPostNodeDelegate in Disqus + 91 at AsyncCollectionViewController.swift:254
    frame #6: 0x000000010806e94d Disqus`Disqus.DiscussionPostNode.fetchData (self=0x00007f93e45f5950)() -> () + 6509 at DiscussionPostNode.swift:210
    frame #7: 0x000000010806eb42 Disqus`@objc Disqus.DiscussionPostNode.fetchData (Disqus.DiscussionPostNode)() -> () + 34 at DiscussionPostNode.swift:0
    frame #8: 0x000000010944b480 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e45f5950, _cmd="recursivelyFetchData") + 576 at ASDisplayNode.mm:1826
    frame #9: 0x000000010944b3c7 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e45f4d30, _cmd="recursivelyFetchData") + 391 at ASDisplayNode.mm:1824
    frame #10: 0x0000000108092df5 Disqus`Disqus.CellNode.layoutSpecThatFits (constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000)), self=0x00007f93e45f4d30)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 117 at CellNode.swift:114
    frame #11: 0x000000010809315f Disqus`@objc Disqus.CellNode.layoutSpecThatFits (Disqus.CellNode)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 95 at CellNode.swift:0
    frame #12: 0x0000000109448daa AsyncDisplayKit`-[ASDisplayNode calculateLayoutThatFits:](self=0x00007f93e45f4d30, _cmd="calculateLayoutThatFits:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 586 at ASDisplayNode.mm:1674
    frame #13: 0x0000000109439c64 AsyncDisplayKit`-[ASDisplayNode measureWithSizeRange:](self=0x00007f93e45f4d30, _cmd="measureWithSizeRange:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 916 at ASDisplayNode.mm:647
    frame #14: 0x000000010940731e AsyncDisplayKit`-[ASDataController _layoutNode:withConstrainedSize:](self=0x00007f93e409ebc0, _cmd="_layoutNode:withConstrainedSize:", node=0x00007f93e45f4d30, constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 142 at ASDataController.mm:143
    frame #15: 0x0000000109408e9c AsyncDisplayKit`__64-[ASDataController _layoutNodes:ofKind:atIndexPaths:completion:]_block_invoke108(.block_descriptor=<unavailable>) + 252 at ASDataController.mm:205
    frame #16: 0x000000010ef1de5d libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #17: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #18: 0x000000010ef26bef libdispatch.dylib`_dispatch_root_queue_drain + 1829
    frame #19: 0x000000010ef264c5 libdispatch.dylib`_dispatch_worker_thread3 + 111
    frame #20: 0x000000010f27668f libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #21: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #11: tid = 0x5b829e, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #16: tid = 0x5b829f, 0x000000010f2b2176 libsystem_kernel.dylib`__select + 10, name = 'com.apple.CFSocket.private'
    frame #0: 0x000000010f2b2176 libsystem_kernel.dylib`__select + 10
    frame #1: 0x000000010deab1fa CoreFoundation`__CFSocketManager + 746
    frame #2: 0x000000010f276c13 libsystem_pthread.dylib`_pthread_body + 131
    frame #3: 0x000000010f276b90 libsystem_pthread.dylib`_pthread_start + 168
    frame #4: 0x000000010f274375 libsystem_pthread.dylib`thread_start + 13

  thread #17: tid = 0x5b82a0, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #18: tid = 0x5b82a1, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #20: tid = 0x5b82a2, 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10, queue = 'com.apple.root.default-qos'
    frame #0: 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010ef29b1a libdispatch.dylib`_dispatch_thread_semaphore_wait + 16
    frame #2: 0x000000010ef2296c libdispatch.dylib`_dispatch_barrier_sync_f_slow + 830
    frame #3: 0x0000000109bd978c CoreData`-[NSManagedObjectContext performBlockAndWait:] + 252
    frame #4: 0x0000000107e4edab Disqus`Disqus.AsyncCollectionViewController.nestingLevelsForNode (node=0x00007f93e46749d0, completion=(Disqus`partial apply forwarder for Disqus.DiscussionPostNode.(fetchData (Disqus.DiscussionPostNode) -> () -> ()).(closure #1) at DiscussionPostNode.swift), self=0x00007f93e5837200)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () + 747 at AsyncCollectionViewController.swift:273
    frame #5: 0x0000000107e5122b Disqus`protocol witness for Disqus.DiscussionPostNodeDelegate.nestingLevelsForNode <A where A: Disqus.DiscussionPostNodeDelegate> (A)(__ObjC.ASCellNode, completion : (previous : Swift.Optional<Swift.Int>, next : Swift.Optional<Swift.Int>) -> ()) -> () in conformance Disqus.AsyncCollectionViewController : Disqus.DiscussionPostNodeDelegate in Disqus + 91 at AsyncCollectionViewController.swift:254
    frame #6: 0x000000010806e94d Disqus`Disqus.DiscussionPostNode.fetchData (self=0x00007f93e4674ce0)() -> () + 6509 at DiscussionPostNode.swift:210
    frame #7: 0x000000010806eb42 Disqus`@objc Disqus.DiscussionPostNode.fetchData (Disqus.DiscussionPostNode)() -> () + 34 at DiscussionPostNode.swift:0
    frame #8: 0x000000010944b480 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e4674ce0, _cmd="recursivelyFetchData") + 576 at ASDisplayNode.mm:1826
    frame #9: 0x000000010944b3c7 AsyncDisplayKit`-[ASDisplayNode recursivelyFetchData](self=0x00007f93e46749d0, _cmd="recursivelyFetchData") + 391 at ASDisplayNode.mm:1824
    frame #10: 0x0000000108092df5 Disqus`Disqus.CellNode.layoutSpecThatFits (constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000)), self=0x00007f93e46749d0)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 117 at CellNode.swift:114
    frame #11: 0x000000010809315f Disqus`@objc Disqus.CellNode.layoutSpecThatFits (Disqus.CellNode)(__C.ASSizeRange) -> __ObjC.ASLayoutSpec + 95 at CellNode.swift:0
    frame #12: 0x0000000109448daa AsyncDisplayKit`-[ASDisplayNode calculateLayoutThatFits:](self=0x00007f93e46749d0, _cmd="calculateLayoutThatFits:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 586 at ASDisplayNode.mm:1674
    frame #13: 0x0000000109439c64 AsyncDisplayKit`-[ASDisplayNode measureWithSizeRange:](self=0x00007f93e46749d0, _cmd="measureWithSizeRange:", constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 916 at ASDisplayNode.mm:647
    frame #14: 0x000000010940731e AsyncDisplayKit`-[ASDataController _layoutNode:withConstrainedSize:](self=0x00007f93e409ebc0, _cmd="_layoutNode:withConstrainedSize:", node=0x00007f93e46749d0, constrainedSize=(min = (width = 375, height = 1), max = (width = 375, height = 10000))) + 142 at ASDataController.mm:143
    frame #15: 0x0000000109408e9c AsyncDisplayKit`__64-[ASDataController _layoutNodes:ofKind:atIndexPaths:completion:]_block_invoke108(.block_descriptor=<unavailable>) + 252 at ASDataController.mm:205
    frame #16: 0x000000010ef1de5d libdispatch.dylib`_dispatch_call_block_and_release + 12
    frame #17: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #18: 0x000000010ef26bef libdispatch.dylib`_dispatch_root_queue_drain + 1829
    frame #19: 0x000000010ef264c5 libdispatch.dylib`_dispatch_worker_thread3 + 111
    frame #20: 0x000000010f27668f libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #21: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #21: tid = 0x5b82a3, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #19: tid = 0x5b82a4, 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10, queue = 'org.AsyncDisplayKit.ASDataController.editingTransactionQueue :: NSOperation 0x7f93e711a3c0 (QOS: LEGACY)'
    frame #0: 0x000000010f2ac3c2 libsystem_kernel.dylib`semaphore_wait_trap + 10
    frame #1: 0x000000010ef29865 libdispatch.dylib`_dispatch_group_wait_slow + 227
    frame #2: 0x0000000109408342 AsyncDisplayKit`-[ASDataController _layoutNodes:ofKind:atIndexPaths:completion:](self=0x00007f93e409ebc0, _cmd="_layoutNodes:ofKind:atIndexPaths:completion:", nodes=0x00007f93e4761670, kind=0x00000001095220f0, indexPaths=0x00007f93e4761600, completionBlock=(AsyncDisplayKit`__72-[ASDataController _batchLayoutNodes:atIndexPaths:withAnimationOptions:]_block_invoke at ASDataController.mm:152)) + 2850 at ASDataController.mm:212
    frame #3: 0x0000000109406a49 AsyncDisplayKit`-[ASDataController batchLayoutNodes:ofKind:atIndexPaths:completion:](self=0x00007f93e409ebc0, _cmd="batchLayoutNodes:ofKind:atIndexPaths:completion:", nodes=0x00007f93e45f1830, kind=0x00000001095220f0, indexPaths=0x00007f93e40cf560, completionBlock=(AsyncDisplayKit`__72-[ASDataController _batchLayoutNodes:atIndexPaths:withAnimationOptions:]_block_invoke at ASDataController.mm:152)) + 729 at ASDataController.mm:122
    frame #4: 0x000000010940765c AsyncDisplayKit`-[ASDataController _batchLayoutNodes:atIndexPaths:withAnimationOptions:](self=0x00007f93e409ebc0, _cmd="_batchLayoutNodes:atIndexPaths:withAnimationOptions:", nodes=0x00007f93e45f1830, indexPaths=0x00007f93e40cf560, animationOptions=5) + 252 at ASDataController.mm:152
    frame #5: 0x000000010941215d AsyncDisplayKit`__64-[ASDataController insertRowsAtIndexPaths:withAnimationOptions:]_block_invoke_3(.block_descriptor=<unavailable>) + 61 at ASDataController.mm:764
    frame #6: 0x000000010a943304 Foundation`__NSBLOCKOPERATION_IS_CALLING_OUT_TO_A_BLOCK__ + 7
    frame #7: 0x000000010a87f035 Foundation`-[NSBlockOperation main] + 101
    frame #8: 0x000000010a861f8a Foundation`-[__NSOperationInternal _start:] + 646
    frame #9: 0x000000010a861b9b Foundation`__NSOQSchedule_f + 194
    frame #10: 0x000000010ef3e49b libdispatch.dylib`_dispatch_client_callout + 8
    frame #11: 0x000000010ef248ec libdispatch.dylib`_dispatch_queue_drain + 2215
    frame #12: 0x000000010ef23e0d libdispatch.dylib`_dispatch_queue_invoke + 601
    frame #13: 0x000000010ef26a56 libdispatch.dylib`_dispatch_root_queue_drain + 1420
    frame #14: 0x000000010ef264c5 libdispatch.dylib`_dispatch_worker_thread3 + 111
    frame #15: 0x000000010f27668f libsystem_pthread.dylib`_pthread_wqthread + 1129
    frame #16: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13

  thread #22: tid = 0x5b83cb, 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #0: 0x000000010f2b26de libsystem_kernel.dylib`__workq_kernreturn + 10
    frame #1: 0x000000010f276729 libsystem_pthread.dylib`_pthread_wqthread + 1283
    frame #2: 0x000000010f274365 libsystem_pthread.dylib`start_wqthread + 13
smyrgl commented 8 years ago

@appleguy As for revisions, the last revision I tested (I'm going to test your fix now but I haven't pulled yet) is cae47e23e1697d9da317743783c4bd02a4e60d99 and the first commit that I pulled that this started happening was de2d3ab024fb683142d06779e5acc964162db5ea which I upgraded to from f696eb74769188f5dacafe178d458ce447e19fac. However it was intermittent then (whereas in cae47e23e1697d9da317743783c4bd02a4e60d99 it is 100% reproducible with no relevant changes in my code) so there is a possibility that this "break" was introduced earlier.

smyrgl commented 8 years ago

@appleguy So I pulled 4c1654673af1ac9a8b2fa1eb140450df10006415 and I can confirm that this deadlock is no longer occurring. It looks like the only change you did was to not use the lock if the thread is main...this fixes the issue (since the changesets can only be called from main due to the thread affinity asserts) but I'm not sure why it was happening in the first place. I'm not complaining but even your documentation for the change only suggests that this is an optimization.

Anyway I will let you know if this reoccurs but if you know what the root cause is that would be helpful to understand.

smyrgl commented 8 years ago

@appleguy As for the architecture of my app, I think it might make sense to take that to iMessage so we can have some back and forth on the subject. The particular collection view that this triggered on is by far the most complex in the app (using extensive use of sections to represent flattened leaves of a tree data structure) but I'm not sure any of that is relevant to why this happened. I emailed you my iMessage info, ping me at your convenience and we can discuss it further.

appleguy commented 8 years ago

@smyrgl thanks for the information! It definitely helps clarify the issue.

Locking overhead is one of the most measurable parts of AsyncDisplayKit on the main thread with app architectures that minimize their own usage of main. That said, the deadlock I mentioned in the commit log was obviously the prompt to investigate the change, which is far as I can tell does not compromise thread safety.

It is very complex to use Core Data in an app with multithreaded UI. This was experience in the main Facebook app with its architecture before ASDK & ComponentKit. It was also experienced when building the Paper app which was based on Core Data for the first year of its development until it was ported off of it before launch.

The framework is one of the best in the world for dealing with certain types of data sets, and is also used by one of the very best contributors to the project (@Adlai-Holler). Fortunately, the source of the deadlock can be very easily understood based on the AsyncDisplayKit threading model. Unfortunately, there is no documentation written about this. The three part tutorial series from Ray Wenderlich may have an opportunity to cover this in the third tutorial, but I will definitely make sure it is added to the website documentation in the next couple months.

Specifically, the framework requires that background threads never synchronously wait on the main thread. The main thread is allowed to synchronously wait on any background thread, As this is necessary in a variety of URI timing sensitive operations that desire explicitly synchronous layout or display.

I think it would be very interesting to discuss this with anyone in the community who has better experience with Core Data than I do, as I am a couple years out of date (and ASDK itself was different then). One thing that we'll almost certainly help your app architecture overcome this in a reliable and graceful way is the change from @Adlai-Holler (surprise!) That he is planning to finish in the next few days, in order to remove thread affinity assertions and oh allow even UIKit and CA bridge properties to be set in the background (even after isNodeLoaded).

It will not facilitate reading the values of /bridged/ properties in that same situation, but this is very rare and almost always possible to work around easily. Reading is possible from all ASDK properties like attributedString, URL, image, are expected by the framework to be threadsafe (locking is practiced quite consistently in the framework, though some ~20% may need auditing - these cases are almost inconceivable to use in a concurrent way).

Thanks for your email, really glad to be in touch with you and excited to find a solution together!

smyrgl commented 8 years ago

@appleguy @Adlai-Holler Ahhhhh...that's interesting and not something I was aware of but it makes sense. Just one point of clarification: I assume when you say that I can't wait on the main thread from a background thread what you really mean is that I can't wait on an ADK queue background thread for the main thread? In other words this would be ok?

backgroundContext.performBlock({ () -> Void in
    mainContext.performBlockAndWait({ () -> Void in
    })
})
smyrgl commented 8 years ago

@appleguy Anyway regardless I don't have a lot of cases where I synchronously wait on the main thread in Core Data scenarios that I'm aware of (the above example is a bit contrived). The reason being is that I have a two context setup but each is directly tied to the PSC and background context actually represents the master data--the main context is basically read only for the UI and all communication between the two happens via standard Core Data merges.

However I do have cases with a few nodes where they use a Core Data object as the "data source" to setup the node like this:

class DiscussionPostNode: ASDisplayNode {

    var postObjectID: NSManagedObjectID?

    override func fetchData() {
        super.fetchData()
        let context = NSManagedObjectContext.currentThreadContext()
        guard let postObjectID = postObjectID, post = context.objectWithID(postObjectID) as? Post else { return }
        let mutableContext = NSMutableAttributedString()
        if let parentUsername = post.parent?.author?.name {
            mutableContext.appendAttributedString(NSAttributedString(string: "in reply to ", attributes: ContextAttributes))
            let usernameAttributed = NSMutableAttributedString(string: parentUsername, attributes: ContextBoldAttributes)
            if let parentResourceUrl = post.parent?.author?.resourceUrl {
                usernameAttributed.addAttribute(DSQActionLinkAttributeName, value: parentResourceUrl, range: NSMakeRange(0, usernameAttributed.length))
            }
            mutableContext.appendAttributedString(usernameAttributed)
            mutableContext.appendAttributedString(NSAttributedString(string: "  ·  ", attributes: ContextBoldAttributes))
        }
        if let createdAtString = post.createdAt?.shortTimeSinceString {
            mutableContext.appendAttributedString(NSAttributedString(string: createdAtString, attributes: ContextAttributes))
        }
        contextNode.attributedString = mutableContext
        if let author = post.author {
            usernameNode.attributedString = author.attributedName(UsernameLinkAttributes)
        }
        if let avatarUrlString = post.author?.avatarCacheUrlString {
            if let avatarURL = NSURL(string: avatarUrlString) {
                avatarNode.URL = avatarURL
                if let userURL = post.author?.resourceUrl {
                    avatarNode.userInteractionEnabled = true
                    self.authorURL = userURL
                } else {
                    avatarNode.userInteractionEnabled = false
                }
            }
        }
        let nestCount = post.nestCount
        guard let cellNode = self.cellNode else { return }
        cellNode.delegate?.nestingLevelsForNode(cellNode, completion: { [weak self] (previous, next) -> () in
            guard let strongSelf = self else { return }
            strongSelf.nestingNode.nestingLevel = nestCount
            if previous != strongSelf.nestingNode.previousLevel || next != strongSelf.nestingNode.nextLevel {
                strongSelf.nestingNode.previousLevel = previous ?? 0
                strongSelf.nestingNode.nextLevel = next ?? 0
            }
        })
    }        
}

I do this with a thread specific context because of the thread affinity problem. If there wasn't thread affinity (or there was some way to dispatch back to it) I wouldn't need to do stuff like this and I could just async grab the data from a background context (something like a mirror of the main context but for ADK) and then use it directly.

smyrgl commented 8 years ago

A couple interesting things I've found here as I work through an implementation to solve some of these gotchas:

  1. Normally I have been using the fetchData method on ASDisplayNode as the place to fetch the Core Data object and then populate the info as needed. What's interesting to note with regards to main thread deadlocks is that while this is normally called on a background thread it can be called on the main thread in certain cases so you can't block while waiting on a background context lookup.
  2. fetchData assumes that the fetch is sync and considers it complete at the end of the function so with no completion block passed in to fire this means you have to take a more active role.

Here's a simplistic example of a solution that I find works:

    override func fetchData() {
        super.fetchData()
        let fetchBlock: (context: NSManagedObjectContext) -> () = { (context) in
            guard let channel = context.objectWithID(self.channel.objectID) as? Channel else {
                return
            }
            self.followButtonNode.selected = channel.currentUserFollowing
        }
        if NSThread.isMainThread() {
            fetchBlock(context: MainContext())
        } else {
            SyncContext().performBlockAndWait { () -> Void in
                fetchBlock(context: SyncContext())
            }
        }
    }
garrettmoon commented 7 years ago

Leaving this in the backlog, but @appleguy think's @Adlai-Holler is the best fit.

garrettmoon commented 7 years ago

This issue was moved to TextureGroup/Texture#122