From b476d0dbb78b01d547f535eee98bb9833f8dcb4e Mon Sep 17 00:00:00 2001 From: Matthias Behr Date: Thu, 2 Jan 2025 12:02:41 +0100 Subject: [PATCH] fix(sequences): debug output of received msgs The debug output of received msgs was not using the sliced 50 msgs but for all messages times the sliced msgs. Added some console.logging output to measure performance of each step. --- src/extension/fbaEditor.ts | 1 - src/extension/fbaNBRQRenderer.ts | 52 +++++++++++++++++++++++++++++++- 2 files changed, 51 insertions(+), 2 deletions(-) diff --git a/src/extension/fbaEditor.ts b/src/extension/fbaEditor.ts index 99d4590..68a74d8 100644 --- a/src/extension/fbaEditor.ts +++ b/src/extension/fbaEditor.ts @@ -553,7 +553,6 @@ export class FBAEditorProvider implements vscode.CustomTextEditorProvider, vscod if (url.startsWith('ext:')) { const extName = url.slice(4, url.indexOf('/')) const query = url.slice(url.indexOf('/')) - console.log(`extName=${extName} request=${url}`) // did this extension offer the restQuery? return new Promise((resolve, reject) => { const rq = this._restQueryExtFunctions.get(extName) diff --git a/src/extension/fbaNBRQRenderer.ts b/src/extension/fbaNBRQRenderer.ts index 6eeee5f..69da943 100644 --- a/src/extension/fbaNBRQRenderer.ts +++ b/src/extension/fbaNBRQRenderer.ts @@ -671,6 +671,7 @@ export class FBANBRestQueryRenderer { cell: vscode.NotebookCell, ): Promise { try { + const perfStart: number = performance.now() const sequences = JSON5.parse(cell.document.getText()) if (Array.isArray(sequences) && sequences.length > 0) { // code similar to fba-cli.processSequences (todo refactor to dlt-log-utils/sequences?) @@ -715,8 +716,15 @@ export class FBANBRestQueryRenderer { }, ], } + let perfStep = performance.now() + let perfInterims = perfStep - perfStart + console.log(`executeSequences: triggering rest query after ${perfInterims}ms, total:${perfStep - perfStart}ms`) await editorProvider.performRestQuery(docData, rqUriEncode(allFiltersRq)).then( async (resJson: any) => { + const perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: got rest query results after ${perfInterims}ms, total:${perfStep - perfStart}ms`) if ('error' in resJson) { exec.appendOutput( new NotebookCellOutput([vscode.NotebookCellOutputItem.stderr(`query got error:${JSON.stringify(resJson.error)}`)]), @@ -728,6 +736,10 @@ export class FBANBRestQueryRenderer { .filter((d: any) => d.type === 'lifecycles') .map((d: any) => [d.id as number, this.getLCInfoFromRQLc(d.attributes)]), ) + let perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: got lifecycles after ${perfInterims}ms, total:${perfStep - perfStart}ms`) const msgs = resJson.data .filter((d: any) => d.type === 'msg') .map((d: any) => { @@ -740,16 +752,34 @@ export class FBANBRestQueryRenderer { } }) const slicedMsgs = msgs.slice(0, 50) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: got slicedMsgs after ${perfInterims}ms, total:${perfStep - perfStart}ms`) + + const msgsText = slicedMsgs.flatMap((msg) => codeBlock(JSON.stringify(msg, undefined, 2), 'json')) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: got msgsText after ${perfInterims}ms, total:${perfStep - perfStart}ms`) appendMarkdown(exec, [ { open: false, summary: `received ${lifecycles.size} lifecycles and ${msgs.length} messages${ msgs.length > slicedMsgs.length ? `. Unfold to see first ${slicedMsgs.length}` : resJson.data.length > 0 ? ':' : '' }`, - texts: msgs.map((msg) => codeBlock(JSON.stringify(slicedMsgs, undefined, 2), 'json')).flat(), + texts: msgsText, }, ]) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: triggering processMsgs() after ${perfInterims}ms, total:${perfStep - perfStart}ms`) seqChecker.processMsgs(msgs) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: finished processMsgs() after ${perfInterims}ms, total:${perfStep - perfStart}ms`) /*appendMarkdown(exec, [ { open: false, @@ -759,6 +789,10 @@ export class FBANBRestQueryRenderer { ])*/ try { const resAsMd = seqResultToMdAst(seqResult) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: finished seqResultToMdAst() after ${perfInterims}ms, total:${perfStep - perfStart}ms`) /*appendMarkdown(exec, [ { open: false, @@ -773,7 +807,15 @@ export class FBANBRestQueryRenderer { { type: 'root', children: resAsMd }, { extensions: [gfmTableToMarkdown({ tablePipeAlign: false })] }, ) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: finished toMarkdown() after ${perfInterims}ms, total:${perfStep - perfStart}ms`) appendMarkdown(exec, [resAsMarkdown]) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log(`executeSequences: finished appendMarkdown() after ${perfInterims}ms, total:${perfStep - perfStart}ms`) } catch (e) { exec.appendOutput( new NotebookCellOutput([vscode.NotebookCellOutputItem.stderr(`converting result to md got err:${e}`)]), @@ -786,6 +828,12 @@ export class FBANBRestQueryRenderer { texts: seqResult.logs.map((log: string) => codeBlock(log, 'json')).flat(), }, ]) + perfNow = performance.now() + perfInterims = perfNow - perfStep + perfStep = perfNow + console.log( + `executeSequences: finished appendMarkdown() for logs after ${perfInterims}ms, total:${perfStep - perfStart}ms`, + ) } else { exec.appendOutput(new NotebookCellOutput([vscode.NotebookCellOutputItem.stderr(`query got no data!`)])) } @@ -798,6 +846,8 @@ export class FBANBRestQueryRenderer { ) } exec.end(true) + const perfStep = performance.now() + console.log(`executeSequences: finished exec(true) for logs after total:${perfStep - perfStart}ms`) } else { exec.appendOutput( new NotebookCellOutput([vscode.NotebookCellOutputItem.stderr(`no sequences provided! Needs to be a non empty json array!`)]),