1
0
mirror of https://github.com/laurent22/joplin.git synced 2025-08-10 22:11:50 +02:00

Chore: Resolves #12813: Move performance logger file labels to the corresponding log statements (#12820)

This commit is contained in:
Henry Heino
2025-08-01 03:43:05 -07:00
committed by GitHub
parent c5b6f0bca1
commit 825ce51a3c
12 changed files with 89 additions and 84 deletions

View File

@@ -64,7 +64,7 @@ import initializeCommandService from './utils/initializeCommandService';
import OcrDriverBase from '@joplin/lib/services/ocr/OcrDriverBase';
import PerformanceLogger from '@joplin/lib/PerformanceLogger';
const perfLogger = PerformanceLogger.create('app-desktop/app');
const perfLogger = PerformanceLogger.create();
const pluginClasses = [
require('./plugins/GotoAnything').default,
@@ -427,7 +427,7 @@ class Application extends BaseApplication {
tasks.push({ label, task });
};
addTask('set up extra debug logging', () => {
addTask('app/set up extra debug logging', () => {
reg.logger().info('app.start: doing regular boot');
const dir: string = Setting.value('profileDir');
@@ -442,27 +442,27 @@ class Application extends BaseApplication {
}
});
addTask('set up registry', () => {
addTask('app/set up registry', () => {
reg.setDispatch(this.dispatch.bind(this));
reg.setShowErrorMessageBoxHandler((message: string) => { bridge().showErrorMessageBox(message); });
});
addTask('set up auto updater', () => {
addTask('app/set up auto updater', () => {
this.setupAutoUpdaterService();
});
addTask('set up AlarmService', () => {
addTask('app/set up AlarmService', () => {
AlarmService.setDriver(new AlarmServiceDriverNode({ appName: packageInfo.build.appId }));
AlarmService.setLogger(reg.logger());
});
if (Setting.value('flagOpenDevTools')) {
addTask('openDevTools', () => {
addTask('app/openDevTools', () => {
bridge().openDevTools();
});
}
addTask('set up custom protocol handler', async () => {
addTask('app/set up custom protocol handler', async () => {
this.protocolHandler_ = bridge().electronApp().getCustomProtocolHandler();
this.protocolHandler_.allowReadAccessToDirectory(__dirname); // App bundle directory
this.protocolHandler_.allowReadAccessToDirectory(Setting.value('cacheDir'));
@@ -475,7 +475,7 @@ class Application extends BaseApplication {
// handler, and, as such, it may make sense to also limit permissions of
// allowed pages with a Content Security Policy.
addTask('initialize PluginManager, redux, CommandService, and KeymapService', async () => {
addTask('app/initialize PluginManager, redux, CommandService, and KeymapService', async () => {
PluginManager.instance().dispatch_ = this.dispatch.bind(this);
PluginManager.instance().setLogger(reg.logger());
PluginManager.instance().register(pluginClasses);
@@ -496,11 +496,11 @@ class Application extends BaseApplication {
}
});
addTask('initialize PerFolderSortOrderService', () => {
addTask('app/initialize PerFolderSortOrderService', () => {
PerFolderSortOrderService.initialize();
});
addTask('dispatch initial settings', () => {
addTask('app/dispatch initial settings', () => {
// Since the settings need to be loaded before the store is
// created, it will never receive the SETTING_UPDATE_ALL even,
// which mean state.settings will not be initialised. So we
@@ -508,7 +508,7 @@ class Application extends BaseApplication {
Setting.dispatchUpdateAll();
});
addTask('update folders and tags', async () => {
addTask('app/update folders and tags', async () => {
await refreshFolders((action) => this.dispatch(action), '');
const tags = await Tag.allWithNotes();
@@ -518,7 +518,7 @@ class Application extends BaseApplication {
});
});
addTask('set up custom CSS', async () => {
addTask('app/set up custom CSS', async () => {
await this.setupCustomCss();
});
@@ -529,7 +529,7 @@ class Application extends BaseApplication {
// items: masterKeys,
// });
addTask('send initial selection to redux', async () => {
addTask('app/send initial selection to redux', async () => {
const getNotesParent = async () => {
let notesParent = parseNotesParent(Setting.value('notesParent'), Setting.value('activeFolderId'));
if (notesParent.type === 'Tag' && !(await Tag.load(notesParent.selectedItemId))) {
@@ -570,14 +570,14 @@ class Application extends BaseApplication {
});
});
addTask('initializeUserFetcher', async () => {
addTask('app/initializeUserFetcher', async () => {
initializeUserFetcher();
shim.setInterval(() => { void userFetcher(); }, 1000 * 60 * 60);
});
addTask('updateTray', () => this.updateTray());
addTask('app/updateTray', () => this.updateTray());
addTask('set main window state', () => {
addTask('app/set main window state', () => {
if (Setting.value('startMinimized') && Setting.value('showTrayIcon')) {
bridge().mainWindow().hide();
} else {
@@ -585,7 +585,7 @@ class Application extends BaseApplication {
}
});
addTask('start maintenance tasks', () => {
addTask('app/start maintenance tasks', () => {
// Always disable on Mac for now - and disable too for the few apps that may have the flag enabled.
// At present, it only seems to work on Windows.
if (shim.isMac()) {
@@ -634,7 +634,7 @@ class Application extends BaseApplication {
this.startRotatingLogMaintenance(Setting.value('profileDir'));
});
addTask('set up ClipperServer', () => {
addTask('app/set up ClipperServer', () => {
const clipperLogger = new Logger();
clipperLogger.addTarget(TargetType.File, { path: `${Setting.value('profileDir')}/log-clipper.txt` });
clipperLogger.addTarget(TargetType.Console);
@@ -649,7 +649,7 @@ class Application extends BaseApplication {
}
});
addTask('set up external edit watchers', () => {
addTask('app/set up external edit watchers', () => {
ExternalEditWatcher.instance().setLogger(reg.logger());
ExternalEditWatcher.instance().initialize(bridge, this.store().dispatch);
@@ -671,7 +671,7 @@ class Application extends BaseApplication {
// Make it available to the console window - useful to call revisionService.collectRevisions()
if (Setting.value('env') === 'dev') {
addTask('add debug variables', () => {
addTask('app/add debug variables', () => {
// eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied
(window as any).joplin = {
revisionService: RevisionService.instance(),
@@ -688,7 +688,7 @@ class Application extends BaseApplication {
});
}
addTask('listen for main process events', () => {
addTask('app/listen for main process events', () => {
bridge().addEventListener('nativeThemeUpdated', this.bridge_nativeThemeUpdated);
bridge().setOnAllowedExtensionsChangeListener((newExtensions) => {
Setting.setValue('linking.extraAllowedExtensions', newExtensions);
@@ -706,17 +706,17 @@ class Application extends BaseApplication {
});
});
addTask('initPluginService', () => this.initPluginService());
addTask('app/initPluginService', () => this.initPluginService());
addTask('setupContextMenu', () => {
addTask('app/setupContextMenu', () => {
this.setupContextMenu();
});
addTask('set up SpellCheckerService', async () => {
addTask('app/set up SpellCheckerService', async () => {
await SpellCheckerService.instance().initialize(new SpellCheckerServiceDriverNative());
});
addTask('listen for resource events', () => {
addTask('app/listen for resource events', () => {
eventManager.on(EventName.OcrServiceResourcesProcessed, async () => {
await ResourceService.instance().indexNoteResources();
});
@@ -726,14 +726,14 @@ class Application extends BaseApplication {
});
});
addTask('setupOcrService', () => this.setupOcrService());
addTask('app/setupOcrService', () => this.setupOcrService());
return tasks;
}
// eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied
public async start(argv: string[], startOptions: StartOptions = null): Promise<any> {
const startupTask = perfLogger.taskStart('start');
const startupTask = perfLogger.taskStart('app/start');
// If running inside a package, the command line, instead of being "node.exe <path> <flags>" is "joplin.exe <flags>" so
// insert an extra argument so that they can be processed in a consistent way everywhere.

View File

@@ -39,7 +39,7 @@ require('@sentry/electron/renderer');
// Allows components to use React as a global
window.React = React;
const perfLogger = PerformanceLogger.create('main-html');
const perfLogger = PerformanceLogger.create();
const main = async () => {

View File

@@ -110,7 +110,7 @@ import buildStartupTasks from './utils/buildStartupTasks';
import { SafeAreaProvider } from 'react-native-safe-area-context';
const logger = Logger.create('root');
const perfLogger = PerformanceLogger.create('root');
const perfLogger = PerformanceLogger.create();
// eslint-disable-next-line @typescript-eslint/no-explicit-any -- Old code before rule was applied
let storeDispatch: any = function(_action: any) {};
@@ -597,7 +597,7 @@ class AppComponent extends React.Component<AppComponentProps, AppComponentState>
}
try {
await perfLogger.track('initialize', () => initialize(this.props.dispatch));
await perfLogger.track('root/initialize', () => initialize(this.props.dispatch));
} catch (error) {
alert(`Something went wrong while starting the application: ${error}`);
this.props.dispatch({
@@ -673,11 +673,11 @@ class AppComponent extends React.Component<AppComponentProps, AppComponentState>
);
onSystemColorSchemeChange(Appearance.getColorScheme());
this.quickActionShortcutListener_ = await perfLogger.track('setupQuickActions',
this.quickActionShortcutListener_ = await perfLogger.track('root/setupQuickActions',
() => setupQuickActions(this.props.dispatch),
);
await perfLogger.track('setupNotifications',
await perfLogger.track('root/setupNotifications',
() => setupNotifications(this.props.dispatch),
);

View File

@@ -148,16 +148,16 @@ const buildStartupTasks = (
let singleInstanceLock: Promise<void>;
addTask('prepare single instance lock', async () => {
addTask('buildStartupTasks/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 () => {
addTask('buildStartupTasks/shimInit', async () => {
shimInit();
});
addTask('initProfile', async () => {
addTask('buildStartupTasks/initProfile', async () => {
const profile = await initProfile(getProfilesRootDir());
isSubProfile = profile.isSubProfile;
currentProfile = getCurrentProfile(profile.profileConfig);
@@ -167,7 +167,7 @@ const buildStartupTasks = (
value: profile.profileConfig,
});
});
addTask('set constants', async () => {
addTask('buildStartupTasks/set constants', async () => {
Setting.setConstant('env', __DEV__ ? Env.Dev : Env.Prod);
Setting.setConstant('appId', 'net.cozic.joplin-mobile');
Setting.setConstant('appType', AppType.Mobile);
@@ -179,15 +179,15 @@ const buildStartupTasks = (
Setting.setConstant('pluginDir', `${getProfilesRootDir()}/plugins`);
Setting.setConstant('pluginDataDir', getPluginDataDir(currentProfile, isSubProfile));
});
addTask('make resource directory', async () => {
addTask('buildStartupTasks/make resource directory', async () => {
await shim.fsDriver().mkdir(Setting.value('resourceDir'));
});
addTask('singleInstanceLock', async () => {
addTask('buildStartupTasks/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 () => {
addTask('buildStartupTasks/set up logger', async () => {
logDatabase = new Database(new DatabaseDriverReactNative());
await logDatabase.open({ name: 'log.sqlite' });
await logDatabase.exec(Logger.databaseCreateTableSql());
@@ -207,7 +207,7 @@ const buildStartupTasks = (
BaseService.logger_ = mainLogger;
PerformanceLogger.setLogger(mainLogger);
});
addTask('set up database', async () => {
addTask('buildStartupTasks/set up database', async () => {
reg.setShowErrorMessageBoxHandler((message: string) => { alert(message); });
reg.setDispatch(dispatch);
@@ -229,7 +229,7 @@ const buildStartupTasks = (
db.setLogger(dbLogger);
reg.setDb(db);
});
addTask('initialize item classes', async () => {
addTask('buildStartupTasks/initialize item classes', async () => {
// reg.dispatch = dispatch;
BaseModel.dispatch = dispatch;
BaseSyncTarget.dispatch = dispatch;
@@ -250,11 +250,11 @@ const buildStartupTasks = (
Resource.fsDriver_ = shim.fsDriver();
FileApiDriverLocal.fsDriver_ = shim.fsDriver();
});
addTask('initializeAlarmService', async () => {
addTask('buildStartupTasks/initializeAlarmService', async () => {
AlarmService.setLogger(reg.logger());
AlarmService.setDriver(new AlarmServiceDriver(reg.logger()));
});
addTask('openDatabase', async () => {
addTask('buildStartupTasks/openDatabase', async () => {
if (Setting.value('env') === 'prod') {
await db.open({ name: getDatabaseName(currentProfile, isSubProfile) });
} else {
@@ -263,7 +263,7 @@ const buildStartupTasks = (
// await db.clearForTesting();
}
});
addTask('setUpSettings', async () => {
addTask('buildStartupTasks/setUpSettings', async () => {
await loadKeychainServiceAndSettings([]);
await migrateMasterPassword();
@@ -331,14 +331,14 @@ const buildStartupTasks = (
}
}
});
addTask('import plugin assets', async () => {
addTask('buildStartupTasks/import plugin assets', async () => {
await PluginAssetsLoader.instance().importAssets();
});
addTask('set up command & keymap services', async () => {
addTask('buildStartupTasks/set up command & keymap services', async () => {
initializeCommandService(store);
KeymapService.instance().initialize();
});
addTask('set up E2EE', async () => {
addTask('buildStartupTasks/set up E2EE', async () => {
setRSA(RSA);
EncryptionService.fsDriver_ = shim.fsDriver();
@@ -353,10 +353,10 @@ const buildStartupTasks = (
await loadMasterKeysFromSettings(EncryptionService.instance());
DecryptionWorker.instance().on('resourceMetadataButNotBlobDecrypted', decryptionWorker_resourceMetadataButNotBlobDecrypted);
});
addTask('set up sharing', async () => {
addTask('buildStartupTasks/set up sharing', async () => {
await ShareService.instance().initialize(store, EncryptionService.instance());
});
addTask('load folders', async () => {
addTask('buildStartupTasks/load folders', async () => {
await refreshFolders(dispatch, '');
dispatch({
@@ -364,7 +364,7 @@ const buildStartupTasks = (
ids: Setting.value('collapsedFolderIds'),
});
});
addTask('load tags', async () => {
addTask('buildStartupTasks/load tags', async () => {
const tags = await Tag.allWithNotes();
dispatch({
@@ -372,8 +372,8 @@ const buildStartupTasks = (
items: tags,
});
});
addTask('clear shared files cache', clearSharedFilesCache);
addTask('go: initial route', async () => {
addTask('buildStartupTasks/clear shared files cache', clearSharedFilesCache);
addTask('buildStartupTasks/go: initial route', async () => {
const folder = await getInitialActiveFolder();
const notesParent = parseNotesParent(Setting.value('notesParent'), Setting.value('activeFolderId'));
@@ -390,15 +390,15 @@ const buildStartupTasks = (
});
}
});
addTask('set up search', async () => {
addTask('buildStartupTasks/set up search', async () => {
SearchEngine.instance().setDb(reg.db());
SearchEngine.instance().setLogger(reg.logger());
SearchEngine.instance().scheduleSyncTables();
});
addTask('run migrations', async () => {
addTask('buildStartupTasks/run migrations', async () => {
await MigrationService.instance().run();
});
addTask('set up background tasks', async () => {
addTask('buildStartupTasks/set up background tasks', async () => {
initializeUserFetcher();
PoorManIntervals.setInterval(() => { void userFetcher(); }, 1000 * 60 * 60);
@@ -433,10 +433,10 @@ const buildStartupTasks = (
void DecryptionWorker.instance().scheduleStart();
});
});
addTask('set up welcome utils', async () => {
addTask('buildStartupTasks/set up welcome utils', async () => {
await WelcomeUtils.install(Setting.value('locale'), dispatch);
});
addTask('set up plugin service', async () => {
addTask('buildStartupTasks/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();
@@ -452,7 +452,7 @@ const buildStartupTasks = (
const updatedSettings = pluginService.clearUpdateState(pluginSettings);
Setting.setValue('plugins.states', updatedSettings);
});
addTask('run startup tests', async () => {
addTask('buildStartupTasks/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

View File

@@ -70,7 +70,7 @@ import getAppName from './getAppName';
import PerformanceLogger from './PerformanceLogger';
const appLogger: LoggerWrapper = Logger.create('App');
const perfLogger = PerformanceLogger.create('BaseApplication');
const perfLogger = PerformanceLogger.create();
// const ntpClient = require('./vendor/ntp-client');
// ntpClient.dgram = require('dgram');
@@ -675,7 +675,7 @@ export default class BaseApplication {
...options,
};
const startTask = perfLogger.taskStart('start');
const startTask = perfLogger.taskStart('BaseApplication/start');
const startFlags = await this.handleStartFlags_(argv);
argv = startFlags.argv;

View File

@@ -6,8 +6,8 @@ describe('PerformanceLogger', () => {
});
test('should buffer log messages created before a logger is attached', () => {
const logger = PerformanceLogger.create('test');
logger.mark('Test');
const logger = PerformanceLogger.create();
logger.mark('test/Test');
const log: string[] = [];
PerformanceLogger.setLogger({
@@ -19,7 +19,7 @@ describe('PerformanceLogger', () => {
expect(log[0]).toMatch(/^info: Performance: test\/Test: Mark at/);
// Should continue using the set logger
const task = logger.taskStart('Test task');
const task = logger.taskStart('test/Test task');
expect(log).toHaveLength(2);
task.onEnd();
expect(log).toHaveLength(3);

View File

@@ -87,15 +87,13 @@ export default class PerformanceLogger {
}
private lastLogTime_ = 0;
public static create(prefix: string) {
return new PerformanceLogger(prefix);
public static create() {
return new PerformanceLogger();
}
private constructor(private readonly prefix_: string) { }
private constructor() { }
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) {
@@ -118,8 +116,6 @@ export default class PerformanceLogger {
}
public taskStart(name: string) {
name = `${this.prefix_}/${name}`;
if (typeof performance.mark === 'function') {
performance.mark(`${name}-start`);
}

View File

@@ -10,7 +10,7 @@ import EncryptionService from './e2ee/EncryptionService';
import PerformanceLogger from '../PerformanceLogger';
const EventEmitter = require('events');
const perfLogger = PerformanceLogger.create('DecryptionWorker');
const perfLogger = PerformanceLogger.create();
interface DecryptionResult {
skippedItemCount?: number;
@@ -327,7 +327,7 @@ 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');
const startTask = perfLogger.taskStart('DecryptionWorker/start');
let output = null;
try {
output = await this.start_(options);

View File

@@ -14,7 +14,7 @@ import { ItemChangeEntity } from './database/types';
import PerformanceLogger from '../PerformanceLogger';
const { sprintf } = require('sprintf-js');
const perfLogger = PerformanceLogger.create('ResourceService');
const perfLogger = PerformanceLogger.create();
export default class ResourceService extends BaseService {
@@ -37,7 +37,7 @@ export default class ResourceService extends BaseService {
}
this.isIndexing_ = true;
const task = perfLogger.taskStart('indexNoteResources');
const task = perfLogger.taskStart('ResourceService/indexNoteResources');
try {
await ItemChange.waitForAllSaved();
@@ -128,7 +128,7 @@ export default class ResourceService extends BaseService {
public async deleteOrphanResources(expiryDelay: number = null) {
if (expiryDelay === null) expiryDelay = Setting.value('revisionService.ttlDays') * 24 * 60 * 60 * 1000;
const task = perfLogger.taskStart('deleteOrphanResources');
const task = perfLogger.taskStart('ResourceService/deleteOrphanResources');
const resourceIds = await NoteResource.orphanResources(expiryDelay);
this.logger().info('ResourceService::deleteOrphanResources:', resourceIds);

View File

@@ -19,7 +19,7 @@ const { sprintf } = require('sprintf-js');
import { pregQuote, scriptType, removeDiacritics } from '../../string-utils';
import PerformanceLogger from '../../PerformanceLogger';
const perfLogger = PerformanceLogger.create('SearchEngine');
const perfLogger = PerformanceLogger.create();
enum SearchType {
Auto = 'auto',
@@ -192,7 +192,7 @@ export default class SearchEngine {
private async syncTables_() {
if (this.isIndexing_) return;
const syncTask = perfLogger.taskStart('syncTables');
const syncTask = perfLogger.taskStart('SearchEngine/syncTables');
this.isIndexing_ = true;

View File

@@ -17,7 +17,7 @@ import { ShareInvitation, SharePermissions, State, stateRootKey, StateShare } fr
import PerformanceLogger from '../../PerformanceLogger';
const logger = Logger.create('ShareService');
const perfLogger = PerformanceLogger.create('ShareService');
const perfLogger = PerformanceLogger.create();
export interface ApiShare {
id: string;
@@ -516,7 +516,7 @@ export default class ShareService {
}
public async maintenance() {
const task = perfLogger.taskStart('maintenance');
const task = perfLogger.taskStart('ShareService/maintenance');
if (this.enabled) {
let hasError = false;

View File

@@ -19,6 +19,14 @@ The `PerformanceLogger` class has a few methods that can help debug performance
- `.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`.
### Naming conventions
The `name` provided to `.mark`, `.track`, and `.taskStart` should have the form `filename/marker name`. For example, in `root.tsx`, a performance task might be named `root/application setup`.
These names should be unique inline string literals so that they can be quickly found with a global search.
### Finding performance markers
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`.
@@ -28,21 +36,22 @@ On desktop and web (in Chrome), `PerformanceLogger` tasks and marks are added to
**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**:
### Example
```ts
const perfLogger = PerformanceLogger.create('VerySlowThing');
const perfLogger = PerformanceLogger.create();
class VerySlowThing {
public doSomethingSlow() {
// It's possible to mark the start and end of tasks with .taskStart and .onEnd:
const task = perfLogger.taskStart('doSomethingSlow');
const task = perfLogger.taskStart('VerySlowThing/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');
perfLogger.mark('VerySlowThing/Counter has reached 100_000');
}
}
@@ -51,7 +60,7 @@ class VerySlowThing {
public async doSomethingElse() {
// .track wraps an async callback.
await perfLogger.track('doSomethingElse', async () => {
await perfLogger.track('VerySlowThing/doSomethingElse', async () => {
await someBackgroundTask();
// Even if the callback throws an Error, .track