DEBUG

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' ||

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
+}

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 (
-    <List
-      ref={scrollElRef}
-      data={conversations}
-      renderItem={renderItem}
-      keyExtractor={keyExtractor}
-      refreshing={isPTRing}
-      onRefresh={() => void onRefresh()}
-      onEndReached={() => void onEndReached()}
-      ListHeaderComponent={
-        chatStatus?.chatDisabled ? (
-          <ChatDisabled shape="banner" style={[isWithinSplitView && a.mb_sm]} />
-        ) : undefined
-      }
-      ListFooterComponent={
-        <ListFooter
-          isFetchingNextPage={isFetchingNextPage}
-          error={cleanError(error)}
-          onRetry={fetchNextPage}
-          style={{borderColor: 'transparent'}}
-          hasNextPage={hasNextPage}
-        />
-      }
-      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
-      }
-    />
+    <>
+      <List
+        ref={scrollElRef}
+        data={conversations}
+        renderItem={renderItem}
+        keyExtractor={keyExtractor}
+        refreshing={isPTRing}
+        onRefresh={() => void onRefresh()}
+        onEndReached={() => void onEndReached()}
+        ListHeaderComponent={
+          chatStatus?.chatDisabled ? (
+            <ChatDisabled
+              shape="banner"
+              style={[isWithinSplitView && a.mb_sm]}
+            />
+          ) : undefined
+        }
+        ListFooterComponent={
+          <ListFooter
+            isFetchingNextPage={isFetchingNextPage}
+            error={cleanError(error)}
+            onRetry={fetchNextPage}
+            style={{borderColor: 'transparent'}}
+            hasNextPage={hasNextPage}
+          />
+        }
+        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 && (
+        <View style={[a.absolute, {bottom: 90, right: 16}]}>
+          <Button
+            label="Test chat push"
+            color="negative"
+            size="small"
+            onPress={() => {
+              void scheduleTestChatNotification({
+                convoId: conversations[0].conversation.id,
+                recipientDid: currentAccount.did,
+              })
+            }}>
+            <ButtonText>Test push (bg now)</ButtonText>
+          </Button>
+        </View>
+      )}
+    </>
   )
 }
 

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) {

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 (
     <View
@@ -168,12 +173,17 @@ export function MessagesList({
   const listOpacity = useSharedValue(0)
 
   useEffect(() => {
+    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({

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()
     }