From d81739c35f5f4085e2e9e1528900671d0545c464 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Tue, 2 Apr 2024 16:22:50 -0700 Subject: [PATCH 01/12] execution plugin --- common/lib/abstract_connection_plugin.ts | 12 ++-- common/lib/connection_plugin_chain_builder.ts | 4 +- common/lib/plugins/execution_time_plugin.ts | 57 +++++++++++++++++++ common/lib/utils/locales/en.json | 3 +- common/lib/utils/utils.ts | 2 +- 5 files changed, 68 insertions(+), 10 deletions(-) create mode 100644 common/lib/plugins/execution_time_plugin.ts diff --git a/common/lib/abstract_connection_plugin.ts b/common/lib/abstract_connection_plugin.ts index 3d38ada8..7a47c804 100644 --- a/common/lib/abstract_connection_plugin.ts +++ b/common/lib/abstract_connection_plugin.ts @@ -24,11 +24,11 @@ export abstract class AbstractConnectionPlugin implements ConnectionPlugin { abstract getSubscribedMethods(): Set; connect(hostInfo: HostInfo, props: Map, isInitialConnection: boolean, connectFunc: () => Promise): Promise { - throw new Error("Method not implemented."); + return connectFunc(); } forceConnect(hostInfo: HostInfo, props: Map, isInitialConnection: boolean, forceConnectFunc: () => Promise): Promise { - throw new Error("Method not implemented."); + return forceConnectFunc(); } execute(methodName: string, methodFunc: () => Promise, methodArgs: any[]): Promise { @@ -41,14 +41,12 @@ export abstract class AbstractConnectionPlugin implements ConnectionPlugin { hostListProviderService: HostListProviderService, initHostProviderFunc: () => void ): void { - throw new Error("Method not implemented."); + initHostProviderFunc(); } notifyConnectionChanged(changes: Set): OldConnectionSuggestionAction { - throw new Error("Method not implemented."); + return OldConnectionSuggestionAction.NO_OPINION; } - notifyNodeListChanged(changes: Map>): void { - throw new Error("Method not implemented."); - } + notifyNodeListChanged(changes: Map>): void {} } diff --git a/common/lib/connection_plugin_chain_builder.ts b/common/lib/connection_plugin_chain_builder.ts index 19a070a4..f067627f 100644 --- a/common/lib/connection_plugin_chain_builder.ts +++ b/common/lib/connection_plugin_chain_builder.ts @@ -22,6 +22,7 @@ import { WrapperProperties } from "./wrapper_property"; import { AwsWrapperError } from "./utils/aws_wrapper_error"; import { Messages } from "./utils/messages"; import { DefaultPlugin } from "./plugins/default_plugin"; +import { ExecutionTimePluginFactory } from './plugins/execution_time_plugin'; export class PluginFactoryInfo {} @@ -33,7 +34,8 @@ export class ConnectionPluginChainBuilder { static readonly PLUGIN_FACTORIES = new Map([ ["iam", IamAuthenticationPluginFactory], - ["failover", FailoverPluginFactory] + ["failover", FailoverPluginFactory], + ["executionTime", ExecutionTimePluginFactory] ]); getPlugins(pluginService: PluginService, props: Map): ConnectionPlugin[] { diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execution_time_plugin.ts new file mode 100644 index 00000000..fdf8a5a6 --- /dev/null +++ b/common/lib/plugins/execution_time_plugin.ts @@ -0,0 +1,57 @@ +/* + Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. + + Licensed under the Apache License, Version 2.0 (the "License"). + You may not use this file except in compliance with the License. + You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. +*/ + +import { logger } from "../../logutils"; +import { AbstractConnectionPlugin } from "../abstract_connection_plugin"; +import { ConnectionPlugin } from "../connection_plugin"; +import { ConnectionPluginFactory } from "../plugin_factory"; +import { PluginService } from "../plugin_service"; +import { Messages } from "../utils/messages"; +import { getTimeInNanos } from "../utils/utils"; + +export class ExecutionTimePlugin extends AbstractConnectionPlugin { + private static subscribedMethods: Set = new Set(["*"]); + private static executionTime: bigint = 0n; + + public override getSubscribedMethods(): Set { + return ExecutionTimePlugin.subscribedMethods; + } + + public override async execute(methodName: string, methodFunc: () => Promise, methodArgs: any[]): Promise { + const startTime = getTimeInNanos(); + + const result = await methodFunc(); + + const elapsedTimeNanos = getTimeInNanos() - startTime; + logger.debug(Messages.get("ExecutionTimeConnectionPlugin.executionTime", methodName, elapsedTimeNanos.toString())); + ExecutionTimePlugin.executionTime += elapsedTimeNanos; + return result; + } + + public static resetExecutionTime(): void { + this.executionTime = 0n; + } + + public static getTotalExecutionTime(): bigint { + return this.executionTime; + } +} + +export class ExecutionTimePluginFactory implements ConnectionPluginFactory { + getInstance(pluginService: PluginService, properties: Map): ConnectionPlugin { + return new ExecutionTimePlugin(); + } +} \ No newline at end of file diff --git a/common/lib/utils/locales/en.json b/common/lib/utils/locales/en.json index 8356367c..66d4ff77 100644 --- a/common/lib/utils/locales/en.json +++ b/common/lib/utils/locales/en.json @@ -33,5 +33,6 @@ "ClusterAwareWriterFailoverHandler.taskBFailedToConnectToAnyReader": "[TaskB] Failed to connect to any reader.", "ClusterAwareWriterFailoverHandler.standaloneNode": "[TaskB] Host %s is not yet connected to a cluster. The cluster is still being reconfigured.", "ClusterAwareWriterFailoverHandler.taskBAttemptConnectionToNewWriter": "[TaskB] Trying to connect to a new writer: '%s'", - "ClusterAwareWriterFailoverHandler.alreadyWriter": "Current reader connection is actually a new writer connection." + "ClusterAwareWriterFailoverHandler.alreadyWriter": "Current reader connection is actually a new writer connection.", + "ExecutionTimeConnectionPlugin.executionTime": "Executed %s in %s nanoseconds." } diff --git a/common/lib/utils/utils.ts b/common/lib/utils/utils.ts index c215e725..553fcdcf 100644 --- a/common/lib/utils/utils.ts +++ b/common/lib/utils/utils.ts @@ -38,7 +38,7 @@ export function logTopology(hosts: HostInfo[], msgPrefix: string) { } export function getTimeInNanos() { - return performance.now(); + return process.hrtime.bigint(); } export function maskProperties(props: Map) { From 5f45648aa7a8697b269055c5526f9760ba8d49b7 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 10:15:21 -0700 Subject: [PATCH 02/12] unit test --- tests/unit/execution_time_plugin.test.ts | 52 ++++++++++++++++++++++++ 1 file changed, 52 insertions(+) create mode 100644 tests/unit/execution_time_plugin.test.ts diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts new file mode 100644 index 00000000..381cbe72 --- /dev/null +++ b/tests/unit/execution_time_plugin.test.ts @@ -0,0 +1,52 @@ +/* + Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. + + Licensed under the Apache License, Version 2.0 (the "License"). + You may not use this file except in compliance with the License. + You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. +*/ + +import { ExecutionTimePlugin } from "aws-wrapper-common-lib/lib/plugins/execution_time_plugin"; +import { sleep } from "aws-wrapper-common-lib/lib/utils/utils"; +import { logger } from "aws-wrapper-common-lib/logutils"; +import { Writable } from "stream"; +import winston, { } from "winston"; + +const mockCallable = jest.fn(); + +describe("executionTimePluginTest", () => { + it("test_executeTime", async () => { + mockCallable.mockImplementation(() => { + sleep(10); + return null; + }) + + const plugin = new ExecutionTimePlugin(); + + let output = ''; + const stream = new Writable(); + stream._write = (chunk, encoding, callback) => { + output = output += chunk.toString(); + callback(); + }; + + const streamTransport = new winston.transports.Stream({ stream }) + logger.add(streamTransport); + logger.level = "debug"; + + await plugin.execute("query", mockCallable, []); + + const logMessages = output.trim().split('\n'); + + expect(logMessages[0]).toContain("Executed query in"); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(0n); + }) +}); From 3a40c148df369f3fe09a240124268a8b40719fbc Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 14:26:25 -0700 Subject: [PATCH 03/12] clean up --- common/lib/plugins/execution_time_plugin.ts | 2 +- common/lib/utils/locales/en.json | 2 +- tests/unit/execution_time_plugin.test.ts | 9 ++++++--- 3 files changed, 8 insertions(+), 5 deletions(-) diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execution_time_plugin.ts index fdf8a5a6..2c80ce25 100644 --- a/common/lib/plugins/execution_time_plugin.ts +++ b/common/lib/plugins/execution_time_plugin.ts @@ -36,7 +36,7 @@ export class ExecutionTimePlugin extends AbstractConnectionPlugin { const result = await methodFunc(); const elapsedTimeNanos = getTimeInNanos() - startTime; - logger.debug(Messages.get("ExecutionTimeConnectionPlugin.executionTime", methodName, elapsedTimeNanos.toString())); + logger.debug(Messages.get("ExecutionTimePlugin.executionTime", methodName, elapsedTimeNanos.toString())); ExecutionTimePlugin.executionTime += elapsedTimeNanos; return result; } diff --git a/common/lib/utils/locales/en.json b/common/lib/utils/locales/en.json index 66d4ff77..4816d151 100644 --- a/common/lib/utils/locales/en.json +++ b/common/lib/utils/locales/en.json @@ -34,5 +34,5 @@ "ClusterAwareWriterFailoverHandler.standaloneNode": "[TaskB] Host %s is not yet connected to a cluster. The cluster is still being reconfigured.", "ClusterAwareWriterFailoverHandler.taskBAttemptConnectionToNewWriter": "[TaskB] Trying to connect to a new writer: '%s'", "ClusterAwareWriterFailoverHandler.alreadyWriter": "Current reader connection is actually a new writer connection.", - "ExecutionTimeConnectionPlugin.executionTime": "Executed %s in %s nanoseconds." + "ExecutionTimePlugin.executionTime": "Executed %s in %s nanoseconds." } diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 381cbe72..c670a160 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -18,7 +18,7 @@ import { ExecutionTimePlugin } from "aws-wrapper-common-lib/lib/plugins/executio import { sleep } from "aws-wrapper-common-lib/lib/utils/utils"; import { logger } from "aws-wrapper-common-lib/logutils"; import { Writable } from "stream"; -import winston, { } from "winston"; +import winston from "winston"; const mockCallable = jest.fn(); @@ -33,9 +33,9 @@ describe("executionTimePluginTest", () => { let output = ''; const stream = new Writable(); - stream._write = (chunk, encoding, callback) => { + stream._write = (chunk, encoding, next) => { output = output += chunk.toString(); - callback(); + next(); }; const streamTransport = new winston.transports.Stream({ stream }) @@ -48,5 +48,8 @@ describe("executionTimePluginTest", () => { expect(logMessages[0]).toContain("Executed query in"); expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(0n); + + ExecutionTimePlugin.resetExecutionTime(); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); }) }); From eef0c269efec8aadf5bd030d3482da0bb6d707b9 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 15:30:52 -0700 Subject: [PATCH 04/12] remove console log output --- tests/unit/execution_time_plugin.test.ts | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index c670a160..0f42e8e7 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -42,8 +42,13 @@ describe("executionTimePluginTest", () => { logger.add(streamTransport); logger.level = "debug"; + // Temporarily suppress console logging + logger.transports[0].silent = true; + await plugin.execute("query", mockCallable, []); + logger.transports[0].silent = false; + const logMessages = output.trim().split('\n'); expect(logMessages[0]).toContain("Executed query in"); From b0feb4d9d697173c5fdb84db0e88050597444679 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 15:36:14 -0700 Subject: [PATCH 05/12] remove transport --- tests/unit/execution_time_plugin.test.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 0f42e8e7..6a46d802 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -48,6 +48,7 @@ describe("executionTimePluginTest", () => { await plugin.execute("query", mockCallable, []); logger.transports[0].silent = false; + logger.remove(streamTransport); const logMessages = output.trim().split('\n'); From eda55bf02c19680097a17bbdab771d6b9912ad06 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 16:07:06 -0700 Subject: [PATCH 06/12] fix logmessage check --- tests/unit/execution_time_plugin.test.ts | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 6a46d802..57ca180a 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -27,10 +27,11 @@ describe("executionTimePluginTest", () => { mockCallable.mockImplementation(() => { sleep(10); return null; - }) + }); const plugin = new ExecutionTimePlugin(); + // Create stream let output = ''; const stream = new Writable(); stream._write = (chunk, encoding, next) => { @@ -38,7 +39,7 @@ describe("executionTimePluginTest", () => { next(); }; - const streamTransport = new winston.transports.Stream({ stream }) + const streamTransport = new winston.transports.Stream({ stream }); logger.add(streamTransport); logger.level = "debug"; @@ -52,7 +53,9 @@ describe("executionTimePluginTest", () => { const logMessages = output.trim().split('\n'); - expect(logMessages[0]).toContain("Executed query in"); + const matches = logMessages.filter(str => str.includes("Executed query in")).length; + expect(matches).toBeGreaterThan(0); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(0n); ExecutionTimePlugin.resetExecutionTime(); From 6a8317985055ca2b927129c31521e70133390c70 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 16:14:24 -0700 Subject: [PATCH 07/12] typo --- tests/unit/execution_time_plugin.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 57ca180a..7ab90acf 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -60,5 +60,5 @@ describe("executionTimePluginTest", () => { ExecutionTimePlugin.resetExecutionTime(); expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); - }) + }); }); From 289021a84be8f682d51d3aae56b66769a37e8ca6 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Wed, 3 Apr 2024 16:28:56 -0700 Subject: [PATCH 08/12] newline --- common/lib/plugins/execution_time_plugin.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execution_time_plugin.ts index 2c80ce25..a2b00386 100644 --- a/common/lib/plugins/execution_time_plugin.ts +++ b/common/lib/plugins/execution_time_plugin.ts @@ -54,4 +54,4 @@ export class ExecutionTimePluginFactory implements ConnectionPluginFactory { getInstance(pluginService: PluginService, properties: Map): ConnectionPlugin { return new ExecutionTimePlugin(); } -} \ No newline at end of file +} From 53800ccb7e0ace09ba76bd3b3d141230649eebb8 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Thu, 4 Apr 2024 16:29:29 -0700 Subject: [PATCH 09/12] changes from review --- common/lib/plugins/default_plugin.ts | 2 +- common/lib/plugins/execution_time_plugin.ts | 52 ++++++++++--------- .../lib/plugins/failover/failover_plugin.ts | 3 +- common/lib/utils/locales/en.json | 2 +- tests/unit/execution_time_plugin.test.ts | 45 +++++----------- 5 files changed, 45 insertions(+), 59 deletions(-) diff --git a/common/lib/plugins/default_plugin.ts b/common/lib/plugins/default_plugin.ts index 24d462ac..be29d61a 100644 --- a/common/lib/plugins/default_plugin.ts +++ b/common/lib/plugins/default_plugin.ts @@ -51,7 +51,7 @@ export class DefaultPlugin extends AbstractConnectionPlugin { logger.debug(Messages.get("DefaultPlugin.executingMethod", methodName)); const start = performance.now(); const res = methodFunc(); - logger.debug(`Execution time for plugin ${this.id}: ${performance.now() - start} ms`); + logger.debug(Messages.get("ExecutionTimePlugin.executionTime", this.id, (performance.now() - start).toString())); return res; } } diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execution_time_plugin.ts index a2b00386..b69acd85 100644 --- a/common/lib/plugins/execution_time_plugin.ts +++ b/common/lib/plugins/execution_time_plugin.ts @@ -23,35 +23,37 @@ import { Messages } from "../utils/messages"; import { getTimeInNanos } from "../utils/utils"; export class ExecutionTimePlugin extends AbstractConnectionPlugin { - private static subscribedMethods: Set = new Set(["*"]); - private static executionTime: bigint = 0n; - - public override getSubscribedMethods(): Set { - return ExecutionTimePlugin.subscribedMethods; - } - - public override async execute(methodName: string, methodFunc: () => Promise, methodArgs: any[]): Promise { - const startTime = getTimeInNanos(); + private static readonly subscribedMethods: Set = new Set(["*"]); + private static executionTime: bigint = 0n; + + public override getSubscribedMethods(): Set { + return ExecutionTimePlugin.subscribedMethods; + } - const result = await methodFunc(); + public override async execute(methodName: string, methodFunc: () => Promise, methodArgs: any[]): Promise { + const startTime = getTimeInNanos(); - const elapsedTimeNanos = getTimeInNanos() - startTime; - logger.debug(Messages.get("ExecutionTimePlugin.executionTime", methodName, elapsedTimeNanos.toString())); - ExecutionTimePlugin.executionTime += elapsedTimeNanos; - return result; - } + const result = await methodFunc(); - public static resetExecutionTime(): void { - this.executionTime = 0n; - } - - public static getTotalExecutionTime(): bigint { - return this.executionTime; - } + const elapsedTimeNanos = getTimeInNanos() - startTime; + + // Convert from ns to ms + logger.debug(Messages.get("ExecutionTimePlugin.executionTime", methodName, (elapsedTimeNanos / 1000000n).toString())); + ExecutionTimePlugin.executionTime += elapsedTimeNanos; + return result; + } + + public static resetExecutionTime(): void { + ExecutionTimePlugin.executionTime = 0n; + } + + public static getTotalExecutionTime(): bigint { + return ExecutionTimePlugin.executionTime; + } } export class ExecutionTimePluginFactory implements ConnectionPluginFactory { - getInstance(pluginService: PluginService, properties: Map): ConnectionPlugin { - return new ExecutionTimePlugin(); - } + getInstance(pluginService: PluginService, properties: Map): ConnectionPlugin { + return new ExecutionTimePlugin(); + } } diff --git a/common/lib/plugins/failover/failover_plugin.ts b/common/lib/plugins/failover/failover_plugin.ts index 7e38ed74..2a7fc3e6 100644 --- a/common/lib/plugins/failover/failover_plugin.ts +++ b/common/lib/plugins/failover/failover_plugin.ts @@ -29,6 +29,7 @@ import { ClusterAwareReaderFailoverHandler } from "./reader_failover_handler"; import { SubscribedMethodHelper } from "../../utils/subsribed_method_helper"; import { HostChangeOptions } from "../../host_change_options"; import { ClusterAwareWriterFailoverHandler } from "./writer_failover_handler"; +import { Messages } from "../../utils/messages"; export class FailoverPlugin extends AbstractConnectionPlugin { private static readonly subscribedMethods: Set = new Set([ @@ -102,7 +103,7 @@ export class FailoverPlugin extends AbstractConnectionPlugin { await this.updateTopology(false); } const res = methodFunc(); - logger.debug(`Execution time for plugin ${this.id}: ${performance.now() - start} ms`); + logger.debug(Messages.get("ExecutionTimePlugin.executionTime", this.id, (performance.now() - start).toString())); return res; } catch (e) { logger.debug(e); diff --git a/common/lib/utils/locales/en.json b/common/lib/utils/locales/en.json index 4816d151..87cd80f5 100644 --- a/common/lib/utils/locales/en.json +++ b/common/lib/utils/locales/en.json @@ -34,5 +34,5 @@ "ClusterAwareWriterFailoverHandler.standaloneNode": "[TaskB] Host %s is not yet connected to a cluster. The cluster is still being reconfigured.", "ClusterAwareWriterFailoverHandler.taskBAttemptConnectionToNewWriter": "[TaskB] Trying to connect to a new writer: '%s'", "ClusterAwareWriterFailoverHandler.alreadyWriter": "Current reader connection is actually a new writer connection.", - "ExecutionTimePlugin.executionTime": "Executed %s in %s nanoseconds." + "ExecutionTimePlugin.executionTime": "Executed %s in %s milliseconds." } diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 7ab90acf..92f49166 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -21,44 +21,27 @@ import { Writable } from "stream"; import winston from "winston"; const mockCallable = jest.fn(); +const timeToSleepMs = 1000; describe("executionTimePluginTest", () => { it("test_executeTime", async () => { - mockCallable.mockImplementation(() => { - sleep(10); - return null; - }); - - const plugin = new ExecutionTimePlugin(); - - // Create stream - let output = ''; - const stream = new Writable(); - stream._write = (chunk, encoding, next) => { - output = output += chunk.toString(); - next(); - }; - - const streamTransport = new winston.transports.Stream({ stream }); - logger.add(streamTransport); - logger.level = "debug"; - - // Temporarily suppress console logging - logger.transports[0].silent = true; - - await plugin.execute("query", mockCallable, []); + mockCallable.mockImplementation(async () => { + await sleep(timeToSleepMs); + return null; + }); + + const plugin = new ExecutionTimePlugin(); - logger.transports[0].silent = false; - logger.remove(streamTransport); + await plugin.execute("query", mockCallable, []); - const logMessages = output.trim().split('\n'); + // Convert ms to ns + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepMs * 1000000); - const matches = logMessages.filter(str => str.includes("Executed query in")).length; - expect(matches).toBeGreaterThan(0); + await plugin.execute("query", mockCallable, []); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(0n); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepMs * 1000000 * 2); - ExecutionTimePlugin.resetExecutionTime(); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); + ExecutionTimePlugin.resetExecutionTime(); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); }); }); From df2f813e1828b8d77cefff6a9efae956b1377d04 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Thu, 4 Apr 2024 16:30:58 -0700 Subject: [PATCH 10/12] remove imports --- tests/unit/execution_time_plugin.test.ts | 3 --- 1 file changed, 3 deletions(-) diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 92f49166..784f53ed 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -16,9 +16,6 @@ import { ExecutionTimePlugin } from "aws-wrapper-common-lib/lib/plugins/execution_time_plugin"; import { sleep } from "aws-wrapper-common-lib/lib/utils/utils"; -import { logger } from "aws-wrapper-common-lib/logutils"; -import { Writable } from "stream"; -import winston from "winston"; const mockCallable = jest.fn(); const timeToSleepMs = 1000; From fb6e2fe4f9dfb881fefe4e0cf0fabdf5f412a131 Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Fri, 5 Apr 2024 16:37:33 -0700 Subject: [PATCH 11/12] review changes --- common/lib/plugins/default_plugin.ts | 5 +--- common/lib/plugins/execution_time_plugin.ts | 4 +-- .../lib/plugins/failover/failover_plugin.ts | 5 +--- tests/unit/execution_time_plugin.test.ts | 26 +++++++++---------- 4 files changed, 17 insertions(+), 23 deletions(-) diff --git a/common/lib/plugins/default_plugin.ts b/common/lib/plugins/default_plugin.ts index be29d61a..16cf833c 100644 --- a/common/lib/plugins/default_plugin.ts +++ b/common/lib/plugins/default_plugin.ts @@ -49,9 +49,6 @@ export class DefaultPlugin extends AbstractConnectionPlugin { override execute(methodName: string, methodFunc: () => Type): Type { logger.debug(Messages.get("DefaultPlugin.executingMethod", methodName)); - const start = performance.now(); - const res = methodFunc(); - logger.debug(Messages.get("ExecutionTimePlugin.executionTime", this.id, (performance.now() - start).toString())); - return res; + return methodFunc(); } } diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execution_time_plugin.ts index b69acd85..1d2f974f 100644 --- a/common/lib/plugins/execution_time_plugin.ts +++ b/common/lib/plugins/execution_time_plugin.ts @@ -25,7 +25,7 @@ import { getTimeInNanos } from "../utils/utils"; export class ExecutionTimePlugin extends AbstractConnectionPlugin { private static readonly subscribedMethods: Set = new Set(["*"]); private static executionTime: bigint = 0n; - + public override getSubscribedMethods(): Set { return ExecutionTimePlugin.subscribedMethods; } @@ -36,7 +36,7 @@ export class ExecutionTimePlugin extends AbstractConnectionPlugin { const result = await methodFunc(); const elapsedTimeNanos = getTimeInNanos() - startTime; - + // Convert from ns to ms logger.debug(Messages.get("ExecutionTimePlugin.executionTime", methodName, (elapsedTimeNanos / 1000000n).toString())); ExecutionTimePlugin.executionTime += elapsedTimeNanos; diff --git a/common/lib/plugins/failover/failover_plugin.ts b/common/lib/plugins/failover/failover_plugin.ts index 2a7fc3e6..67e32be3 100644 --- a/common/lib/plugins/failover/failover_plugin.ts +++ b/common/lib/plugins/failover/failover_plugin.ts @@ -98,13 +98,10 @@ export class FailoverPlugin extends AbstractConnectionPlugin { override async execute(methodName: string, methodFunc: () => Promise): Promise { try { - const start = performance.now(); if (this.canUpdateTopology(methodName)) { await this.updateTopology(false); } - const res = methodFunc(); - logger.debug(Messages.get("ExecutionTimePlugin.executionTime", this.id, (performance.now() - start).toString())); - return res; + return methodFunc(); } catch (e) { logger.debug(e); throw e; diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execution_time_plugin.test.ts index 784f53ed..28a784b8 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execution_time_plugin.test.ts @@ -19,26 +19,26 @@ import { sleep } from "aws-wrapper-common-lib/lib/utils/utils"; const mockCallable = jest.fn(); const timeToSleepMs = 1000; +const timeToSleepNs = timeToSleepMs * 1000000; describe("executionTimePluginTest", () => { it("test_executeTime", async () => { - mockCallable.mockImplementation(async () => { - await sleep(timeToSleepMs); - return null; - }); - - const plugin = new ExecutionTimePlugin(); + mockCallable.mockImplementation(async () => { + await sleep(timeToSleepMs); + return null; + }); + + const plugin = new ExecutionTimePlugin(); - await plugin.execute("query", mockCallable, []); + await plugin.execute("query", mockCallable, []); - // Convert ms to ns - expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepMs * 1000000); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepNs); - await plugin.execute("query", mockCallable, []); + await plugin.execute("query", mockCallable, []); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepMs * 1000000 * 2); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepNs * 2); - ExecutionTimePlugin.resetExecutionTime(); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); + ExecutionTimePlugin.resetExecutionTime(); + expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); }); }); From 22ea7ac954e4440c266c0015448b08634a5bf73b Mon Sep 17 00:00:00 2001 From: jasonlamz Date: Mon, 8 Apr 2024 13:21:23 -0700 Subject: [PATCH 12/12] review changes --- common/lib/connection_plugin_chain_builder.ts | 4 ++-- ..._time_plugin.ts => execute_time_plugin.ts} | 22 +++++++++---------- common/lib/utils/locales/en.json | 2 +- ...in.test.ts => execute_time_plugin.test.ts} | 14 ++++++------ 4 files changed, 21 insertions(+), 21 deletions(-) rename common/lib/plugins/{execution_time_plugin.ts => execute_time_plugin.ts} (70%) rename tests/unit/{execution_time_plugin.test.ts => execute_time_plugin.test.ts} (68%) diff --git a/common/lib/connection_plugin_chain_builder.ts b/common/lib/connection_plugin_chain_builder.ts index f067627f..16d8c8de 100644 --- a/common/lib/connection_plugin_chain_builder.ts +++ b/common/lib/connection_plugin_chain_builder.ts @@ -22,7 +22,7 @@ import { WrapperProperties } from "./wrapper_property"; import { AwsWrapperError } from "./utils/aws_wrapper_error"; import { Messages } from "./utils/messages"; import { DefaultPlugin } from "./plugins/default_plugin"; -import { ExecutionTimePluginFactory } from './plugins/execution_time_plugin'; +import { ExecuteTimePluginFactory } from "./plugins/execute_time_plugin"; export class PluginFactoryInfo {} @@ -35,7 +35,7 @@ export class ConnectionPluginChainBuilder { static readonly PLUGIN_FACTORIES = new Map([ ["iam", IamAuthenticationPluginFactory], ["failover", FailoverPluginFactory], - ["executionTime", ExecutionTimePluginFactory] + ["executeTime", ExecuteTimePluginFactory] ]); getPlugins(pluginService: PluginService, props: Map): ConnectionPlugin[] { diff --git a/common/lib/plugins/execution_time_plugin.ts b/common/lib/plugins/execute_time_plugin.ts similarity index 70% rename from common/lib/plugins/execution_time_plugin.ts rename to common/lib/plugins/execute_time_plugin.ts index 1d2f974f..4e2e77b3 100644 --- a/common/lib/plugins/execution_time_plugin.ts +++ b/common/lib/plugins/execute_time_plugin.ts @@ -22,12 +22,12 @@ import { PluginService } from "../plugin_service"; import { Messages } from "../utils/messages"; import { getTimeInNanos } from "../utils/utils"; -export class ExecutionTimePlugin extends AbstractConnectionPlugin { +export class ExecuteTimePlugin extends AbstractConnectionPlugin { private static readonly subscribedMethods: Set = new Set(["*"]); - private static executionTime: bigint = 0n; + private static executeTime: bigint = 0n; public override getSubscribedMethods(): Set { - return ExecutionTimePlugin.subscribedMethods; + return ExecuteTimePlugin.subscribedMethods; } public override async execute(methodName: string, methodFunc: () => Promise, methodArgs: any[]): Promise { @@ -38,22 +38,22 @@ export class ExecutionTimePlugin extends AbstractConnectionPlugin { const elapsedTimeNanos = getTimeInNanos() - startTime; // Convert from ns to ms - logger.debug(Messages.get("ExecutionTimePlugin.executionTime", methodName, (elapsedTimeNanos / 1000000n).toString())); - ExecutionTimePlugin.executionTime += elapsedTimeNanos; + logger.debug(Messages.get("ExecuteTimePlugin.executeTime", methodName, (elapsedTimeNanos / 1000000n).toString())); + ExecuteTimePlugin.executeTime += elapsedTimeNanos; return result; } - public static resetExecutionTime(): void { - ExecutionTimePlugin.executionTime = 0n; + public static resetExecuteTime(): void { + ExecuteTimePlugin.executeTime = 0n; } - public static getTotalExecutionTime(): bigint { - return ExecutionTimePlugin.executionTime; + public static getTotalExecuteTime(): bigint { + return ExecuteTimePlugin.executeTime; } } -export class ExecutionTimePluginFactory implements ConnectionPluginFactory { +export class ExecuteTimePluginFactory implements ConnectionPluginFactory { getInstance(pluginService: PluginService, properties: Map): ConnectionPlugin { - return new ExecutionTimePlugin(); + return new ExecuteTimePlugin(); } } diff --git a/common/lib/utils/locales/en.json b/common/lib/utils/locales/en.json index 87cd80f5..ac895adc 100644 --- a/common/lib/utils/locales/en.json +++ b/common/lib/utils/locales/en.json @@ -34,5 +34,5 @@ "ClusterAwareWriterFailoverHandler.standaloneNode": "[TaskB] Host %s is not yet connected to a cluster. The cluster is still being reconfigured.", "ClusterAwareWriterFailoverHandler.taskBAttemptConnectionToNewWriter": "[TaskB] Trying to connect to a new writer: '%s'", "ClusterAwareWriterFailoverHandler.alreadyWriter": "Current reader connection is actually a new writer connection.", - "ExecutionTimePlugin.executionTime": "Executed %s in %s milliseconds." + "ExecuteTimePlugin.executeTime": "Executed method '%s' in %s milliseconds." } diff --git a/tests/unit/execution_time_plugin.test.ts b/tests/unit/execute_time_plugin.test.ts similarity index 68% rename from tests/unit/execution_time_plugin.test.ts rename to tests/unit/execute_time_plugin.test.ts index 28a784b8..a77d7978 100644 --- a/tests/unit/execution_time_plugin.test.ts +++ b/tests/unit/execute_time_plugin.test.ts @@ -14,31 +14,31 @@ limitations under the License. */ -import { ExecutionTimePlugin } from "aws-wrapper-common-lib/lib/plugins/execution_time_plugin"; +import { ExecuteTimePlugin } from "aws-wrapper-common-lib/lib/plugins/execute_time_plugin"; import { sleep } from "aws-wrapper-common-lib/lib/utils/utils"; const mockCallable = jest.fn(); const timeToSleepMs = 1000; const timeToSleepNs = timeToSleepMs * 1000000; -describe("executionTimePluginTest", () => { +describe("executeTimePluginTest", () => { it("test_executeTime", async () => { mockCallable.mockImplementation(async () => { await sleep(timeToSleepMs); return null; }); - const plugin = new ExecutionTimePlugin(); + const plugin = new ExecuteTimePlugin(); await plugin.execute("query", mockCallable, []); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepNs); + expect(ExecuteTimePlugin.getTotalExecuteTime()).toBeGreaterThan(timeToSleepNs); await plugin.execute("query", mockCallable, []); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toBeGreaterThan(timeToSleepNs * 2); + expect(ExecuteTimePlugin.getTotalExecuteTime()).toBeGreaterThan(timeToSleepNs * 2); - ExecutionTimePlugin.resetExecutionTime(); - expect(ExecutionTimePlugin.getTotalExecutionTime()).toEqual(0n); + ExecuteTimePlugin.resetExecuteTime(); + expect(ExecuteTimePlugin.getTotalExecuteTime()).toEqual(0n); }); });