diff --git a/AsyncDisplayKit.xcodeproj/project.pbxproj b/AsyncDisplayKit.xcodeproj/project.pbxproj index aa4b91640..77c10f78e 100644 --- a/AsyncDisplayKit.xcodeproj/project.pbxproj +++ b/AsyncDisplayKit.xcodeproj/project.pbxproj @@ -376,6 +376,8 @@ CCA282D01E9EBF6C0037E8B7 /* ASTipsWindow.h in Headers */ = {isa = PBXBuildFile; fileRef = CCA282CE1E9EBF6C0037E8B7 /* ASTipsWindow.h */; }; CCA282D11E9EBF6C0037E8B7 /* ASTipsWindow.m in Sources */ = {isa = PBXBuildFile; fileRef = CCA282CF1E9EBF6C0037E8B7 /* ASTipsWindow.m */; }; CCA5F62E1EECC2A80060C137 /* ASAssert.m in Sources */ = {isa = PBXBuildFile; fileRef = CCA5F62D1EECC2A80060C137 /* ASAssert.m */; }; + CCB1F95A1EFB60A5009C7475 /* ASLog.m in Sources */ = {isa = PBXBuildFile; fileRef = CCB1F9591EFB60A5009C7475 /* ASLog.m */; }; + CCB1F95C1EFB6350009C7475 /* ASSignpost.h in Headers */ = {isa = PBXBuildFile; fileRef = CCB1F95B1EFB6316009C7475 /* ASSignpost.h */; }; CCB2F34D1D63CCC6004E6DE9 /* ASDisplayNodeSnapshotTests.m in Sources */ = {isa = PBXBuildFile; fileRef = CCB2F34C1D63CCC6004E6DE9 /* ASDisplayNodeSnapshotTests.m */; }; CCBBBF5D1EB161760069AA91 /* ASRangeManagingNode.h in Headers */ = {isa = PBXBuildFile; fileRef = CCBBBF5C1EB161760069AA91 /* ASRangeManagingNode.h */; settings = {ATTRIBUTES = (Public, ); }; }; CCCCCCD51EC3EF060087FE10 /* ASTextDebugOption.h in Headers */ = {isa = PBXBuildFile; fileRef = CCCCCCC31EC3EF060087FE10 /* ASTextDebugOption.h */; }; @@ -842,6 +844,8 @@ CCA282CE1E9EBF6C0037E8B7 /* ASTipsWindow.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = ASTipsWindow.h; sourceTree = ""; }; CCA282CF1E9EBF6C0037E8B7 /* ASTipsWindow.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = ASTipsWindow.m; sourceTree = ""; }; CCA5F62D1EECC2A80060C137 /* ASAssert.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = ASAssert.m; sourceTree = ""; }; + CCB1F9591EFB60A5009C7475 /* ASLog.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = ASLog.m; sourceTree = ""; }; + CCB1F95B1EFB6316009C7475 /* ASSignpost.h */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.c.h; path = ASSignpost.h; sourceTree = ""; }; CCB2F34C1D63CCC6004E6DE9 /* ASDisplayNodeSnapshotTests.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = ASDisplayNodeSnapshotTests.m; sourceTree = ""; }; CCBBBF5C1EB161760069AA91 /* ASRangeManagingNode.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = ASRangeManagingNode.h; sourceTree = ""; }; CCBD05DE1E4147B000D18509 /* ASIGListAdapterBasedDataSource.m */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.objc; path = ASIGListAdapterBasedDataSource.m; sourceTree = ""; }; @@ -1387,6 +1391,8 @@ 058D0A44195D058D00B7D73C /* ASBaseDefines.h */, 1950C4481A3BB5C1005C8279 /* ASEqualityHelpers.h */, 0516FA3B1A15563400B4EBED /* ASLog.h */, + CCB1F9591EFB60A5009C7475 /* ASLog.m */, + CCB1F95B1EFB6316009C7475 /* ASSignpost.h */, ); path = Base; sourceTree = ""; @@ -1692,6 +1698,7 @@ 9019FBBF1ED8061D00C45F72 /* ASYogaUtilities.h in Headers */, DE84918D1C8FFF2B003D89E9 /* ASRunLoopQueue.h in Headers */, CC0F88621E4281E200576FED /* ASSectionController.h in Headers */, + CCB1F95C1EFB6350009C7475 /* ASSignpost.h in Headers */, A2763D7A1CBDD57D00A9ADBD /* ASPINRemoteImageDownloader.h in Headers */, 34EFC7611B701C9C00AD841F /* ASBackgroundLayoutSpec.h in Headers */, B35062591B010F070018CF92 /* ASBaseDefines.h in Headers */, @@ -2180,6 +2187,7 @@ B35061F91B010EFD0018CF92 /* ASControlNode.mm in Sources */, 8021EC1F1D2B00B100799119 /* UIImage+ASConvenience.m in Sources */, B35062181B010EFD0018CF92 /* ASDataController.mm in Sources */, + CCB1F95A1EFB60A5009C7475 /* ASLog.m in Sources */, 767E7F8E1C90191D0066C000 /* AsyncDisplayKit+Debug.m in Sources */, CCCCCCD61EC3EF060087FE10 /* ASTextDebugOption.m in Sources */, 34EFC75C1B701BD200AD841F /* ASDimension.mm in Sources */, diff --git a/CHANGELOG.md b/CHANGELOG.md index da89e40e3..98e348db8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,10 @@ - [ASTextNode2] Add initial implementation for link handling. [Scott Goodson](https://github.com/appleguy) [#396](https://github.com/TextureGroup/Texture/pull/396) - [ASTextNode2] Provide compile flag to globally enable new implementation of ASTextNode: ASTEXTNODE_EXPERIMENT_GLOBAL_ENABLE. [Scott Goodson](https://github.com/appleguy) [#396](https://github.com/TextureGroup/Texture/pull/410) +##2.3.5 +- Fix an issue where inserting/deleting sections could lead to inconsistent supplementary element behavior. [Adlai Holler](https://github.com/Adlai-Holler) +- Overhaul logging and add activity tracing support. [Adlai Holler](https://github.com/Adlai-Holler) + ##2.3.4 - [Yoga] Rewrite YOGA_TREE_CONTIGUOUS mode with improved behavior and cleaner integration [Scott Goodson](https://github.com/appleguy) - [ASTraitCollection] Convert ASPrimitiveTraitCollection from lock to atomic. [Scott Goodson](https://github.com/appleguy) @@ -15,7 +19,6 @@ - Migrated unit tests to OCMock 3.4 (from 2.2) and improved the multiplex image node tests. [Adlai Holler](https://github.com/Adlai-Holler) - Fix CollectionNode double-load issue. This should significantly improve performance in cases where a collection node has content immediately available on first layout i.e. not fetched from the network. [Adlai Holler](https://github.com/Adlai-Holler) - Overhaul layout flattening algorithm [Huy Nguyen](https://github.com/nguyenhuy) [#395](https://github.com/TextureGroup/Texture/pull/395). -- Fix an issue where inserting/deleting sections could lead to inconsistent supplementary element behavior. [Adlai Holler](https://github.com/Adlai-Holler) ## 2.3.3 - [ASTextKitFontSizeAdjuster] Replace use of NSAttributedString's boundingRectWithSize:options:context: with NSLayoutManager's boundingRectForGlyphRange:inTextContainer: [Ricky Cancro](https://github.com/rcancro) diff --git a/Source/ASCellNode.mm b/Source/ASCellNode.mm index 197c02b21..e3d2d25e5 100644 --- a/Source/ASCellNode.mm +++ b/Source/ASCellNode.mm @@ -315,13 +315,13 @@ - (void)handleVisibilityChange:(BOOL)isVisible if (ip != nil) { [result addObject:@{ @"indexPath" : ip }]; } - [result addObject:@{ @"collectionNode" : ASObjectDescriptionMakeTiny(owningNode) }]; + [result addObject:@{ @"collectionNode" : owningNode }]; } else if ([owningNode isKindOfClass:[ASTableNode class]]) { NSIndexPath *ip = [(ASTableNode *)owningNode indexPathForNode:self]; if (ip != nil) { [result addObject:@{ @"indexPath" : ip }]; } - [result addObject:@{ @"tableNode" : ASObjectDescriptionMakeTiny(owningNode) }]; + [result addObject:@{ @"tableNode" : owningNode }]; } else if ([scrollView isKindOfClass:[ASCollectionView class]]) { NSIndexPath *ip = [(ASCollectionView *)scrollView indexPathForNode:self]; diff --git a/Source/ASCollectionView.mm b/Source/ASCollectionView.mm index 906268349..8777145aa 100644 --- a/Source/ASCollectionView.mm +++ b/Source/ASCollectionView.mm @@ -800,6 +800,8 @@ - (void)beginUpdates if (_batchUpdateCount == 0) { _changeSet = [[_ASHierarchyChangeSet alloc] initWithOldData:[_dataController itemCountsFromDataSource]]; + _changeSet.rootActivity = as_activity_create("Perform async collection update", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT); + _changeSet.submitActivity = as_activity_create("Submit changes for collection update", _changeSet.rootActivity, OS_ACTIVITY_FLAG_DEFAULT); } _batchUpdateCount++; } @@ -817,6 +819,7 @@ - (void)endUpdatesAnimated:(BOOL)animated completion:(nullable void (^)(BOOL))co if (_batchUpdateCount == 0) { _ASHierarchyChangeSet *changeSet = _changeSet; + // Nil out _changeSet before forwarding to _dataController to allow the change set to cause subsequent batch updates on the same run loop _changeSet = nil; changeSet.animated = animated; @@ -828,8 +831,13 @@ - (void)performBatchAnimated:(BOOL)animated updates:(void (^)())updates completi { ASDisplayNodeAssertMainThread(); [self beginUpdates]; - if (updates) { - updates(); + as_activity_scope(_changeSet.rootActivity); + { + // Only include client code in the submit activity, the rest just lives in the root activity. + as_activity_scope(_changeSet.submitActivity); + if (updates) { + updates(); + } } [self endUpdatesAnimated:animated completion:completion]; } @@ -1575,10 +1583,12 @@ - (void)_beginBatchFetchingIfNeededWithContentOffset:(CGPoint)contentOffset velo - (void)_beginBatchFetching { + as_activity_create_for_scope("Batch fetch for collection node"); [_batchContext beginBatchFetching]; if (_asyncDelegateFlags.collectionNodeWillBeginBatchFetch) { dispatch_async(dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_DEFAULT, 0), ^{ GET_COLLECTIONNODE_OR_RETURN(collectionNode, (void)0); + as_log_debug(ASCollectionLog(), "Beginning batch fetch for %@ with context %@", collectionNode, _batchContext); [_asyncDelegate collectionNode:collectionNode willBeginBatchFetchWithContext:_batchContext]; }); } else if (_asyncDelegateFlags.collectionViewWillBeginBatchFetch) { @@ -1894,9 +1904,11 @@ - (void)rangeController:(ASRangeController *)rangeController didUpdateWithChange } ASPerformBlockWithoutAnimation(!changeSet.animated, ^{ - if(changeSet.includesReloadData) { + as_activity_scope(as_activity_create("Commit collection update", changeSet.rootActivity, OS_ACTIVITY_FLAG_DEFAULT)); + if (changeSet.includesReloadData) { _superIsPendingDataLoad = YES; [super reloadData]; + as_log_debug(ASCollectionLog(), "Did reloadData %@", self.collectionNode); [changeSet executeCompletionHandlerWithFinished:YES]; } else { [_layoutFacilitator collectionViewWillPerformBatchUpdates]; @@ -1933,13 +1945,17 @@ - (void)rangeController:(ASRangeController *)rangeController didUpdateWithChange numberOfUpdates++; } } completion:^(BOOL finished){ + as_activity_scope(as_activity_create("Handle collection update completion", changeSet.rootActivity, OS_ACTIVITY_FLAG_DEFAULT)); + as_log_verbose(ASCollectionLog(), "Update animation finished %{public}@", self.collectionNode); // Flush any range changes that happened as part of the update animations ending. [_rangeController updateIfNeeded]; [self _scheduleCheckForBatchFetchingForNumberOfChanges:numberOfUpdates]; [changeSet executeCompletionHandlerWithFinished:finished]; }]; + as_log_debug(ASCollectionLog(), "Completed batch update %{public}@", self.collectionNode); // Flush any range changes that happened as part of submitting the update. + as_activity_scope(changeSet.rootActivity); [_rangeController updateIfNeeded]; } }); diff --git a/Source/ASDisplayNode+Layout.mm b/Source/ASDisplayNode+Layout.mm index 8006b13ff..f7dfa006b 100644 --- a/Source/ASDisplayNode+Layout.mm +++ b/Source/ASDisplayNode+Layout.mm @@ -15,6 +15,7 @@ #import #import #import +#import #import @@ -127,13 +128,8 @@ - (ASTraitCollection *)asyncTraitCollection ASPrimitiveTraitCollectionDeprecatedImplementation -@end - -#pragma mark - #pragma mark - ASLayoutElementAsciiArtProtocol -@implementation ASDisplayNode (ASLayoutElementAsciiArtProtocol) - - (NSString *)asciiArtString { return [ASLayoutSpec asciiArtStringForChildren:@[] parentName:[self asciiArtName]]; @@ -141,11 +137,11 @@ - (NSString *)asciiArtString - (NSString *)asciiArtName { - NSString *string = NSStringFromClass([self class]); + NSMutableString *result = [NSMutableString stringWithCString:object_getClassName(self) encoding:NSASCIIStringEncoding]; if (_debugName) { - string = [string stringByAppendingString:[NSString stringWithFormat:@"\"%@\"",_debugName]]; + [result appendFormat:@" (%@)", _debugName]; } - return string; + return result; } @end @@ -222,6 +218,7 @@ @implementation ASDisplayNode (ASLayoutInternal) */ - (void)_setNeedsLayoutFromAbove { + as_activity_create_for_scope("Set needs layout from above"); ASDisplayNodeAssertThreadAffinity(self); // Mark the node for layout in the next layout pass @@ -315,6 +312,8 @@ - (void)_locked_measureNodeWithBoundsIfNecessary:(CGRect)bounds } } + as_activity_create_for_scope("Update node layout for current bounds"); + as_log_verbose(ASLayoutLog(), "Node %@, bounds size %@, calculatedSize %@, calculatedIsDirty %d", self, NSStringFromCGSize(boundsSizeForLayout), NSStringFromCGSize(_calculatedDisplayNodeLayout->layout.size), _calculatedDisplayNodeLayout->isDirty()); // _calculatedDisplayNodeLayout is not reusable we need to transition to a new one [self cancelLayoutTransition]; @@ -332,7 +331,20 @@ - (void)_locked_measureNodeWithBoundsIfNecessary:(CGRect)bounds // nextLayout was likely created by a call to layoutThatFits:, check if it is valid and can be applied. // If our bounds size is different than it, or invalid, recalculate. Use #define to avoid nullptr-> - if (nextLayout == nullptr || nextLayout->isDirty() == YES || layoutSizeDifferentFromBounds) { + BOOL pendingLayoutApplicable = NO; + if (nextLayout == nullptr) { + as_log_verbose(ASLayoutLog(), "No pending layout."); + } else if (nextLayout->isDirty()) { + as_log_verbose(ASLayoutLog(), "Pending layout is invalid."); + } else if (layoutSizeDifferentFromBounds) { + as_log_verbose(ASLayoutLog(), "Pending layout size %@ doesn't match bounds size.", NSStringFromCGSize(nextLayout->layout.size)); + } else { + as_log_verbose(ASLayoutLog(), "Using pending layout %@.", nextLayout->layout); + pendingLayoutApplicable = YES; + } + + if (!pendingLayoutApplicable) { + as_log_verbose(ASLayoutLog(), "Measuring with previous constrained size."); // Use the last known constrainedSize passed from a parent during layout (if never, use bounds). ASSizeRange constrainedSize = [self _locked_constrainedSizeForLayoutPass]; ASLayout *layout = [self calculateLayoutThatFits:constrainedSize @@ -350,6 +362,7 @@ - (void)_locked_measureNodeWithBoundsIfNecessary:(CGRect)bounds // This can occur for either pre-calculated or newly-calculated layouts. if (nextLayout->requestedLayoutFromAbove == NO && CGSizeEqualToSize(boundsSizeForLayout, nextLayout->layout.size) == NO) { + as_log_verbose(ASLayoutLog(), "Layout size doesn't match bounds size. Requesting layout from above."); // The layout that we have specifies that this node (self) would like to be a different size // than it currently is. Because that size has been computed within the constrainedSize, we // expect that calling setNeedsLayoutFromAbove will result in our parent resizing us to this. @@ -506,10 +519,13 @@ - (void)transitionLayoutWithSizeRange:(ASSizeRange)constrainedSize measurementCompletion:(void(^)())completion { ASDisplayNodeAssertMainThread(); + as_activity_create_for_scope("Transition node layout"); + as_log_debug(ASLayoutLog(), "Transition layout for %@ sizeRange %@ anim %d asyncMeasure %d", self, NSStringFromASSizeRange(constrainedSize), animated, shouldMeasureAsync); if (constrainedSize.max.width <= 0.0 || constrainedSize.max.height <= 0.0) { // Using CGSizeZero for the sizeRange can cause negative values in client layout code. // Most likely called transitionLayout: without providing a size, before first layout pass. + as_log_verbose(ASLayoutLog(), "Ignoring transition due to bad size range."); return; } @@ -526,9 +542,14 @@ - (void)transitionLayoutWithSizeRange:(ASSizeRange)constrainedSize // Every new layout transition has a transition id associated to check in subsequent transitions for cancelling int32_t transitionID = [self _startNewTransition]; + as_log_verbose(ASLayoutLog(), "Transition ID is %d", transitionID); // NOTE: This block captures self. It's cheaper than hitting the weak table. asdisplaynode_iscancelled_block_t isCancelled = ^{ - return (BOOL)(_transitionID != transitionID); + BOOL result = (_transitionID != transitionID); + if (result) { + as_log_verbose(ASLayoutLog(), "Transition %d canceled, superseded by %d", transitionID, _transitionID.load()); + } + return result; }; // Move all subnodes in layout pending state for this transition @@ -573,6 +594,7 @@ - (void)transitionLayoutWithSizeRange:(ASSizeRange)constrainedSize if (isCancelled()) { return; } + as_activity_create_for_scope("Commit layout transition"); ASLayoutTransition *pendingLayoutTransition; _ASTransitionContext *pendingLayoutTransitionContext; { @@ -598,10 +620,13 @@ - (void)transitionLayoutWithSizeRange:(ASSizeRange)constrainedSize } // Apply complete layout transitions for all subnodes - ASDisplayNodePerformBlockOnEverySubnode(self, NO, ^(ASDisplayNode * _Nonnull node) { - [node _completePendingLayoutTransition]; - node.hierarchyState &= (~ASHierarchyStateLayoutPending); - }); + { + as_activity_create_for_scope("Complete pending layout transitions for subtree"); + ASDisplayNodePerformBlockOnEverySubnode(self, NO, ^(ASDisplayNode * _Nonnull node) { + [node _completePendingLayoutTransition]; + node.hierarchyState &= (~ASHierarchyStateLayoutPending); + }); + } // Measurement pass completion // Give the subclass a change to hook into before calling the completion block @@ -614,7 +639,10 @@ - (void)transitionLayoutWithSizeRange:(ASSizeRange)constrainedSize [pendingLayoutTransition applySubnodeInsertions]; // Kick off animating the layout transition - [self animateLayoutTransition:pendingLayoutTransitionContext]; + { + as_activity_create_for_scope("Animate layout transition"); + [self animateLayoutTransition:pendingLayoutTransitionContext]; + } // Mark transaction as finished [self _finishOrCancelTransition]; @@ -805,7 +833,7 @@ - (void)_completePendingLayoutTransition */ - (void)_completeLayoutTransition:(ASLayoutTransition *)layoutTransition { - // Layout transition is not supported for nodes that are not have automatic subnode management enabled + // Layout transition is not supported for nodes that do not have automatic subnode management enabled if (layoutTransition == nil || self.automaticallyManagesSubnodes == NO) { return; } diff --git a/Source/ASDisplayNode+Subclasses.h b/Source/ASDisplayNode+Subclasses.h index efc9faba4..c89d7fef3 100644 --- a/Source/ASDisplayNode+Subclasses.h +++ b/Source/ASDisplayNode+Subclasses.h @@ -514,7 +514,7 @@ NS_ASSUME_NONNULL_BEGIN @end -#define ASDisplayNodeAssertThreadAffinity(viewNode) ASDisplayNodeAssert(!viewNode || ASDisplayNodeThreadIsMain() || !(viewNode).nodeLoaded, @"Incorrect display node thread affinity - this method should not be called off the main thread after the ASDisplayNode's view or layer have been created") -#define ASDisplayNodeCAssertThreadAffinity(viewNode) ASDisplayNodeCAssert(!viewNode || ASDisplayNodeThreadIsMain() || !(viewNode).nodeLoaded, @"Incorrect display node thread affinity - this method should not be called off the main thread after the ASDisplayNode's view or layer have been created") +#define ASDisplayNodeAssertThreadAffinity(viewNode) ASDisplayNodeAssert(!viewNode || ASMainThreadAssertionsAreDisabled() || ASDisplayNodeThreadIsMain() || !(viewNode).nodeLoaded, @"Incorrect display node thread affinity - this method should not be called off the main thread after the ASDisplayNode's view or layer have been created") +#define ASDisplayNodeCAssertThreadAffinity(viewNode) ASDisplayNodeCAssert(!viewNode || ASMainThreadAssertionsAreDisabled() || ASDisplayNodeThreadIsMain() || !(viewNode).nodeLoaded, @"Incorrect display node thread affinity - this method should not be called off the main thread after the ASDisplayNode's view or layer have been created") NS_ASSUME_NONNULL_END diff --git a/Source/ASDisplayNode.h b/Source/ASDisplayNode.h index f3745f91f..96bb2c3c5 100644 --- a/Source/ASDisplayNode.h +++ b/Source/ASDisplayNode.h @@ -748,9 +748,6 @@ extern NSInteger const ASDefaultDrawingPriority; @end -@interface ASDisplayNode (ASLayoutElementAsciiArtProtocol) -@end - @interface ASDisplayNode (ASLayout) /** @name Managing dimensions */ diff --git a/Source/ASDisplayNode.mm b/Source/ASDisplayNode.mm index 18528f9d9..27fe8c9a9 100644 --- a/Source/ASDisplayNode.mm +++ b/Source/ASDisplayNode.mm @@ -41,18 +41,14 @@ #import #import #import +#import #import +#import #import #import #import #import -#if ASDisplayNodeLoggingEnabled - #define LOG(...) NSLog(__VA_ARGS__) -#else - #define LOG(...) -#endif - // Conditionally time these scopes to our debug ivars (only exist in debug/profile builds) #if TIME_DISPLAYNODE_OPS #define TIME_SCOPED(outVar) ASDN::ScopeTimer t(outVar) @@ -452,10 +448,10 @@ - (void)_scheduleIvarsForMainDeallocation for (Ivar ivar : ivars) { id value = object_getIvar(self, ivar); if (ASClassRequiresMainThreadDeallocation(object_getClass(value))) { - LOG(@"Trampolining ivar '%s' value %@ for main deallocation.", ivar_getName(ivar), value); + as_log_debug(ASMainThreadDeallocationLog(), "%@: Trampolining ivar '%s' value %@ for main deallocation.", self, ivar_getName(ivar), value); ASPerformMainThreadDeallocation(value); } else { - LOG(@"Not trampolining ivar '%s' value %@.", ivar_getName(ivar), value); + as_log_debug(ASMainThreadDeallocationLog(), "%@: Not trampolining ivar '%s' value %@.", self, ivar_getName(ivar), value); } } } @@ -512,16 +508,16 @@ + (NSValue * _Nonnull)_ivarsThatMayNeedMainDeallocation // If it's `id` we have to include it just in case. resultIvars[resultCount] = ivar; resultCount += 1; - LOG(@"Marking ivar '%s' for possible main deallocation due to type id", ivar_getName(ivar)); + as_log_debug(ASMainThreadDeallocationLog(), "%@: Marking ivar '%s' for possible main deallocation due to type id", self, ivar_getName(ivar)); } else { // If it's an ivar with a static type, check the type. Class c = ASGetClassFromType(type); if (ASClassRequiresMainThreadDeallocation(c)) { resultIvars[resultCount] = ivar; resultCount += 1; - LOG(@"Marking ivar '%s' for main deallocation due to class %@", ivar_getName(ivar), c); + as_log_debug(ASMainThreadDeallocationLog(), "%@: Marking ivar '%s' for main deallocation due to class %@", self, ivar_getName(ivar), c); } else { - LOG(@"Skipping ivar '%s' for main deallocation.", ivar_getName(ivar)); + as_log_debug(ASMainThreadDeallocationLog(), "%@: Skipping ivar '%s' for main deallocation.", self, ivar_getName(ivar)); } } } @@ -629,6 +625,7 @@ - (void)_didLoad ASDisplayNodeAssertMainThread(); ASDisplayNodeAssertLockUnownedByCurrentThread(__instanceLock__); ASDisplayNodeLogEvent(self, @"didLoad"); + as_log_verbose(ASNodeLog(), "didLoad %@", self); TIME_SCOPED(_debugTimeForDidLoad); [self didLoad]; @@ -914,7 +911,7 @@ - (void)__layout // Performing layout on a zero-bounds view often results in frame calculations // with negative sizes after applying margins, which will cause // measureWithSizeRange: on subnodes to assert. - LOG(@"Warning: No size given for node before node was trying to layout itself: %@. Please provide a frame for the node.", self); + as_log_debug(OS_LOG_DISABLED, "Warning: No size given for node before node was trying to layout itself: %@. Please provide a frame for the node.", self); return; } @@ -962,6 +959,8 @@ - (ASLayout *)calculateLayoutThatFits:(ASSizeRange)constrainedSize // This is fast enough to do it unconditionally. auto key = ASPthreadStaticKey(NULL); BOOL isRootCall = (pthread_getspecific(key) == NULL); + as_activity_scope_verbose(as_activity_create("Calculate node layout", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); + as_log_verbose(ASLayoutLog(), "Calculating layout for %@ sizeRange %@", self, NSStringFromASSizeRange(constrainedSize)); if (isRootCall) { pthread_setspecific(key, kCFBooleanTrue); ASSignpostStart(ASSignpostCalculateLayout); @@ -970,6 +969,7 @@ - (ASLayout *)calculateLayoutThatFits:(ASSizeRange)constrainedSize ASSizeRange styleAndParentSize = ASLayoutElementSizeResolve(self.style.size, parentSize); const ASSizeRange resolvedRange = ASSizeRangeIntersect(constrainedSize, styleAndParentSize); ASLayout *result = [self calculateLayoutThatFits:resolvedRange]; + as_log_verbose(ASLayoutLog(), "Calculated layout %@", result); if (isRootCall) { pthread_setspecific(key, NULL); @@ -1024,6 +1024,12 @@ - (ASLayout *)calculateLayoutThatFits:(ASSizeRange)constrainedSize // Get layout element from the node id layoutElement = [self _locked_layoutElementThatFits:constrainedSize]; +#if ASEnableVerboseLogging + for (NSString *asciiLine in [[layoutElement asciiArtString] componentsSeparatedByString:@"\n"]) { + as_log_verbose(ASLayoutLog(), "%@", asciiLine); + } +#endif + // Certain properties are necessary to set on an element of type ASLayoutSpec if (layoutElement.layoutElementType == ASLayoutElementTypeLayoutSpec) { @@ -1304,6 +1310,7 @@ + (void)scheduleNodeForRecursiveDisplay:(ASDisplayNode *)node }]; }); + as_log_verbose(ASDisplayLog(), "%s %@", sel_getName(_cmd), node); [renderQueue enqueue:node]; } @@ -1906,6 +1913,7 @@ - (NSArray *)subnodes - (void)_insertSubnode:(ASDisplayNode *)subnode atSubnodeIndex:(NSInteger)subnodeIndex sublayerIndex:(NSInteger)sublayerIndex andRemoveSubnode:(ASDisplayNode *)oldSubnode { ASDisplayNodeAssertLockUnownedByCurrentThread(__instanceLock__); + as_log_verbose(ASNodeLog(), "Insert subnode %@ at index %zd of %@ and remove subnode %@", subnode, subnodeIndex, self, oldSubnode); if (subnode == nil || subnode == self) { ASDisplayNodeFailAssert(@"Cannot insert a nil subnode or self as subnode"); @@ -2331,6 +2339,12 @@ - (void)_removeFromSupernodeIfEqualTo:(ASDisplayNode *)supernode - (void)_removeFromSupernode:(ASDisplayNode *)supernode view:(UIView *)view layer:(CALayer *)layer { + // Note: we continue even if supernode is nil to ensure view/layer are removed from hierarchy. + + if (supernode != nil) { + as_log_verbose(ASNodeLog(), "Remove %@ from supernode %@", self, supernode); + } + // Clear supernode's reference to us before removing the view from the hierarchy, as _ASDisplayView // will trigger us to clear our _supernode pointer in willMoveToSuperview:nil. // This may result in removing the last strong reference, triggering deallocation after this method. @@ -2682,7 +2696,7 @@ - (void)exitInterfaceState:(ASInterfaceState)interfaceState if (interfaceState == ASInterfaceStateNone) { return; // This method is a no-op with a 0-bitfield argument, so don't bother recursing. } - ASDisplayNodeLogEvent(self, @"%@ %@", NSStringFromSelector(_cmd), NSStringFromASInterfaceState(interfaceState)); + ASDisplayNodeLogEvent(self, @"%s %@", sel_getName(_cmd), NSStringFromASInterfaceState(interfaceState)); ASDisplayNodePerformBlockOnEveryNode(nil, self, YES, ^(ASDisplayNode *node) { node.interfaceState &= (~interfaceState); }); @@ -2690,6 +2704,8 @@ - (void)exitInterfaceState:(ASInterfaceState)interfaceState - (void)recursivelySetInterfaceState:(ASInterfaceState)newInterfaceState { + as_activity_create_for_scope("Recursively set interface state"); + // Instead of each node in the recursion assuming it needs to schedule itself for display, // setInterfaceState: skips this when handling range-managed nodes (our whole subtree has this set). // If our range manager intends for us to be displayed right now, and didn't before, get started! @@ -2813,7 +2829,14 @@ - (void)setInterfaceState:(ASInterfaceState)newState } } - ASDisplayNodeLogEvent(self, @"interfaceStateDidChange: %@, old: %@", NSStringFromASInterfaceState(newState), NSStringFromASInterfaceState(oldState)); + // Log this change, unless it's just the node going from {} -> {Measure} because that change happens + // for all cell nodes and it isn't currently meaningful. + BOOL measureChangeOnly = ((oldState | newState) == ASInterfaceStateMeasureLayout); + if (!measureChangeOnly) { + as_log_verbose(ASNodeLog(), "%s %@ %@", sel_getName(_cmd), NSStringFromASInterfaceStateChange(oldState, newState), self); + } + + ASDisplayNodeLogEvent(self, @"interfaceStateDidChange: %@", NSStringFromASInterfaceStateChange(oldState, newState)); [self interfaceStateDidChange:newState fromState:oldState]; } @@ -3166,9 +3189,19 @@ - (ASEventLog *)eventLog - (NSMutableArray *)propertiesForDescription { NSMutableArray *result = [NSMutableArray array]; - if (self.debugName.length > 0) { - [result addObject:@{ @"debugName" : ASStringWithQuotesIfMultiword(self.debugName) }]; + ASPushMainThreadAssertionsDisabled(); + + NSString *debugName = self.debugName; + if (debugName.length > 0) { + [result addObject:@{ (id)kCFNull : ASStringWithQuotesIfMultiword(debugName) }]; + } + + NSString *axId = self.accessibilityIdentifier; + if (axId.length > 0) { + [result addObject:@{ (id)kCFNull : ASStringWithQuotesIfMultiword(axId) }]; } + + ASPopMainThreadAssertionsDisabled(); return result; } @@ -3179,7 +3212,10 @@ - (ASEventLog *)eventLog if (self.debugName.length > 0) { [result addObject:@{ @"debugName" : ASStringWithQuotesIfMultiword(self.debugName)}]; } - + if (self.accessibilityIdentifier.length > 0) { + [result addObject:@{ @"axId": ASStringWithQuotesIfMultiword(self.accessibilityIdentifier) }]; + } + CGRect windowFrame = [self _frameInWindow]; if (CGRectIsNull(windowFrame) == NO) { [result addObject:@{ @"frameInWindow" : [NSValue valueWithCGRect:windowFrame] }]; diff --git a/Source/ASDisplayNodeExtras.h b/Source/ASDisplayNodeExtras.h index c49d57df8..aefb445f9 100644 --- a/Source/ASDisplayNodeExtras.h +++ b/Source/ASDisplayNodeExtras.h @@ -27,8 +27,10 @@ * for the nodes will be set to `MYButtonNode.titleNode` and `MYButtonNode.countNode`. */ #if DEBUG + #define ASSetDebugName(node, format, ...) node.debugName = [NSString stringWithFormat:format, __VA_ARGS__] #define ASSetDebugNames(...) _ASSetDebugNames(self.class, @"" # __VA_ARGS__, __VA_ARGS__, nil) #else + #define ASSetDebugName(node, name) #define ASSetDebugNames(...) #endif @@ -78,6 +80,30 @@ __unused static NSString * _Nonnull NSStringFromASInterfaceState(ASInterfaceStat return [NSString stringWithFormat:@"{ %@ }", [states componentsJoinedByString:@" | "]]; } +#define INTERFACE_STATE_DELTA(Name) ({ \ + if ((oldState & ASInterfaceState##Name) != (newState & ASInterfaceState##Name)) { \ + [changes appendFormat:@"%c%s ", (newState & ASInterfaceState##Name ? '+' : '-'), #Name]; \ + } \ +}) + +/// e.g. { +Visible, -Preload } (although that should never actually happen.) +/// NOTE: Changes to MeasureLayout state don't really mean anything so we omit them for now. +__unused static NSString * _Nonnull NSStringFromASInterfaceStateChange(ASInterfaceState oldState, ASInterfaceState newState) +{ + if (oldState == newState) { + return @"{ }"; + } + + NSMutableString *changes = [NSMutableString stringWithString:@"{ "]; + INTERFACE_STATE_DELTA(Preload); + INTERFACE_STATE_DELTA(Display); + INTERFACE_STATE_DELTA(Visible); + [changes appendString:@"}"]; + return changes; +} + +#undef INTERFACE_STATE_DELTA + NS_ASSUME_NONNULL_BEGIN ASDISPLAYNODE_EXTERN_C_BEGIN diff --git a/Source/ASMultiplexImageNode.mm b/Source/ASMultiplexImageNode.mm index 4a2a13404..97652ec52 100644 --- a/Source/ASMultiplexImageNode.mm +++ b/Source/ASMultiplexImageNode.mm @@ -24,6 +24,7 @@ #import #import #import +#import #if AS_PIN_REMOTE_IMAGE #import @@ -450,7 +451,7 @@ - (void)_loadImageIdentifiers // Grab the best possible image we can load right now. id bestImmediatelyAvailableImageIdentifier = nil; UIImage *bestImmediatelyAvailableImage = [self _bestImmediatelyAvailableImageFromDataSource:&bestImmediatelyAvailableImageIdentifier]; - ASMultiplexImageNodeLogDebug(@"[%p] Best immediately available image identifier is %@", self, bestImmediatelyAvailableImageIdentifier); + as_log_verbose(ASImageLoadingLog(), "%@ Best immediately available image identifier is %@", self, bestImmediatelyAvailableImageIdentifier); // Load it. This kicks off cache fetching/downloading, as appropriate. [self _finishedLoadingImage:bestImmediatelyAvailableImage forIdentifier:bestImmediatelyAvailableImageIdentifier error:nil]; @@ -580,6 +581,8 @@ - (void)_loadNextImage return; } + as_activity_create_for_scope("Load next image for multiplex image node"); + as_log_verbose(ASImageLoadingLog(), "Loading image for %@ ident: %@", self, nextImageIdentifier); self.loadingImageIdentifier = nextImageIdentifier; __weak __typeof__(self) weakSelf = self; @@ -595,13 +598,11 @@ - (void)_loadNextImage [strongSelf _finishedLoadingImage:image forIdentifier:imageIdentifier error:error]; }; - ASMultiplexImageNodeLogDebug(@"[%p] Loading next image, ident: %@", self, nextImageIdentifier); - // Ask our data-source if it's got this image. if (_dataSourceFlags.image) { UIImage *image = [_dataSource multiplexImageNode:self imageForImageIdentifier:nextImageIdentifier]; if (image) { - ASMultiplexImageNodeLogDebug(@"[%p] Acquired next image (%@) from data-source", self, nextImageIdentifier); + as_log_verbose(ASImageLoadingLog(), "Acquired image from data source for %@ ident: %@", self, nextImageIdentifier); finishedLoadingBlock(image, nextImageIdentifier, nil); return; } @@ -610,7 +611,7 @@ - (void)_loadNextImage NSURL *nextImageURL = (_dataSourceFlags.URL) ? [_dataSource multiplexImageNode:self URLForImageIdentifier:nextImageIdentifier] : nil; // If we fail to get a URL for the image, we have no source and can't proceed. if (!nextImageURL) { - ASMultiplexImageNodeLogError(@"[%p] Could not acquire URL for next image (%@). Bailing.", self, nextImageIdentifier); + as_log_error(ASImageLoadingLog(), "Could not acquire URL %@ ident: (%@)", self, nextImageIdentifier); finishedLoadingBlock(nil, nil, [NSError errorWithDomain:ASMultiplexImageNodeErrorDomain code:ASMultiplexImageNodeErrorCodeNoSourceForImage userInfo:nil]); return; } @@ -620,14 +621,14 @@ - (void)_loadNextImage if ([[nextImageURL scheme] isEqualToString:kAssetsLibraryURLScheme]) { // Load the asset. [self _loadALAssetWithIdentifier:nextImageIdentifier URL:nextImageURL completion:^(UIImage *downloadedImage, NSError *error) { - ASMultiplexImageNodeCLogDebug(@"[%p] Acquired next image (%@) from asset library", weakSelf, nextImageIdentifier); + as_log_verbose(ASImageLoadingLog(), "Acquired image from assets library for %@ %@", weakSelf, nextImageIdentifier); finishedLoadingBlock(downloadedImage, nextImageIdentifier, error); }]; } // Likewise, if it's a iOS 8 Photo asset, we need to fetch it accordingly. else if (ASPhotosFrameworkImageRequest *request = [ASPhotosFrameworkImageRequest requestWithURL:nextImageURL]) { [self _loadPHAssetWithRequest:request identifier:nextImageIdentifier completion:^(UIImage *image, NSError *error) { - ASMultiplexImageNodeCLogDebug(@"[%p] Acquired next image (%@) from Photos Framework", weakSelf, nextImageIdentifier); + as_log_verbose(ASImageLoadingLog(), "Acquired image from Photos for %@ %@", weakSelf, nextImageIdentifier); finishedLoadingBlock(image, nextImageIdentifier, error); }]; } @@ -642,7 +643,7 @@ - (void)_loadNextImage // If we had a cache-hit, we're done. if (imageFromCache) { - ASMultiplexImageNodeCLogDebug(@"[%p] Acquired next image (%@) from cache", strongSelf, nextImageIdentifier); + as_log_verbose(ASImageLoadingLog(), "Acquired image from cache for %@ id: %@ img: %@", strongSelf, nextImageIdentifier, imageFromCache); finishedLoadingBlock(imageFromCache, nextImageIdentifier, nil); return; } @@ -655,7 +656,12 @@ - (void)_loadNextImage // Otherwise, we've got to download it. [strongSelf _downloadImageWithIdentifier:nextImageIdentifier URL:nextImageURL completion:^(UIImage *downloadedImage, NSError *error) { - ASMultiplexImageNodeCLogDebug(@"[%p] Acquired next image (%@) from download", strongSelf, nextImageIdentifier); + __typeof__(self) strongSelf = weakSelf; + if (downloadedImage) { + as_log_verbose(ASImageLoadingLog(), "Acquired image from download for %@ id: %@ img: %@", strongSelf, nextImageIdentifier, downloadedImage); + } else { + as_log_error(ASImageLoadingLog(), "Error downloading image for %@ id: %@ err: %@", strongSelf, nextImageIdentifier, error); + } finishedLoadingBlock(downloadedImage, nextImageIdentifier, error); }]; }]; @@ -851,7 +857,7 @@ - (void)_finishedLoadingImage:(UIImage *)image forIdentifier:(id)imageIdentifier // We explicitly perform this check because our datasource often doesn't give back immediately available images, even though we might have downloaded one already. // Because we seed this call with bestImmediatelyAvailableImageFromDataSource, we must be careful not to trample an existing image. if (image || imageIdentifierCount == 0) { - ASMultiplexImageNodeLogDebug(@"[%p] loaded -> displaying (%@, %@)", self, imageIdentifier, image); + as_log_verbose(ASImageLoadingLog(), "[%p] loaded -> displaying (%@, %@)", self, imageIdentifier, image); id previousIdentifier = self.loadedImageIdentifier; UIImage *previousImage = self.image; diff --git a/Source/ASNavigationController.m b/Source/ASNavigationController.m index 424b31628..24423ea6c 100644 --- a/Source/ASNavigationController.m +++ b/Source/ASNavigationController.m @@ -16,6 +16,8 @@ // #import +#import +#import @implementation ASNavigationController { @@ -65,39 +67,53 @@ - (NSInteger)visibilityDepthOfChildViewController:(UIViewController *)childViewC - (NSArray *)popToViewController:(UIViewController *)viewController animated:(BOOL)animated { + as_activity_create_for_scope("Pop multiple from ASNavigationController"); NSArray *viewControllers = [super popToViewController:viewController animated:animated]; + as_log_info(ASNodeLog(), "Popped %@ to %@, removing %@", self, viewController, ASGetDescriptionValueString(viewControllers)); + [self visibilityDepthDidChange]; return viewControllers; } - (NSArray *)popToRootViewControllerAnimated:(BOOL)animated { + as_activity_create_for_scope("Pop to root of ASNavigationController"); NSArray *viewControllers = [super popToRootViewControllerAnimated:animated]; + as_log_info(ASNodeLog(), "Popped view controllers %@ from %@", ASGetDescriptionValueString(viewControllers), self); + [self visibilityDepthDidChange]; return viewControllers; } - (void)setViewControllers:(NSArray *)viewControllers { + // NOTE: As of now this method calls through to setViewControllers:animated: so no need to log/activity here. + [super setViewControllers:viewControllers]; [self visibilityDepthDidChange]; } - (void)setViewControllers:(NSArray *)viewControllers animated:(BOOL)animated { + as_activity_create_for_scope("Set view controllers of ASNavigationController"); + as_log_info(ASNodeLog(), "Set view controllers of %@ to %@ animated: %d", self, ASGetDescriptionValueString(viewControllers), animated); [super setViewControllers:viewControllers animated:animated]; [self visibilityDepthDidChange]; } - (void)pushViewController:(UIViewController *)viewController animated:(BOOL)animated { + as_activity_create_for_scope("Push view controller on ASNavigationController"); + as_log_info(ASNodeLog(), "Pushing %@ onto %@", viewController, self); [super pushViewController:viewController animated:animated]; [self visibilityDepthDidChange]; } - (UIViewController *)popViewControllerAnimated:(BOOL)animated { + as_activity_create_for_scope("Pop view controller from ASNavigationController"); UIViewController *viewController = [super popViewControllerAnimated:animated]; + as_log_info(ASNodeLog(), "Popped %@ from %@", viewController, self); [self visibilityDepthDidChange]; return viewController; } diff --git a/Source/ASNetworkImageNode.mm b/Source/ASNetworkImageNode.mm index d462c3836..d6bd4dfbe 100755 --- a/Source/ASNetworkImageNode.mm +++ b/Source/ASNetworkImageNode.mm @@ -26,6 +26,7 @@ #import #import #import +#import #if AS_PIN_REMOTE_IMAGE #import @@ -417,6 +418,7 @@ - (void)handleProgressImage:(UIImage *)progressImage progress:(CGFloat)progress return; } + as_log_verbose(ASImageLoadingLog(), "Received progress image for %@ q: %.2g id: %@", self, progress, progressImage); [self _locked_setCurrentImageQuality:progress]; [self _locked__setImage:progressImage]; } @@ -443,12 +445,14 @@ - (void)_updateProgressImageBlockOnDownloaderIfNeeded // Unbind from the previous download. if (oldDownloadIDForProgressBlock != nil) { + as_log_verbose(ASImageLoadingLog(), "Disabled progress images for %@ id: %@", self, oldDownloadIDForProgressBlock); [_downloader setProgressImageBlock:nil callbackQueue:dispatch_get_main_queue() withDownloadIdentifier:oldDownloadIDForProgressBlock]; } // Bind to the current download. if (newDownloadIDForProgressBlock != nil) { __weak __typeof(self) weakSelf = self; + as_log_verbose(ASImageLoadingLog(), "Enabled progress images for %@ id: %@", self, newDownloadIDForProgressBlock); [_downloader setProgressImageBlock:^(UIImage * _Nonnull progressImage, CGFloat progress, id _Nullable downloadIdentifier) { [weakSelf handleProgressImage:progressImage progress:progress downloadIdentifier:downloadIdentifier]; } callbackQueue:dispatch_get_main_queue() withDownloadIdentifier:newDownloadIDForProgressBlock]; @@ -507,6 +511,7 @@ - (void)_locked_cancelDownloadAndClearImageWithResumePossibility:(BOOL)storeResu if (_cacheFlags.cacheSupportsClearing) { if (_URL != nil) { + as_log_verbose(ASImageLoadingLog(), "Clearing cached image for %@ url: %@", self, _URL); [_cache clearFetchedImageFromCacheWithURL:_URL]; } } @@ -526,8 +531,10 @@ - (void)_locked_cancelImageDownloadWithResumePossibility:(BOOL)storeResume if (_downloadIdentifier) { if (storeResume && _downloaderFlags.downloaderImplementsCancelWithResume) { + as_log_verbose(ASImageLoadingLog(), "Canceling image download w resume for %@ id: %@", self, _downloadIdentifier); [_downloader cancelImageDownloadWithResumePossibilityForIdentifier:_downloadIdentifier]; } else { + as_log_verbose(ASImageLoadingLog(), "Canceling image download no resume for %@ id: %@", self, _downloadIdentifier); [_downloader cancelImageDownloadForIdentifier:_downloadIdentifier]; } } @@ -550,7 +557,8 @@ - (void)_downloadImageWithCompletion:(void (^)(id ima ASDN::MutexLocker l(__instanceLock__); url = _URL; } - + + downloadIdentifier = [_downloader downloadImageWithURL:url callbackQueue:dispatch_get_main_queue() downloadProgress:NULL @@ -559,6 +567,7 @@ - (void)_downloadImageWithCompletion:(void (^)(id ima finished(imageContainer, error, downloadIdentifier); } }]; + as_log_verbose(ASImageLoadingLog(), "Downloading image for %@ url: %@", self, url); { ASDN::MutexLocker l(__instanceLock__); @@ -574,6 +583,7 @@ - (void)_downloadImageWithCompletion:(void (^)(id ima if (cancelAndReattempt) { if (downloadIdentifier != nil) { + as_log_verbose(ASImageLoadingLog(), "Canceling image download no resume for %@ id: %@", self, downloadIdentifier); [_downloader cancelImageDownloadForIdentifier:downloadIdentifier]; } [self _downloadImageWithCompletion:finished]; @@ -654,13 +664,15 @@ - (void)_lazilyLoadImageIfNecessary }); } else { __weak __typeof__(self) weakSelf = self; - void (^finished)(id , NSError *, id downloadIdentifier) = ^(id imageContainer, NSError *error, id downloadIdentifier) { + auto finished = ^(id imageContainer, NSError *error, id downloadIdentifier) { __typeof__(self) strongSelf = weakSelf; if (strongSelf == nil) { return; } + as_log_verbose(ASImageLoadingLog(), "Downloaded image for %@ img: %@ url: %@", self, [imageContainer asdk_image], url); + // Grab the lock for the rest of the block ASDN::MutexLocker l(strongSelf->__instanceLock__); @@ -702,6 +714,7 @@ - (void)_lazilyLoadImageIfNecessary _cacheUUID = cacheUUID; __instanceLock__.unlock(); + as_log_verbose(ASImageLoadingLog(), "Decaching image for %@ url: %@", self, URL); [_cache cachedImageWithURL:URL callbackQueue:dispatch_get_main_queue() completion:^(id imageContainer) { @@ -717,6 +730,7 @@ - (void)_lazilyLoadImageIfNecessary if ([imageContainer asdk_image] == nil && _downloader != nil) { [self _downloadImageWithCompletion:finished]; } else { + as_log_verbose(ASImageLoadingLog(), "Decached image for %@ img: %@ url: %@", self, [imageContainer asdk_image], URL); finished(imageContainer, nil, nil); } }]; diff --git a/Source/ASRunLoopQueue.mm b/Source/ASRunLoopQueue.mm index e45ac0999..004d4abb9 100644 --- a/Source/ASRunLoopQueue.mm +++ b/Source/ASRunLoopQueue.mm @@ -16,9 +16,11 @@ // #import +#import +#import #import #import -#import +#import #import #import #import @@ -190,7 +192,10 @@ @interface ASRunLoopQueue () { CFRunLoopObserverRef _runLoopObserver; NSPointerArray *_internalQueue; // Use NSPointerArray so we can decide __strong or __weak per-instance. ASDN::RecursiveMutex _internalQueueLock; - + + // In order to not pollute the top-level activities, each queue has 1 root activity. + os_activity_t _rootActivity; + #if ASRunLoopQueueLoggingEnabled NSTimer *_runloopQueueLoggingTimer; #endif @@ -272,6 +277,15 @@ - (instancetype)initWithRunLoop:(CFRunLoopRef)runloop retainObjects:(BOOL)retain _queueConsumer = handlerBlock; _batchSize = 1; _ensureExclusiveMembership = YES; + + // We don't want to pollute the top-level app activities with run loop batches, so we create one top-level + // activity per queue, and each batch activity joins that one instead. + _rootActivity = as_activity_create("Process run loop queue items", OS_ACTIVITY_NONE, OS_ACTIVITY_FLAG_DEFAULT); + { + // Log a message identifying this queue into the queue's root activity. + as_activity_scope_verbose(_rootActivity); + as_log_verbose(ASDisplayLog(), "Created run loop queue: %@", self); + } // Self is guaranteed to outlive the observer. Without the high cost of a weak pointer, // __unsafe_unretained allows us to avoid flagging the memory cycle detector. @@ -375,16 +389,17 @@ - (void)processQueue } // itemsToProcess will be empty if _queueConsumer == nil so no need to check again. - if (itemsToProcess.empty() == false) { -#if ASRunLoopQueueLoggingEnabled - NSLog(@"<%@> - Starting processing of: %ld", self, itemsToProcess.size()); -#endif + auto count = itemsToProcess.size(); + if (count > 0) { + as_activity_scope_verbose(as_activity_create("Process run loop queue batch", _rootActivity, OS_ACTIVITY_FLAG_DEFAULT)); auto itemsEnd = itemsToProcess.cend(); for (auto iterator = itemsToProcess.begin(); iterator < itemsEnd; iterator++) { - _queueConsumer(*iterator, isQueueDrained && iterator == itemsEnd - 1); -#if ASRunLoopQueueLoggingEnabled - NSLog(@"<%@> - Finished processing 1 item", self); -#endif + __unsafe_unretained id value = *iterator; + _queueConsumer(value, isQueueDrained && iterator == itemsEnd - 1); + as_log_verbose(ASDisplayLog(), "processed %@", value); + } + if (count > 1) { + as_log_verbose(ASDisplayLog(), "processed %lu items", (unsigned long)count); } } diff --git a/Source/ASTabBarController.m b/Source/ASTabBarController.m index 73b698adb..f43ecf784 100644 --- a/Source/ASTabBarController.m +++ b/Source/ASTabBarController.m @@ -16,6 +16,7 @@ // #import +#import @implementation ASTabBarController { @@ -72,12 +73,18 @@ - (void)setViewControllers:(NSArray<__kindof UIViewController *> *)viewControlle - (void)setSelectedIndex:(NSUInteger)selectedIndex { + as_activity_create_for_scope("Set selected index of ASTabBarController"); + as_log_info(ASNodeLog(), "Selected tab %tu of %@", selectedIndex, self); + [super setSelectedIndex:selectedIndex]; [self visibilityDepthDidChange]; } - (void)setSelectedViewController:(__kindof UIViewController *)selectedViewController { + as_activity_create_for_scope("Set selected view controller of ASTabBarController"); + as_log_info(ASNodeLog(), "Selected view controller %@ of %@", selectedViewController, self); + [super setSelectedViewController:selectedViewController]; [self visibilityDepthDidChange]; } diff --git a/Source/ASTextNode.mm b/Source/ASTextNode.mm index acfe9e6bd..18f0198ef 100644 --- a/Source/ASTextNode.mm +++ b/Source/ASTextNode.mm @@ -252,7 +252,7 @@ - (NSString *)_plainStringForDescription NSMutableArray *result = [super propertiesForDescription]; NSString *plainString = [self _plainStringForDescription]; if (plainString.length > 0) { - [result insertObject:@{ @"text" : ASStringWithQuotesIfMultiword(plainString) } atIndex:0]; + [result addObject:@{ (id)kCFNull : ASStringWithQuotesIfMultiword(plainString) }]; } return result; } diff --git a/Source/ASViewController.mm b/Source/ASViewController.mm index f9af1bfe4..d4dab1a62 100644 --- a/Source/ASViewController.mm +++ b/Source/ASViewController.mm @@ -19,12 +19,11 @@ #import #import #import +#import #import #import #import -#define AS_LOG_VISIBILITY_CHANGES 0 - @implementation ASViewController { BOOL _ensureDisplayed; @@ -169,7 +168,11 @@ - (void)viewDidLayoutSubviews - (void)viewWillAppear:(BOOL)animated { + as_activity_create_for_scope("ASViewController will appear"); + as_log_debug(ASNodeLog(), "View controller %@ will appear", self); + [super viewWillAppear:animated]; + _ensureDisplayed = YES; // A layout pass is forced this early to get nodes like ASCollectionNode, ASTableNode etc. @@ -191,7 +194,7 @@ - (void)viewWillAppear:(BOOL)animated - (void)visibilityDepthDidChange { ASLayoutRangeMode rangeMode = ASLayoutRangeModeForVisibilityDepth(self.visibilityDepth); -#if AS_LOG_VISIBILITY_CHANGES +#if ASEnableVerboseLogging NSString *rangeModeString; switch (rangeMode) { case ASLayoutRangeModeMinimum: @@ -213,7 +216,7 @@ - (void)visibilityDepthDidChange default: break; } - NSLog(@"Updating visibility of:%@ to: %@ (visibility depth: %d)", self, rangeModeString, self.visibilityDepth); + as_log_verbose(ASNodeLog(), "Updating visibility of %@ to: %@ (visibility depth: %zd)", self, rangeModeString, self.visibilityDepth); #endif [self updateCurrentRangeModeWithModeIfPossible:rangeMode]; } @@ -284,6 +287,8 @@ - (void)propagateNewTraitCollection:(ASPrimitiveTraitCollection)traitCollection ASPrimitiveTraitCollection oldTraitCollection = self.node.primitiveTraitCollection; if (ASPrimitiveTraitCollectionIsEqualToASPrimitiveTraitCollection(traitCollection, oldTraitCollection) == NO) { + as_activity_scope_verbose(as_activity_create("Propagate ASViewController trait collection", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); + as_log_debug(ASNodeLog(), "Propagating new traits for %@: %@", self, NSStringFromASPrimitiveTraitCollection(traitCollection)); self.node.primitiveTraitCollection = traitCollection; NSArray> *children = [self.node sublayoutElements]; @@ -295,6 +300,7 @@ - (void)propagateNewTraitCollection:(ASPrimitiveTraitCollection)traitCollection #pragma clang diagnostic ignored "-Wdeprecated-declarations" // Once we've propagated all the traits, layout this node. // Remeasure the node with the latest constrained size – old constrained size may be incorrect. + as_activity_scope_verbose(as_activity_create("Layout ASViewController node with new traits", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); [_node layoutThatFits:[self nodeConstrainedSize]]; #pragma clang diagnostic pop } diff --git a/Source/Base/ASBaseDefines.h b/Source/Base/ASBaseDefines.h index b269096f4..b75f51c16 100755 --- a/Source/Base/ASBaseDefines.h +++ b/Source/Base/ASBaseDefines.h @@ -15,10 +15,6 @@ // http://www.apache.org/licenses/LICENSE-2.0 // -#pragma once - -#import - // The C++ compiler mangles C function names. extern "C" { /* your C functions */ } prevents this. // You should wrap all C function prototypes declared in headers with ASDISPLAYNODE_EXTERN_C_BEGIN/END, even if // they are included only from .m (Objective-C) files. It's common for .m files to start using C++ diff --git a/Source/Base/ASLog.h b/Source/Base/ASLog.h index ae734e0ba..412b9d905 100644 --- a/Source/Base/ASLog.h +++ b/Source/Base/ASLog.h @@ -16,93 +16,106 @@ // #import +#import #import +#import +#import -/// The signposts we use. Signposts are grouped by color. The SystemTrace.tracetemplate file -/// should be kept up-to-date with these values. -typedef NS_ENUM(uint32_t, ASSignpostName) { - // Collection/Table (Blue) - ASSignpostDataControllerBatch = 300, // Alloc/layout nodes before collection update. - ASSignpostRangeControllerUpdate, // Ranges update pass. - ASSignpostCollectionUpdate, // Entire update process, from -endUpdates to [super perform…] - - // Rendering (Green) - ASSignpostLayerDisplay = 325, // Client display callout. - ASSignpostRunLoopQueueBatch, // One batch of ASRunLoopQueue. - - // Layout (Purple) - ASSignpostCalculateLayout = 350, // Start of calculateLayoutThatFits to end. Max 1 per thread. - - // Misc (Orange) - ASSignpostDeallocQueueDrain = 375, // One chunk of dealloc queue work. arg0 is count. - ASSignpostCATransactionLayout, // The CA transaction commit layout phase. - ASSignpostCATransactionCommit // The CA transaction commit post-layout phase. -}; - -typedef NS_ENUM(uintptr_t, ASSignpostColor) { - ASSignpostColorBlue, - ASSignpostColorGreen, - ASSignpostColorPurple, - ASSignpostColorOrange, - ASSignpostColorRed, - ASSignpostColorDefault -}; - -static inline ASSignpostColor ASSignpostGetColor(ASSignpostName name, ASSignpostColor colorPref) { - if (colorPref == ASSignpostColorDefault) { - return (ASSignpostColor)((name / 25) % 4); - } else { - return colorPref; - } -} - -#define ASMultiplexImageNodeLogDebug(...) -#define ASMultiplexImageNodeCLogDebug(...) - -#define ASMultiplexImageNodeLogError(...) -#define ASMultiplexImageNodeCLogError(...) - -#define AS_KDEBUG_ENABLE defined(PROFILE) && __has_include() - -#if AS_KDEBUG_ENABLE - -#import - -// These definitions are required to build the backward-compatible kdebug trace -// on the iOS 10 SDK. The kdebug_trace function crashes if run on iOS 9 and earlier. -// It's valuable to support trace signposts on iOS 9, because A5 devices don't support iOS 10. -#ifndef DBG_MACH_CHUD -#define DBG_MACH_CHUD 0x0A -#define DBG_FUNC_NONE 0 -#define DBG_FUNC_START 1 -#define DBG_FUNC_END 2 -#define DBG_APPS 33 -#define SYS_kdebug_trace 180 -#define KDBG_CODE(Class, SubClass, code) (((Class & 0xff) << 24) | ((SubClass & 0xff) << 16) | ((code & 0x3fff) << 2)) -#define APPSDBG_CODE(SubClass,code) KDBG_CODE(DBG_APPS, SubClass, code) +#ifndef ASEnableLogs + #define ASEnableLogs 1 #endif -// Currently we'll reserve arg3. -#define ASSignpost(name, identifier, arg2, color) \ - AS_AT_LEAST_IOS10 ? kdebug_signpost(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)) \ - : syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_NONE, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)); - -#define ASSignpostStartCustom(name, identifier, arg2) \ - AS_AT_LEAST_IOS10 ? kdebug_signpost_start(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, 0) \ - : syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_START, (uintptr_t)identifier, (uintptr_t)arg2, 0, 0); -#define ASSignpostStart(name) ASSignpostStartCustom(name, self, 0) +#ifndef ASEnableVerboseLogging + #define ASEnableVerboseLogging 0 +#endif -#define ASSignpostEndCustom(name, identifier, arg2, color) \ - AS_AT_LEAST_IOS10 ? kdebug_signpost_end(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)) \ - : syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_END, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)); -#define ASSignpostEnd(name) ASSignpostEndCustom(name, self, 0, ASSignpostColorDefault) +ASDISPLAYNODE_EXTERN_C_BEGIN + +/// Log for general node events e.g. interfaceState, didLoad. +#define ASNodeLogEnabled 1 +os_log_t ASNodeLog(); + +/// Log for layout-specific events e.g. calculateLayout. +#define ASLayoutLogEnabled 1 +os_log_t ASLayoutLog(); + +/// Log for display-specific events e.g. display queue batches. +#define ASDisplayLogEnabled 1 +os_log_t ASDisplayLog(); + +/// Log for collection events e.g. reloadData, performBatchUpdates. +#define ASCollectionLogEnabled 1 +os_log_t ASCollectionLog(); + +/// Log for ASNetworkImageNode and ASMultiplexImageNode events. +#define ASImageLoadingLogEnabled 1 +os_log_t ASImageLoadingLog(); + +/// Specialized log for our main thread deallocation trampoline. +#define ASMainThreadDeallocationLogEnabled 0 +os_log_t ASMainThreadDeallocationLog(); + +ASDISPLAYNODE_EXTERN_C_END + +/** + * The activity tracing system changed a lot between iOS 9 and 10. + * In iOS 10, the system was merged with logging and became much more powerful + * and adopted a new API. + * + * The legacy API is visible, but its functionality is extremely limited and the API is so different + * that we don't bother with it. For example, activities described by os_activity_start/end are not + * reflected in the log whereas activities described by the newer + * os_activity_scope are. So unfortunately we must use these iOS 10 + * APIs to get meaningful logging data. + */ +#if OS_LOG_TARGET_HAS_10_12_FEATURES + +#define OS_ACTIVITY_NULLABLE nullable +#define AS_ACTIVITY_CURRENT OS_ACTIVITY_CURRENT +#define as_activity_scope(activity) os_activity_scope(activity) +#define as_activity_apply(activity, block) os_activity_apply(activity, block) +#define as_activity_create(description, parent_activity, flags) os_activity_create(description, parent_activity, flags) +#define as_activity_scope_enter(activity, statePtr) os_activity_scope_enter(activity, statePtr) +#define as_activity_scope_leave(statePtr) os_activity_scope_leave(statePtr) +#define as_activity_get_identifier(activity, outParentID) os_activity_get_identifier(activity, outParentID) #else -#define ASSignpost(name, identifier, arg2, color) -#define ASSignpostStartCustom(name, identifier, arg2) -#define ASSignpostStart(name) -#define ASSignpostEndCustom(name, identifier, arg2, color) -#define ASSignpostEnd(name) +#define OS_ACTIVITY_NULLABLE +#define AS_ACTIVITY_CURRENT OS_ACTIVITY_NULL +#define as_activity_scope(activity) +#define as_activity_apply(activity, block) +#define as_activity_create(description, parent_activity, flags) OS_ACTIVITY_NULL +#define as_activity_scope_enter(activity, statePtr) +#define as_activity_scope_leave(statePtr) +#define as_activity_get_identifier(activity, outParentID) (os_activity_id_t)0 + +#endif // OS_LOG_TARGET_HAS_10_12_FEATURES + +// Create activities only when verbose enabled. Doesn't materially impact performance, but good if we're cluttering up +// activity scopes and reducing readability. +#if ASEnableVerboseLogging + #define as_activity_scope_verbose(activity) as_activity_scope(activity) +#else + #define as_activity_scope_verbose(activity) +#endif +// Convenience for: as_activity_scope(as_activity_create(description, AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)) +#define as_activity_create_for_scope(description) \ + as_activity_scope(as_activity_create(description, AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)) + +/** + * The logging macros are not guarded by deployment-target checks like the activity macros are, but they are + * only available on iOS >= 9 at runtime, so just make them conditional. + */ +#define as_log_create(subsystem, category) (AS_AT_LEAST_IOS9 ? os_log_create(subsystem, category) : (os_log_t)0) +#define as_log_debug(log, format, ...) (AS_AT_LEAST_IOS9 ? os_log_debug(log, format, ##__VA_ARGS__) : (void)0) +#define as_log_info(log, format, ...) (AS_AT_LEAST_IOS9 ? os_log_info(log, format, ##__VA_ARGS__) : (void)0) +#define as_log_error(log, format, ...) (AS_AT_LEAST_IOS9 ? os_log_error(log, format, ##__VA_ARGS__) : (void)0) +#define as_log_fault(log, format, ...) (AS_AT_LEAST_IOS9 ? os_log_fault(log, format, ##__VA_ARGS__) : (void)0) + +#if ASEnableVerboseLogging + #define as_log_verbose(log, format, ...) as_log_debug(log, format, ##__VA_ARGS__) +#else + #define as_log_verbose(log, format, ...) #endif diff --git a/Source/Base/ASLog.m b/Source/Base/ASLog.m new file mode 100644 index 000000000..42148de9f --- /dev/null +++ b/Source/Base/ASLog.m @@ -0,0 +1,37 @@ +// +// ASLog.m +// Texture +// +// Copyright (c) 2017-present, Pinterest, Inc. All rights reserved. +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// + +#import + +os_log_t ASNodeLog() { + return ASCreateOnce((ASEnableLogs && ASNodeLogEnabled) ? as_log_create("org.TextureGroup.Texture", "Node") : OS_LOG_DISABLED); +} + +os_log_t ASLayoutLog() { + return ASCreateOnce((ASEnableLogs && ASLayoutLogEnabled) ? as_log_create("org.TextureGroup.Texture", "Layout") : OS_LOG_DISABLED); +} + +os_log_t ASCollectionLog() { + return ASCreateOnce((ASEnableLogs && ASCollectionLogEnabled) ? as_log_create("org.TextureGroup.Texture", "Collection") : OS_LOG_DISABLED); +} + +os_log_t ASDisplayLog() { + return ASCreateOnce((ASEnableLogs && ASDisplayLogEnabled) ? as_log_create("org.TextureGroup.Texture", "Display") : OS_LOG_DISABLED); +} + +os_log_t ASImageLoadingLog() { + return ASCreateOnce((ASEnableLogs && ASImageLoadingLogEnabled) ? as_log_create("org.TextureGroup.Texture", "ImageLoading") : OS_LOG_DISABLED); +} + +os_log_t ASMainThreadDeallocationLog() { + return ASCreateOnce((ASEnableLogs && ASMainThreadDeallocationLogEnabled) ? as_log_create("org.TextureGroup.Texture", "MainDealloc") : OS_LOG_DISABLED); +} diff --git a/Source/Base/ASSignpost.h b/Source/Base/ASSignpost.h new file mode 100644 index 000000000..c11a71878 --- /dev/null +++ b/Source/Base/ASSignpost.h @@ -0,0 +1,94 @@ +// +// ASSignpost.h +// Texture +// +// Copyright (c) 2017-present, Pinterest, Inc. All rights reserved. +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// + +/// The signposts we use. Signposts are grouped by color. The SystemTrace.tracetemplate file +/// should be kept up-to-date with these values. +typedef NS_ENUM(uint32_t, ASSignpostName) { + // Collection/Table (Blue) + ASSignpostDataControllerBatch = 300, // Alloc/layout nodes before collection update. + ASSignpostRangeControllerUpdate, // Ranges update pass. + ASSignpostCollectionUpdate, // Entire update process, from -endUpdates to [super perform…] + + // Rendering (Green) + ASSignpostLayerDisplay = 325, // Client display callout. + ASSignpostRunLoopQueueBatch, // One batch of ASRunLoopQueue. + + // Layout (Purple) + ASSignpostCalculateLayout = 350, // Start of calculateLayoutThatFits to end. Max 1 per thread. + + // Misc (Orange) + ASSignpostDeallocQueueDrain = 375, // One chunk of dealloc queue work. arg0 is count. + ASSignpostCATransactionLayout, // The CA transaction commit layout phase. + ASSignpostCATransactionCommit // The CA transaction commit post-layout phase. +}; + +typedef NS_ENUM(uintptr_t, ASSignpostColor) { + ASSignpostColorBlue, + ASSignpostColorGreen, + ASSignpostColorPurple, + ASSignpostColorOrange, + ASSignpostColorRed, + ASSignpostColorDefault +}; + +static inline ASSignpostColor ASSignpostGetColor(ASSignpostName name, ASSignpostColor colorPref) { + if (colorPref == ASSignpostColorDefault) { + return (ASSignpostColor)((name / 25) % 4); + } else { + return colorPref; + } +} + +#define AS_KDEBUG_ENABLE defined(PROFILE) && __has_include() + +#if AS_KDEBUG_ENABLE + +#import + +// These definitions are required to build the backward-compatible kdebug trace +// on the iOS 10 SDK. The kdebug_trace function crashes if run on iOS 9 and earlier. +// It's valuable to support trace signposts on iOS 9, because A5 devices don't support iOS 10. +#ifndef DBG_MACH_CHUD +#define DBG_MACH_CHUD 0x0A +#define DBG_FUNC_NONE 0 +#define DBG_FUNC_START 1 +#define DBG_FUNC_END 2 +#define DBG_APPS 33 +#define SYS_kdebug_trace 180 +#define KDBG_CODE(Class, SubClass, code) (((Class & 0xff) << 24) | ((SubClass & 0xff) << 16) | ((code & 0x3fff) << 2)) +#define APPSDBG_CODE(SubClass,code) KDBG_CODE(DBG_APPS, SubClass, code) +#endif + +// Currently we'll reserve arg3. +#define ASSignpost(name, identifier, arg2, color) \ +AS_AT_LEAST_IOS10 ? kdebug_signpost(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)) \ +: syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_NONE, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)); + +#define ASSignpostStartCustom(name, identifier, arg2) \ +AS_AT_LEAST_IOS10 ? kdebug_signpost_start(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, 0) \ +: syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_START, (uintptr_t)identifier, (uintptr_t)arg2, 0, 0); +#define ASSignpostStart(name) ASSignpostStartCustom(name, self, 0) + +#define ASSignpostEndCustom(name, identifier, arg2, color) \ +AS_AT_LEAST_IOS10 ? kdebug_signpost_end(name, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)) \ +: syscall(SYS_kdebug_trace, APPSDBG_CODE(DBG_MACH_CHUD, name) | DBG_FUNC_END, (uintptr_t)identifier, (uintptr_t)arg2, 0, ASSignpostGetColor(name, color)); +#define ASSignpostEnd(name) ASSignpostEndCustom(name, self, 0, ASSignpostColorDefault) + +#else + +#define ASSignpost(name, identifier, arg2, color) +#define ASSignpostStartCustom(name, identifier, arg2) +#define ASSignpostStart(name) +#define ASSignpostEndCustom(name, identifier, arg2, color) +#define ASSignpostEnd(name) + +#endif diff --git a/Source/Details/ASBatchContext.mm b/Source/Details/ASBatchContext.mm index 7a93a0b69..8598126d2 100644 --- a/Source/Details/ASBatchContext.mm +++ b/Source/Details/ASBatchContext.mm @@ -17,6 +17,7 @@ #import +#import #import typedef NS_ENUM(NSInteger, ASBatchContextState) { @@ -63,6 +64,7 @@ - (void)beginBatchFetching - (void)completeBatchFetching:(BOOL)didComplete { if (didComplete) { + as_log_debug(ASCollectionLog(), "Completed batch fetch with context %@", self); ASDN::MutexLocker l(__instanceLock__); _state = ASBatchContextStateCompleted; } diff --git a/Source/Details/ASDataController.mm b/Source/Details/ASDataController.mm index bace28112..932a12dac 100644 --- a/Source/Details/ASDataController.mm +++ b/Source/Details/ASDataController.mm @@ -24,8 +24,11 @@ #import #import #import +#import #import #import +#import +#import #import #import #import @@ -168,7 +171,11 @@ - (void)batchAllocateNodesFromElements:(NSArray *)element for (NSUInteger i = 0; i < count; i += batchSize) { NSRange batchedRange = NSMakeRange(i, MIN(count - i, batchSize)); NSArray *batchedElements = [elements subarrayWithRange:batchedRange]; - NSArray *nodes = [self _allocateNodesFromElements:batchedElements andLayout:shouldLayout]; + NSArray *nodes; + { + as_activity_create_for_scope("Data controller batch"); + nodes = [self _allocateNodesFromElements:batchedElements andLayout:shouldLayout]; + } batchCompletionHandler(batchedElements, nodes); } @@ -491,7 +498,14 @@ - (void)updateWithChangeSet:(_ASHierarchyChangeSet *)changeSet ASDisplayNodeAssertMainThread(); if (changeSet.includesReloadData) { - _initialReloadDataHasBeenCalled = YES; + if (_initialReloadDataHasBeenCalled) { + as_log_debug(ASCollectionLog(), "reloadData %@", ASViewToDisplayNode(ASDynamicCast(self.dataSource, UIView))); + } else { + as_log_debug(ASCollectionLog(), "Initial reloadData %@", ASViewToDisplayNode(ASDynamicCast(self.dataSource, UIView))); + _initialReloadDataHasBeenCalled = YES; + } + } else { + as_log_debug(ASCollectionLog(), "performBatchUpdates %@ %@", ASViewToDisplayNode(ASDynamicCast(self.dataSource, UIView)), changeSet); } NSTimeInterval transactionQueueFlushDuration = 0.0f; @@ -504,6 +518,7 @@ - (void)updateWithChangeSet:(_ASHierarchyChangeSet *)changeSet // See ASUICollectionViewTests.testThatIssuingAnUpdateBeforeInitialReloadIsUnacceptable // for the issue that UICollectionView has that we're choosing to workaround. if (!_initialReloadDataHasBeenCalled) { + as_log_debug(ASCollectionLog(), "%@ Skipped update because load hasn't happened.", ASObjectDescriptionMakeTiny(_dataSource)); [changeSet executeCompletionHandlerWithFinished:YES]; return; } @@ -546,28 +561,37 @@ - (void)updateWithChangeSet:(_ASHierarchyChangeSet *)changeSet return; } - // Mutable copy of current data. - ASElementMap *previousMap = _pendingMap; - ASMutableElementMap *mutableMap = [previousMap mutableCopy]; - - BOOL canDelegateLayout = (_layoutDelegate != nil); + BOOL canDelegateLayout; + ASElementMap *newMap; + id layoutContext; + { + as_activity_scope(as_activity_create("Latch new data for collection update", changeSet.rootActivity, OS_ACTIVITY_FLAG_DEFAULT)); + // Mutable copy of current data. + ASElementMap *previousMap = _pendingMap; + ASMutableElementMap *mutableMap = [previousMap mutableCopy]; - // Step 1: Update the mutable copies to match the data source's state - [self _updateSectionContextsInMap:mutableMap changeSet:changeSet]; - ASPrimitiveTraitCollection existingTraitCollection = [self.node primitiveTraitCollection]; - [self _updateElementsInMap:mutableMap changeSet:changeSet traitCollection:existingTraitCollection shouldFetchSizeRanges:(! canDelegateLayout) previousMap:previousMap]; - - // Step 2: Clone the new data - ASElementMap *newMap = [mutableMap copy]; - self.pendingMap = newMap; - - // Step 3: Ask layout delegate for contexts - id layoutContext = nil; - if (canDelegateLayout) { - layoutContext = [_layoutDelegate layoutContextWithElements:newMap]; + canDelegateLayout = (_layoutDelegate != nil); + + // Step 1: Update the mutable copies to match the data source's state + [self _updateSectionContextsInMap:mutableMap changeSet:changeSet]; + ASPrimitiveTraitCollection existingTraitCollection = [self.node primitiveTraitCollection]; + [self _updateElementsInMap:mutableMap changeSet:changeSet traitCollection:existingTraitCollection shouldFetchSizeRanges:(! canDelegateLayout) previousMap:previousMap]; + + // Step 2: Clone the new data + newMap = [mutableMap copy]; + self.pendingMap = newMap; + + // Step 3: Ask layout delegate for contexts + if (canDelegateLayout) { + layoutContext = [_layoutDelegate layoutContextWithElements:newMap]; + } } + + as_log_debug(ASCollectionLog(), "New content: %@", newMap.smallDescription); dispatch_group_async(_editingTransactionGroup, _editingTransactionQueue, ^{ + __block __unused os_activity_scope_state_s preparationScope = {}; // unused if deployment target < iOS10 + as_activity_scope_enter(as_activity_create("Prepare nodes for collection update", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT), &preparationScope); // Step 4: Allocate and layout elements if can't delegate NSArray *elementsToProcess; if (canDelegateLayout) { @@ -588,8 +612,9 @@ - (void)updateWithChangeSet:(_ASHierarchyChangeSet *)changeSet if (canDelegateLayout) { [_layoutDelegate prepareLayoutWithContext:layoutContext]; } - + [_mainSerialQueue performBlockOnMainThread:^{ + as_activity_scope_leave(&preparationScope); [_delegate dataController:self willUpdateWithChangeSet:changeSet]; // Step 5: Deploy the new data as "completed" and inform delegate diff --git a/Source/Details/ASElementMap.h b/Source/Details/ASElementMap.h index 11366e85b..fb53ee818 100644 --- a/Source/Details/ASElementMap.h +++ b/Source/Details/ASElementMap.h @@ -96,6 +96,11 @@ AS_SUBCLASSING_RESTRICTED */ - (nullable ASCollectionElement *)elementForLayoutAttributes:(UICollectionViewLayoutAttributes *)layoutAttributes; +/** + * A very terse description e.g. { itemCounts = [ ] } + */ +@property (atomic, readonly) NSString *smallDescription; + #pragma mark - Initialization -- Only Useful to ASDataController diff --git a/Source/Details/ASElementMap.m b/Source/Details/ASElementMap.m index 5c3a80c05..a4195e1e1 100644 --- a/Source/Details/ASElementMap.m +++ b/Source/Details/ASElementMap.m @@ -183,6 +183,18 @@ - (NSUInteger)countByEnumeratingWithState:(NSFastEnumerationState *)state object return [_elementToIndexPathMap countByEnumeratingWithState:state objects:buffer count:len]; } +- (NSString *)smallDescription +{ + NSMutableArray *sectionDescriptions = [NSMutableArray array]; + + NSUInteger i = 0; + for (NSArray *section in _sectionsOfItems) { + [sectionDescriptions addObject:[NSString stringWithFormat:@"", i, section.count]]; + i++; + } + return ASObjectDescriptionMakeWithoutObject(@[ @{ @"itemCounts": sectionDescriptions }]); +} + #pragma mark - ASDescriptionProvider - (NSString *)description diff --git a/Source/Details/ASObjectDescriptionHelpers.m b/Source/Details/ASObjectDescriptionHelpers.m index c62c6f154..b34872868 100644 --- a/Source/Details/ASObjectDescriptionHelpers.m +++ b/Source/Details/ASObjectDescriptionHelpers.m @@ -47,6 +47,9 @@ [strings addObject:[NSString stringWithFormat:@"%lu", (unsigned long)[indexPath indexAtPosition:i]]]; } return [NSString stringWithFormat:@"(%@)", [strings componentsJoinedByString:@", "]]; + } else if ([object respondsToSelector:@selector(componentsJoinedByString:)]) { + // e.g. "[ ]" + return [NSString stringWithFormat:@"[ %@ ]", [object componentsJoinedByString:@" "]]; } return [object description]; } @@ -56,7 +59,13 @@ NSMutableArray *components = [NSMutableArray array]; for (NSDictionary *properties in propertyGroups) { [properties enumerateKeysAndObjectsUsingBlock:^(id _Nonnull key, id _Nonnull obj, BOOL * _Nonnull stop) { - [components addObject:[NSString stringWithFormat:@"%@ = %@", key, ASGetDescriptionValueString(obj)]]; + NSString *str; + if (key == (id)kCFNull) { + str = ASGetDescriptionValueString(obj); + } else { + str = [NSString stringWithFormat:@"%@ = %@", key, ASGetDescriptionValueString(obj)]; + } + [components addObject:str]; }]; } return [components componentsJoinedByString:@"; "]; @@ -73,7 +82,7 @@ return @"(null)"; } - NSMutableString *str = [NSMutableString stringWithFormat:@"<%@: %p", [object class], object]; + NSMutableString *str = [NSMutableString stringWithFormat:@"<%s: %p", object_getClassName(object), object]; NSString *propList = _ASObjectDescriptionMakePropertyList(propertyGroups); if (propList.length > 0) { diff --git a/Source/Details/ASRangeController.mm b/Source/Details/ASRangeController.mm index cf0acaab6..4384b1b15 100644 --- a/Source/Details/ASRangeController.mm +++ b/Source/Details/ASRangeController.mm @@ -25,6 +25,7 @@ #import // Required for interfaceState and hierarchyState setter methods. #import #import +#import #import #import @@ -203,6 +204,8 @@ - (void)_setVisibleNodes:(NSHashTable *)newVisibleNodes - (void)_updateVisibleNodeIndexPaths { + as_activity_scope_verbose(as_activity_create("Update range controller", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); + as_log_verbose(ASCollectionLog(), "Updating ranges for %@", ASViewToDisplayNode(ASDynamicCast(self.delegate, UIView))); ASDisplayNodeAssert(_layoutController, @"An ASLayoutController is required by ASRangeController"); if (!_layoutController || !_dataSource) { return; diff --git a/Source/Details/_ASDisplayLayer.mm b/Source/Details/_ASDisplayLayer.mm index 93eb2cb0e..7ceba1c79 100644 --- a/Source/Details/_ASDisplayLayer.mm +++ b/Source/Details/_ASDisplayLayer.mm @@ -198,7 +198,7 @@ - (NSString *)description NSMutableString *description = [[super description] mutableCopy]; ASDisplayNode *node = self.asyncdisplaykit_node; if (node != nil) { - NSString *classString = [NSString stringWithFormat:@"%@-", [node class]]; + NSString *classString = [NSString stringWithFormat:@"%s-", object_getClassName(node)]; [description replaceOccurrencesOfString:@"_ASDisplay" withString:classString options:kNilOptions range:NSMakeRange(0, description.length)]; NSUInteger insertionIndex = [description rangeOfString:@">"].location; if (insertionIndex != NSNotFound) { diff --git a/Source/Details/_ASDisplayView.mm b/Source/Details/_ASDisplayView.mm index f1c56517e..93f3187f6 100644 --- a/Source/Details/_ASDisplayView.mm +++ b/Source/Details/_ASDisplayView.mm @@ -58,7 +58,7 @@ - (NSString *)description ASDisplayNode *node = _asyncdisplaykit_node; if (node != nil) { - NSString *classString = [NSString stringWithFormat:@"%@-", [node class]]; + NSString *classString = [NSString stringWithFormat:@"%s-", object_getClassName(node)]; [description replaceOccurrencesOfString:@"_ASDisplay" withString:classString options:kNilOptions range:NSMakeRange(0, description.length)]; NSUInteger semicolon = [description rangeOfString:@";"].location; if (semicolon != NSNotFound) { diff --git a/Source/Layout/ASDimension.mm b/Source/Layout/ASDimension.mm index 9a938c0c3..2a9ccbbb3 100644 --- a/Source/Layout/ASDimension.mm +++ b/Source/Layout/ASDimension.mm @@ -104,9 +104,17 @@ ASSizeRange ASSizeRangeIntersect(ASSizeRange sizeRange, ASSizeRange otherSizeRan NSString *NSStringFromASSizeRange(ASSizeRange sizeRange) { - return [NSString stringWithFormat:@"", - NSStringFromCGSize(sizeRange.min), - NSStringFromCGSize(sizeRange.max)]; + // 17 field length copied from iOS 10.3 impl of NSStringFromCGSize. + if (CGSizeEqualToSize(sizeRange.min, sizeRange.max)) { + return [NSString stringWithFormat:@"{{%.*g, %.*g}}", + 17, sizeRange.min.width, + 17, sizeRange.min.height]; + } + return [NSString stringWithFormat:@"{{%.*g, %.*g}, {%.*g, %.*g}}", + 17, sizeRange.min.width, + 17, sizeRange.min.height, + 17, sizeRange.max.width, + 17, sizeRange.max.height]; } #if YOGA diff --git a/Source/Layout/ASLayout.h b/Source/Layout/ASLayout.h index 039032512..a0aff5b7b 100644 --- a/Source/Layout/ASLayout.h +++ b/Source/Layout/ASLayout.h @@ -66,9 +66,9 @@ ASDISPLAYNODE_EXTERN_C_END @property (nonatomic, assign, readonly) CGSize size; /** - * Position in parent. Default to CGPointNull. + * Position in parent. Default to ASPointNull. * - * @discussion When being used as a sublayout, this property must not equal CGPointNull. + * @discussion When being used as a sublayout, this property must not equal ASPointNull. */ @property (nonatomic, assign, readonly) CGPoint position; diff --git a/Source/Layout/ASLayout.mm b/Source/Layout/ASLayout.mm index 7df657911..82eb62a87 100644 --- a/Source/Layout/ASLayout.mm +++ b/Source/Layout/ASLayout.mm @@ -316,9 +316,16 @@ - (CGRect)frame - (NSMutableArray *)propertiesForDescription { NSMutableArray *result = [NSMutableArray array]; - [result addObject:@{ @"layoutElement" : (self.layoutElement ?: (id)kCFNull) }]; - [result addObject:@{ @"position" : [NSValue valueWithCGPoint:self.position] }]; [result addObject:@{ @"size" : [NSValue valueWithCGSize:self.size] }]; + + if (auto layoutElement = self.layoutElement) { + [result addObject:@{ @"layoutElement" : layoutElement }]; + } + + auto pos = self.position; + if (!ASPointIsNull(pos)) { + [result addObject:@{ @"position" : [NSValue valueWithCGPoint:pos] }]; + } return result; } diff --git a/Source/Layout/ASLayoutElement.h b/Source/Layout/ASLayoutElement.h index 880f70209..2ebd55a46 100644 --- a/Source/Layout/ASLayoutElement.h +++ b/Source/Layout/ASLayoutElement.h @@ -21,6 +21,7 @@ #import #import #import +#import @class ASLayout; @class ASLayoutSpec; @@ -60,7 +61,7 @@ typedef NS_ENUM(NSUInteger, ASLayoutElementType) { * access to the options via convenience properties. If you are creating custom layout spec, then you can * extend the backing layout options class to accommodate any new layout options. */ -@protocol ASLayoutElement +@protocol ASLayoutElement #pragma mark - Getter diff --git a/Source/Layout/ASLayoutSpec.h b/Source/Layout/ASLayoutSpec.h index 0ca4eba87..e4d9d42db 100644 --- a/Source/Layout/ASLayoutSpec.h +++ b/Source/Layout/ASLayoutSpec.h @@ -24,7 +24,7 @@ NS_ASSUME_NONNULL_BEGIN /** * A layout spec is an immutable object that describes a layout, loosely inspired by React. */ -@interface ASLayoutSpec : NSObject +@interface ASLayoutSpec : NSObject /** * Creation of a layout spec should only happen by a user in layoutSpecThatFits:. During that method, a @@ -95,7 +95,7 @@ NS_ASSUME_NONNULL_BEGIN @end -@interface ASLayoutSpec (Debugging) +@interface ASLayoutSpec (Debugging) /** * Used by other layout specs to create ascii art debug strings */ diff --git a/Source/Layout/ASLayoutSpec.mm b/Source/Layout/ASLayoutSpec.mm index bc572d430..6600f5086 100644 --- a/Source/Layout/ASLayoutSpec.mm +++ b/Source/Layout/ASLayoutSpec.mm @@ -173,6 +173,24 @@ - (ASTraitCollection *)asyncTraitCollection ASLayoutElementStyleExtensibilityForwarding +#pragma mark - ASDescriptionProvider + +- (NSMutableArray *)propertiesForDescription +{ + auto result = [NSMutableArray array]; + if (NSArray *children = self.children) { + // Use tiny descriptions because these trees can get nested very deep. + auto tinyDescriptions = ASArrayByFlatMapping(children, id object, ASObjectDescriptionMakeTiny(object)); + [result addObject:@{ @"children": tinyDescriptions }]; + } + return result; +} + +- (NSString *)description +{ + return ASObjectDescriptionMake(self, [self propertiesForDescription]); +} + #pragma mark - Framework Private #if AS_DEDUPE_LAYOUT_SPEC_TREE @@ -236,6 +254,23 @@ - (void)setDebugName:(NSString *)debugName } } +#pragma mark - ASLayoutElementAsciiArtProtocol + +- (NSString *)asciiArtString +{ + NSArray *children = self.children.count < 2 && self.child ? @[self.child] : self.children; + return [ASLayoutSpec asciiArtStringForChildren:children parentName:[self asciiArtName]]; +} + +- (NSString *)asciiArtName +{ + NSMutableString *result = [NSMutableString stringWithCString:object_getClassName(self) encoding:NSASCIIStringEncoding]; + if (_debugName) { + [result appendFormat:@" (%@)", _debugName]; + } + return result; +} + @end #pragma mark - ASWrapperLayoutSpec @@ -295,7 +330,7 @@ - (ASLayout *)calculateLayoutThatFits:(ASSizeRange)constrainedSize @implementation ASLayoutSpec (Debugging) -#pragma mark - ASLayoutElementAsciiArtProtocol +#pragma mark - ASCII Art Helpers + (NSString *)asciiArtStringForChildren:(NSArray *)children parentName:(NSString *)parentName direction:(ASStackLayoutDirection)direction { @@ -317,21 +352,6 @@ + (NSString *)asciiArtStringForChildren:(NSArray *)children parentName:(NSString return [self asciiArtStringForChildren:children parentName:parentName direction:ASStackLayoutDirectionHorizontal]; } -- (NSString *)asciiArtString -{ - NSArray *children = self.children.count < 2 && self.child ? @[self.child] : self.children; - return [ASLayoutSpec asciiArtStringForChildren:children parentName:[self asciiArtName]]; -} - -- (NSString *)asciiArtName -{ - NSString *string = NSStringFromClass([self class]); - if (_debugName) { - string = [string stringByAppendingString:[NSString stringWithFormat:@" (debugName = %@)",_debugName]]; - } - return string; -} - @end #pragma mark - ASLayoutSpec (Deprecated) diff --git a/Source/Layout/ASStackLayoutSpec.mm b/Source/Layout/ASStackLayoutSpec.mm index 570769a29..4a3de0c70 100644 --- a/Source/Layout/ASStackLayoutSpec.mm +++ b/Source/Layout/ASStackLayoutSpec.mm @@ -25,6 +25,7 @@ #import #import #import +#import #import #import @@ -134,6 +135,8 @@ - (ASLayout *)calculateLayoutThatFits:(ASSizeRange)constrainedSize return [ASLayout layoutWithLayoutElement:self size:constrainedSize.min]; } + as_activity_scope_verbose(as_activity_create("Calculate stack layout", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); + as_log_verbose(ASLayoutLog(), "Stack layout %@", self); // Accessing the style and size property is pretty costly we create layout spec children we use to figure // out the layout for each child const auto stackChildren = AS::map(children, [&](const id child) -> ASStackLayoutSpecChild { @@ -177,6 +180,23 @@ - (void)resolveVerticalAlignment } } +- (NSMutableArray *)propertiesForDescription +{ + auto result = [super propertiesForDescription]; + + // Add our direction + switch (self.direction) { + case ASStackLayoutDirectionVertical: + [result insertObject:@{ (id)kCFNull: @"vertical" } atIndex:0]; + break; + case ASStackLayoutDirectionHorizontal: + [result insertObject:@{ (id)kCFNull: @"horizontal" } atIndex:0]; + break; + } + + return result; +} + @end @implementation ASStackLayoutSpec (Debugging) diff --git a/Source/Private/ASLayoutTransition.mm b/Source/Private/ASLayoutTransition.mm index 940687d24..85cfcd208 100644 --- a/Source/Private/ASLayoutTransition.mm +++ b/Source/Private/ASLayoutTransition.mm @@ -22,6 +22,7 @@ #import #import // Required for _insertSubnode... / _removeFromSupernode. +#import #import #import @@ -106,6 +107,8 @@ - (void)applySubnodeInsertions ASDN::MutexSharedLocker l(__instanceLock__); [self calculateSubnodeOperationsIfNeeded]; + // Create an activity even if no subnodes affected. + as_activity_create_for_scope("Apply subnode insertions"); if (_insertedSubnodes.count == 0) { return; } @@ -121,6 +124,7 @@ - (void)applySubnodeInsertions - (void)applySubnodeRemovals { + as_activity_scope(as_activity_create("Apply subnode removals", AS_ACTIVITY_CURRENT, OS_ACTIVITY_FLAG_DEFAULT)); ASDN::MutexSharedLocker l(__instanceLock__); [self calculateSubnodeOperationsIfNeeded]; @@ -144,6 +148,8 @@ - (void)calculateSubnodeOperationsIfNeeded return; } + // Create an activity even if no subnodes affected. + as_activity_create_for_scope("Calculate subnode operations"); ASLayout *previousLayout = _previousLayout->layout; ASLayout *pendingLayout = _pendingLayout->layout; diff --git a/Source/Private/ASRectTable.m b/Source/Private/ASRectTable.m index 00f30a566..5a98a3f70 100644 --- a/Source/Private/ASRectTable.m +++ b/Source/Private/ASRectTable.m @@ -25,7 +25,7 @@ static NSUInteger ASRectSize(const void *ptr) @implementation NSMapTable (ASRectTableMethods) -+ (instancetype)rectTableWithKeyPointerFunctions:(NSPointerFunctions *)keyFuncs ++ (NSMapTable *)rectTableWithKeyPointerFunctions:(NSPointerFunctions *)keyFuncs { static NSPointerFunctions *cgRectFuncs; static dispatch_once_t onceToken; @@ -37,7 +37,7 @@ + (instancetype)rectTableWithKeyPointerFunctions:(NSPointerFunctions *)keyFuncs return [[NSMapTable alloc] initWithKeyPointerFunctions:keyFuncs valuePointerFunctions:cgRectFuncs capacity:0]; } -+ (instancetype)rectTableForStrongObjectPointers ++ (NSMapTable *)rectTableForStrongObjectPointers { static NSPointerFunctions *strongObjectPointerFuncs; static dispatch_once_t onceToken; @@ -47,7 +47,7 @@ + (instancetype)rectTableForStrongObjectPointers return [self rectTableWithKeyPointerFunctions:strongObjectPointerFuncs]; } -+ (instancetype)rectTableForWeakObjectPointers ++ (NSMapTable *)rectTableForWeakObjectPointers { static NSPointerFunctions *weakObjectPointerFuncs; static dispatch_once_t onceToken; diff --git a/Source/Private/_ASHierarchyChangeSet.h b/Source/Private/_ASHierarchyChangeSet.h index a5046b4b9..dce5fd4cc 100644 --- a/Source/Private/_ASHierarchyChangeSet.h +++ b/Source/Private/_ASHierarchyChangeSet.h @@ -18,6 +18,7 @@ #import #import #import +#import NS_ASSUME_NONNULL_BEGIN @@ -119,6 +120,12 @@ NSString *NSStringFromASHierarchyChangeType(_ASHierarchyChangeType changeType); /// Indicates whether the change set is empty, that is it includes neither reload data nor per item or section changes. @property (nonatomic, readonly) BOOL isEmpty; +/// The top-level activity for this update. +@property (nonatomic, OS_ACTIVITY_NULLABLE) os_activity_t rootActivity; + +/// The activity for submitting this update i.e. between -beginUpdates and -endUpdates. +@property (nonatomic, OS_ACTIVITY_NULLABLE) os_activity_t submitActivity; + - (instancetype)initWithOldData:(std::vector)oldItemCounts NS_DESIGNATED_INITIALIZER; /** diff --git a/Source/Private/_ASHierarchyChangeSet.mm b/Source/Private/_ASHierarchyChangeSet.mm index 967ecc99d..4326b5e9e 100644 --- a/Source/Private/_ASHierarchyChangeSet.mm +++ b/Source/Private/_ASHierarchyChangeSet.mm @@ -601,7 +601,7 @@ - (BOOL)_includesPerItemOrSectionChanges - (NSString *)description { - return ASObjectDescriptionMake(self, [self propertiesForDescription]); + return ASObjectDescriptionMakeWithoutObject([self propertiesForDescription]); } - (NSString *)debugDescription @@ -612,7 +612,9 @@ - (NSString *)debugDescription - (NSMutableArray *)propertiesForDescription { NSMutableArray *result = [NSMutableArray array]; - [result addObject:@{ @"includesReloadData" : @(_includesReloadData) }]; + if (_includesReloadData) { + [result addObject:@{ @"reloadData" : @"YES" }]; + } if (_reloadSectionChanges.count > 0) { [result addObject:@{ @"reloadSections" : [_ASHierarchySectionChange smallDescriptionForSectionChanges:_reloadSectionChanges] }]; } diff --git a/Tests/ASDisplayNodeTests.mm b/Tests/ASDisplayNodeTests.mm index 69d184687..99882df06 100644 --- a/Tests/ASDisplayNodeTests.mm +++ b/Tests/ASDisplayNodeTests.mm @@ -1880,10 +1880,8 @@ - (void)checkNameInDescriptionIsLayerBacked:(BOOL)isLayerBacked node.debugName = @"big troll eater name"; XCTAssertTrue([node.description containsString:node.debugName], @"debugName didn't end up in description"); - XCTAssertTrue([node.description containsString:@"debugName"], @"Node description should contain `debugName`."); [node layer]; XCTAssertTrue([node.description containsString:node.debugName], @"debugName didn't end up in description"); - XCTAssertTrue([node.description containsString:@"debugName"], @"Node description should contain `debugName`."); } - (void)testNameInDescriptionLayer diff --git a/examples/CatDealsCollectionView/Sample/ItemNode.m b/examples/CatDealsCollectionView/Sample/ItemNode.m index 50ce9e106..400f5b79e 100644 --- a/examples/CatDealsCollectionView/Sample/ItemNode.m +++ b/examples/CatDealsCollectionView/Sample/ItemNode.m @@ -18,6 +18,7 @@ #import "ItemNode.h" #import "ItemStyles.h" #import "PlaceholderNetworkImageNode.h" +#import const CGFloat kFixedLabelsAreaHeight = 96.0; const CGFloat kDesignWidth = 320.0; @@ -45,6 +46,7 @@ @interface ItemNode() @end @implementation ItemNode +@dynamic viewModel; - (instancetype)initWithViewModel:(ItemViewModel *)viewModel { @@ -55,6 +57,8 @@ - (instancetype)initWithViewModel:(ItemViewModel *)viewModel [self updateLabels]; [self updateBackgroundColor]; + ASSetDebugName(self, @"Item #%zd", viewModel.identifier); + self.accessibilityIdentifier = viewModel.titleText; } return self; } diff --git a/examples/CatDealsCollectionView/Sample/ItemViewModel.h b/examples/CatDealsCollectionView/Sample/ItemViewModel.h index 4f73f3afe..621b4060a 100644 --- a/examples/CatDealsCollectionView/Sample/ItemViewModel.h +++ b/examples/CatDealsCollectionView/Sample/ItemViewModel.h @@ -1,20 +1,18 @@ // // ItemViewModel.h -// Sample -// -// Created by Samuel Stow on 12/29/15. +// Texture // // Copyright (c) 2014-present, Facebook, Inc. All rights reserved. // This source code is licensed under the BSD-style license found in the -// LICENSE file in the root directory of this source tree. An additional grant -// of patent rights can be found in the PATENTS file in the same directory. +// LICENSE file in the /ASDK-Licenses directory of this source tree. An additional +// grant of patent rights can be found in the PATENTS file in the same directory. +// +// Modifications to this file made after 4/13/2017 are: Copyright (c) 2017-present, +// Pinterest, Inc. Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at // -// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR -// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, -// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL -// FACEBOOK BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN -// ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN -// CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. +// http://www.apache.org/licenses/LICENSE-2.0 // #import @@ -22,8 +20,9 @@ @interface ItemViewModel : NSObject -+ (instancetype)randomItem; ++ (ItemViewModel *)randomItem; +@property (nonatomic, readonly) NSInteger identifier; @property (nonatomic, copy) NSString *titleText; @property (nonatomic, copy) NSString *firstInfoText; @property (nonatomic, copy) NSString *secondInfoText; diff --git a/examples/CatDealsCollectionView/Sample/ItemViewModel.m b/examples/CatDealsCollectionView/Sample/ItemViewModel.m index c975a798f..4cf925e5d 100644 --- a/examples/CatDealsCollectionView/Sample/ItemViewModel.m +++ b/examples/CatDealsCollectionView/Sample/ItemViewModel.m @@ -1,23 +1,22 @@ // // ItemViewModel.m -// Sample -// -// Created by Samuel Stow on 12/29/15. +// Texture // // Copyright (c) 2014-present, Facebook, Inc. All rights reserved. // This source code is licensed under the BSD-style license found in the -// LICENSE file in the root directory of this source tree. An additional grant -// of patent rights can be found in the PATENTS file in the same directory. +// LICENSE file in the /ASDK-Licenses directory of this source tree. An additional +// grant of patent rights can be found in the PATENTS file in the same directory. +// +// Modifications to this file made after 4/13/2017 are: Copyright (c) 2017-present, +// Pinterest, Inc. Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at // -// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR -// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, -// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL -// FACEBOOK BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN -// ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN -// CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. +// http://www.apache.org/licenses/LICENSE-2.0 // #import "ItemViewModel.h" +#import NSArray *titles; NSArray *firstInfos; @@ -32,28 +31,29 @@ @interface ItemViewModel() @implementation ItemViewModel -+ (instancetype)randomItem { ++ (ItemViewModel *)randomItem { return [[ItemViewModel alloc] init]; } - (instancetype)init { self = [super init]; if (self) { - _titleText = [self randomObjectFromArray:titles]; - _firstInfoText = [self randomObjectFromArray:firstInfos]; - _secondInfoText = [NSString stringWithFormat:@"%zd+ bought", [self randomNumberInRange:5 to:6000]]; - _originalPriceText = [NSString stringWithFormat:@"$%zd", [self randomNumberInRange:40 to:90]]; - _finalPriceText = [NSString stringWithFormat:@"$%zd", [self randomNumberInRange:5 to:30]]; - BOOL isSoldOut = arc4random() % 5 == 0; - _soldOutText = isSoldOut ? @"SOLD OUT" : nil; - _distanceLabelText = [NSString stringWithFormat:@"%zd mi", [self randomNumberInRange:1 to:20]]; - BOOL isBadged = arc4random() % 2 == 0; - if (isBadged) { - _badgeText = [self randomObjectFromArray:badges]; - } - _catNumber = [self randomNumberInRange:1 to:10]; - _labelNumber = [self randomNumberInRange:1 to:10000]; - + static _Atomic(NSInteger) nextID = ATOMIC_VAR_INIT(1); + _identifier = atomic_fetch_add(&nextID, 1); + _titleText = [self randomObjectFromArray:titles]; + _firstInfoText = [self randomObjectFromArray:firstInfos]; + _secondInfoText = [NSString stringWithFormat:@"%zd+ bought", [self randomNumberInRange:5 to:6000]]; + _originalPriceText = [NSString stringWithFormat:@"$%zd", [self randomNumberInRange:40 to:90]]; + _finalPriceText = [NSString stringWithFormat:@"$%zd", [self randomNumberInRange:5 to:30]]; + BOOL isSoldOut = arc4random() % 5 == 0; + _soldOutText = isSoldOut ? @"SOLD OUT" : nil; + _distanceLabelText = [NSString stringWithFormat:@"%zd mi", [self randomNumberInRange:1 to:20]]; + BOOL isBadged = arc4random() % 2 == 0; + if (isBadged) { + _badgeText = [self randomObjectFromArray:badges]; + } + _catNumber = [self randomNumberInRange:1 to:10]; + _labelNumber = [self randomNumberInRange:1 to:10000]; } return self; } diff --git a/examples/CatDealsCollectionView/Sample/ViewController.m b/examples/CatDealsCollectionView/Sample/ViewController.m index 02fb5de8d..6e63dabe0 100644 --- a/examples/CatDealsCollectionView/Sample/ViewController.m +++ b/examples/CatDealsCollectionView/Sample/ViewController.m @@ -1,11 +1,11 @@ // // ViewController.m -// Sample +// Texture // // Copyright (c) 2014-present, Facebook, Inc. All rights reserved. // This source code is licensed under the BSD-style license found in the -// LICENSE file in the root directory of this source tree. An additional grant -// of patent rights can be found in the PATENTS file in the same directory. +// LICENSE file in the /ASDK-Licenses directory of this source tree. An additional +// grant of patent rights can be found in the PATENTS file in the same directory. // // Modifications to this file made after 4/13/2017 are: Copyright (c) 2017-present, // Pinterest, Inc. Licensed under the Apache License, Version 2.0 (the "License"); @@ -56,6 +56,7 @@ - (instancetype)init _collectionNode.dataSource = self; _collectionNode.delegate = self; _collectionNode.backgroundColor = [UIColor grayColor]; + _collectionNode.accessibilityIdentifier = @"Cat deals list"; ASRangeTuningParameters preloadTuning; preloadTuning.leadingBufferScreenfuls = 2; @@ -96,12 +97,10 @@ - (void)fetchMoreCatsWithCompletion:(void (^)(BOOL))completion { ViewController *strongSelf = weakSelf; if (strongSelf != nil) { - NSLog(@"ViewController is not nil"); [strongSelf appendMoreItems:kBatchSize completion:completion]; - NSLog(@"ViewController finished updating collectionView"); } else { - NSLog(@"ViewController is nil - won't update collectionView"); + NSLog(@"ViewController is nil - won't update collection"); } }; @@ -113,13 +112,11 @@ - (void)fetchMoreCatsWithCompletion:(void (^)(BOOL))completion { - (void)appendMoreItems:(NSInteger)numberOfNewItems completion:(void (^)(BOOL))completion { NSArray *newData = [self getMoreData:numberOfNewItems]; - dispatch_async(dispatch_get_main_queue(), ^{ - [_collectionNode performBatchAnimated:YES updates:^{ - [_data addObjectsFromArray:newData]; - NSArray *addedIndexPaths = [self indexPathsForObjects:newData]; - [_collectionNode insertItemsAtIndexPaths:addedIndexPaths]; - } completion:completion]; - }); + [_collectionNode performBatchAnimated:YES updates:^{ + [_data addObjectsFromArray:newData]; + NSArray *addedIndexPaths = [self indexPathsForObjects:newData]; + [_collectionNode insertItemsAtIndexPaths:addedIndexPaths]; + } completion:completion]; } - (NSArray *)getMoreData:(NSInteger)count { @@ -196,7 +193,6 @@ - (NSInteger)numberOfSectionsInCollectionNode:(ASCollectionNode *)collectionNode - (void)collectionNode:(ASCollectionNode *)collectionNode willBeginBatchFetchWithContext:(ASBatchContext *)context { - NSLog(@"fetch additional content"); [self fetchMoreCatsWithCompletion:^(BOOL finished){ [context completeBatchFetching:YES]; }];