improved login logs (#1034)

This commit is contained in:
Blake Kaufman
2026-07-26 12:05:11 -04:00
committed by GitHub
parent 9e02bb3258
commit f0b68fafae
4 changed files with 311 additions and 27 deletions
+31 -10
View File
@@ -102,6 +102,10 @@ import { useTranslation } from 'react-i18next';
import { AnalyticsNumbersProvider } from './context-store/analyticsContext';
import { BTCMapProvider } from './context-store/btcMapContext';
import { SpendAndReplaceProvider } from './context-store/spendAndReplaceContext';
import {
crashlyticsLogReport,
crashlyticsRecordErrorReport,
} from './app/functions/crashlyticsLogs';
const DeepLinkIntentModule = NativeModules.DeepLinkIntentModule;
// Last URL handled via getInitialURL in this JS context. Belt-and-braces only:
// getInitialURL runs once per JS context, and this resets on a JS reload, so
@@ -477,8 +481,10 @@ function ResetStack(): JSX.Element | null {
useEffect(() => {
let cancelled = false;
async function initWallet(skipURL = false) {
crashlyticsLogReport('initWallet: start');
await runPinAndMnemoicMigration();
await runSecureStoreMigrationV2();
crashlyticsLogReport('initWallet: secure store migrations done');
const [
initialURL,
loginModeType,
@@ -501,7 +507,16 @@ function ResetStack(): JSX.Element | null {
}),
]);
const storedSettings = JSON.parse(securitySettings);
crashlyticsLogReport('initWallet: read secure store + local settings');
// A corrupt value here would otherwise throw and strand the app on the
// native splash forever — fall back to the defaults below instead.
let storedSettings = null;
try {
storedSettings = JSON.parse(securitySettings);
} catch {
console.log('Corrupt stored security settings, using defaults');
}
const isPinFromMode = loginModeType?.value === 'pin';
const isBiometricFromMode = loginModeType?.value === 'biometric';
@@ -566,23 +581,30 @@ function ResetStack(): JSX.Element | null {
if (appState === 'background') return;
// initWallet is the ONLY thing that sets isLoaded, and the render gate below
// returns null until it does. Because preventAutoHideAsync() runs at module
// scope and only SplashScreen ever calls hideAsync(), a rejection here leaves
// the native splash on screen forever with no error and no way out. Always
// open the gate — landing on a screen is recoverable, an endless splash isn't.
const onInitFailure = (err: unknown) => {
console.log('initWallet error', err);
crashlyticsRecordErrorReport(
`initWallet failed: ${(err as Error)?.message}`,
);
setInitSettings(prev => ({ ...prev, isLoaded: true }));
};
if (!didInitializeSettings.current) {
didInitializeSettings.current = true;
initWallet(false);
initWallet(false).catch(onInitFailure);
} else {
didInitializeSettings.current = true;
initWallet(true);
initWallet(true).catch(onInitFailure);
}
return () => {
cancelled = true;
};
}, [appState]);
const handleAnimationFinish = () => {
setInitSettings(prev => {
return { ...prev, isLoaded: true };
});
};
const navigationTheme = useMemo(
() => ({
...DefaultTheme,
@@ -638,7 +660,6 @@ function ResetStack(): JSX.Element | null {
name="Splash"
component={SplashScreen}
options={{ animation: 'fade', gestureEnabled: false }}
// initialParams={{ onAnimationFinish: handleAnimationFinish }}
/>
<Stack.Screen
name="SplashReload"
@@ -0,0 +1,211 @@
/**
* Regression test for the silent infinite-hang on the login loading screen.
*
* The watchdog used to key off `didRunConnectionRef`, which is set the instant the
* connect process is *scheduled* — so the only timeout in the login flow was
* disarmed exactly when the risky, network-bound work began. Anything that stayed
* pending forever without rejecting (firestore reads/writes, the NWC spark wallet
* init) left the user on an endless mascot animation with no error.
*
* These tests pin the fixed contract: the process either settles, or the user gets
* the recoverable error UI within 30s.
*/
import React from 'react';
import ReactTestRenderer, { act } from 'react-test-renderer';
const ERROR_UI_TEXT = 'NO_CONTENT_SCREEN';
// ── Contexts ────────────────────────────────────────────────────────────────
const didRunHandshakeRef = { current: true };
jest.mock('../../context-store/context', () => ({
useGlobalContextProvider: () => ({
toggleMasterInfoObject: jest.fn(),
masterInfoObject: {},
setMasterInfoObject: jest.fn(),
preloadedUserData: { isLoading: false, data: null },
setPreLoadedUserData: jest.fn(),
}),
}));
jest.mock('../../context-store/webViewContext', () => ({
useWebView: () => ({ didRunHandshakeRef: { current: true } }),
}));
jest.mock('../../context-store/sparkContext', () => ({
useSparkWallet: () => ({
connectToSparkWallet: jest.fn(),
setSparkInformation: jest.fn(),
}),
}));
jest.mock('../../context-store/keys', () => ({
useKeysContext: () => ({
toggleContactsPrivateKey: jest.fn(),
accountMnemoinc: 'test mnemonic',
}),
}));
jest.mock('../../context-store/theme', () => ({
useGlobalThemeContext: () => ({ theme: false }),
}));
jest.mock('../../context-store/globalContacts', () => ({
useGlobalContactsInfo: () => ({ toggleGlobalContactsInformation: jest.fn() }),
}));
jest.mock('../../context-store/appData', () => ({
useGlobalAppData: () => ({ toggleGlobalAppDataInformation: jest.fn() }),
}));
jest.mock('../../context-store/appStatus', () => ({
useAppStatus: () => ({ screenDimensions: { width: 400 } }),
}));
jest.mock('../../context-store/nodeContext', () => ({
useNodeContext: () => ({ toggleFiatStats: jest.fn() }),
}));
// ── Navigation ──────────────────────────────────────────────────────────────
jest.mock('@react-navigation/native', () => ({
useNavigation: () => ({ navigate: jest.fn(), replace: jest.fn() }),
useRoute: () => ({ params: {} }),
StackActions: { replace: jest.fn(() => ({ type: 'REPLACE' })) },
}));
jest.mock('../../navigation/navigationService', () => ({
navigationRef: {
getCurrentRoute: () => ({ name: 'ConnectingToNodeLoadingScreen' }),
isReady: () => true,
dispatch: jest.fn(),
},
}));
// ── UI leaves ───────────────────────────────────────────────────────────────
jest.mock('react-i18next', () => ({ useTranslation: () => ({ t: k => k }) }));
jest.mock('lottie-react-native', () => 'LottieView');
jest.mock('../../app/functions/CustomElements', () => ({
GlobalThemeView: ({ children }) => children,
}));
jest.mock('../../app/functions/CustomElements/themeIcon', () => 'ThemeIcon');
jest.mock('../../app/functions/CustomElements/noContentScreen', () => {
const MockReact = require('react');
const { Text } = require('react-native');
return {
__esModule: true,
default: () => MockReact.createElement(Text, null, 'NO_CONTENT_SCREEN'),
};
});
jest.mock('../../app/functions/lottieViewColorTransformer', () => ({
updateMascatWalkingAnimation: () => ({}),
}));
jest.mock('../../app/functions/openWebBrowser', () => ({
__esModule: true,
default: jest.fn(),
}));
// ── Boot-path work ──────────────────────────────────────────────────────────
jest.mock('../../app/functions/crashlyticsLogs', () => ({
crashlyticsLogReport: jest.fn(),
crashlyticsRecordErrorReport: jest.fn(),
}));
jest.mock('../../app/functions/localStorage', () => ({
removeLocalStorageItem: jest.fn(),
}));
jest.mock('../../app/functions/hash', () => ({
__esModule: true,
default: () => 'hash',
}));
jest.mock('../../app/functions/nostrCompatability', () => ({
privateKeyFromSeedWords: jest.fn(async () => 'privkey'),
}));
jest.mock('nostr-tools', () => ({ getPublicKey: () => 'pubkey' }));
jest.mock('../../app/functions/gift/deriveGiftWallet', () => ({
deriveSparkIdentityKey: jest.fn(async () => ({ publicKeyHex: 'abc' })),
}));
jest.mock('../../app/functions/initializeAllDatabases', () => ({
initializeAllDatabases: jest.fn(async () => true),
}));
jest.mock('../../app/functions/spark', () => ({
getCachedSparkTransactions: jest.fn(async () => []),
}));
jest.mock('../../app/functions/spark/balanceSnapshots', () => ({
getAccountBalanceSnapshot: jest.fn(async () => ({ balance: 0 })),
}));
jest.mock('../../app/functions/saveAndUpdateFiatData', () => ({
getCachedFiatRate: jest.fn(async () => null),
}));
jest.mock('../../app/functions/initializeUserSettings', () => ({
__esModule: true,
default: jest.fn(),
}));
const initializeUserSettingsFromHistory =
require('../../app/functions/initializeUserSettings').default;
const { crashlyticsRecordErrorReport } = require('../../app/functions/crashlyticsLogs');
const ConnectingToNodeLoadingScreen =
require('../../app/screens/inAccount/loadingScreen').default;
// Let the effect's requestAnimationFrame run synchronously under fake timers.
global.requestAnimationFrame = cb => cb();
const showsErrorUI = renderer =>
JSON.stringify(renderer.toJSON() ?? '').includes(ERROR_UI_TEXT);
// Drains queued microtasks so pending awaits advance between timer jumps.
const flush = async () => {
for (let i = 0; i < 10; i++) {
await act(async () => {
await Promise.resolve();
});
}
};
describe('loading screen watchdog', () => {
beforeEach(() => {
jest.useFakeTimers();
jest.clearAllMocks();
});
afterEach(() => {
jest.useRealTimers();
});
test('shows the recoverable error UI when a boot dependency never settles', async () => {
// The exact failure mode from the field report: a promise that stays pending
// forever and never rejects, so no try/catch in the chain can see it.
initializeUserSettingsFromHistory.mockReturnValue(new Promise(() => {}));
let renderer;
await act(async () => {
renderer = ReactTestRenderer.create(<ConnectingToNodeLoadingScreen />);
});
await flush();
expect(showsErrorUI(renderer)).toBe(false);
await act(async () => {
jest.advanceTimersByTime(30000);
});
await flush();
expect(showsErrorUI(renderer)).toBe(true);
expect(crashlyticsRecordErrorReport).toHaveBeenCalledWith(
expect.stringContaining('Login watchdog fired'),
);
});
test('does not fire once the connect process has settled', async () => {
initializeUserSettingsFromHistory.mockResolvedValue(true);
let renderer;
await act(async () => {
renderer = ReactTestRenderer.create(<ConnectingToNodeLoadingScreen />);
});
await flush();
// Clear the "minimum perceived loading time" wait so the process completes.
await act(async () => {
jest.advanceTimersByTime(2000);
});
await flush();
await act(async () => {
jest.advanceTimersByTime(30000);
});
await flush();
expect(showsErrorUI(renderer)).toBe(false);
expect(crashlyticsRecordErrorReport).not.toHaveBeenCalled();
});
});
+22 -6
View File
@@ -33,6 +33,7 @@ export default async function initializeUserSettingsFromHistory({
let needsToUpdate = false;
let tempObject = {};
crashlyticsLogReport('Authenticating with firebase');
const [
_,
// pastExploreData,
@@ -45,6 +46,8 @@ export default async function initializeUserSettingsFromHistory({
// const shouldLoadExporeDataResp = shouldLoadExploreData(pastExploreData);
crashlyticsLogReport('Firebase authenticated, reading user document');
// Wrap both of thses in promise.all to fetch together.
let [
blitzStoredData,
@@ -67,6 +70,8 @@ export default async function initializeUserSettingsFromHistory({
// : Promise.resolve(null),
]);
crashlyticsLogReport('Read user document and local storage items');
if (preloadedData) {
// clear refrenace to remove uneeded object
setPreLoadedUserData({});
@@ -331,13 +336,18 @@ export default async function initializeUserSettingsFromHistory({
// }
if (!nwc_identity_pub_key) {
const didInit = await initializeNWCWallet();
if (didInit.isConnected) {
// Deliberately not awaited. This backfills nwc_identity_pub_key, which
// nothing below reads, but it runs a full SparkWallet.initialize() network
// handshake with no timeout — and because the key is only persisted on
// success, it re-runs on every cold start for anyone whose NWC wallet has
// never initialized. Awaiting it made an optional side quest a hard gate on
// login. Let it settle on its own.
(async () => {
const didInit = await initializeNWCWallet();
if (!didInit.isConnected) return;
const pubkey = await getNWCSparkIdentityPubKey();
toggleMasterInfoObject({ [NWC_IDENTITY_PUB_KEY]: pubkey });
}
})().catch(err => console.log('NWC identity backfill error', err));
}
if (!userBalanceDenomination) {
@@ -429,7 +439,13 @@ export default async function initializeUserSettingsFromHistory({
tempObject['didViewNWCMessage'] = didViewNWCMessage;
if (needsToUpdate || Object.keys(blitzStoredData).length === 0) {
await sendDataToDB(tempObject, publicKey);
// Deliberately not awaited. tempObject is already fully built in memory, so
// this is pure persistence — and a firestore write promise only settles on
// server ack, meaning offline it stays pending forever without rejecting.
// Firestore queues the write durably and flushes on reconnect either way.
sendDataToDB(tempObject, publicKey).catch(err =>
console.log('Deferred settings write error', err),
);
}
delete tempObject['contacts'];
// delete tempObject['eCashInformation'];
+47 -11
View File
@@ -17,7 +17,10 @@ import { navigationRef } from '../../../navigation/navigationService';
import { useGlobalThemeContext } from '../../../context-store/theme';
import { useKeysContext } from '../../../context-store/keys';
import { updateMascatWalkingAnimation } from '../../functions/lottieViewColorTransformer';
import { crashlyticsLogReport } from '../../functions/crashlyticsLogs';
import {
crashlyticsLogReport,
crashlyticsRecordErrorReport,
} from '../../functions/crashlyticsLogs';
import { useSparkWallet } from '../../../context-store/sparkContext';
import { removeLocalStorageItem } from '../../functions/localStorage';
import { getAccountBalanceSnapshot } from '../../functions/spark/balanceSnapshots';
@@ -34,6 +37,7 @@ import openWebBrowser from '../../functions/openWebBrowser';
import NoContentScreen from '../../functions/CustomElements/noContentScreen';
import { useNodeContext } from '../../../context-store/nodeContext';
import { getCachedFiatRate } from '../../functions/saveAndUpdateFiatData';
import i18next from 'i18next';
const mascotAnimation = require('../../assets/MOSCATWALKING.json');
@@ -64,6 +68,13 @@ export default function ConnectingToNodeLoadingScreen() {
const [hasError, setHasError] = useState(null);
const { t } = useTranslation();
const didRunConnectionRef = useRef(null);
// Latched once startConnectProcess has fully settled (navigated, or errored
// into the recoverable UI). The watchdog below keys off this, NOT off
// didRunConnectionRef — see the comment there.
const didCompleteRef = useRef(false);
// Last boundary startConnectProcess got past. Reported with the watchdog error
// so a stall in the wild names its own phase in Crashlytics.
const phaseRef = useRef('mounted');
const transformedAnimation = useMemo(
() =>
@@ -83,6 +94,7 @@ export default function ConnectingToNodeLoadingScreen() {
crashlyticsLogReport(
'Begining app connnection procress in loading screen',
);
phaseRef.current = 'deriving keys + webview handshake + db init';
removeLocalStorageItem(PERSISTED_LOGIN_COUNT_KEY);
// ── Phase 1: Derive keys + wait for webview handshake in parallel ──
@@ -108,6 +120,9 @@ export default function ConnectingToNodeLoadingScreen() {
initializeAllDatabases(),
]);
crashlyticsLogReport('Derived keys, webview handshake and db ready');
phaseRef.current = 'loading user settings + cached balance/txs';
// Start wallet connection after keys are derived — passes identityPubKey
// so initializeSparkSession can skip getSparkBalance when snapshot exists
connectToSparkWallet(identityPubKey.publicKeyHex);
@@ -153,6 +168,8 @@ export default function ConnectingToNodeLoadingScreen() {
//https://github.com/firebase/firebase-ios-sdk/pull/15991
toggleContactsPrivateKey(privateKey);
console.log(balanceSnapshot, placeholderTxs, 'balance and tx snapshot');
crashlyticsLogReport('Loaded user settings and cached balance/txs');
phaseRef.current = 'applying cached state + navigating home';
// ── Phase 3: Apply cached balance ─────────────────────────────────
setSparkInformation(prev => ({
@@ -199,6 +216,10 @@ export default function ConnectingToNodeLoadingScreen() {
subtitle: err.message,
});
}
} finally {
// Settled either way (navigated, bailed as a stale duplicate, or errored
// into the recoverable UI) — disarm the watchdog.
didCompleteRef.current = true;
}
}
@@ -229,20 +250,35 @@ export default function ConnectingToNodeLoadingScreen() {
expectedMnemonicHash,
]);
// Safety valve for the seed gate: if the in-context seed never converges to
// the expected one (should not happen once the eager restore-path generation
// is fixed), surface the recoverable error UI instead of spinning forever.
// Safety valve for the WHOLE login process, not just the seed gate.
//
// This previously keyed off didRunConnectionRef, which is set the instant
// startConnectProcess is scheduled — so the only timeout in the login flow was
// switched off at exactly the moment the risky work began. Everything after it
// (firebase auth, firestore reads/writes, the NWC spark wallet init) is network
// bound and can stay pending forever without ever rejecting, which no try/catch
// can see. That produced the reported symptom: an endless mascot animation with
// no error and no way out.
//
// Keying off didCompleteRef instead means no reachable path can spin forever —
// any stall lands on the recoverable error UI below, which carries the doomsday
// settings button and the recovery link. Deps are empty (t is read through a
// ref) so an i18n language change can't restart the timer.
useEffect(() => {
const timer = setTimeout(() => {
if (!didRunConnectionRef.current) {
setHasError({
title: t('screens.inAccount.loadingScreen.initErrorTitle'),
subtitle: t('screens.inAccount.loadingScreen.userSettingsError'),
});
}
if (didCompleteRef.current) return;
crashlyticsRecordErrorReport(
`Login watchdog fired after 30s. Last phase reached: ${phaseRef.current}`,
);
setHasError({
title: i18next.t('screens.inAccount.loadingScreen.initErrorTitle'),
subtitle: i18next.t(
'screens.inAccount.loadingScreen.userSettingsError',
),
});
}, 30000);
return () => clearTimeout(timer);
}, [t]);
}, []);
return (
<GlobalThemeView useStandardWidth={true}>