Hook debugging
Hook debugging¶
traceHook¶
All hooks in DragonFly should have traceHook currently implemented in order to provide invocation counters and timing for them. Here is an example of the traceHook output after visiting a User PDP.
In this view we can see some important pieces of information.
Event count provides us with how many times the hook was invoked. This can showcase areas where a hook is being invoked more times than it should (showing re-renders).
Total duration gives us an idea of the total impact for a hook. This can be somewhat deceiving as some hooks are dependencies of others. A very large impact from useContentAvailability could adversely affect usePlayCapability, which would then have impact on useOptimalPlaymode. It is still a good metric to use in order to highlight problem areas.
Another benefit of this value is that it helps to highlight relatively quick hooks that end up being a problem due to the amount they are called. Taking the screenshot above as an example, usePlayCapability only takes 0.38ms on average, but with 247 invocations that adds up to 93ms of impact.
Avg duration is useful for finding the problem children. usePlaylistMessaging is only called once, but that 1 time takes over 12ms on its own, can that be reduced?
Context is based off of the pageType and a uniqueId that is set when the pageType changes in order to track individual instances of a page. It is not 100% accurate, as navigating between the same pageTypes without an intermediary will not trigger a new uniqueId.
hook breakdown¶
The screenshot above is generated by wrapping all of the primary logical areas of the hook with individual traces. This allows us to see the impact of individual pieces of a hook and to find the actual problem area. In the above screenshot we can actually see 2 problems.
suggestedTracks takes a really long time. That is a useFragment call to pull in a track list that can be added to a playlist. That call is not conditional and happens for all playlists.
memo and memoContents have the same exact number of invocations. This means that the memo is not doing anything, the contents are being re-evaluated each time.
usePropDiff¶
To get better a better idea of what is causing the memo to re-evaluate each time we can use a helper utility, usePropDiff. What this utility does is it compares the dependencies of the memo on each re-render to highlight which of them changed which would cause the memo contents to be re-evaluated.
You can see the example code for how usePropDiff is setup at the bottom of this doc. That code will output the following result in piggy.
In this screenshot we can see that for one of the re-renders editCapability, playCapability, and isPlaylistAutofillWeblabEnabled all changed, thus causing the memo contents to be re-evaluated. We are then able to go into each of those and try to debug what exactly caused them to change and see if those can be mitigated.
If the memo contents are going to be re-evaluated each time simply due to the dependencies changing then there is a good chance that useMemo is not actually useful in that scenario.
Example implementation of wrapping the usePlaylistAutoFillCapability hook.¶
const traceOptions: TraceOptions = {
namespace: 'usePlaylistAutofillCapability',
enableNativeTrace: false,
endpoints: ['counter'],
}
/**
* Evaluates the playlist autofill button capability.
* The hook will retrieve dependency data, subscribes to data change and manage loading state.
* When data value changes, it will re-compute the result and cause re-render of the components using the hook.
* @param {PlaylistAutofillCapabilityProps} props - The props for the hook.
* @returns {UseCapabilityResult<CanDisplayAction>} An object containing the evaluation result and a loading state.
*/
export function usePlaylistAutofillCapability({
playlistId,
}: PlaylistAutofillCapabilityProps): UseCapabilityResult<CanDisplayAction> {
const split = traceHook('usePlaylistAutofillCapability')
const entity = { id: playlistId, __typename: 'Playlist' as const }
// Wrap each functional area with a trace to get fine-grained numbers
const editSplit = trace.start('editCapability', traceOptions)
const editCapability = useEditCapability({ entity })
editSplit.stop()
const playCapabilitySplit = trace.start('playCapability', traceOptions)
const playCapability = usePlayCapability({ entity })
playCapabilitySplit.stop()
const playlistIdSplit = trace.start('playlistId', traceOptions)
const playlistFragment = useFragment(getAutofillPlaylistFragmentConfig(playlistId))
playlistIdSplit.stop()
const suggestedTracksSplit = trace.start('suggestedTracks', traceOptions)
const suggestedTracksFragment = useFragment(
getPlaylistSuggestionOnRecommendationFragmentConfig(playlistId),
)
suggestedTracksSplit.stop()
const storesSplit = trace.start('stores', traceOptions)
const {
NetworkInfo: { isOffline },
} = useStores()
storesSplit.stop()
const userTierSplit = trace.start('userTier', traceOptions)
const { tier, benefits } = useTierAndBenefits()
userTierSplit.stop()
const featureGateSplit = trace.start('featureGate', traceOptions)
const [{ isPlaylistAutofillWeblabEnabled }, isFeatureGateLoading] = useFeatureGate({
isPlaylistAutofillWeblabEnabled: playlistAutofillWeblabRule,
})
featureGateSplit.stop()
// Wrap useMemo in a trace to get the total number of renders
const memoSplit = trace.start('memo', traceOptions)
const memoizedResult = useMemo(() => {
// Wrap the memo contents in a trace, the difference in invocations will indicate if memo is working
// it should be less than the useMemo wrapper.
const memoContentsSplit = trace.start('memoContents', traceOptions)
const playlistTracksCount = playlistFragment.data.trackCount ?? 0
const suggestedTracksCount = suggestedTracksFragment.data.recommendedContent?.edges?.length ?? 0
const dependencyData: PlaylistAutofillCapabilityData = {
playlistTracksCount,
suggestedTracksCount,
editCapability,
playCapability,
isOffline,
tier,
benefits,
isPlaylistAutofillWeblabEnabled,
}
// As long as one dependency is loading, overall state is loading
const overallLoadingState =
editCapability.isLoading || playCapability.isLoading || isFeatureGateLoading
if (overallLoadingState === true) {
return { data: undefined, isLoading: overallLoadingState }
}
Logger.info(`PlaylistAutofillCapability dependency data: ${JSON.stringify(dependencyData)}`)
try {
const playlistAutofillCapability = new PlaylistAutofillCapability(dependencyData)
const playlistAutofillCapabilityResult = playlistAutofillCapability.evaluate()
memoContentsSplit.stop()
return { data: playlistAutofillCapabilityResult, isLoading: overallLoadingState }
} catch (error) {
const errorStrongType: Error = error as Error
Logger.info(
`Error evaluating playlistAutofillCapability on ${JSON.stringify(errorStrongType.message)}`,
)
memoContentsSplit.stop()
return { data: undefined, isLoading: overallLoadingState, error: errorStrongType }
}
}, [
playlistFragment.data.trackCount,
suggestedTracksFragment.data.recommendedContent?.edges?.length,
editCapability,
playCapability,
isOffline,
tier,
benefits,
isPlaylistAutofillWeblabEnabled,
isFeatureGateLoading,
])
// Use the utility usePropDiff in order to get the dependencies for useMemo that changed on each render
// This allows us to see what is causing useMemo to re-calculate.
usePropDiff({
componentName: 'usePlaylistAutofillCapability',
compare: {
props: {
trackCount: playlistFragment.data.trackCount,
suggestedTracksFragment: suggestedTracksFragment.data.recommendedContent?.edges?.length,
editCapability,
playCapability,
isOffline,
tier,
benefits,
isPlaylistAutofillWeblabEnabled,
isFeatureGateLoading,
},
},
})
memoSplit.stop()
split.stop()
return memoizedResult
}