UIKit semantics for when "visibleIndexPaths" is valid are not clear (.visibleNodes)

[garrettmoon]

From @nvh on October 20, 2015 8:11

Although it maybe doesn't make sense to call it directly in the performBatchUpdates block
- (void)collectionView:(ASCollectionView *)collectionView willDisplayNodeForItemAtIndexPath:(NSIndexPath *)indexPath; is called before the batch update completes as well, which can lead to this crash when calling 'visibleNodes' inside that delegate function:

2015-10-20 09:45:54.936 demo-app[99621:4521736] *** Terminating app due to uncaught exception 'NSRangeException', reason: '*** -[__NSArrayM objectAtIndex:]: index 5 beyond bounds [0 .. 4]'
*** First throw call stack:
(
    0   CoreFoundation                      0x0000000106c44f65 __exceptionPreprocess + 165
    1   libobjc.A.dylib                     0x00000001066bedeb objc_exception_throw + 48
    2   CoreFoundation                      0x0000000106b28a94 -[__NSArrayM objectAtIndex:] + 212
    3   AsyncDisplayKit                     0x0000000106231662 -[ASDataController nodeAtIndexPath:] + 118
    4   AsyncDisplayKit                     0x000000010620bea0 -[ASCollectionView nodeForItemAtIndexPath:] + 28
    5   AsyncDisplayKit                     0x000000010620bb8f __32-[ASCollectionView visibleNodes]_block_invoke + 33
    6   CoreFoundation                      0x0000000106b86d7d __53-[__NSArrayI enumerateObjectsWithOptions:usingBlock:]_block_invoke + 77
    7   CoreFoundation                      0x0000000106b86c4f -[__NSArrayI enumerateObjectsWithOptions:usingBlock:] + 207
    8   AsyncDisplayKit                     0x000000010620bafe -[ASCollectionView visibleNodes] + 175
    9   demo-app                            0x0000000102de26cd _TFC10demo_app26ViewController18updateVisibleNodesfS0_FT_T_ + 157
    10  demo-app                            0x0000000102de3b92 _TFC10demo_app26ViewController14collectionViewfS0_FTGSQCSo16ASCollectionView_33willDisplayNodeForItemAtIndexPathGSQCSo11NSIndexPath__T_ + 50
    11  demo-app                            0x0000000102de3bf7 _TToFC10demo_app26ViewController14collectionViewfS0_FTGSQCSo16ASCollectionView_33willDisplayNodeForItemAtIndexPathGSQCSo11NSIndexPath__T_ + 71
    12  AsyncDisplayKit                     0x000000010620c417 -[ASCollectionView collectionView:willDisplayCell:forItemAtIndexPath:] + 169
    13  UIKit                               0x00000001040e92f1 -[UICollectionView _createPreparedCellForItemAtIndexPath:withLayoutAttributes:applyAttributes:isFocused:] + 2017
    14  UIKit                               0x00000001040ffef9 -[UICollectionView _viewAnimationsForCurrentUpdate] + 7236
    15  UIKit                               0x000000010410380b __62-[UICollectionView _updateWithItems:tentativelyForReordering:]_block_invoke1580 + 197
    16  UIKit                               0x0000000103984eec +[UIView(Animation) performWithoutAnimation:] + 65
    17  UIKit                               0x0000000104102c8e -[UICollectionView _updateWithItems:tentativelyForReordering:] + 2946
    18  UIKit                               0x00000001040fdd0c -[UICollectionView _endItemAnimationsWithInvalidationContext:tentativelyForReordering:] + 15456
    19  UIKit                               0x0000000104104c3e -[UICollectionView _performBatchUpdates:completion:invalidationContext:tentativelyForReordering:] + 415
    20  UIKit                               0x0000000104104a7c -[UICollectionView _performBatchUpdates:completion:invalidationContext:] + 74
    21  UIKit                               0x0000000104104a1f -[UICollectionView performBatchUpdates:completion:] + 53
    22  AsyncDisplayKit                     0x000000010620ce67 -[ASCollectionView rangeController:endUpdatesAnimated:completion:] + 369
    23  AsyncDisplayKit                     0x00000001062367ef __66-[ASRangeController dataController:endUpdatesAnimated:completion:]_block_invoke + 57
    24  AsyncDisplayKit                     0x000000010620f7c0 _Z37ASDisplayNodePerformBlockOnMainThreadU13block_pointerFvvE + 53
    25  AsyncDisplayKit                     0x000000010623676e -[ASRangeController dataController:endUpdatesAnimated:completion:] + 120
    26  AsyncDisplayKit                     0x000000010622f10a __50-[ASDataController endUpdatesAnimated:completion:]_block_invoke_3 + 57
    27  libdispatch.dylib                   0x000000010b8acef9 _dispatch_call_block_and_release + 12
    28  libdispatch.dylib                   0x000000010b8cd49b _dispatch_client_callout + 8
    29  libdispatch.dylib                   0x000000010b8b534b _dispatch_main_queue_callback_4CF + 1738
    30  CoreFoundation                      0x0000000106ba53e9 __CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__ + 9
    31  CoreFoundation                      0x0000000106b66939 __CFRunLoopRun + 2073
    32  CoreFoundation                      0x0000000106b65e98 CFRunLoopRunSpecific + 488
    33  GraphicsServices                    0x0000000108baead2 GSEventRunModal + 161
    34  UIKit                               0x00000001038df676 UIApplicationMain + 171
    35  demo-app                          0x00000001031d0e1d main + 109
    36  libdyld.dylib                       0x000000010b90192d start + 1
)
libc++abi.dylib: terminating with uncaught exception of type NSException

Copied from original issue: facebookarchive/AsyncDisplayKit#755

[garrettmoon]

From @appleguy on October 20, 2015 20:23

@nvh I believe this issue had been encountered and fixed, but if it is still happening in the latest master, it's a very important issue to solve and we'll investigate it promptly.

Can you confirm what version of ASDK you're running against? Either a version number, or a commit hash?

I have been delayed in pushing the 1.9 stable release due to getting sick & needing to prioritize the day job, but may be able to get it finalized tomorrow (fallback is the weekend). If this is happening on master, though, I will want to make sure it is fixed before we do 1.9.

[garrettmoon]

From @appleguy on October 20, 2015 20:30

@nguyenhuy since you just significantly revised how batch processing works, take a look at this stack and let us know if you think it would be addressed by your diff.

@nvh, please look at the active PR that is up for that. If you were already running against master, if you could do a quick test for us against @nguyenhuy's patch it would be really awesome.

Batch updates in particular have been a weak spot for a long time; my ASDataController refactor from a couple months ago stabilized the basic editing flows, but it's taken until now to get the critical investment needed to finally eliminate all remaining issues with slightly more complex editing flows. This is arguably the #1 priority of the project right now, so being able to confirm whether Huy's patch is sufficient or incomplete will be excellent input.

[garrettmoon]

From @nguyenhuy on October 21, 2015 18:35

@nvh: Can you try to run your code against #753. One explanation for the crash is that there is a mismatch between the ways ASDataController and the underlying UICollectionView perform batch updates. And my recent PR is supposed to fix this crash, if it is the case.

[garrettmoon]

From @nvh on October 26, 2015 9:19

I was running 1.2.3, I will tryout master and the code from #753 as well

[garrettmoon]

From @nvh on October 26, 2015 10:5

With both master (6c08187) and #753 (ecc5e1a) I have the same crash.

[garrettmoon]

From @nguyenhuy on October 26, 2015 12:4

Thanks for trying it out, @nvh. I will try to reproduce this crash and fix it ASAP. In the meantime, it will be tremendously helpful if you could post a project (maybe based on our existing examples) that can reliably reproduce the crash.

[garrettmoon]

From @appleguy on October 27, 2015 5:54

@nguyenhuy thanks a bunch for digging into this. We absolutely have to fix this. @nvh we appreciate you trying yet another patch and apologize for the fact that this has not worked in your app.

@levi, was it your app that had an NSFetchedResultsController? We really need to make a checked-in examples/ test case that uses an FRC and can reproduce a case as stressful as @nvh's app causes, as I think we have at least 5 different apps with pretty serious edit behavior that haven't yet broken master.

[garrettmoon]

From @nvh on October 27, 2015 8:33

I was able to reproduce the crash by adding this code to ViewController.m in the ASCollectionView sample:

- (void)collectionView:(UICollectionView *)collectionView didSelectItemAtIndexPath:(NSIndexPath *)indexPath {
  [collectionView performBatchUpdates:^{
    NSMutableArray* indexPaths = [NSMutableArray array];
    for (NSInteger i = 0; i < 6; i++) {
      [indexPaths addObject:[NSIndexPath indexPathForItem:i inSection:0]];
    }
    [collectionView deleteItemsAtIndexPaths: indexPaths];
  } completion:nil];
}

#pragma mark -
#pragma mark ASCollectionView delegate

- (void)collectionView:(ASCollectionView *)collectionView willDisplayNodeForItemAtIndexPath:(NSIndexPath *)indexPath {
  NSLog(@"%@",[collectionView visibleNodes]);
}

- (void)collectionView:(ASCollectionView *)collectionView didEndDisplayingNodeForItemAtIndexPath:(NSIndexPath *)indexPath {
  NSLog(@"%@",[collectionView visibleNodes]);
}

And then tapping one of the cells.
(this was in master, but as the crash is the same as the one I'm seeing, I assume it also fails on @nguyenhuy's fork)

Let me know if you want me to put this into a sample project, but as it's very simple, I thought this would be more efficient :)

[garrettmoon]

From @levi on October 27, 2015 15:44

@appleguy no fetched results controller in my app. What 5 apps that haven't broken master are you referring to?

[garrettmoon]

From @appleguy on October 27, 2015 17:59

@levi does your app's usage of ASTableView / ASCollectionView cause crashes in ASDataController? Pinterest doesn't, nor do a few other clients' following the improvements on master, but that is irrelevant as long as we can still cause an issue :).

I'm very grateful that @nvh found a reduction case! @nguyenhuy if you don't have time this week to look, simply let me know and I will make it a priority.

[garrettmoon]

From @nguyenhuy on October 28, 2015 13:6

@nvh: Thanks for providing the code. Yes it is enough for me to debug and there is no need to put into a sample project.

I don't think this is caused by ASDK. As you guys may already know, a UICollectionViewDataSource is required to update its data before a batch-updates block returns (and ASDataController rightfully conforms to this requirement). However, UICollectionView indexPathsForVisibleItems (which is used by ASCollectionView visibleNodes) doesn't return a list of updated index paths until after the last call of collectionView:willDisplayNodeForItemAtIndexPath, and before the first call of collectionView:didEndDisplayingNodeForItemAtIndexPath. And because of this UICollectionView's behaviour, it's actually not safe to call indexPathsForVisibleItems (and therefore visibleNodes) in willDisplayNodeForItemAtIndexPath.

[garrettmoon]

From @nguyenhuy on October 28, 2015 13:31

And in case you are wondering, willDisplayNodeForItemAtIndexPath is simply forwarded from UICollectionViewDataSource collectionView:willDisplayCell:forItemAtIndexPath: here.

Also, I didn't find any places where ASRangeController or ASDK's layout controllers could cause UICollectionView to return old index paths. Ideally, I should try to reproduce above behaviour using UIKit components only, but I run out of time for today.

[garrettmoon]

From @nguyenhuy on October 28, 2015 15:27

Trying out a UICollectionView sample project from Apple confirms the above behaviour of indexPathsForVisibleItems during willDisplayCell and didEndDisplayingCell.

[garrettmoon]

From @appleguy on October 28, 2015 23:43

@nguyenhuy fascinating details! I definitely did not know that.

These call order / API guarantee subtleties can be extremely complex to figure out for many developers, as it often doesn't seem like the most plausible cause of a given issue. It's not actually about bad developers (it should be very clear that nvh can debug / derive these kind of implied behaviors / call orders), but more about the set of assumptions and expectations you approach an API with.

Can anyone think of a way that we can better document stuff like this, even though it is actually a UIKit behavior / limitation? I'm not sure if an assertion or log message makes sense, but it might, if an edit transaction were recently submitted and the developer is asking for visible* when we know it will not have been updated. A non-asserting log might be best.