From 4c90cd62fe451de044e6818d5109c95fcd65b54f Mon Sep 17 00:00:00 2001 From: Henry Heino <46334387+personalizedrefrigerator@users.noreply.github.com> Date: Fri, 25 Jul 2025 01:20:38 -0700 Subject: [PATCH] Chore: Mobile: Log startup performance information (#12776) Co-authored-by: Laurent Cozic --- .eslintignore | 3 + .gitignore | 3 + packages/app-desktop/ElectronAppWrapper.ts | 2 +- packages/app-mobile/root.tsx | 463 +--------------- .../app-mobile/utils/buildStartupTasks.ts | 496 ++++++++++++++++++ packages/lib/BaseApplication.ts | 6 + packages/lib/PerformanceLogger.test.ts | 27 + packages/lib/PerformanceLogger.ts | 148 ++++++ packages/lib/services/DecryptionWorker.ts | 4 + packages/lib/services/search/SearchEngine.ts | 6 + readme/dev/spec/performance.md | 63 +++ 11 files changed, 784 insertions(+), 437 deletions(-) create mode 100644 packages/app-mobile/utils/buildStartupTasks.ts create mode 100644 packages/lib/PerformanceLogger.test.ts create mode 100644 packages/lib/PerformanceLogger.ts create mode 100644 readme/dev/spec/performance.md diff --git a/.eslintignore b/.eslintignore index 1c7a6c3245..0a9d67706c 100644 --- a/.eslintignore +++ b/.eslintignore @@ -892,6 +892,7 @@ packages/app-mobile/utils/ShareUtils.js packages/app-mobile/utils/TlsUtils.js packages/app-mobile/utils/appDefaultState.js packages/app-mobile/utils/autodetectTheme.js +packages/app-mobile/utils/buildStartupTasks.js packages/app-mobile/utils/checkPermissions.js packages/app-mobile/utils/createRootStyle.js packages/app-mobile/utils/database-driver-react-native.js @@ -1077,6 +1078,8 @@ packages/lib/JoplinDatabase.js packages/lib/JoplinError.js packages/lib/JoplinServerApi.js packages/lib/ObjectUtils.js +packages/lib/PerformanceLogger.test.js +packages/lib/PerformanceLogger.js packages/lib/PoorManIntervals.js packages/lib/RotatingLogs.test.js packages/lib/RotatingLogs.js diff --git a/.gitignore b/.gitignore index 63600b7217..8f8653d68b 100644 --- a/.gitignore +++ b/.gitignore @@ -867,6 +867,7 @@ packages/app-mobile/utils/ShareUtils.js packages/app-mobile/utils/TlsUtils.js packages/app-mobile/utils/appDefaultState.js packages/app-mobile/utils/autodetectTheme.js +packages/app-mobile/utils/buildStartupTasks.js packages/app-mobile/utils/checkPermissions.js packages/app-mobile/utils/createRootStyle.js packages/app-mobile/utils/database-driver-react-native.js @@ -1052,6 +1053,8 @@ packages/lib/JoplinDatabase.js packages/lib/JoplinError.js packages/lib/JoplinServerApi.js packages/lib/ObjectUtils.js +packages/lib/PerformanceLogger.test.js +packages/lib/PerformanceLogger.js packages/lib/PoorManIntervals.js packages/lib/RotatingLogs.test.js packages/lib/RotatingLogs.js diff --git a/packages/app-desktop/ElectronAppWrapper.ts b/packages/app-desktop/ElectronAppWrapper.ts index 3f8766253f..9028f6b309 100644 --- a/packages/app-desktop/ElectronAppWrapper.ts +++ b/packages/app-desktop/ElectronAppWrapper.ts @@ -8,7 +8,7 @@ import { FileLocker } from '@joplin/utils/fs'; import { IpcMessageHandler, IpcServer, Message, newHttpError, sendMessage, SendMessageOptions, startServer, stopServer } from '@joplin/utils/ipc'; import { BrowserWindow, Tray, WebContents, screen, App, nativeTheme } from 'electron'; import bridge from './bridge'; -const url = require('url'); +import * as url from 'url'; const path = require('path'); const { dirname } = require('@joplin/lib/path-utils'); const fs = require('fs-extra'); diff --git a/packages/app-mobile/root.tsx b/packages/app-mobile/root.tsx index 05ef30599a..9d0ceefe72 100644 --- a/packages/app-mobile/root.tsx +++ b/packages/app-mobile/root.tsx @@ -1,32 +1,26 @@ import * as React from 'react'; import shim from '@joplin/lib/shim'; +import PerformanceLogger from '@joplin/lib/PerformanceLogger'; + shim.setReact(React); +PerformanceLogger.onAppStartBegin(); import setupQuickActions from './setupQuickActions'; -import PluginAssetsLoader from './PluginAssetsLoader'; import AlarmService from '@joplin/lib/services/AlarmService'; import Alarm from '@joplin/lib/models/Alarm'; import time from '@joplin/lib/time'; -import Logger, { TargetType } from '@joplin/utils/Logger'; -import BaseModel from '@joplin/lib/BaseModel'; -import BaseService from '@joplin/lib/services/BaseService'; -import ResourceService from '@joplin/lib/services/ResourceService'; -import KvStore from '@joplin/lib/services/KvStore'; +import Logger from '@joplin/utils/Logger'; import NoteScreen from './components/screens/Note/Note'; import UpgradeSyncTargetScreen from './components/screens/UpgradeSyncTargetScreen'; -import Setting, { AppType, Env } from '@joplin/lib/models/Setting'; +import Setting, { } from '@joplin/lib/models/Setting'; import PoorManIntervals from '@joplin/lib/PoorManIntervals'; -import reducer, { NotesParent, parseNotesParent, serializeNotesParent } from '@joplin/lib/reducer'; +import reducer, { NotesParent, serializeNotesParent } from '@joplin/lib/reducer'; import ShareExtension, { UnsubscribeShareListener } from './utils/ShareExtension'; import handleShared from './utils/shareHandler'; -import uuid from '@joplin/lib/uuid'; -import { loadKeychainServiceAndSettings } from '@joplin/lib/services/SettingUtils'; import { _, setLocale } from '@joplin/lib/locale'; import SyncTargetJoplinServer from '@joplin/lib/SyncTargetJoplinServer'; import SyncTargetJoplinCloud from '@joplin/lib/SyncTargetJoplinCloud'; import SyncTargetOneDrive from '@joplin/lib/SyncTargetOneDrive'; -import initProfile from '@joplin/lib/services/profileConfig/initProfile'; -const VersionInfo = require('react-native-version-info').default; import { Keyboard, BackHandler, Animated, StatusBar, Platform, Dimensions } from 'react-native'; import { AppState as RNAppState, EmitterSubscription, View, Text, Linking, NativeEventSubscription, Appearance, ActivityIndicator } from 'react-native'; import getResponsiveValue from './components/getResponsiveValue'; @@ -41,20 +35,8 @@ import BackButtonService, { BackButtonHandler } from './services/BackButtonServi import NavService from '@joplin/lib/services/NavService'; import { createStore, applyMiddleware, Dispatch } from 'redux'; import reduxSharedMiddleware from '@joplin/lib/components/shared/reduxSharedMiddleware'; -import shimInit from './utils/shim-init-react'; const { AppNav } = require('./components/app-nav.js'); -import Note from '@joplin/lib/models/Note'; import Folder from '@joplin/lib/models/Folder'; -import BaseSyncTarget from '@joplin/lib/BaseSyncTarget'; -import Resource from '@joplin/lib/models/Resource'; -import Tag from '@joplin/lib/models/Tag'; -import NoteTag from '@joplin/lib/models/NoteTag'; -import BaseItem from '@joplin/lib/models/BaseItem'; -import MasterKey from '@joplin/lib/models/MasterKey'; -import Revision from '@joplin/lib/models/Revision'; -import RevisionService from '@joplin/lib/services/RevisionService'; -import JoplinDatabase from '@joplin/lib/JoplinDatabase'; -import Database from '@joplin/lib/database'; import NotesScreen from './components/screens/Notes/Notes'; import TagsScreen from './components/screens/tags'; import ConfigScreen from './components/screens/ConfigScreen/ConfigScreen'; @@ -71,10 +53,8 @@ import SideMenuContent from './components/side-menu-content'; import SideMenuContentNote, { SideMenuContentOptions } from './components/SideMenuContentNote'; import { reg } from '@joplin/lib/registry'; import { defaultState } from '@joplin/lib/reducer'; -import FileApiDriverLocal from '@joplin/lib/file-api-driver-local'; import ResourceFetcher from '@joplin/lib/services/ResourceFetcher'; import SearchEngine from '@joplin/lib/services/search/SearchEngine'; -import WelcomeUtils from '@joplin/lib/WelcomeUtils'; import { themeStyle } from './components/global-style'; import SyncTargetRegistry from '@joplin/lib/SyncTargetRegistry'; import SyncTargetFilesystem from '@joplin/lib/SyncTargetFilesystem'; @@ -84,7 +64,6 @@ const SyncTargetDropbox = require('@joplin/lib/SyncTargetDropbox.js'); const SyncTargetAmazonS3 = require('@joplin/lib/SyncTargetAmazonS3.js'); import SyncTargetJoplinServerSAML from '@joplin/lib/SyncTargetJoplinServerSAML'; import BiometricPopup from './components/biometrics/BiometricPopup'; -import initLib from '@joplin/lib/initLib'; import { isCallbackUrl, parseCallbackUrl, CallbackUrlCommand } from '@joplin/lib/callbackUrlUtils'; import JoplinCloudLoginScreen from './components/screens/JoplinCloudLoginScreen'; @@ -103,42 +82,23 @@ SyncTargetRegistry.addClass(SyncTargetJoplinServer); SyncTargetRegistry.addClass(SyncTargetJoplinServerSAML); SyncTargetRegistry.addClass(SyncTargetJoplinCloud); -import FsDriverRN from './utils/fs-driver/fs-driver-rn'; import DecryptionWorker from '@joplin/lib/services/DecryptionWorker'; import EncryptionService from '@joplin/lib/services/e2ee/EncryptionService'; -import MigrationService from '@joplin/lib/services/MigrationService'; -import { clearSharedFilesCache } from './utils/ShareUtils'; -import setIgnoreTlsErrors from './utils/TlsUtils'; -import ShareService from '@joplin/lib/services/share/ShareService'; import setupNotifications from './utils/setupNotifications'; -import { loadMasterKeysFromSettings, migrateMasterPassword } from '@joplin/lib/services/e2ee/utils'; -import { setRSA } from '@joplin/lib/services/e2ee/ppk'; -import RSA from './services/e2ee/RSA.react-native'; -import { runIntegrationTests as runRsaIntegrationTests } from '@joplin/lib/services/e2ee/ppkTestUtils'; -import { runIntegrationTests as runCryptoIntegrationTests } from '@joplin/lib/services/e2ee/cryptoTestUtils'; +import { loadMasterKeysFromSettings } from '@joplin/lib/services/e2ee/utils'; import { Theme, ThemeAppearance } from '@joplin/lib/themes/type'; import ProfileSwitcher from './components/ProfileSwitcher/ProfileSwitcher'; import ProfileEditor from './components/ProfileSwitcher/ProfileEditor'; import sensorInfo, { SensorInfo } from './components/biometrics/sensorInfo'; -import { getCurrentProfile } from '@joplin/lib/services/profileConfig'; -import { getDatabaseName, getPluginDataDir, getProfilesRootDir, getResourceDir, setDispatch } from './services/profiles'; -import userFetcher, { initializeUserFetcher } from '@joplin/lib/utils/userFetcher'; +import { setDispatch } from './services/profiles'; import { ReactNode } from 'react'; -import { parseShareCache } from '@joplin/lib/services/share/reducer'; import autodetectTheme, { onSystemColorSchemeChange } from './utils/autodetectTheme'; -import runOnDeviceFsDriverTests from './utils/fs-driver/runOnDeviceTests'; import PluginRunnerWebView from './components/plugins/PluginRunnerWebView'; import { refreshFolders, scheduleRefreshFolders } from '@joplin/lib/folders-screen-utils'; -import KeymapService from '@joplin/lib/services/KeymapService'; -import PluginService from '@joplin/lib/services/plugins/PluginService'; -import initializeCommandService from './utils/initializeCommandService'; -import PlatformImplementation from './services/plugins/PlatformImplementation'; import ShareManager from './components/screens/ShareManager'; -import appDefaultState, { DEFAULT_ROUTE } from './utils/appDefaultState'; +import appDefaultState from './utils/appDefaultState'; import { setDateFormat, setTimeFormat, setTimeLocale } from '@joplin/utils/time'; -import DatabaseDriverReactNative from './utils/database-driver-react-native'; import DialogManager from './components/DialogManager'; -import lockToSingleInstance from './utils/lockToSingleInstance'; import { AppState } from './utils/types'; import { getDisplayParentId } from '@joplin/lib/services/trash'; import PluginNotification from './components/plugins/PluginNotification'; @@ -147,9 +107,11 @@ import SsoLoginScreen from './components/screens/SsoLoginScreen'; import SamlShared from '@joplin/lib/components/shared/SamlShared'; import NoteRevisionViewer from './components/screens/NoteRevisionViewer'; import DocumentScanner from './components/screens/DocumentScanner/DocumentScanner'; +import buildStartupTasks from './utils/buildStartupTasks'; import { SafeAreaProvider } from 'react-native-safe-area-context'; const logger = Logger.create('root'); +const perfLogger = PerformanceLogger.create('root'); // eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied let storeDispatch: any = function(_action: any) {}; @@ -471,398 +433,23 @@ const appReducer = (state = appDefaultState, action: any) => { const store = createStore(appReducer, applyMiddleware(generalMiddleware)); storeDispatch = store.dispatch; -// eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied -function resourceFetcher_downloadComplete(event: any) { - if (event.encrypted) { - void DecryptionWorker.instance().scheduleStart(); - } -} - -function decryptionWorker_resourceMetadataButNotBlobDecrypted() { - ResourceFetcher.instance().scheduleAutoAddResources(); -} - -const initializeTempDir = async () => { - const tempDir = `${getProfilesRootDir()}/tmp`; - - // Re-create the temporary directory. - try { - await shim.fsDriver().remove(tempDir); - } catch (_error) { - // The logger may not exist yet. Do nothing. - } - - await shim.fsDriver().mkdir(tempDir); - return tempDir; -}; - -const getInitialActiveFolder = async () => { - let folderId = Setting.value('activeFolderId'); - - // In some cases (e.g. new profile/install), activeFolderId hasn't been set yet. - // Because activeFolderId is used to determine the parent for new notes, initialize - // it here: - if (!folderId) { - folderId = (await Folder.defaultFolder())?.id; - if (folderId) { - Setting.setValue('activeFolderId', folderId); - } - } - return await Folder.load(folderId); -}; - -const singleInstanceLock = lockToSingleInstance(); - -// eslint-disable-next-line @typescript-eslint/ban-types -- Old code before rule was applied async function initialize(dispatch: Dispatch) { - shimInit(); - setDispatch(dispatch); - const { profileConfig, isSubProfile } = await initProfile(getProfilesRootDir()); - const currentProfile = getCurrentProfile(profileConfig); - dispatch({ - type: 'PROFILE_CONFIG_SET', - value: profileConfig, - }); + const startupTasks = buildStartupTasks(dispatch, store); - Setting.setConstant('env', __DEV__ ? Env.Dev : Env.Prod); - Setting.setConstant('appId', 'net.cozic.joplin-mobile'); - Setting.setConstant('appType', AppType.Mobile); - Setting.setConstant('tempDir', await initializeTempDir()); - Setting.setConstant('cacheDir', `${getProfilesRootDir()}/cache`); - const resourceDir = getResourceDir(currentProfile, isSubProfile); - Setting.setConstant('resourceDir', resourceDir); - Setting.setConstant('pluginAssetDir', `${Setting.value('resourceDir')}/pluginAssets`); - Setting.setConstant('pluginDir', `${getProfilesRootDir()}/plugins`); - Setting.setConstant('pluginDataDir', getPluginDataDir(currentProfile, isSubProfile)); - - await shim.fsDriver().mkdir(resourceDir); - - // Do as much setup as possible before checking the lock -- the lock intentionally waits for - // messages from other clients for several hundred ms. - await singleInstanceLock; - - const logDatabase = new Database(new DatabaseDriverReactNative()); - await logDatabase.open({ name: 'log.sqlite' }); - await logDatabase.exec(Logger.databaseCreateTableSql()); - - const mainLogger = new Logger(); - mainLogger.addTarget(TargetType.Database, { database: logDatabase, source: 'm' }); - mainLogger.setLevel(Logger.LEVEL_INFO); - - if (Setting.value('env') === 'dev') { - mainLogger.addTarget(TargetType.Console); - mainLogger.setLevel(Logger.LEVEL_DEBUG); - } - - Logger.initializeGlobalLogger(mainLogger); - initLib(mainLogger); - - reg.setLogger(mainLogger); - reg.setShowErrorMessageBoxHandler((message: string) => { alert(message); }); - reg.setDispatch(dispatch); - - BaseService.logger_ = mainLogger; - // require('@joplin/lib/ntpDate').setLogger(reg.logger()); - - reg.logger().info('===================================='); - reg.logger().info(`Starting application ${Setting.value('appId')} v${VersionInfo.appVersion} (${Setting.value('env')})`); - - const dbLogger = new Logger(); - dbLogger.addTarget(TargetType.Database, { database: logDatabase, source: 'm' }); - if (Setting.value('env') === 'dev') { - dbLogger.addTarget(TargetType.Console); - dbLogger.setLevel(Logger.LEVEL_INFO); // Set to LEVEL_DEBUG for full SQL queries - } else { - dbLogger.setLevel(Logger.LEVEL_INFO); - } - - const db = new JoplinDatabase(new DatabaseDriverReactNative()); - db.setLogger(dbLogger); - reg.setDb(db); - - // reg.dispatch = dispatch; - BaseModel.dispatch = dispatch; - BaseSyncTarget.dispatch = dispatch; - NavService.dispatch = dispatch; - BaseModel.setDb(db); - - KvStore.instance().setDb(reg.db()); - - BaseItem.loadClass('Note', Note); - BaseItem.loadClass('Folder', Folder); - BaseItem.loadClass('Resource', Resource); - BaseItem.loadClass('Tag', Tag); - BaseItem.loadClass('NoteTag', NoteTag); - BaseItem.loadClass('MasterKey', MasterKey); - BaseItem.loadClass('Revision', Revision); - - const fsDriver = new FsDriverRN(); - - Resource.fsDriver_ = fsDriver; - FileApiDriverLocal.fsDriver_ = fsDriver; - - AlarmService.setDriver(new AlarmServiceDriver(mainLogger)); - AlarmService.setLogger(mainLogger); - - // Currently CommandService is just used for plugins. - initializeCommandService(store); - - // KeymapService is also present for plugin compatibility - KeymapService.instance().initialize(); - - // Even if there are no plugins, we need to initialize the PluginService so that - // plugin search can work. - const platformImplementation = PlatformImplementation.instance(); - PluginService.instance().initialize( - platformImplementation.versionInfo.version, platformImplementation, null, store, - ); - - setRSA(RSA); - - try { - if (Setting.value('env') === 'prod') { - await db.open({ name: getDatabaseName(currentProfile, isSubProfile) }); - } else { - await db.open({ name: getDatabaseName(currentProfile, isSubProfile, '-20240127-1') }); - - // await db.clearForTesting(); - } - - reg.logger().info('Database is ready.'); - reg.logger().info('Loading settings...'); - - await loadKeychainServiceAndSettings([]); - await migrateMasterPassword(); - - if (!Setting.value('clientId')) Setting.setValue('clientId', uuid.create()); - reg.logger().info(`Client ID: ${Setting.value('clientId')}`); - - BaseItem.syncShareCache = parseShareCache(Setting.value('sync.shareCache')); - - if (Setting.value('firstStart')) { - const detectedLocale = shim.detectAndSetLocale(Setting); - reg.logger().info(`First start: detected locale as ${detectedLocale}`); - - if (shim.mobilePlatform() === 'web') { - // Web browsers generally have more limited storage than desktop and mobile apps: - Setting.setValue('sync.resourceDownloadMode', 'auto'); - // For now, geolocation is disabled by default on web until the web permissions workflow - // is improved. At present, trackLocation=true causes the "allow location access" prompt - // to appear without a clear indicator for why Joplin wants this information. - Setting.setValue('trackLocation', false); - logger.info('First start on web: Set resource download mode to auto and disabled location tracking.'); + for (const [name, task] of startupTasks) { + await perfLogger.track(name, async () => { + try { + await task(); + } catch (error) { + logger.error(`Startup failure during task: ${name}`); + throw error; } - - Setting.skipDefaultMigrations(); - Setting.setValue('firstStart', false); - } else { - Setting.applyDefaultMigrations(); - } - - if (Setting.value('env') === Env.Dev) { - // Setting.setValue('sync.10.path', 'https://api.joplincloud.com'); - // Setting.setValue('sync.10.userContentPath', 'https://joplinusercontent.com'); - Setting.setValue('sync.10.path', 'http://api.joplincloud.local:22300'); - Setting.setValue('sync.10.userContentPath', 'http://joplinusercontent.local:22300'); - Setting.setValue('sync.10.website', 'http://joplincloud.local:22300'); - - // Setting.setValue('sync.target', 10); - // Setting.setValue('sync.10.username', 'user1@example.com'); - // Setting.setValue('sync.10.password', '111111'); - } - - if (Setting.value('db.ftsEnabled') === -1) { - const ftsEnabled = await db.ftsEnabled(); - Setting.setValue('db.ftsEnabled', ftsEnabled ? 1 : 0); - reg.logger().info('db.ftsEnabled = ', Setting.value('db.ftsEnabled')); - } - - if (Setting.value('env') === 'dev') { - Setting.setValue('welcome.enabled', false); - } - - await PluginAssetsLoader.instance().importAssets(); - - // eslint-disable-next-line require-atomic-updates - BaseItem.revisionService_ = RevisionService.instance(); - - // Note: for now we hard-code the folder sort order as we need to - // create a UI to allow customisation (started in branch mobile_add_sidebar_buttons) - Setting.setValue('folders.sortOrder.field', 'title'); - Setting.setValue('folders.sortOrder.reverse', false); - - reg.logger().info(`Sync target: ${Setting.value('sync.target')}`); - - setLocale(Setting.value('locale')); - - if (Platform.OS === 'android') { - const ignoreTlsErrors = Setting.value('net.ignoreTlsErrors'); - if (ignoreTlsErrors) { - await setIgnoreTlsErrors(ignoreTlsErrors); - } - } - - // ---------------------------------------------------------------- - // E2EE SETUP - // ---------------------------------------------------------------- - - EncryptionService.fsDriver_ = fsDriver; - // eslint-disable-next-line require-atomic-updates - BaseItem.encryptionService_ = EncryptionService.instance(); - BaseItem.shareService_ = ShareService.instance(); - Resource.shareService_ = ShareService.instance(); - DecryptionWorker.instance().dispatch = dispatch; - DecryptionWorker.instance().setLogger(mainLogger); - DecryptionWorker.instance().setKvStore(KvStore.instance()); - DecryptionWorker.instance().setEncryptionService(EncryptionService.instance()); - await loadMasterKeysFromSettings(EncryptionService.instance()); - DecryptionWorker.instance().on('resourceMetadataButNotBlobDecrypted', decryptionWorker_resourceMetadataButNotBlobDecrypted); - - // ---------------------------------------------------------------- - // / E2EE SETUP - // ---------------------------------------------------------------- - - await ShareService.instance().initialize(store, EncryptionService.instance()); - - reg.logger().info('Loading folders...'); - - // eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied - await refreshFolders((action: any) => dispatch(action), ''); - - const tags = await Tag.allWithNotes(); - - dispatch({ - type: 'TAG_UPDATE_ALL', - items: tags, }); - - // const masterKeys = await MasterKey.all(); - - // dispatch({ - // type: 'MASTERKEY_UPDATE_ALL', - // items: masterKeys, - // }); - - const folder = await getInitialActiveFolder(); - - dispatch({ - type: 'FOLDER_SET_COLLAPSED_ALL', - ids: Setting.value('collapsedFolderIds'), - }); - - const notesParent = parseNotesParent(Setting.value('notesParent'), Setting.value('activeFolderId')); - - if (notesParent && notesParent.type === 'SmartFilter') { - dispatch(DEFAULT_ROUTE); - } else if (!folder) { - dispatch(DEFAULT_ROUTE); - } else { - dispatch({ - type: 'NAV_GO', - routeName: 'Notes', - folderId: folder.id, - }); - } - - await clearSharedFilesCache(); - } catch (error) { - alert(`Initialization error: ${error.message}`); - reg.logger().error('Initialization error:', error); } - reg.setupRecurrentSync(); - - initializeUserFetcher(); - PoorManIntervals.setInterval(() => { void userFetcher(); }, 1000 * 60 * 60); - - PoorManIntervals.setTimeout(() => { - void AlarmService.garbageCollect(); - }, 1000 * 60 * 60); - - ResourceService.runInBackground(); - - ResourceFetcher.instance().setFileApi(() => { return reg.syncTarget().fileApi(); }); - ResourceFetcher.instance().setLogger(reg.logger()); - ResourceFetcher.instance().dispatch = dispatch; - ResourceFetcher.instance().on('downloadComplete', resourceFetcher_downloadComplete); - void ResourceFetcher.instance().start(); - - SearchEngine.instance().setDb(reg.db()); - SearchEngine.instance().setLogger(reg.logger()); - SearchEngine.instance().scheduleSyncTables(); - - await MigrationService.instance().run(); - - // When the app starts we want the full sync to - // start almost immediately to get the latest data. - // doWifiConnectionCheck set to true so initial sync - // doesn't happen on mobile data - // eslint-disable-next-line promise/prefer-await-to-then -- Old code before rule was applied - void reg.scheduleSync(100, null, true).then(() => { - // Wait for the first sync before updating the notifications, since synchronisation - // might change the notifications. - void AlarmService.updateAllNotifications(); - - void DecryptionWorker.instance().scheduleStart(); - }); - - await WelcomeUtils.install(Setting.value('locale'), dispatch); - - // Collect revisions more frequently on mobile because it doesn't auto-save - // and it cannot collect anything when the app is not active. - RevisionService.instance().runInBackground(1000 * 30); - - // ---------------------------------------------------------------------------- - // Plugin service setup - // ---------------------------------------------------------------------------- - - // On startup, we can clear plugin update state -- plugins that were updated when the - // user last ran the app have been updated and will be reloaded. - const pluginService = PluginService.instance(); - const pluginSettings = pluginService.unserializePluginSettings(Setting.value('plugins.states')); - - const updatedSettings = pluginService.clearUpdateState(pluginSettings); - Setting.setValue('plugins.states', updatedSettings); - - // ---------------------------------------------------------------------------- - // Keep this below to test react-native-rsa-native - // ---------------------------------------------------------------------------- - - // const testData = await createTestData(); - // await checkTestData(testData); - - // const testData = { - // "publicKey": "-----BEGIN RSA PUBLIC KEY-----\nMIIBCgKCAQEAoMx9NBioka8DUjO3bKrWMn8uJ23LH1xySogQFR6yh6qbl6i5LKTw\nPgqvv55FUuQtYTMtUTVLggYQhdCBvwbBrD1OqO4xU6Ew7x5/TQKPV3MSgYaps3FF\nOdipC4FyA00jBe6Z1CIpL+ZaSnvjDbMUf5lW8bmfRuXfdBGAcdSBjqm9ttajOws+\n7BBSQ9nI5dnBnWRIVEUb7e9bulgANzM1LMUOE+gaef7T3uKzc+Cx3BhHgw1JdFbL\nZAndYtP52KI5N3oiFM4II26DxmDrO1tQokNM88l5xT0BXPhYiEl1CeBpo5VHZBY2\nRHr4MM/OyAXSUdulsDzbntpE+Y85zv7gpQIDAQAB\n-----END RSA PUBLIC KEY-----", - // "privateKey": "-----BEGIN RSA PRIVATE KEY-----\nMIIEpAIBAAKCAQEAoMx9NBioka8DUjO3bKrWMn8uJ23LH1xySogQFR6yh6qbl6i5\nLKTwPgqvv55FUuQtYTMtUTVLggYQhdCBvwbBrD1OqO4xU6Ew7x5/TQKPV3MSgYap\ns3FFOdipC4FyA00jBe6Z1CIpL+ZaSnvjDbMUf5lW8bmfRuXfdBGAcdSBjqm9ttaj\nOws+7BBSQ9nI5dnBnWRIVEUb7e9bulgANzM1LMUOE+gaef7T3uKzc+Cx3BhHgw1J\ndFbLZAndYtP52KI5N3oiFM4II26DxmDrO1tQokNM88l5xT0BXPhYiEl1CeBpo5VH\nZBY2RHr4MM/OyAXSUdulsDzbntpE+Y85zv7gpQIDAQABAoIBAEA0Zmm+ztAcyX6x\nF7RUImLXVV55AHntN9V6rrFAKJjzDl1oCUhCM4sSSUqBr7yBT31YKegbF6M7OK21\nq5jS4dIcSKQ7N4bk/dz8mGfvdby9Pc5qLqhvuex3DkiBzzxyOGHN+64wVbHCkJrd\nDLQTpUOtvoGWVHrCno6Bzn+lEnYbvdr0hqI5H4D0ubk6TYed1/4ZlJf0R/o/4jnl\nou0UG2hpJN4ur506cttkZJSTxLjzdO38JuQIAkCEglrMYVY61lBNPxC11Kr3ZN7o\ncm7gWZVyP26KoU27t/g+2FoiBGsWLqGYiuTaqT6dKZ2vHyJGjJIZZStv5ye2Ez8V\nKQwpjQECgYEA3xtwYu4n/G5UjEMumkXHNd/bDamelo1aQvvjkVvxKeASNBqV8cM0\n6Jb2FCuT9Y3mWbFTM0jpqXehpHUOCCnrPKGKnJ0ZS4/SRIrtw0iM6q17fTAqmuOt\nhX0pJ77Il8lVCtx4ItsW+LUGbm6CwotlYLVUuyluhKe0pGw2yafi2N0CgYEAuIFk\ng4p7x0i1LFAlIP0YQ07bJQ0E6FEWbCfMgrV3VjtbnT99EaqPOHhMasITCuoEFlh8\ncgyZ6oH7GEy4IRWrM+Mlm47S+NTrr6KgnTGf570ZAFuqnJac97oFB7BvlQsQot6F\n0L2JKM7dQKIMlvwA9DoXZdKX/9ykiqqIpawNxmkCgYEAuyJOwAw2ads4+3UWT7wb\nfarIF8ugA3OItAqHNFNEEvWpDx8FigVMCZMl0IFE14AwKCc+PBP6OXTolgLAxEQ0\n1WRB2V9D6kc1/Nvy1guydt0QaU7PTZ+O2hrDPF0f74Cl3jhSZBoUSIO+Yz46W2eE\nnvs5mMsFsirgr9E8myRAd9kCgYAGMCDE4KIiHugkolN8dcCYkU58QaGGgSG1YuhT\nAe8Mr1T1QynYq9W92RsHAZdN6GdWsIUL9iw7VzyqpfgO9AEX7mhWfUXKHqoA6/1j\nCEUKqqbqAikIs2x0SoLcrSgw4XwfWkM2qwSsn7N/9W9iqPUHO+OJALUkWawTEoEe\nvVSA8QKBgQCEYCPnxgeQSZkrv7x5soXzgF1YN5EZRa1mTUqPBubs564ZjIIY66mI\nCTaHl7U1cPAhx7mHkSzP/i5NjjLqPZZNOyawWDEEmOzxX69OIzKImb6mEQNyS3do\nI8jnpN5q9pw5TvuEIYSrGqQVnHeaEjSvcT48W9GuzjNVscGfw76fPg==\n-----END RSA PRIVATE KEY-----", - // "plaintext": "just testing", - // "ciphertext": "BfkKLdrmd2UX4sPf0bzhfqrg3rKwH5DS7dPAqdmoQuHlrvEBrYKqheekwpnWQgGggGcm/orlrsQRwlexLv7jfRbb0bMnElkySMu4w6wTxILB66RX9H3vXCz02SwHKFRcuGJxlzTPUC23ki6f/McYJ2n/2L8qYxBO8fncTKutIWV54jY19RS1wQ4IdVDBqzji8D0QsRxUhVlpRk4qxsVnyuoyg9AyDe91LOYKfRc6NdapFij996nKzjxFcKOdBqpis34fN3Cg7avcs2Dm5vi7zlRhyGqJJhORXTU3x6hVwOBkVAisgaB7xS3lHiYp6Fs5tP3hBd0kFwVVx8gALbHsgg==" - // }; - // await checkTestData(testData); - - // await printTestData(); - - // ---------------------------------------------------------------------------- - // On desktop and CLI we run various tests to check that node-rsa is working - // as expected. On mobile however we cannot run test units directly on - // device, and that's what would be needed to automatically verify - // react-native-rsa-native. So instead we run the tests every time the - // mobile app is started in dev mode. If there's any regression the below - // call will throw an error, alerting us of the issue. Otherwise it will - // just print some messages in the console. - // ---------------------------------------------------------------------------- - if (Setting.value('env') === 'dev') { - if (Platform.OS !== 'web') { - await runRsaIntegrationTests(); - } else { - logger.info('Skipping encryption tests -- not supported on web.'); - } - await runCryptoIntegrationTests(); - await runOnDeviceFsDriverTests(); - } - - reg.logger().info('Application initialized'); + logger.info('Application initialized'); } interface AppComponentProps { @@ -1007,7 +594,7 @@ class AppComponent extends React.Component } try { - await initialize(this.props.dispatch); + await perfLogger.track('initialize', () => initialize(this.props.dispatch)); } catch (error) { alert(`Something went wrong while starting the application: ${error}`); this.props.dispatch({ @@ -1083,9 +670,13 @@ class AppComponent extends React.Component ); onSystemColorSchemeChange(Appearance.getColorScheme()); - this.quickActionShortcutListener_ = await setupQuickActions(this.props.dispatch); + this.quickActionShortcutListener_ = await perfLogger.track('setupQuickActions', + () => setupQuickActions(this.props.dispatch), + ); - await setupNotifications(this.props.dispatch); + await perfLogger.track('setupNotifications', + () => setupNotifications(this.props.dispatch), + ); this.keyboardShowListener_ = Keyboard.addListener('keyboardDidShow', () => { this.props.dispatch({ diff --git a/packages/app-mobile/utils/buildStartupTasks.ts b/packages/app-mobile/utils/buildStartupTasks.ts new file mode 100644 index 0000000000..d6c1390c85 --- /dev/null +++ b/packages/app-mobile/utils/buildStartupTasks.ts @@ -0,0 +1,496 @@ +import PluginAssetsLoader from '../PluginAssetsLoader'; +import AlarmService from '@joplin/lib/services/AlarmService'; +import Logger, { TargetType } from '@joplin/utils/Logger'; +import BaseModel from '@joplin/lib/BaseModel'; +import BaseService from '@joplin/lib/services/BaseService'; +import ResourceService from '@joplin/lib/services/ResourceService'; +import KvStore from '@joplin/lib/services/KvStore'; +import Setting, { AppType, Env } from '@joplin/lib/models/Setting'; +import PoorManIntervals from '@joplin/lib/PoorManIntervals'; +import { parseNotesParent } from '@joplin/lib/reducer'; +import uuid from '@joplin/lib/uuid'; +import { loadKeychainServiceAndSettings } from '@joplin/lib/services/SettingUtils'; +import { setLocale } from '@joplin/lib/locale'; +import SyncTargetJoplinServer from '@joplin/lib/SyncTargetJoplinServer'; +import SyncTargetJoplinCloud from '@joplin/lib/SyncTargetJoplinCloud'; +import SyncTargetOneDrive from '@joplin/lib/SyncTargetOneDrive'; +import initProfile from '@joplin/lib/services/profileConfig/initProfile'; +const VersionInfo = require('react-native-version-info').default; +const AlarmServiceDriver = require('../services/AlarmServiceDriver').default; +import NavService from '@joplin/lib/services/NavService'; +import { Dispatch, Store } from 'redux'; +import shimInit from '../utils/shim-init-react'; +import Note from '@joplin/lib/models/Note'; +import Folder from '@joplin/lib/models/Folder'; +import BaseSyncTarget from '@joplin/lib/BaseSyncTarget'; +import Resource from '@joplin/lib/models/Resource'; +import Tag from '@joplin/lib/models/Tag'; +import NoteTag from '@joplin/lib/models/NoteTag'; +import BaseItem from '@joplin/lib/models/BaseItem'; +import MasterKey from '@joplin/lib/models/MasterKey'; +import Revision from '@joplin/lib/models/Revision'; +import RevisionService from '@joplin/lib/services/RevisionService'; +import JoplinDatabase from '@joplin/lib/JoplinDatabase'; +import Database from '@joplin/lib/database'; +import { reg } from '@joplin/lib/registry'; +import FileApiDriverLocal from '@joplin/lib/file-api-driver-local'; +import ResourceFetcher from '@joplin/lib/services/ResourceFetcher'; +import SearchEngine from '@joplin/lib/services/search/SearchEngine'; +import WelcomeUtils from '@joplin/lib/WelcomeUtils'; +import SyncTargetRegistry from '@joplin/lib/SyncTargetRegistry'; +import SyncTargetFilesystem from '@joplin/lib/SyncTargetFilesystem'; +const SyncTargetNextcloud = require('@joplin/lib/SyncTargetNextcloud.js'); +const SyncTargetWebDAV = require('@joplin/lib/SyncTargetWebDAV.js'); +const SyncTargetDropbox = require('@joplin/lib/SyncTargetDropbox.js'); +const SyncTargetAmazonS3 = require('@joplin/lib/SyncTargetAmazonS3.js'); +import SyncTargetJoplinServerSAML from '@joplin/lib/SyncTargetJoplinServerSAML'; +import initLib from '@joplin/lib/initLib'; + +import SyncTargetNone from '@joplin/lib/SyncTargetNone'; + +const logger = Logger.create('buildStartupTasks'); + +SyncTargetRegistry.addClass(SyncTargetNone); +SyncTargetRegistry.addClass(SyncTargetOneDrive); +SyncTargetRegistry.addClass(SyncTargetNextcloud); +SyncTargetRegistry.addClass(SyncTargetWebDAV); +SyncTargetRegistry.addClass(SyncTargetDropbox); +SyncTargetRegistry.addClass(SyncTargetFilesystem); +SyncTargetRegistry.addClass(SyncTargetAmazonS3); +SyncTargetRegistry.addClass(SyncTargetJoplinServer); +SyncTargetRegistry.addClass(SyncTargetJoplinServerSAML); +SyncTargetRegistry.addClass(SyncTargetJoplinCloud); + +import DecryptionWorker from '@joplin/lib/services/DecryptionWorker'; +import EncryptionService from '@joplin/lib/services/e2ee/EncryptionService'; +import MigrationService from '@joplin/lib/services/MigrationService'; +import { clearSharedFilesCache } from '../utils/ShareUtils'; +import setIgnoreTlsErrors from '../utils/TlsUtils'; +import ShareService from '@joplin/lib/services/share/ShareService'; +import { loadMasterKeysFromSettings, migrateMasterPassword } from '@joplin/lib/services/e2ee/utils'; +import { setRSA } from '@joplin/lib/services/e2ee/ppk'; +import RSA from '../services/e2ee/RSA.react-native'; +import { runIntegrationTests as runRsaIntegrationTests } from '@joplin/lib/services/e2ee/ppkTestUtils'; +import { runIntegrationTests as runCryptoIntegrationTests } from '@joplin/lib/services/e2ee/cryptoTestUtils'; +import { getCurrentProfile } from '@joplin/lib/services/profileConfig'; +import { getDatabaseName, getPluginDataDir, getProfilesRootDir, getResourceDir } from '../services/profiles'; +import userFetcher, { initializeUserFetcher } from '@joplin/lib/utils/userFetcher'; +import { parseShareCache } from '@joplin/lib/services/share/reducer'; +import runOnDeviceFsDriverTests from '../utils/fs-driver/runOnDeviceTests'; +import { refreshFolders } from '@joplin/lib/folders-screen-utils'; +import KeymapService from '@joplin/lib/services/KeymapService'; +import PluginService from '@joplin/lib/services/plugins/PluginService'; +import initializeCommandService from '../utils/initializeCommandService'; +import PlatformImplementation from '../services/plugins/PlatformImplementation'; +import { DEFAULT_ROUTE } from '../utils/appDefaultState'; +import DatabaseDriverReactNative from '../utils/database-driver-react-native'; +import lockToSingleInstance from '../utils/lockToSingleInstance'; +import { AppState } from '../utils/types'; +import PerformanceLogger from '@joplin/lib/PerformanceLogger'; +import { Profile } from '@joplin/lib/services/profileConfig/types'; +import shim from '@joplin/lib/shim'; +import { Platform } from 'react-native'; + + +// eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied +function resourceFetcher_downloadComplete(event: any) { + if (event.encrypted) { + void DecryptionWorker.instance().scheduleStart(); + } +} + +function decryptionWorker_resourceMetadataButNotBlobDecrypted() { + ResourceFetcher.instance().scheduleAutoAddResources(); +} + +const initializeTempDir = async () => { + const tempDir = `${getProfilesRootDir()}/tmp`; + + // Re-create the temporary directory. + try { + await shim.fsDriver().remove(tempDir); + } catch (_error) { + // The logger may not exist yet. Do nothing. + } + + await shim.fsDriver().mkdir(tempDir); + return tempDir; +}; + +const getInitialActiveFolder = async () => { + let folderId = Setting.value('activeFolderId'); + + // In some cases (e.g. new profile/install), activeFolderId hasn't been set yet. + // Because activeFolderId is used to determine the parent for new notes, initialize + // it here: + if (!folderId) { + folderId = (await Folder.defaultFolder())?.id; + if (folderId) { + Setting.setValue('activeFolderId', folderId); + } + } + return await Folder.load(folderId); +}; + +const buildStartupTasks = ( + dispatch: Dispatch, store: Store, +) => { + type StartupTask = [string, ()=> Promise]; + const startupTasks: StartupTask[] = []; + const addTask = (name: string, task: ()=> Promise) => { + startupTasks.push([name, task]); + }; + + let logDatabase: Database; + let db: JoplinDatabase; + let isSubProfile: boolean; + let currentProfile: Profile; + let singleInstanceLock: Promise; + + + addTask('prepare single instance lock', async () => { + // The single instance lock involves waiting for messages -- start checking + // the lock as early as possible. + singleInstanceLock = lockToSingleInstance(); + }); + + addTask('shimInit', async () => { + shimInit(); + }); + addTask('initProfile', async () => { + const profile = await initProfile(getProfilesRootDir()); + isSubProfile = profile.isSubProfile; + currentProfile = getCurrentProfile(profile.profileConfig); + + dispatch({ + type: 'PROFILE_CONFIG_SET', + value: profile.profileConfig, + }); + }); + addTask('set constants', async () => { + Setting.setConstant('env', __DEV__ ? Env.Dev : Env.Prod); + Setting.setConstant('appId', 'net.cozic.joplin-mobile'); + Setting.setConstant('appType', AppType.Mobile); + Setting.setConstant('tempDir', await initializeTempDir()); + Setting.setConstant('cacheDir', `${getProfilesRootDir()}/cache`); + const resourceDir = getResourceDir(currentProfile, isSubProfile); + Setting.setConstant('resourceDir', resourceDir); + Setting.setConstant('pluginAssetDir', `${Setting.value('resourceDir')}/pluginAssets`); + Setting.setConstant('pluginDir', `${getProfilesRootDir()}/plugins`); + Setting.setConstant('pluginDataDir', getPluginDataDir(currentProfile, isSubProfile)); + }); + addTask('make resource directory', async () => { + await shim.fsDriver().mkdir(Setting.value('resourceDir')); + }); + addTask('singleInstanceLock', async () => { + // Do as much setup as possible before checking the lock -- the lock intentionally waits for + // messages from other clients for several hundred ms. + await singleInstanceLock; + }); + addTask('set up logger', async () => { + logDatabase = new Database(new DatabaseDriverReactNative()); + await logDatabase.open({ name: 'log.sqlite' }); + await logDatabase.exec(Logger.databaseCreateTableSql()); + + const mainLogger = new Logger(); + mainLogger.addTarget(TargetType.Database, { database: logDatabase, source: 'm' }); + mainLogger.setLevel(Logger.LEVEL_INFO); + + if (Setting.value('env') === 'dev') { + mainLogger.addTarget(TargetType.Console); + mainLogger.setLevel(Logger.LEVEL_DEBUG); + } + + Logger.initializeGlobalLogger(mainLogger); + initLib(mainLogger); + reg.setLogger(mainLogger); + BaseService.logger_ = mainLogger; + PerformanceLogger.setLogger(mainLogger); + }); + addTask('set up database', async () => { + reg.setShowErrorMessageBoxHandler((message: string) => { alert(message); }); + reg.setDispatch(dispatch); + + // require('@joplin/lib/ntpDate').setLogger(reg.logger()); + + reg.logger().info('===================================='); + reg.logger().info(`Starting application ${Setting.value('appId')} v${VersionInfo.appVersion} (${Setting.value('env')})`); + + const dbLogger = new Logger(); + dbLogger.addTarget(TargetType.Database, { database: logDatabase, source: 'm' }); + if (Setting.value('env') === 'dev') { + dbLogger.addTarget(TargetType.Console); + dbLogger.setLevel(Logger.LEVEL_INFO); // Set to LEVEL_DEBUG for full SQL queries + } else { + dbLogger.setLevel(Logger.LEVEL_INFO); + } + + db = new JoplinDatabase(new DatabaseDriverReactNative()); + db.setLogger(dbLogger); + reg.setDb(db); + }); + addTask('initialize item classes', async () => { + // reg.dispatch = dispatch; + BaseModel.dispatch = dispatch; + BaseSyncTarget.dispatch = dispatch; + NavService.dispatch = dispatch; + BaseModel.setDb(reg.db()); + KvStore.instance().setDb(reg.db()); + + BaseItem.loadClass('Note', Note); + BaseItem.loadClass('Folder', Folder); + BaseItem.loadClass('Resource', Resource); + BaseItem.loadClass('Tag', Tag); + BaseItem.loadClass('NoteTag', NoteTag); + BaseItem.loadClass('MasterKey', MasterKey); + BaseItem.loadClass('Revision', Revision); + + BaseItem.revisionService_ = RevisionService.instance(); + + Resource.fsDriver_ = shim.fsDriver(); + FileApiDriverLocal.fsDriver_ = shim.fsDriver(); + }); + addTask('initializeAlarmService', async () => { + AlarmService.setLogger(reg.logger()); + AlarmService.setDriver(new AlarmServiceDriver(reg.logger())); + }); + addTask('openDatabase', async () => { + if (Setting.value('env') === 'prod') { + await db.open({ name: getDatabaseName(currentProfile, isSubProfile) }); + } else { + await db.open({ name: getDatabaseName(currentProfile, isSubProfile, '-20240127-1') }); + + // await db.clearForTesting(); + } + }); + addTask('setUpSettings', async () => { + await loadKeychainServiceAndSettings([]); + await migrateMasterPassword(); + + if (!Setting.value('clientId')) Setting.setValue('clientId', uuid.create()); + reg.logger().info(`Client ID: ${Setting.value('clientId')}`); + + BaseItem.syncShareCache = parseShareCache(Setting.value('sync.shareCache')); + + if (Setting.value('firstStart')) { + const detectedLocale = shim.detectAndSetLocale(Setting); + reg.logger().info(`First start: detected locale as ${detectedLocale}`); + + if (shim.mobilePlatform() === 'web') { + // Web browsers generally have more limited storage than desktop and mobile apps: + Setting.setValue('sync.resourceDownloadMode', 'auto'); + // For now, geolocation is disabled by default on web until the web permissions workflow + // is improved. At present, trackLocation=true causes the "allow location access" prompt + // to appear without a clear indicator for why Joplin wants this information. + Setting.setValue('trackLocation', false); + logger.info('First start on web: Set resource download mode to auto and disabled location tracking.'); + } + + Setting.skipDefaultMigrations(); + Setting.setValue('firstStart', false); + } else { + Setting.applyDefaultMigrations(); + } + + if (Setting.value('env') === Env.Dev) { + // Setting.setValue('sync.10.path', 'https://api.joplincloud.com'); + // Setting.setValue('sync.10.userContentPath', 'https://joplinusercontent.com'); + Setting.setValue('sync.10.path', 'http://api.joplincloud.local:22300'); + Setting.setValue('sync.10.userContentPath', 'http://joplinusercontent.local:22300'); + Setting.setValue('sync.10.website', 'http://joplincloud.local:22300'); + + // Setting.setValue('sync.target', 10); + // Setting.setValue('sync.10.username', 'user1@example.com'); + // Setting.setValue('sync.10.password', '111111'); + } + + if (Setting.value('db.ftsEnabled') === -1) { + const ftsEnabled = await db.ftsEnabled(); + Setting.setValue('db.ftsEnabled', ftsEnabled ? 1 : 0); + reg.logger().info('db.ftsEnabled = ', Setting.value('db.ftsEnabled')); + } + + if (Setting.value('env') === 'dev') { + Setting.setValue('welcome.enabled', false); + } + + // Note: for now we hard-code the folder sort order as we need to + // create a UI to allow customisation (started in branch mobile_add_sidebar_buttons) + Setting.setValue('folders.sortOrder.field', 'title'); + Setting.setValue('folders.sortOrder.reverse', false); + + + reg.logger().info(`Sync target: ${Setting.value('sync.target')}`); + + setLocale(Setting.value('locale')); + + if (Platform.OS === 'android') { + const ignoreTlsErrors = Setting.value('net.ignoreTlsErrors'); + if (ignoreTlsErrors) { + await setIgnoreTlsErrors(ignoreTlsErrors); + } + } + }); + addTask('import plugin assets', async () => { + await PluginAssetsLoader.instance().importAssets(); + }); + addTask('set up command & keymap services', async () => { + initializeCommandService(store); + KeymapService.instance().initialize(); + }); + addTask('set up E2EE', async () => { + setRSA(RSA); + + EncryptionService.fsDriver_ = shim.fsDriver(); + // eslint-disable-next-line require-atomic-updates + BaseItem.encryptionService_ = EncryptionService.instance(); + BaseItem.shareService_ = ShareService.instance(); + Resource.shareService_ = ShareService.instance(); + DecryptionWorker.instance().dispatch = dispatch; + DecryptionWorker.instance().setLogger(reg.logger()); + DecryptionWorker.instance().setKvStore(KvStore.instance()); + DecryptionWorker.instance().setEncryptionService(EncryptionService.instance()); + await loadMasterKeysFromSettings(EncryptionService.instance()); + DecryptionWorker.instance().on('resourceMetadataButNotBlobDecrypted', decryptionWorker_resourceMetadataButNotBlobDecrypted); + }); + addTask('set up sharing', async () => { + await ShareService.instance().initialize(store, EncryptionService.instance()); + }); + addTask('load folders', async () => { + await refreshFolders(dispatch, ''); + + dispatch({ + type: 'FOLDER_SET_COLLAPSED_ALL', + ids: Setting.value('collapsedFolderIds'), + }); + }); + addTask('load tags', async () => { + const tags = await Tag.allWithNotes(); + + dispatch({ + type: 'TAG_UPDATE_ALL', + items: tags, + }); + }); + addTask('clear shared files cache', clearSharedFilesCache); + addTask('go: initial route', async () => { + const folder = await getInitialActiveFolder(); + + const notesParent = parseNotesParent(Setting.value('notesParent'), Setting.value('activeFolderId')); + + if (notesParent && notesParent.type === 'SmartFilter') { + dispatch(DEFAULT_ROUTE); + } else if (!folder) { + dispatch(DEFAULT_ROUTE); + } else { + dispatch({ + type: 'NAV_GO', + routeName: 'Notes', + folderId: folder.id, + }); + } + }); + addTask('set up search', async () => { + SearchEngine.instance().setDb(reg.db()); + SearchEngine.instance().setLogger(reg.logger()); + SearchEngine.instance().scheduleSyncTables(); + }); + addTask('run migrations', async () => { + await MigrationService.instance().run(); + }); + addTask('set up background tasks', async () => { + initializeUserFetcher(); + PoorManIntervals.setInterval(() => { void userFetcher(); }, 1000 * 60 * 60); + + PoorManIntervals.setTimeout(() => { + void AlarmService.garbageCollect(); + }, 1000 * 60 * 60); + + ResourceService.runInBackground(); + + ResourceFetcher.instance().setFileApi(() => { return reg.syncTarget().fileApi(); }); + ResourceFetcher.instance().setLogger(reg.logger()); + ResourceFetcher.instance().dispatch = dispatch; + ResourceFetcher.instance().on('downloadComplete', resourceFetcher_downloadComplete); + void ResourceFetcher.instance().start(); + + // Collect revisions more frequently on mobile because it doesn't auto-save + // and it cannot collect anything when the app is not active. + RevisionService.instance().runInBackground(1000 * 30); + + reg.setupRecurrentSync(); + + // When the app starts we want the full sync to + // start almost immediately to get the latest data. + // doWifiConnectionCheck set to true so initial sync + // doesn't happen on mobile data + // eslint-disable-next-line promise/prefer-await-to-then -- Old code before rule was applied + void reg.scheduleSync(100, null, true).then(() => { + // Wait for the first sync before updating the notifications, since synchronisation + // might change the notifications. + void AlarmService.updateAllNotifications(); + + void DecryptionWorker.instance().scheduleStart(); + }); + }); + addTask('set up welcome utils', async () => { + await WelcomeUtils.install(Setting.value('locale'), dispatch); + }); + addTask('set up plugin service', async () => { + // Even if there are no plugins, we need to initialize the PluginService so that + // plugin search can work. + const platformImplementation = PlatformImplementation.instance(); + PluginService.instance().initialize( + platformImplementation.versionInfo.version, platformImplementation, null, store, + ); + + // On startup, we can clear plugin update state -- plugins that were updated when the + // user last ran the app have been updated and will be reloaded. + const pluginService = PluginService.instance(); + const pluginSettings = pluginService.unserializePluginSettings(Setting.value('plugins.states')); + + const updatedSettings = pluginService.clearUpdateState(pluginSettings); + Setting.setValue('plugins.states', updatedSettings); + }); + addTask('run startup tests', async () => { + // ---------------------------------------------------------------------------- + // On desktop and CLI we run various tests to check that node-rsa is working + // as expected. On mobile however we cannot run test units directly on + // device, and that's what would be needed to automatically verify + // react-native-rsa-native. So instead we run the tests every time the + // mobile app is started in dev mode. If there's any regression the below + // call will throw an error, alerting us of the issue. Otherwise it will + // just print some messages in the console. + // ---------------------------------------------------------------------------- + if (Setting.value('env') === 'dev') { + if (Platform.OS !== 'web') { + await runRsaIntegrationTests(); + } else { + logger.info('Skipping encryption tests -- not supported on web.'); + } + await runCryptoIntegrationTests(); + await runOnDeviceFsDriverTests(); + } + + // ---------------------------------------------------------------------------- + // Keep this below to test react-native-rsa-native + // ---------------------------------------------------------------------------- + + // const testData = await createTestData(); + // await checkTestData(testData); + + // const testData = { + // "publicKey": "-----BEGIN RSA PUBLIC KEY-----\nMIIBCgKCAQEAoMx9NBioka8DUjO3bKrWMn8uJ23LH1xySogQFR6yh6qbl6i5LKTw\nPgqvv55FUuQtYTMtUTVLggYQhdCBvwbBrD1OqO4xU6Ew7x5/TQKPV3MSgYaps3FF\nOdipC4FyA00jBe6Z1CIpL+ZaSnvjDbMUf5lW8bmfRuXfdBGAcdSBjqm9ttajOws+\n7BBSQ9nI5dnBnWRIVEUb7e9bulgANzM1LMUOE+gaef7T3uKzc+Cx3BhHgw1JdFbL\nZAndYtP52KI5N3oiFM4II26DxmDrO1tQokNM88l5xT0BXPhYiEl1CeBpo5VHZBY2\nRHr4MM/OyAXSUdulsDzbntpE+Y85zv7gpQIDAQAB\n-----END RSA PUBLIC KEY-----", + // "privateKey": "-----BEGIN RSA PRIVATE KEY-----\nMIIEpAIBAAKCAQEAoMx9NBioka8DUjO3bKrWMn8uJ23LH1xySogQFR6yh6qbl6i5\nLKTwPgqvv55FUuQtYTMtUTVLggYQhdCBvwbBrD1OqO4xU6Ew7x5/TQKPV3MSgYap\ns3FFOdipC4FyA00jBe6Z1CIpL+ZaSnvjDbMUf5lW8bmfRuXfdBGAcdSBjqm9ttaj\nOws+7BBSQ9nI5dnBnWRIVEUb7e9bulgANzM1LMUOE+gaef7T3uKzc+Cx3BhHgw1J\ndFbLZAndYtP52KI5N3oiFM4II26DxmDrO1tQokNM88l5xT0BXPhYiEl1CeBpo5VH\nZBY2RHr4MM/OyAXSUdulsDzbntpE+Y85zv7gpQIDAQABAoIBAEA0Zmm+ztAcyX6x\nF7RUImLXVV55AHntN9V6rrFAKJjzDl1oCUhCM4sSSUqBr7yBT31YKegbF6M7OK21\nq5jS4dIcSKQ7N4bk/dz8mGfvdby9Pc5qLqhvuex3DkiBzzxyOGHN+64wVbHCkJrd\nDLQTpUOtvoGWVHrCno6Bzn+lEnYbvdr0hqI5H4D0ubk6TYed1/4ZlJf0R/o/4jnl\nou0UG2hpJN4ur506cttkZJSTxLjzdO38JuQIAkCEglrMYVY61lBNPxC11Kr3ZN7o\ncm7gWZVyP26KoU27t/g+2FoiBGsWLqGYiuTaqT6dKZ2vHyJGjJIZZStv5ye2Ez8V\nKQwpjQECgYEA3xtwYu4n/G5UjEMumkXHNd/bDamelo1aQvvjkVvxKeASNBqV8cM0\n6Jb2FCuT9Y3mWbFTM0jpqXehpHUOCCnrPKGKnJ0ZS4/SRIrtw0iM6q17fTAqmuOt\nhX0pJ77Il8lVCtx4ItsW+LUGbm6CwotlYLVUuyluhKe0pGw2yafi2N0CgYEAuIFk\ng4p7x0i1LFAlIP0YQ07bJQ0E6FEWbCfMgrV3VjtbnT99EaqPOHhMasITCuoEFlh8\ncgyZ6oH7GEy4IRWrM+Mlm47S+NTrr6KgnTGf570ZAFuqnJac97oFB7BvlQsQot6F\n0L2JKM7dQKIMlvwA9DoXZdKX/9ykiqqIpawNxmkCgYEAuyJOwAw2ads4+3UWT7wb\nfarIF8ugA3OItAqHNFNEEvWpDx8FigVMCZMl0IFE14AwKCc+PBP6OXTolgLAxEQ0\n1WRB2V9D6kc1/Nvy1guydt0QaU7PTZ+O2hrDPF0f74Cl3jhSZBoUSIO+Yz46W2eE\nnvs5mMsFsirgr9E8myRAd9kCgYAGMCDE4KIiHugkolN8dcCYkU58QaGGgSG1YuhT\nAe8Mr1T1QynYq9W92RsHAZdN6GdWsIUL9iw7VzyqpfgO9AEX7mhWfUXKHqoA6/1j\nCEUKqqbqAikIs2x0SoLcrSgw4XwfWkM2qwSsn7N/9W9iqPUHO+OJALUkWawTEoEe\nvVSA8QKBgQCEYCPnxgeQSZkrv7x5soXzgF1YN5EZRa1mTUqPBubs564ZjIIY66mI\nCTaHl7U1cPAhx7mHkSzP/i5NjjLqPZZNOyawWDEEmOzxX69OIzKImb6mEQNyS3do\nI8jnpN5q9pw5TvuEIYSrGqQVnHeaEjSvcT48W9GuzjNVscGfw76fPg==\n-----END RSA PRIVATE KEY-----", + // "plaintext": "just testing", + // "ciphertext": "BfkKLdrmd2UX4sPf0bzhfqrg3rKwH5DS7dPAqdmoQuHlrvEBrYKqheekwpnWQgGggGcm/orlrsQRwlexLv7jfRbb0bMnElkySMu4w6wTxILB66RX9H3vXCz02SwHKFRcuGJxlzTPUC23ki6f/McYJ2n/2L8qYxBO8fncTKutIWV54jY19RS1wQ4IdVDBqzji8D0QsRxUhVlpRk4qxsVnyuoyg9AyDe91LOYKfRc6NdapFij996nKzjxFcKOdBqpis34fN3Cg7avcs2Dm5vi7zlRhyGqJJhORXTU3x6hVwOBkVAisgaB7xS3lHiYp6Fs5tP3hBd0kFwVVx8gALbHsgg==" + // }; + // await checkTestData(testData); + + // await printTestData(); + }); + + return startupTasks; +}; + +export default buildStartupTasks; diff --git a/packages/lib/BaseApplication.ts b/packages/lib/BaseApplication.ts index ce9192ee68..6843027e4d 100644 --- a/packages/lib/BaseApplication.ts +++ b/packages/lib/BaseApplication.ts @@ -67,8 +67,10 @@ import { setupAutoDeletion } from './services/trash/permanentlyDeleteOldItems'; import determineProfileAndBaseDir from './determineBaseAppDirs'; import NavService from './services/NavService'; import getAppName from './getAppName'; +import PerformanceLogger from './PerformanceLogger'; const appLogger: LoggerWrapper = Logger.create('App'); +const perfLogger = PerformanceLogger.create('BaseApplication'); // const ntpClient = require('./vendor/ntp-client'); // ntpClient.dgram = require('dgram'); @@ -673,6 +675,7 @@ export default class BaseApplication { ...options, }; + const startTask = perfLogger.taskStart('start'); const startFlags = await this.handleStartFlags_(argv); argv = startFlags.argv; @@ -748,6 +751,8 @@ export default class BaseApplication { globalLogger.setLevel(initArgs.logLevel); } + PerformanceLogger.setLogger(globalLogger); + reg.setLogger(Logger.create('') as Logger); // reg.dispatch = () => {}; @@ -890,6 +895,7 @@ export default class BaseApplication { await MigrationService.instance().run(); + startTask.onEnd(); return argv; } } diff --git a/packages/lib/PerformanceLogger.test.ts b/packages/lib/PerformanceLogger.test.ts new file mode 100644 index 0000000000..abc381bc1b --- /dev/null +++ b/packages/lib/PerformanceLogger.test.ts @@ -0,0 +1,27 @@ +import PerformanceLogger from './PerformanceLogger'; + +describe('PerformanceLogger', () => { + beforeEach(() => { + PerformanceLogger.reset_(); + }); + + test('should buffer log messages created before a logger is attached', () => { + const logger = PerformanceLogger.create('test'); + logger.mark('Test'); + + const log: string[] = []; + PerformanceLogger.setLogger({ + info: (message) => log.push(`info: ${message}`), + debug: (message) => log.push(`debug: ${message}`), + }); + + expect(log).toHaveLength(1); + expect(log[0]).toMatch(/^info: Performance: test\/Test: Mark at/); + + // Should continue using the set logger + const task = logger.taskStart('Test task'); + expect(log).toHaveLength(2); + task.onEnd(); + expect(log).toHaveLength(3); + }); +}); diff --git a/packages/lib/PerformanceLogger.ts b/packages/lib/PerformanceLogger.ts new file mode 100644 index 0000000000..ad342f7637 --- /dev/null +++ b/packages/lib/PerformanceLogger.ts @@ -0,0 +1,148 @@ +import { Second } from '@joplin/utils/time'; + +const formatDuration = (durationMs: number) => { + const round = (n: number) => Math.round(n * 100) / 100; + if (durationMs < Second / 4) { + return `${round(durationMs)}ms`; + } else { + return `${round(durationMs / Second)}s`; + } +}; + +const formatTaskDuration = (durationMs: number) => { + const formatted = formatDuration(durationMs); + if (durationMs < Second / 2) { + return formatted; + } else if (durationMs < Second) { + return `[ ${formatted} ]`; + } else { + // Wrap in [[ ]]s to make longer durations more visible. + return `[[ ${formatted} ]]`; + } +}; + +let timeOrigin = 0; +const formatAbsoluteTime = (time: number) => { + return formatDuration(time - timeOrigin); +}; + +const hasPerformanceMarkApi = typeof performance.mark === 'function' && typeof performance.measure === 'function'; + +type LogCallback = (message: string)=> void; +type LogEntry = { + isDebug: boolean; + message: string; +}; + +type LoggerSlice = { + info: (message: string)=> void; + debug: (message: string)=> void; +}; + +export default class PerformanceLogger { + // Since one of the performance logger's uses is profiling + // startup code, it's useful to have a default log implementation + // (for before the logger is initialized). + private static logBuffer_: LogEntry[] = []; + private static readonly defaultLog_: LogCallback = message => { + this.logBuffer_.push({ message, isDebug: false }); + }; + private static readonly defaultLogDebug_: LogCallback = message => { + this.logBuffer_.push({ message, isDebug: true }); + }; + private static log_: LogCallback = this.defaultLog_; + private static logDebug_: LogCallback = this.defaultLogDebug_; + + // For testing + public static reset_() { + timeOrigin = 0; + this.logBuffer_ = []; + this.log_ = this.defaultLog_; + this.logDebug_ = this.defaultLogDebug_; + } + + // In some environments, performance.now() gives the number of milliseconds since + // application startup. This does not seem to be the case on all environments, however, + // so we allow customizing the app start time. + public static onAppStartBegin() { + const now = performance.now(); + timeOrigin = now; + + this.log_(`Starting application at ${formatDuration(now)}`); + } + + public static setLogger(logger: LoggerSlice) { + const tag = 'Performance'; + this.log_ = (message) => logger.info(`${tag}: ${message}`); + this.logDebug_ = (message) => logger.debug(`${tag}: ${message}`); + + for (const item of this.logBuffer_) { + if (item.isDebug) { + this.logDebug_(item.message); + } else { + this.log_(item.message); + } + } + this.logBuffer_ = []; + } + + private lastLogTime_ = 0; + public static create(prefix: string) { + return new PerformanceLogger(prefix); + } + + private constructor(private readonly prefix_: string) { } + + public mark(name: string) { + name = `${this.prefix_}/${name}`; + + // If available, make it possible to inspect the performance mark from the F12 + // developer tools. + if (hasPerformanceMarkApi) { + performance.mark(name); + } + + const now = performance.now(); + const timeDelta = now - this.lastLogTime_; + this.lastLogTime_ = now; + PerformanceLogger.log_(`${name}: Mark at ${formatAbsoluteTime(now)} +${formatDuration(timeDelta)}`); + } + + public async track(name: string, task: ()=> Promise): Promise { + const tracker = this.taskStart(name); + try { + return await task(); + } finally { + tracker.onEnd(); + } + } + + public taskStart(name: string) { + name = `${this.prefix_}/${name}`; + + if (typeof performance.mark === 'function') { + performance.mark(`${name}-start`); + } + + const startTime = performance.now(); + PerformanceLogger.logDebug_(`${name}: Start at ${formatAbsoluteTime(startTime)}`); + + const onEnd = () => { + const now = performance.now(); + if (hasPerformanceMarkApi) { + performance.mark(`${name}-end`); + performance.measure(name, `${name}-start`, `${name}-end`); + } + + const duration = now - startTime; + // Increase the log level for long-running tasks + const isLong = duration >= Second / 10; + const log = isLong ? PerformanceLogger.log_ : PerformanceLogger.logDebug_; + + log(`${name}: End at ${formatAbsoluteTime(now)} (took ${formatTaskDuration(now - startTime)})`); + }; + return { + onEnd, + }; + } +} diff --git a/packages/lib/services/DecryptionWorker.ts b/packages/lib/services/DecryptionWorker.ts index 0db9aded16..c0cfaa3da0 100644 --- a/packages/lib/services/DecryptionWorker.ts +++ b/packages/lib/services/DecryptionWorker.ts @@ -7,8 +7,10 @@ import Logger from '@joplin/utils/Logger'; import shim from '../shim'; import KvStore from './KvStore'; import EncryptionService from './e2ee/EncryptionService'; +import PerformanceLogger from '../PerformanceLogger'; const EventEmitter = require('events'); +const perfLogger = PerformanceLogger.create('DecryptionWorker'); interface DecryptionResult { skippedItemCount?: number; @@ -325,11 +327,13 @@ export default class DecryptionWorker { // eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied public async start(options: any = {}) { this.startCalls_.push(true); + const startTask = perfLogger.taskStart('start'); let output = null; try { output = await this.start_(options); } finally { this.startCalls_.pop(); + startTask.onEnd(); } return output; } diff --git a/packages/lib/services/search/SearchEngine.ts b/packages/lib/services/search/SearchEngine.ts index 566693925e..f6eb944a65 100644 --- a/packages/lib/services/search/SearchEngine.ts +++ b/packages/lib/services/search/SearchEngine.ts @@ -17,6 +17,9 @@ import replaceUnsupportedCharacters from '../../utils/replaceUnsupportedCharacte import { htmlentitiesDecode } from '@joplin/utils/html'; const { sprintf } = require('sprintf-js'); import { pregQuote, scriptType, removeDiacritics } from '../../string-utils'; +import PerformanceLogger from '../../PerformanceLogger'; + +const perfLogger = PerformanceLogger.create('SearchEngine'); enum SearchType { Auto = 'auto', @@ -189,6 +192,8 @@ export default class SearchEngine { private async syncTables_() { if (this.isIndexing_) return; + const syncTask = perfLogger.taskStart('syncTables'); + this.isIndexing_ = true; this.logger().info('SearchEngine: Updating FTS table...'); @@ -330,6 +335,7 @@ export default class SearchEngine { this.logger().info(sprintf('SearchEngine: Updated FTS table in %dms. Inserted: %d. Deleted: %d', Date.now() - startTime, report.inserted, report.deleted)); this.isIndexing_ = false; + syncTask.onEnd(); } public async syncTables() { diff --git a/readme/dev/spec/performance.md b/readme/dev/spec/performance.md new file mode 100644 index 0000000000..63ae1af37b --- /dev/null +++ b/readme/dev/spec/performance.md @@ -0,0 +1,63 @@ +# Debugging performance issues + +## Using the profiler + +The developer tools for the desktop and web apps include a ["Performance"](https://developer.chrome.com/docs/devtools/performance) tab. It can be useful for debugging startup and runtime performance. To use it: +1. Open the developer tools window. +2. Click on the "Performance" tab. + +**Profiling application startup**: To record performance information during app startup, click the "Record and reload" button. After the application finishes reloading, a chart with sections for different tasks (e.g. "Main", "Animations", "Timings") should be shown. The "Timings" section should include marks and tasks logged with `PerformanceLogger`. + +For React Native, see: +- [Profiling on Android](https://reactnative.dev/docs/profiling) +- [Information about the React Profiler](https://reactnative.dev/docs/react-native-devtools#react-profiler). + +## Performance logging + +The `PerformanceLogger` class has a few methods that can help debug performance issues: +- `.mark(name)`: Adds a performance mark with a timestamp. For tasks with duration, prefer `.track` or `.taskStart`. +- `.track(name, task)`: Logs information about how long it takes the async `task` to complete. +- `.taskStart(name)`: Marks the start of a task with some `name`. + +Performance marks can be found by searching for `Performance:` in Joplin's logs. Be aware that more information is logged in development mode (or with debug logging enabled) than in release mode. In particular: +- **.mark**: Performance `.mark`s are logged with level `info`. +- **.taskStart**: The start of tasks logged with `.track` or `.taskStart` are logged with `debug`. +- **.onEnd**: Information about the end of tasks are logged with `info` **if** the task takes longer than 0.1s. Otherwise, the information is logged with level `debug`. + +On desktop and web (in Chrome), `PerformanceLogger` tasks and marks are added to the "Timings" tab of the performance timeline (see ["Using the profiler"](#using-the-profiler)). + +**Note**: To allow profiling startup code that runs before the main `Logger` is initialized, `PerformanceLogger` buffers log output until `PerformanceLogger.setLogger` is called (usually done during the application startup process). At this point, all buffered messages are logged. + +**Example**: +```ts +const perfLogger = PerformanceLogger.create('VerySlowThing'); + +class VerySlowThing { + public doSomethingSlow() { + // It's possible to mark the start and end of tasks with .taskStart and .onEnd: + const task = perfLogger.taskStart('doSomethingSlow'); + + // This will take some time to complete: + for (let i = 0; i < 10_000_000; i++) { + i -= Math.random() * 1.9; + + if (i >= 100_000) { + perfLogger.mark('Counter has reached 100_000'); + } + } + + task.onEnd(); + } + + public async doSomethingElse() { + // .track wraps an async callback. + await perfLogger.track('doSomethingElse', async () => { + await someBackgroundTask(); + + // Even if the callback throws an Error, .track + // ends the task in the log file. + throw new Error('An error!'); + }); + } +} +```