From 09c3a8828f749949294e048750c21fe7a555f08f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E6=9D=8E=E5=8D=8E=E6=A1=A5?= Date: Fri, 10 Nov 2023 00:25:15 +0800 Subject: [PATCH] chore: add performance logger --- packages/common/debug/src/index.ts | 5 +++++ packages/frontend/core/src/app.tsx | 9 +++++++++ packages/frontend/core/src/bootstrap/setup.ts | 12 ++++++++++-- packages/frontend/core/src/index.tsx | 10 ++++++++++ .../frontend/core/src/pages/workspace/all-page.tsx | 3 +++ .../core/src/pages/workspace/detail-page.tsx | 3 +++ .../frontend/core/src/pages/workspace/index.tsx | 13 +++++++++++++ packages/frontend/core/src/shared/index.ts | 4 ++++ packages/frontend/workspace/src/affine/sync.ts | 9 +++++++++ packages/frontend/workspace/src/atom.ts | 14 +++++++++++++- 10 files changed, 79 insertions(+), 3 deletions(-) diff --git a/packages/common/debug/src/index.ts b/packages/common/debug/src/index.ts index 179838c501..d943e27fd5 100644 --- a/packages/common/debug/src/index.ts +++ b/packages/common/debug/src/index.ts @@ -58,4 +58,9 @@ export class DebugLogger { this._debug.log = console[level].bind(console); this._debug(`[${level.toUpperCase()}] ${message}`, ...args); } + + namespace(extra: string) { + const currentNamespace = this._debug.namespace; + return new DebugLogger(`${currentNamespace}:${extra}`); + } } diff --git a/packages/frontend/core/src/app.tsx b/packages/frontend/core/src/app.tsx index 697b35e5b5..e88920d8cf 100644 --- a/packages/frontend/core/src/app.tsx +++ b/packages/frontend/core/src/app.tsx @@ -14,8 +14,10 @@ import { RouterProvider } from 'react-router-dom'; import { CloudSessionProvider } from './providers/session-provider'; import { router } from './router'; +import { performanceLogger, performanceRenderLogger } from './shared'; import createEmotionCache from './utils/create-emotion-cache'; +const performanceI18nLogger = performanceLogger.namespace('i18n'); const cache = createEmotionCache(); const DevTools = lazy(() => @@ -37,16 +39,23 @@ const future = { async function loadLanguage() { if (environment.isBrowser) { + performanceI18nLogger.info('start'); + const { createI18n, setUpLanguage } = await import('@affine/i18n'); const i18n = createI18n(); document.documentElement.lang = i18n.language; + + performanceI18nLogger.info('set up'); await setUpLanguage(i18n); + performanceI18nLogger.info('done'); } } const languageLoadingPromise = loadLanguage().catch(console.error); export const App = memo(function App() { + performanceRenderLogger.info('App'); + use(languageLoadingPromise); return ( diff --git a/packages/frontend/core/src/bootstrap/setup.ts b/packages/frontend/core/src/bootstrap/setup.ts index e8e78bdc26..53b2021a9f 100644 --- a/packages/frontend/core/src/bootstrap/setup.ts +++ b/packages/frontend/core/src/bootstrap/setup.ts @@ -23,6 +23,9 @@ import { nanoid } from 'nanoid'; import { applyUpdate, Doc as YDoc, encodeStateAsUpdate } from 'yjs'; import { WorkspaceAdapters } from '../adapters/workspace'; +import { performanceLogger } from '../shared'; + +const performanceSetupLogger = performanceLogger.namespace('setup'); async function tryMigration() { const value = localStorage.getItem('jotai-workspaces'); @@ -148,6 +151,7 @@ export function createFirstAppData(store: ReturnType) { } export async function setup(store: ReturnType) { + performanceSetupLogger.info('start'); store.set( workspaceAdaptersAtom, WorkspaceAdapters as Record< @@ -156,11 +160,15 @@ export async function setup(store: ReturnType) { > ); - console.log('setup global'); + performanceSetupLogger.info('setup global'); setupGlobal(); + performanceSetupLogger.info('try migration'); await tryMigration(); + + performanceSetupLogger.info('get root workspace meta'); // do not read `rootWorkspacesMetadataAtom` before migration await store.get(rootWorkspacesMetadataAtom); - console.log('setup done'); + + performanceSetupLogger.info('done'); } diff --git a/packages/frontend/core/src/index.tsx b/packages/frontend/core/src/index.tsx index 00ffc6392a..c75e392975 100644 --- a/packages/frontend/core/src/index.tsx +++ b/packages/frontend/core/src/index.tsx @@ -5,18 +5,28 @@ import { StrictMode, Suspense } from 'react'; import { createRoot } from 'react-dom/client'; import { bootstrapPluginSystem } from './bootstrap/register-plugins'; +import { performanceLogger } from './shared'; +const performanceMainLogger = performanceLogger.namespace('main'); async function main() { + performanceMainLogger.info('start'); const { setup } = await import('./bootstrap/setup'); + const rootStore = getCurrentStore(); + performanceMainLogger.info('setup start'); await setup(rootStore); + performanceMainLogger.info('setup done'); + bootstrapPluginSystem(rootStore).catch(err => { console.error('Failed to bootstrap plugin system', err); }); + + performanceMainLogger.info('import app'); const { App } = await import('./app'); const root = document.getElementById('app'); assertExists(root); + performanceMainLogger.info('render app'); createRoot(root).render( }> diff --git a/packages/frontend/core/src/pages/workspace/all-page.tsx b/packages/frontend/core/src/pages/workspace/all-page.tsx index c108e742d7..f4a44e1e40 100644 --- a/packages/frontend/core/src/pages/workspace/all-page.tsx +++ b/packages/frontend/core/src/pages/workspace/all-page.tsx @@ -40,6 +40,7 @@ import { WorkspaceHeader } from '../../components/workspace-header'; import { useBlockSuiteMetaHelper } from '../../hooks/affine/use-block-suite-meta-helper'; import { useTrashModalHelper } from '../../hooks/affine/use-trash-modal-helper'; import { useCurrentWorkspace } from '../../hooks/current/use-current-workspace'; +import { performanceRenderLogger } from '../../shared'; import * as styles from './all-page.css'; import { EmptyPageList } from './page-list-empty'; import { useFilteredPageMetas } from './pages'; @@ -302,5 +303,7 @@ export const AllPage = () => { }; export const Component = () => { + performanceRenderLogger.info('AllPage'); + return ; }; diff --git a/packages/frontend/core/src/pages/workspace/detail-page.tsx b/packages/frontend/core/src/pages/workspace/detail-page.tsx index ed928023c3..5a546028f1 100644 --- a/packages/frontend/core/src/pages/workspace/detail-page.tsx +++ b/packages/frontend/core/src/pages/workspace/detail-page.tsx @@ -29,6 +29,7 @@ import { WorkspaceHeader } from '../../components/workspace-header'; import { useRegisterBlocksuiteEditorCommands } from '../../hooks/affine/use-register-blocksuite-editor-commands'; import { useCurrentWorkspace } from '../../hooks/current/use-current-workspace'; import { useNavigateHelper } from '../../hooks/use-navigate-helper'; +import { performanceRenderLogger } from '../../shared'; const DetailPageImpl = (): ReactElement => { const { openPage, jumpToSubPath } = useNavigateHelper(); @@ -145,5 +146,7 @@ export const loader: LoaderFunction = async args => { }; export const Component = () => { + performanceRenderLogger.info('DetailPage'); + return ; }; diff --git a/packages/frontend/core/src/pages/workspace/index.tsx b/packages/frontend/core/src/pages/workspace/index.tsx index 27109384cc..298930bbc3 100644 --- a/packages/frontend/core/src/pages/workspace/index.tsx +++ b/packages/frontend/core/src/pages/workspace/index.tsx @@ -15,10 +15,17 @@ import { } from 'react-router-dom'; import { WorkspaceLayout } from '../../layouts/workspace-layout'; +import { performanceLogger, performanceRenderLogger } from '../../shared'; + +const workspaceLoaderLogger = performanceLogger.namespace('workspace_loader'); export const loader: LoaderFunction = async args => { + workspaceLoaderLogger.info('start'); + const rootStore = getCurrentStore(); const meta = await rootStore.get(rootWorkspacesMetadataAtom); + workspaceLoaderLogger.info('meta loaded'); + const currentMetadata = meta.find(({ id }) => id === args.params.workspaceId); if (!currentMetadata) { return redirect('/404'); @@ -32,6 +39,8 @@ export const loader: LoaderFunction = async args => { } if (currentMetadata.flavour === WorkspaceFlavour.AFFINE_CLOUD) { const [workspaceAtom] = getBlockSuiteWorkspaceAtom(currentMetadata.id); + workspaceLoaderLogger.info('get cloud workspace atom'); + const workspace = await rootStore.get(workspaceAtom); return (() => { const blockVersions = workspace.meta.blockVersions; @@ -46,10 +55,14 @@ export const loader: LoaderFunction = async args => { return false; })(); } + + workspaceLoaderLogger.info('done'); return null; }; export const Component = (): ReactElement => { + performanceRenderLogger.info('WorkspaceLayout'); + const incompatible = useLoaderData(); return ( diff --git a/packages/frontend/core/src/shared/index.ts b/packages/frontend/core/src/shared/index.ts index 7e94890b6c..b7c908ab62 100644 --- a/packages/frontend/core/src/shared/index.ts +++ b/packages/frontend/core/src/shared/index.ts @@ -1,3 +1,4 @@ +import { DebugLogger } from '@affine/debug'; import type { WorkspaceRegistry } from '@affine/env/workspace'; import { Workspace as BlockSuiteWorkspace } from '@blocksuite/store'; @@ -26,3 +27,6 @@ export const pathGenerator = { } satisfies { [Path in WorkspaceSubPath]: (workspaceId: string) => string; }; + +export const performanceLogger = new DebugLogger('performance'); +export const performanceRenderLogger = performanceLogger.namespace('render'); diff --git a/packages/frontend/workspace/src/affine/sync.ts b/packages/frontend/workspace/src/affine/sync.ts index c36bba1bbe..c126439cc9 100644 --- a/packages/frontend/workspace/src/affine/sync.ts +++ b/packages/frontend/workspace/src/affine/sync.ts @@ -1,3 +1,4 @@ +import { DebugLogger } from '@affine/debug'; import { createIndexeddbStorage } from '@blocksuite/store'; import { createIndexedDBDatasource, @@ -12,6 +13,7 @@ import { createCloudBlobStorage } from '../blob/cloud-blob-storage'; import { createAffineDataSource } from '.'; import { CRUD } from './crud'; +const performanceLogger = new DebugLogger('performance:sync'); let abortController: AbortController | undefined; const downloadRootFromIndexedDB = async ( @@ -29,9 +31,13 @@ const downloadRootFromIndexedDB = async ( }; export async function startSync() { + performanceLogger.info('start'); + abortController = new AbortController(); const signal = abortController.signal; const workspaces = await CRUD.list(); + performanceLogger.info('CRUD list'); + const syncDocPromises = workspaces.map(workspace => downloadRootFromIndexedDB( workspace.id, @@ -40,6 +46,8 @@ export async function startSync() { ) ); await Promise.all(syncDocPromises); + performanceLogger.info('all sync promise'); + const syncPromises = workspaces.map(workspace => { const remoteDataSource = createAffineDataSource( workspace.id, @@ -104,6 +112,7 @@ export async function startSync() { }); }); await Promise.all([...syncPromises, ...syncBlobPromises]); + performanceLogger.info('sync done'); } export async function stopSync() { diff --git a/packages/frontend/workspace/src/atom.ts b/packages/frontend/workspace/src/atom.ts index 31188095d7..d26bc58ffd 100644 --- a/packages/frontend/workspace/src/atom.ts +++ b/packages/frontend/workspace/src/atom.ts @@ -1,3 +1,4 @@ +import { DebugLogger } from '@affine/debug'; import type { WorkspaceAdapter } from '@affine/env/workspace'; import { WorkspaceFlavour } from '@affine/env/workspace'; import type { BlockHub } from '@blocksuite/blocks'; @@ -12,6 +13,8 @@ import { z } from 'zod'; import { getOrCreateWorkspace } from './manager'; +const performanceJotaiLogger = new DebugLogger('performance:jotai'); + const rootWorkspaceMetadataV1Schema = z.object({ id: z.string(), flavour: z.nativeEnum(WorkspaceFlavour), @@ -80,6 +83,8 @@ type FetchMetadata = ( * @internal */ const fetchMetadata: FetchMetadata = async (get, { signal }) => { + performanceJotaiLogger.info('fetch metadata start'); + const WorkspaceAdapters = get(workspaceAdaptersAtom); assertExists(WorkspaceAdapters, 'workspace adapter should be defined'); const metadata: RootWorkspaceMetadata[] = []; @@ -120,6 +125,7 @@ const fetchMetadata: FetchMetadata = async (get, { signal }) => { once: true, }); }); + performanceJotaiLogger.info('migration done'); } metadata.push(...loadFromLocalStorage()); @@ -131,11 +137,15 @@ const fetchMetadata: FetchMetadata = async (get, { signal }) => { ); for (const Adapter of Adapters) { + performanceJotaiLogger.info('%s adapter', Adapter.flavour); + const { CRUD, flavour: currentFlavour } = Adapter; if ( Adapter.Events['app:access'] && !(await Adapter.Events['app:access']()) ) { + performanceJotaiLogger.info('%s app:access', Adapter.flavour); + // skip the adapter if the user doesn't have access to it const removed = metadata.filter( meta => meta.flavour === currentFlavour @@ -148,6 +158,7 @@ const fetchMetadata: FetchMetadata = async (get, { signal }) => { } try { const item = await CRUD.list(); + performanceJotaiLogger.info('%s CRUD list', Adapter.flavour); // remove the metadata that is not in the list // because we treat the workspace adapter as the source of truth { @@ -179,6 +190,7 @@ const fetchMetadata: FetchMetadata = async (get, { signal }) => { } catch (e) { console.error('list data error:', e); } + performanceJotaiLogger.info('%s service:start', Adapter.flavour); Adapter.Events['service:start']?.(); } } @@ -195,7 +207,7 @@ const fetchMetadata: FetchMetadata = async (get, { signal }) => { } }); const result = Array.from(metadataMap.values()); - console.info('metadata', result); + performanceJotaiLogger.info('fetch metadata done', result); return result; };