diff --git a/src/lib/hooks/useNotificationHandler.ts b/src/lib/hooks/useNotificationHandler.ts index 65332dea0b..b74426d11e 100644 --- a/src/lib/hooks/useNotificationHandler.ts +++ b/src/lib/hooks/useNotificationHandler.ts @@ -17,7 +17,7 @@ import {useSession} from '#/state/session' import {useLoggedOutViewControls} from '#/state/shell/logged-out' import {useCloseAllActiveElements} from '#/state/util' import {useAnalytics} from '#/analytics' -import {IS_ANDROID, IS_IOS} from '#/env' +import {IS_ANDROID, IS_DEV, IS_IOS} from '#/env' import {resetToTab} from '#/Navigation' import {router} from '#/routes' @@ -423,6 +423,18 @@ export function storePayloadForAccountSwitch(payload: NotificationPayload) { export function getNotificationPayload( e: Notifications.Notification, ): NotificationPayload | null { + // [CHATDBG] TEMP: accept locally-scheduled test notifications in dev. Real + // pushes use a 'push' trigger, which local notifs can't produce, so we tag + // test notifs with `__chatdbg` in their data and let them through here. + if (IS_DEV) { + const data = e.request.content.data as + | (NotificationPayload & {__chatdbg?: boolean}) + | undefined + if (data?.__chatdbg && data.reason) { + return data + } + } + if ( e.request.trigger == null || typeof e.request.trigger !== 'object' || diff --git a/src/lib/notifications/devChatNotif.ts b/src/lib/notifications/devChatNotif.ts new file mode 100644 index 0000000000..c7d146fcb4 --- /dev/null +++ b/src/lib/notifications/devChatNotif.ts @@ -0,0 +1,62 @@ +/** + * [CHATDBG] TEMPORARY dev-only helper for reproducing the "chat opened from a + * push never finishes loading" bug (APP-2238). + * + * Schedules a LOCAL notification that mimics a chat push payload. Local notifs + * can't produce a real `'push'` trigger, so we tag the payload with `__chatdbg` + * and `getNotificationPayload` lets it through in dev (see + * useNotificationHandler.ts). + * + * Usage: call this, then immediately background the app. When the banner + * appears, tap it - the tap handler routes to the convo exactly like a real + * push, while Metro captures the [CHATDBG] timeline. + * + * DELETE THIS FILE when the investigation is done. + */ +import * as Notifications from 'expo-notifications' + +import {logger} from '#/logger' + +export async function scheduleTestChatNotification({ + convoId, + recipientDid, + delaySeconds = 4, +}: { + convoId: string + recipientDid: string + delaySeconds?: number +}) { + const perms = await Notifications.getPermissionsAsync() + if (!perms.granted) { + const req = await Notifications.requestPermissionsAsync() + if (!req.granted) { + logger.warn('[CHATDBG] notification permission not granted, cannot test') + return false + } + } + + await Notifications.scheduleNotificationAsync({ + content: { + title: '[CHATDBG] Test chat message', + body: 'Tap me after backgrounding the app', + data: { + __chatdbg: true, + reason: 'chat-message', + convoId, + messageId: '__chatdbg_test__', + recipientDid, + }, + }, + trigger: { + type: Notifications.SchedulableTriggerInputTypes.TIME_INTERVAL, + seconds: delaySeconds, + }, + }) + + logger.debug('[CHATDBG] scheduled test chat notification', { + convoId, + recipientDid, + delaySeconds, + }) + return true +} diff --git a/src/screens/Messages/ChatList.tsx b/src/screens/Messages/ChatList.tsx index 387fcd2bd1..21cc2f5be6 100644 --- a/src/screens/Messages/ChatList.tsx +++ b/src/screens/Messages/ChatList.tsx @@ -9,6 +9,8 @@ import {type NativeStackScreenProps} from '@react-navigation/native-stack' import {useAppState} from '#/lib/appState' import {useInitialNumToRender} from '#/lib/hooks/useInitialNumToRender' import {useRequireEmailVerification} from '#/lib/hooks/useRequireEmailVerification' +// [CHATDBG] TEMP: dev-only test-notification helper. Delete with the button below. +import {scheduleTestChatNotification} from '#/lib/notifications/devChatNotif' import {type MessagesTabNavigatorParams} from '#/lib/routes/types' import {cleanError} from '#/lib/strings/errors' import {logger} from '#/logger' @@ -18,6 +20,7 @@ import {useMessagesEventBus} from '#/state/messages/events' import {useChatActorStatusQuery} from '#/state/queries/messages/get-status' import {useLeftConvos} from '#/state/queries/messages/leave-conversation' import {useListConvosQuery} from '#/state/queries/messages/list-conversations' +import {useSession} from '#/state/session' import {EmptyState} from '#/view/com/util/EmptyState' import {List, type ListRef} from '#/view/com/util/List' import {ChatListLoadingPlaceholder} from '#/view/com/util/LoadingPlaceholder' @@ -42,7 +45,7 @@ import {Link} from '#/components/Link' import {ListFooter} from '#/components/Lists' import {Text} from '#/components/Typography' import {useAgeAssurance} from '#/ageAssurance' -import {IS_NATIVE} from '#/env' +import {IS_DEV, IS_NATIVE} from '#/env' import {ChatDisabled} from './components/ChatDisabled' import {ChatListItem} from './components/ChatListItem' import {InboxRequests} from './components/InboxRequests' @@ -200,6 +203,7 @@ export function ChatList({ const {t: l} = useLingui() const scrollElRef: ListRef = useAnimatedRef() const {isWithinSplitView} = useIsWithinSplitView() + const {currentAccount} = useSession() // [CHATDBG] TEMP: for test-notif button const openChatControl = useCallback(() => { newChatControl.open() @@ -395,48 +399,70 @@ export function ChatList({ } return ( - void onRefresh()} - onEndReached={() => void onEndReached()} - ListHeaderComponent={ - chatStatus?.chatDisabled ? ( - - ) : undefined - } - ListFooterComponent={ - - } - onEndReachedThreshold={IS_NATIVE ? 1.5 : 0} - onContentSizeChange={onContentSizeChange} - initialNumToRender={initialNumToRender} - windowSize={11} - desktopFixedHeight - sideBorders={false} - disableFullWindowScroll={isWithinSplitView} - style={ - isWithinSplitView && [ - a.w_full, - web({ - scrollbarWidth: 'thin', - scrollbarColor: `${t.palette.contrast_100} transparent`, - }), - ] - } - contentContainerStyle={ - isWithinSplitView && !chatStatus?.chatDisabled && a.py_sm - } - /> + <> + void onRefresh()} + onEndReached={() => void onEndReached()} + ListHeaderComponent={ + chatStatus?.chatDisabled ? ( + + ) : undefined + } + ListFooterComponent={ + + } + onEndReachedThreshold={IS_NATIVE ? 1.5 : 0} + onContentSizeChange={onContentSizeChange} + initialNumToRender={initialNumToRender} + windowSize={11} + desktopFixedHeight + sideBorders={false} + disableFullWindowScroll={isWithinSplitView} + style={ + isWithinSplitView && [ + a.w_full, + web({ + scrollbarWidth: 'thin', + scrollbarColor: `${t.palette.contrast_100} transparent`, + }), + ] + } + contentContainerStyle={ + isWithinSplitView && !chatStatus?.chatDisabled && a.py_sm + } + /> + {/* [CHATDBG] TEMP: schedules a fake chat push for the first convo. Delete this. */} + {IS_DEV && IS_NATIVE && conversations.length > 0 && currentAccount && ( + + + + )} + ) } diff --git a/src/screens/Messages/Conversation.tsx b/src/screens/Messages/Conversation.tsx index 36adb63e7a..03c4ce673d 100644 --- a/src/screens/Messages/Conversation.tsx +++ b/src/screens/Messages/Conversation.tsx @@ -1,5 +1,5 @@ import {useCallback, useEffect, useMemo, useRef, useState} from 'react' -import {type LayoutChangeEvent, View} from 'react-native' +import {AppState, type LayoutChangeEvent, View} from 'react-native' import {useSafeAreaInsets} from 'react-native-safe-area-context' import {ChatBskyConvoDefs, moderateProfile} from '@atproto/api' import { @@ -22,6 +22,7 @@ import { type CommonNavigatorParams, type NavigationProp, } from '#/lib/routes/types' +import {Logger} from '#/logger' import {useMaybeProfileShadow} from '#/state/cache/profile-shadow' import {useEmail} from '#/state/email-verification' import {ConvoProvider, isConvoActive, useConvo} from '#/state/messages/convo' @@ -59,6 +60,11 @@ type Props = NativeStackScreenProps< 'MessagesConversation' > +// [CHATDBG] TEMP: routed through the conversation-agent context so it shows in +// the in-app System Log (which filters debug logs by context). Delete with the +// rest of the [CHATDBG] instrumentation. +const chatdbg = Logger.create(Logger.Context.ConversationAgent) + export function MessagesConversationScreen(props: Props) { const {t: l} = useLingui() const aaCopy = useAgeAssuranceCopy() @@ -75,6 +81,14 @@ export function MessagesConversationScreenInner({route}: Props) { const convoId = route.params.conversation const {setCurrentConvoId} = useCurrentConvoId() + useEffect(() => { + chatdbg.debug('[CHATDBG] ConversationScreen mount', { + t: Date.now(), + convoId, + appState: AppState.currentState, + }) + }, [convoId]) + useFocusEffect( useCallback(() => { setCurrentConvoId(convoId) @@ -116,9 +130,33 @@ function Inner({convoId}: {convoId: string}) { const [hasScrolled, setHasScrolled] = useState(false) + useEffect(() => { + chatdbg.debug('[CHATDBG] hasScrolled changed', { + t: Date.now(), + convoId, + hasScrolled, + }) + }, [hasScrolled, convoId]) + // Any time that we re-render the `Initializing` state, we have to reset `hasScrolled` to false. After entering this // state, we know that we're resetting the list of messages and need to re-scroll to the bottom when they get added. const [prevState, setPrevState] = useState(convoState.status) + // Ref-based so it captures the real status change independently of the + // render-phase setPrevState below (which would otherwise make prevState === + // status by the time this effect runs, hiding the transition). + const loggedStatusRef = useRef(convoState.status) + useEffect(() => { + if (loggedStatusRef.current !== convoState.status) { + chatdbg.debug('[CHATDBG] Inner status transition', { + t: Date.now(), + convoId, + prev: loggedStatusRef.current, + next: convoState.status, + willResetHasScrolled: convoState.status === ConvoStatus.Initializing, + }) + loggedStatusRef.current = convoState.status + } + }, [convoState.status, convoId]) if (prevState !== convoState.status) { setPrevState(convoState.status) if (convoState.status === ConvoStatus.Initializing) { diff --git a/src/screens/Messages/components/MessagesList.tsx b/src/screens/Messages/components/MessagesList.tsx index 727829795c..20b829a751 100644 --- a/src/screens/Messages/components/MessagesList.tsx +++ b/src/screens/Messages/components/MessagesList.tsx @@ -41,7 +41,7 @@ import { getChatInviteCodeFromUrl, isBskyPostUrl, } from '#/lib/strings/url-helpers' -import {logger} from '#/logger' +import {Logger, logger} from '#/logger' import { type ActiveConvoStates, isConvoActive, @@ -75,6 +75,11 @@ import {MessagesListGroupInfoPanel} from './MessagesListGroupInfoPanel' import {MessagesListInfoPanel} from './MessagesListInfoPanel' import {KeyboardStickyView} from './vendor/KeyboardStickyView' +// [CHATDBG] TEMP: routed through the conversation-agent context so it shows in +// the in-app System Log (which filters debug logs by context). Delete with the +// rest of the [CHATDBG] instrumentation. +const chatdbg = Logger.create(Logger.Context.ConversationAgent) + function MaybeLoader({isLoading}: {isLoading: boolean}) { return ( { + chatdbg.debug('[CHATDBG] listOpacity effect', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + hasScrolled, + }) if (hasScrolled) { listOpacity.set(withTiming(1, {duration: 200})) } else { listOpacity.set(0) } - }, [hasScrolled, listOpacity]) + }, [hasScrolled, listOpacity, convoState.convo?.view?.id]) const inputHeightUI = useSharedValue(0) const [inputHeightJS, setInputHeightJS] = useState(0) @@ -235,6 +245,17 @@ export function MessagesList({ // we will not scroll whenever new items get prepended to the top. const onContentSizeChange = useCallback( (_: number, height: number) => { + chatdbg.debug('[CHATDBG] onContentSizeChange enter', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + height, + hasInitiallyScrolled: hasInitiallyScrolled.current, + hasScrolled, + renderItems: renderItems.length, + isFetchingHistory: convoState.isFetchingHistory, + isAtBottom: isAtBottom.get(), + isAtTop: isAtTop.get(), + }) // Because web does not have `maintainVisibleContentPosition` support, we will need to manually scroll to the // previous off whenever we add new content to the previous offset whenever we add new content to the list. if (IS_WEB && isAtTop.get() && hasScrolled) { @@ -252,11 +273,22 @@ export function MessagesList({ (renderItems.length > 0 || !convoState.isFetchingHistory) ) { hasInitiallyScrolled.current = true + chatdbg.debug('[CHATDBG] onContentSizeChange INITIAL branch', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + renderItems: renderItems.length, + isFetchingHistory: convoState.isFetchingHistory, + willSetHasScrolled: !convoState.isFetchingHistory, + }) flatListRef.current?.scrollToOffset({offset: height, animated: false}) // If history is already done loading, mark ready after a frame for the scroll to settle. // Otherwise, the footer sentinel's onLayout will handle it when history finishes. if (!convoState.isFetchingHistory) { requestAnimationFrame(() => { + chatdbg.debug( + '[CHATDBG] setHasScrolled(true) from onContentSizeChange rAF', + {t: Date.now(), convoId: convoState.convo?.view?.id}, + ) setHasScrolled(true) }) } @@ -311,6 +343,10 @@ export function MessagesList({ ) const onStartReached = useCallback(() => { + chatdbg.debug('[CHATDBG] onStartReached -> fetchMessageHistory', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + }) void convoState.fetchMessageHistory() }, [convoState]) @@ -507,16 +543,32 @@ export function MessagesList({ // Footer sentinel: when history is still loading during the initial scroll, the footer's onLayout fires each time // new items are prepended (shifting its position). Once history finishes, this triggers setHasScrolled. const onFooterLayout = useCallback(() => { + chatdbg.debug('[CHATDBG] onFooterLayout enter', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + hasInitiallyScrolled: hasInitiallyScrolled.current, + hasScrolled, + isFetchingHistory: convoState.isFetchingHistory, + }) if ( hasInitiallyScrolled.current && !hasScrolled && !convoState.isFetchingHistory ) { requestAnimationFrame(() => { + chatdbg.debug( + '[CHATDBG] setHasScrolled(true) from onFooterLayout rAF', + {t: Date.now(), convoId: convoState.convo?.view?.id}, + ) setHasScrolled(true) }) } - }, [hasScrolled, setHasScrolled, convoState.isFetchingHistory]) + }, [ + hasScrolled, + setHasScrolled, + convoState.isFetchingHistory, + convoState.convo?.view?.id, + ]) const renderScrollComponent = useCallback( (props: ScrollViewProps) => ( @@ -705,23 +757,37 @@ function ChatScrollComponent({ type FooterState = 'loading' | 'new-chat' | 'request' | 'standard' +// [CHATDBG] TEMP: dedupe key so the per-render getFooterState log only fires on +// change. Delete with the rest of the [CHATDBG] instrumentation. +let chatdbgLastFooterKey = '' + function getFooterState( convoState: ActiveConvoStates, hasAcceptOverride?: boolean, ): FooterState { + let result: FooterState if (convoState.convo.view.status === 'request' && !hasAcceptOverride) { - return 'request' + result = 'request' + } else if (convoState.items.length === 0) { + result = convoState.isFetchingHistory ? 'loading' : 'new-chat' + } else { + result = 'standard' } - if (convoState.items.length === 0) { - if (convoState.isFetchingHistory) { - return 'loading' - } else { - return 'new-chat' - } + const key = `${convoState.convo?.view?.id}:${result}:${convoState.items.length}:${convoState.isFetchingHistory}:${convoState.status}` + if (key !== chatdbgLastFooterKey) { + chatdbgLastFooterKey = key + chatdbg.debug('[CHATDBG] getFooterState', { + t: Date.now(), + convoId: convoState.convo?.view?.id, + footerState: result, + itemsLength: convoState.items.length, + isFetchingHistory: convoState.isFetchingHistory, + status: convoState.status, + }) } - return 'standard' + return result } function ConversationFooter({ diff --git a/src/state/messages/convo/agent.ts b/src/state/messages/convo/agent.ts index e89965eb45..5cb9ca5efb 100644 --- a/src/state/messages/convo/agent.ts +++ b/src/state/messages/convo/agent.ts @@ -477,6 +477,13 @@ export class Convo { prev: prevStatus, next: this.status, }) + logger.debug('[CHATDBG] agent.dispatch', { + t: Date.now(), + convoId: this.convoId, + event: action.event, + prev: prevStatus, + next: this.status, + }) this.updateLastActiveTimestamp() this.commit() @@ -712,26 +719,56 @@ export class Convo { private fetchMessageHistoryError: {retry: () => void} | undefined async fetchMessageHistory() { logger.debug('fetch message history', {}) + logger.debug('[CHATDBG] fetchMessageHistory called', { + t: Date.now(), + convoId: this.convoId, + oldestRev: this.oldestRev, + isFetchingHistory: this.isFetchingHistory, + hasFetchError: !!this.fetchMessageHistoryError, + }) /* * If oldestRev is null, we've fetched all history. * Needs to explicitly check for `null` since this is initially `undefined`. */ - if (this.oldestRev === null) return + if (this.oldestRev === null) { + logger.debug( + '[CHATDBG] fetchMessageHistory EARLY RETURN oldestRev===null', + {t: Date.now(), convoId: this.convoId}, + ) + return + } /* * Don't fetch again if a fetch is already in progress */ - if (this.isFetchingHistory) return + if (this.isFetchingHistory) { + logger.debug( + '[CHATDBG] fetchMessageHistory EARLY RETURN already fetching', + {t: Date.now(), convoId: this.convoId}, + ) + return + } /* * If we've rendered a retry state for history fetching, exit. Upon retry, * this will be removed and we'll try again. */ - if (this.fetchMessageHistoryError) return + if (this.fetchMessageHistoryError) { + logger.debug( + '[CHATDBG] fetchMessageHistory EARLY RETURN has fetchError', + {t: Date.now(), convoId: this.convoId}, + ) + return + } try { this.isFetchingHistory = true + logger.debug('[CHATDBG] fetchMessageHistory START fetch', { + t: Date.now(), + convoId: this.convoId, + cursor: this.oldestRev, + }) this.commit() const nextCursor = this.oldestRev // for TS @@ -795,6 +832,14 @@ export class Convo { } } finally { this.isFetchingHistory = false + logger.debug('[CHATDBG] fetchMessageHistory FINALLY done', { + t: Date.now(), + convoId: this.convoId, + pastMessages: this.pastMessages.size, + newMessages: this.newMessages.size, + oldestRev: this.oldestRev, + hadError: !!this.fetchMessageHistoryError, + }) this.commit() } } @@ -832,6 +877,11 @@ export class Convo { private firehoseError: MessagesEventBusError | undefined onFirehoseConnect() { + logger.debug('[CHATDBG] onFirehoseConnect', { + t: Date.now(), + convoId: this.convoId, + status: this.status, + }) this.firehoseError = undefined void this.batchRetryPendingMessages() this.commit() @@ -936,6 +986,16 @@ export class Convo { } } + logger.debug('[CHATDBG] ingestFirehose', { + t: Date.now(), + convoId: this.convoId, + eventCount: events.length, + needsCommit, + status: this.status, + isFetchingHistory: this.isFetchingHistory, + pastMessages: this.pastMessages.size, + newMessages: this.newMessages.size, + }) if (needsCommit) { this.commit() }