Isolate benchmarking code because npm run is erroneous and sadly runs other code too

We now have more isolated and more accurate values

```shell
  Benchmarking Database
Total Runs:   20000
Warm up runs: 2500
databaseRunSelect1AsyncAwait
	RAM Untraced(209.906kB) vs Traced     (224.453kB): increase by (14.547kB) or 6.93%
	RAM Untraced(209.906kB) vs Traced+OTEL(243.211kB): increase by (33.305kB) or 15.87%
	Time Untraced(901.139µs) vs Traced     (918.845µs):  increase by (17.706µs) or 1.96%
	Time Untraced(901.139µs) vs Traced+OTEL(1.019ms):  increase by (118.223µs) or 13.12%

databaseRunSelect1Callback
	RAM Untraced(209.789kB) vs Traced     (224.641kB): increase by (14.852kB) or 7.08%
	RAM Untraced(209.789kB) vs Traced+OTEL(242.500kB): increase by (32.711kB) or 15.59%
	Time Untraced(902.862µs) vs Traced     (920.289µs):  increase by (17.427µs) or 1.93%
	Time Untraced(902.862µs) vs Traced+OTEL(1.027ms):  increase by (124.280µs) or 13.77%

databaseRunTransactionAsyncTxRunUpdate
	RAM Untraced(309.352kB) vs Traced     (323.734kB): increase by (14.383kB) or 4.65%
	RAM Untraced(309.352kB) vs Traced+OTEL(324.258kB): increase by (14.906kB) or 4.82%
	Time Untraced(1.508ms) vs Traced     (1.516ms):  increase by (7.340µs) or 0.49%
	Time Untraced(1.508ms) vs Traced+OTEL(1.679ms):  increase by (170.989µs) or 11.34%

databaseRunTransactionAsyncTxRun
	RAM Untraced(299.117kB) vs Traced     (311.320kB): increase by (12.203kB) or 4.08%
	RAM Untraced(299.117kB) vs Traced+OTEL(313.602kB): increase by (14.484kB) or 4.84%
	Time Untraced(1.460ms) vs Traced     (1.469ms):  increase by (8.468µs) or 0.58%
	Time Untraced(1.460ms) vs Traced+OTEL(1.679ms):  increase by (219.068µs) or 15.00%

    ✔ Database runs compared (403854ms)

  Benchmark getTracer
tracerProvider
Total Runs:   20000
Warm up runs: 2500
withNullTracerProviderUnsetGlobalTracerProvider
	RAM (2.273kB)
	TimeSpent (12.171µs)
withTracerDefinedTracerProvider
	RAM (2.695kB)
	TimeSpent (14.074µs)
withTracerRegisteredGlobally
	RAM (2.727kB)
	TimeSpent (14.413µs)
```

Author: odeke-em

observability-test/benchmark.ts observability-benchmark/benchmark.tsobservability-test/benchmark.ts renamed to observability-benchmark/benchmark.ts

@@ -26,7 +26,7 @@ const lessComparator = (a, b) => {
  * a map of functionNames to the percentiles of RAM usage and time spent.
  */
 export async function runBenchmarks(runners: Function[], done: Function) {
-  const nRuns = 10000;
+  const nRuns = 20000;
   const nWarmups = Math.round(nRuns / 8);
   const benchmarkValues = {_totalRuns: nRuns, _warmRuns: nWarmups};
 

observability-test/comparisons.ts observability-benchmark/comparisons.tsobservability-test/comparisons.ts renamed to observability-benchmark/comparisons.ts

@@ -34,8 +34,15 @@ const {
 } = require('@opentelemetry/sdk-trace-node');
 const {SimpleSpanProcessor} = require('@opentelemetry/sdk-trace-base');
 import {humanizeBytes, humanizeTime, runBenchmarks} from './benchmark';
+const {diag, DiagConsoleLogger, DiagLogLevel} = require('@opentelemetry/api');
+// diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.DEBUG);
 
-const {ObservabilityOptions} = require('../src/instrument');
+const {
+  getTracer,
+  startTrace,
+  traceConfig,
+  ObservabilityOptions,
+} = require('../src/instrument');
 
 const selectSql = 'SELECT 1';
 const updateSql = 'UPDATE FOO SET BAR=1 WHERE BAZ=2';
@@ -124,6 +131,16 @@ async function setup(
   });
 }
 
+interface percentiles {
+  p50: number;
+  p50_s: string;
+}
+
+interface description {
+  ram: percentiles;
+  timeSpent: percentiles;
+}
+
 describe('Benchmarking Database', () => {
   if (!process.env.SPANNER_RUN_BENCHMARKS) {
     console.log(
@@ -207,23 +224,6 @@ describe('Benchmarking Database', () => {
         });
       },
 
-      /*
-    async function databaseGetTransactionAsync() {
-      const tx = await database.getTransction();
-
-      try {
-        await tx!.begin();
-        return await tx!.runUpdate(updateSql);
-      } catch (e) {
-	console.log(e);
-        return null;
-      } finally {
-	console.log('tx.end');
-        tx!.end();
-	console.log('exiting');
-      }
-    },
-    */
       async function databaseRunTransactionAsyncTxRunUpdate() {
         const withTx = async tx => {
           await tx!.begin();
@@ -274,16 +274,6 @@ describe('Benchmarking Database', () => {
     });
   }
 
-  interface percentiles {
-    p50: number;
-    p50_s: string;
-  }
-
-  interface description {
-    ram: percentiles;
-    timeSpent: percentiles;
-  }
-
   it('Database runs compared', async () => {
     const traced = await setItUp(true);
     const untraced = await setItUp(false);
@@ -327,3 +317,151 @@ describe('Benchmarking Database', () => {
 function percentDiff(orig, fresh) {
   return ((Number(fresh) - Number(orig)) * 100.0) / Number(orig);
 }
+
+describe('Benchmark getTracer', () => {
+  it('No tracerProvider/global tracerProvider', async () => {
+    console.log('tracerProvider');
+    const results = await benchmarkStartTrace();
+
+    console.log(
+      `Total Runs:   ${results['_totalRuns']}\nWarm up runs: ${results['_warmRuns']}`
+    );
+
+    for (const method in results) {
+      const values = results[method];
+      if (typeof values !== 'object') {
+        continue;
+      }
+      const desc = values as description;
+      const ram = desc.ram;
+      const timeSpent = desc!.timeSpent;
+      console.log(`${method}`);
+      console.log(`\tRAM (${ram.p50_s})`);
+      console.log(`\tTimeSpent (${timeSpent.p50_s})`);
+    }
+  });
+});
+
+function benchmarkGetTracer(): Promise<Map<string, unknown>> {
+  const customTracerProvider = new NodeTracerProvider();
+  let trapDoorCalled = false;
+
+  const runners: Function[] = [
+    function getTracerNullTracerProviderUnsetGlobalTracerProvider() {
+      return getTracer(null);
+    },
+
+    function getTracerDefinedTracerProvider() {
+      return getTracer(customTracerProvider);
+    },
+
+    function getTracerRegisteredGlobally() {
+      if (!trapDoorCalled) {
+        customTracerProvider.register();
+        trapDoorCalled = true;
+      }
+      return getTracer(null);
+    },
+  ];
+
+  return new Promise(resolve => {
+    runBenchmarks(runners, results => {
+      resolve(results);
+    });
+  });
+}
+
+function benchmarkStartSpan(): Promise<Map<string, unknown>> {
+  const customTracerProvider = new NodeTracerProvider();
+  let trapDoorCalled = false;
+
+  const runners: Function[] = [
+    function withNullTracerProviderUnsetGlobalTracerProvider() {
+      return new Promise(resolve => {
+        getTracer(null).startActiveSpan('aSpan', {}, span => {
+          resolve(span);
+        });
+      });
+    },
+
+    function withTracerDefinedTracerProvider() {
+      return new Promise(resolve => {
+        getTracer(customTracerProvider).startActiveSpan('aSpan', {}, span => {
+          resolve(span);
+        });
+      });
+    },
+
+    function getTracerRegisteredGlobally() {
+      if (!trapDoorCalled) {
+        customTracerProvider.register();
+        trapDoorCalled = true;
+      }
+      return new Promise(resolve => {
+        getTracer(null).startActiveSpan('aSpan', {}, span => {
+          resolve(span);
+        });
+      });
+    },
+  ];
+
+  return new Promise(resolve => {
+    runBenchmarks(runners, results => {
+      resolve(results);
+    });
+  });
+}
+
+function benchmarkStartTrace(): Promise<Map<string, unknown>> {
+  const customTracerProvider = new NodeTracerProvider();
+  let trapDoorCalled = false;
+
+  const runners: Function[] = [
+    async function withNullTracerProviderUnsetGlobalTracerProvider() {
+      const promise = new Promise((resolve, reject) => {
+        const opts: typeof traceConfig = {
+          opts: {tracerProvider: null},
+        };
+        startTrace('aspan', null, span => {
+          span.end();
+          resolve(span);
+        });
+      });
+      return promise;
+    },
+
+    function withTracerDefinedTracerProvider() {
+      return new Promise(resolve => {
+        const opts: typeof traceConfig = {
+          opts: {tracerProvider: customTracerProvider},
+        };
+        startTrace('aspan', opts, span => {
+          span.end();
+          resolve(span);
+        });
+      });
+    },
+
+    function withTracerRegisteredGlobally() {
+      if (!trapDoorCalled) {
+        customTracerProvider.register();
+        trapDoorCalled = true;
+      }
+      return new Promise(resolve => {
+        const opts: typeof traceConfig = {
+          opts: {tracerProvider: null},
+        };
+        startTrace('aspan', opts, span => {
+          span.end();
+          resolve(span);
+        });
+      });
+    },
+  ];
+
+  return new Promise(resolve => {
+    runBenchmarks(runners, results => {
+      resolve(results);
+    });
+  });
+}

observability-test/spanner.ts

@@ -45,7 +45,6 @@ const {
   AsyncHooksContextManager,
 } = require('@opentelemetry/context-async-hooks');
 import {promisify} from '@google-cloud/promisify';
-import {runBenchmarks} from './benchmark';
 
 const {ObservabilityOptions} = require('../src/instrument');
 import {SessionPool} from '../src/session-pool';

package.json

@@ -33,6 +33,7 @@
     "samples-test-with-archived": "cd samples/ && npm link ../ && npm test-with-archived && cd ../",
     "samples-test": "cd samples/ && npm link ../ && npm test && cd ../",
     "system-test": "mocha build/system-test --timeout 1600000",
+    "observability-benchmark": "mocha build/observability-benchmark --timeout 1600000",
     "observability-test": "mocha build/observability-test --timeout 1600000",
     "cleanup": "mocha scripts/cleanup.js --timeout 30000",
     "test": "mocha build/test build/test/common build/observability-test",
@@ -43,6 +44,7 @@
     "prepare": "npm run compile-protos && npm run compile",
     "pretest": "npm run compile",
     "presystem-test": "npm run compile",
+    "preobservability-benchmark": "npm run compile",
     "preobservability-test": "npm run compile",
     "proto": "compileProtos src",
     "docs-test": "linkinator docs",

tsconfig.json

@@ -20,6 +20,7 @@
     "test/**/*.ts",
     "system-test/*.ts",
     "benchmark/*.ts",
+    "observability-benchmark/*.ts",
     "observability-test/*.ts"
   ]
 }