From 36079fc1d0127cf4974b747625c08d1f330ad4f1 Mon Sep 17 00:00:00 2001 From: fyears <1142836+fyears@users.noreply.github.com> Date: Thu, 9 May 2024 00:01:30 +0800 Subject: [PATCH] add profiler --- src/baseTypes.ts | 7 ++++ src/langs/en.json | 4 +++ src/main.ts | 19 ++++++++-- src/misc.ts | 38 ++++++++++++++++++++ src/profiler.ts | 89 ++++++++++++++++++++++++++++++++++++++--------- src/settings.ts | 39 +++++++++++++++++++++ src/sync.ts | 46 ++++++++++++++++++++++-- 7 files changed, 220 insertions(+), 22 deletions(-) diff --git a/src/baseTypes.ts b/src/baseTypes.ts index 947bc9e..1b2d16e 100644 --- a/src/baseTypes.ts +++ b/src/baseTypes.ts @@ -107,6 +107,11 @@ export type CipherMethodType = "rclone-base64" | "openssl-base64" | "unknown"; export type QRExportType = "all_but_oauth2" | "dropbox" | "onedrive"; +export interface ProfilerConfig { + enablePrinting?: boolean; + recordSize?: boolean; +} + export interface RemotelySavePluginSettings { s3: S3Config; webdav: WebdavConfig; @@ -141,6 +146,8 @@ export interface RemotelySavePluginSettings { encryptionMethod?: CipherMethodType; + profiler?: ProfilerConfig; + /** * @deprecated */ diff --git a/src/langs/en.json b/src/langs/en.json index 751316e..9e9bf0c 100644 --- a/src/langs/en.json +++ b/src/langs/en.json @@ -330,6 +330,10 @@ "settings_profiler_results_desc": "The plugin records the time cost of each steps. Here you can export them to know which step is slow.", "settings_profiler_results_notice": "Profiler results exported.", "settings_profiler_results_button_all": "Export All", + "settings_profiler_enabledebugprint": "Enable Profiler Printing", + "settings_profiler_enabledebugprint_desc": "Print profiler result in each insertion to console or not?", + "settings_profiler_recordsize": "Enable Profiler Recording Size", + "settings_profiler_recordsize_desc": "Let profiler record object sizes or not?", "settings_outputbasepathvaultid": "Output Vault Base Path And Randomly Assigned ID", "settings_outputbasepathvaultid_desc": "For debugging purposes.", "settings_outputbasepathvaultid_button": "Output", diff --git a/src/main.ts b/src/main.ts index 644d461..6947dd0 100644 --- a/src/main.ts +++ b/src/main.ts @@ -62,7 +62,7 @@ import { getClient } from "./fsGetter"; import { FakeFsLocal } from "./fsLocal"; import { DEFAULT_WEBDIS_CONFIG } from "./fsWebdis"; import { changeMobileStatusBar } from "./misc"; -import { Profiler } from "./profiler"; +import { DEFAULT_PROFILER_CONFIG, Profiler } from "./profiler"; import { syncer } from "./sync"; const DEFAULT_SETTINGS: RemotelySavePluginSettings = { @@ -96,6 +96,7 @@ const DEFAULT_SETTINGS: RemotelySavePluginSettings = { obfuscateSettingFile: true, enableMobileStatusBar: false, encryptionMethod: "unknown", + profiler: DEFAULT_PROFILER_CONFIG, }; interface OAuth2Info { @@ -151,7 +152,11 @@ export default class RemotelySavePlugin extends Plugin { appContainerObserver?: MutationObserver; async syncRun(triggerSource: SyncTriggerSourceType = "manual") { - const profiler = new Profiler(); + const profiler = new Profiler( + undefined, + this.settings.profiler?.enablePrinting ?? false, + this.settings.profiler?.recordSize ?? false + ); const fsLocal = new FakeFsLocal( this.app.vault, this.settings.syncConfigDir ?? false, @@ -940,6 +945,16 @@ export default class RemotelySavePlugin extends Plugin { } } + if (this.settings.profiler === undefined) { + this.settings.profiler = DEFAULT_PROFILER_CONFIG; + } + if (this.settings.profiler.enablePrinting === undefined) { + this.settings.profiler.enablePrinting = false; + } + if (this.settings.profiler.recordSize === undefined) { + this.settings.profiler.recordSize = false; + } + await this.saveSettings(); } diff --git a/src/misc.ts b/src/misc.ts index 457e1f8..1ff70da 100644 --- a/src/misc.ts +++ b/src/misc.ts @@ -641,3 +641,41 @@ export const fixEntityListCasesInplace = (entities: { keyRaw: string }[]) => { return entities; }; + +/** + * https://stackoverflow.com/questions/1248302/how-to-get-the-size-of-a-javascript-object + * @param object + * @returns bytes + */ +export const roughSizeOfObject = (object: any) => { + const objectList: any[] = []; + const stack = [object]; + let bytes = 0; + + while (stack.length) { + const value = stack.pop(); + + switch (typeof value) { + case "boolean": + bytes += 4; + break; + case "string": + bytes += value.length * 2; + break; + case "number": + bytes += 8; + break; + case "object": + if (!objectList.includes(value)) { + objectList.push(value); + for (const prop in value) { + if (value.hasOwnProperty(prop)) { + stack.push(value[prop]); + } + } + } + break; + } + } + return bytes; +}; diff --git a/src/profiler.ts b/src/profiler.ts index 71b98b3..0935232 100644 --- a/src/profiler.ts +++ b/src/profiler.ts @@ -1,29 +1,43 @@ -import type { SUPPORTED_SERVICES_TYPE } from "./baseTypes"; +import type { ProfilerConfig, SUPPORTED_SERVICES_TYPE } from "./baseTypes"; import { type InternalDBs, insertProfilerResultByVault } from "./localdb"; -import { unixTimeToStr } from "./misc"; +import { roughSizeOfObject, unixTimeToStr } from "./misc"; interface BreakPoint { label: string; fakeTimeMilli: number; // it's NOT a unix timestamp indent: number; + size?: number; } +export const DEFAULT_PROFILER_CONFIG: ProfilerConfig = { + enablePrinting: false, + recordSize: false, +}; + export class Profiler { startTime: number; breakPoints: BreakPoint[]; indent: number; - constructor(label?: string) { + enablePrinting: boolean; + recordSize: boolean; + constructor(label?: string, enablePrinting?: boolean, recordSize?: boolean) { this.breakPoints = []; this.indent = 0; this.startTime = 0; + this.enablePrinting = enablePrinting ?? false; + this.recordSize = recordSize ?? false; if (label !== undefined) { this.startTime = Date.now(); - this.breakPoints.push({ + const p = { label: label, fakeTimeMilli: performance.now(), indent: this.indent, - }); + }; + this.breakPoints.push(p); + if (this.enablePrinting) { + console.debug(this.toString(-1)); + } } } @@ -31,11 +45,36 @@ export class Profiler { if (this.breakPoints.length === 0) { this.startTime = Date.now(); } - this.breakPoints.push({ + const p = { label: label, fakeTimeMilli: performance.now(), indent: this.indent, - }); + }; + this.breakPoints.push(p); + if (this.enablePrinting) { + console.debug(this.toString(-1)); + } + + return this; + } + + insertSize(label: string, obj: any) { + if (!this.recordSize) { + return; + } + if (this.breakPoints.length === 0) { + this.startTime = Date.now(); + } + const p = { + label: label, + fakeTimeMilli: performance.now(), + indent: this.indent, + size: roughSizeOfObject(obj), + }; + this.breakPoints.push(p); + if (this.enablePrinting) { + console.debug(this.toString(-1)); + } return this; } @@ -57,7 +96,31 @@ export class Profiler { return this; } - toString() { + toString(idx?: number) { + if (idx !== undefined) { + let i = idx; + if (idx < 0) { + i = this.breakPoints.length + idx; + } + const label = this.breakPoints?.[i]["label"]; + const indent = this.breakPoints?.[i]["indent"]; + let millsec = 0; + if (i >= 1) { + millsec = + Math.round( + (this.breakPoints?.[i]["fakeTimeMilli"] - + this.breakPoints?.[i - 1]["fakeTimeMilli"]) * + 10 + ) / 10.0; + } + let res = `${" ".repeat(indent)}[${label}]: ${millsec}ms`; + if (this.breakPoints[i].hasOwnProperty("size")) { + const size = this.breakPoints[i].size as number; + res += `, size=${size}`; + } + return res; + } + if (this.breakPoints.length === 0) { return "nothing in profiler"; } @@ -67,15 +130,7 @@ export class Profiler { if (i === 0) { res += `\n[${this.breakPoints[i]["label"]}]: start`; } else { - const label = this.breakPoints[i]["label"]; - const indent = this.breakPoints[i]["indent"]; - const millsec = - Math.round( - (this.breakPoints[i]["fakeTimeMilli"] - - this.breakPoints[i - 1]["fakeTimeMilli"]) * - 10 - ) / 10.0; - res += `\n${" ".repeat(indent)}[${label}]: ${millsec}ms`; + res += `\n${this.toString(i)}`; } } diff --git a/src/settings.ts b/src/settings.ts index fbf1c2c..594deea 100644 --- a/src/settings.ts +++ b/src/settings.ts @@ -57,6 +57,7 @@ import { checkHasSpecialCharForDir, stringToFragment, } from "./misc"; +import { DEFAULT_PROFILER_CONFIG } from "./profiler"; class PasswordModal extends Modal { plugin: RemotelySavePlugin; @@ -2478,6 +2479,44 @@ export class RemotelySaveSettingTab extends PluginSettingTab { }); }); + new Setting(debugDiv) + .setName(t("settings_profiler_enabledebugprint")) + .setDesc(t("settings_profiler_enabledebugprint_desc")) + .addDropdown((dropdown) => { + dropdown.addOption("enable", t("enable")); + dropdown.addOption("disable", t("disable")); + dropdown + .setValue( + this.plugin.settings.profiler?.enablePrinting ? "enable" : "disable" + ) + .onChange(async (val: string) => { + if (this.plugin.settings.profiler === undefined) { + this.plugin.settings.profiler = DEFAULT_PROFILER_CONFIG; + } + this.plugin.settings.profiler.enablePrinting = val === "enable"; + await this.plugin.saveSettings(); + }); + }); + + new Setting(debugDiv) + .setName(t("settings_profiler_recordsize")) + .setDesc(t("settings_profiler_recordsize_desc")) + .addDropdown((dropdown) => { + dropdown.addOption("enable", t("enable")); + dropdown.addOption("disable", t("disable")); + dropdown + .setValue( + this.plugin.settings.profiler?.recordSize ? "enable" : "disable" + ) + .onChange(async (val: string) => { + if (this.plugin.settings.profiler === undefined) { + this.plugin.settings.profiler = DEFAULT_PROFILER_CONFIG; + } + this.plugin.settings.profiler.recordSize = val === "enable"; + await this.plugin.saveSettings(); + }); + }); + new Setting(debugDiv) .setName(t("settings_outputbasepathvaultid")) .setDesc(t("settings_outputbasepathvaultid_desc")) diff --git a/src/sync.ts b/src/sync.ts index 75ff1a8..1e6955b 100644 --- a/src/sync.ts +++ b/src/sync.ts @@ -30,6 +30,7 @@ import { getParentFolder, isHiddenPath, isSpecialFolderNameToSkip, + roughSizeOfObject, unixTimeToStr, } from "./misc"; import type { Profiler } from "./profiler"; @@ -158,6 +159,9 @@ const ensembleMixedEnties = async ( ): Promise => { profiler.addIndent(); profiler.insert("ensembleMixedEnties: enter"); + profiler.insertSize("sizeof localEntityList", localEntityList); + profiler.insertSize("sizeof prevSyncEntityList", prevSyncEntityList); + profiler.insertSize("sizeof remoteEntityList", remoteEntityList); const finalMappings: SyncPlanType = {}; @@ -187,6 +191,7 @@ const ensembleMixedEnties = async ( } profiler.insert("ensembleMixedEnties: finish remote"); + profiler.insertSize("sizeof finalMappings", finalMappings); if (Object.keys(finalMappings).length === 0 || localEntityList.length === 0) { // Special checking: @@ -227,6 +232,7 @@ const ensembleMixedEnties = async ( } profiler.insert("ensembleMixedEnties: finish prevSync"); + profiler.insertSize("sizeof finalMappings", finalMappings); // local has to be last // because we want to get keyEnc based on the remote @@ -260,6 +266,7 @@ const ensembleMixedEnties = async ( } profiler.insert("ensembleMixedEnties: finish local"); + profiler.insertSize("sizeof finalMappings", finalMappings); // console.debug("in the end of ensembleMixedEnties, finalMappings is:"); // console.debug(finalMappings); @@ -280,7 +287,9 @@ const getSyncPlanInplace = async ( skipSizeLargerThan: number, conflictAction: ConflictActionType, syncDirection: SyncDirectionType, - profiler: Profiler + profiler: Profiler, + settings: RemotelySavePluginSettings, + triggerSource: SyncTriggerSourceType ) => { profiler.addIndent(); profiler.insert("getSyncPlanInplace: enter"); @@ -289,10 +298,17 @@ const getSyncPlanInplace = async ( (k1, k2) => k2.length - k1.length ); profiler.insert("getSyncPlanInplace: finish sorting"); + profiler.insertSize("sizeof sortedKeys", sortedKeys); const keptFolder = new Set(); for (let i = 0; i < sortedKeys.length; ++i) { + if (i % 100 === 0) { + profiler.insertSize( + `sizeof sortedKeys in the beginning of i=${i}`, + mixedEntityMappings + ); + } const key = sortedKeys[i]; const mixedEntry = mixedEntityMappings[key]; const { local, prevSync, remote } = mixedEntry; @@ -703,16 +719,28 @@ const getSyncPlanInplace = async ( const currTimeFmt = unixTimeToStr(currTime); // because the path should not as / in the beginning, // we should be safe to add these keys: + const sizeofmixedEntityMappings = roughSizeOfObject(mixedEntityMappings); mixedEntityMappings["/$@meta"] = { key: "/$@meta", // don't mess up with the types sideNotes: { - version: "2024047 fs version", + version: "20240508 fs version", generateTime: currTime, generateTimeFmt: currTimeFmt, + service: settings.serviceType, + hasPassword: settings.password !== "", + syncConfigDir: settings.syncConfigDir, + conflictAction: conflictAction, + syncDirection: syncDirection, + triggerSource: triggerSource, + sizeof: sizeofmixedEntityMappings }, }; profiler.insert("getSyncPlanInplace: exit"); + profiler.insertSize( + "sizeof mixedEntityMappings in the end of getSyncPlanInplace", + mixedEntityMappings + ); profiler.removeIndent(); return mixedEntityMappings; @@ -1126,6 +1154,16 @@ export const doActualSync = async ( console.debug(`realTotalCount: ${realTotalCount}`); profiler.insert("doActualSync: finish splitting steps"); + profiler.insertSize( + "doActualSync: sizeof onlyMarkSyncedOps", + onlyMarkSyncedOps + ); + profiler.insertSize( + "doActualSync: sizeof folderCreationOps", + folderCreationOps + ); + profiler.insertSize("doActualSync: sizeof realTotalCount", deletionOps); + console.debug(`protectModifyPercentage: ${protectModifyPercentage}`); if ( @@ -1375,7 +1413,9 @@ export async function syncer( settings.skipSizeLargerThan ?? -1, settings.conflictAction ?? "keep_newer", settings.syncDirection ?? "bidirectional", - profiler + profiler, + settings, + triggerSource ); console.debug(`mixedEntityMappings:`); console.debug(mixedEntityMappings); // for debugging