feat: added tracing implementation

.gitignore

@@ -41,3 +41,4 @@ coverage/
 
 # Notes file
 _notes.txt
+.private

README.md

@@ -16,14 +16,15 @@ It is written in [TypeScript](https://www.typescriptlang.org/) and comes with mi
   - [Add eimer.js to the Preload Script](#add-eimerjs-to-the-preload-script)
   - [Add eimer.js to the Browser Window](#add-eimerjs-to-the-browser-window)
   - [Build Process Considerations](#build-process-considerations)
+- [Tracing](#tracing)
 - [Limitations](#limitations)
 - [Authors](#authors)
 - [License](#license)
 
 ## What problem(s) does it solve?
 Even simple Electron applications are naturally [split into two different processes](https://www.electronjs.org/docs/latest/tutorial/process-model) (main and renderer), which have to be linked through a "preload script". Exchanging data and calling functions across these process boundaries is already non-trivial and the [interfaces provided by Electron](https://www.electronjs.org/docs/latest/tutorial/ipc) make it difficult to keep a growing code base maintainable.
 
-As applications grow in functionality and complexity, even more processes become involved - [multiple windows](https://www.electronjs.org/docs/latest/api/base-window) on the rendering side, each potentially with [web workers](https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API) or iframes and the main process can start [worker threads](https://nodejs.org/api/worker_threads.html) or spawn [utility processes](https://www.electronjs.org/docs/latest/api/utility-process) which themselves can spawn more processes and threads.
+As applications grow in functionality and complexity, even more processes become involved - [multiple windows](https://www.electronjs.org/docs/latest/api/base-window) on the rendering side, each potentially with [web workers](https://developer.mozilla.org/en-US/docs/Web/API/Web_Workers_API) or iframes; and the main process can start [worker threads](https://nodejs.org/api/worker_threads.html) or spawn [utility processes](https://www.electronjs.org/docs/latest/api/utility-process), which themselves can spawn more processes and threads.
 
 All of the different process-like concepts in Electron have slightly different APIs for inter-process communication and while [MessagePorts](https://www.electronjs.org/docs/latest/tutorial/message-ports) can be used to unify these concepts, even these are limited to point-to-point communication between at most *two* processes at a time.
 
@@ -37,7 +38,7 @@ All of the different process-like concepts in Electron have slightly different A
 ## Getting Started
 We'll assume that you already have an Electron.js project that is written in TypeScript and it can be compiled / started.
 
-If not, check out the [examples](./examples) directory! It also contains examples that show how to implement a [basic counter](./examples/basic-counter/) with RPC and publish/subscribe and how to extend that to [multiple windows](./examples/multi-window/) or [worker threads](./examples/worker-thread/).
+If not, check out the [`examples`](./examples) directory! It also contains examples that show how to implement a [basic counter](./examples/basic-counter/) with RPC and publish/subscribe and how to extend that to [multiple windows](./examples/multi-window/) or [worker threads](./examples/worker-thread/).
 
 ### Install eimer.js
 ```shell
@@ -73,7 +74,7 @@ app.whenReady().then(() => {
 ### Add eimer.js to the *Preload Script*
 The purpose of the [Preload Script](https://www.electronjs.org/docs/latest/tutorial/tutorial-preload) is to set up communication between the main process and the "browser" window, without exposing too many APIs of the main process in the browser context.
 
-We set up another instance of eimer.js in the preload script, which simply forwards messages. It uses Electron's [ipcRenderer](https://www.electronjs.org/docs/latest/api/ipc-renderer) to communicate with the main process and [window.postMessage](https://developer.mozilla.org/en-US/docs/Web/API/Window/postMessage) to communicate with the  browser window.
+We set up another instance of eimer.js in the preload script, which simply forwards messages. It uses Electron's [ipcRenderer](https://www.electronjs.org/docs/latest/api/ipc-renderer) to communicate with the main process and [window.postMessage](https://developer.mozilla.org/en-US/docs/Web/API/Window/postMessage) to communicate with the browser window.
 ```typescript
 import { ipcRenderer } from 'electron';
 import { Eimer, EimerIpcRendererTransport, EimerBrowserTransport } from 'eimer';
@@ -95,14 +96,14 @@ eimer.callRpc<string>('hello').then(value => { console.log('hello ' + value) });
 ```
 
 ### Build Process Considerations
-* The Preload Script as well as the Renderer / Browser Code run inside separate browser environments and need to be separately compiled and bundled with the eimer.js library.
+* The Preload Script as well as the Renderer / Browser Code runs inside separate browser environments and needs to be separately compiled and bundled with the eimer.js library.
   * This is not specific to eimer.js but a general pitfall of Electron Applications
 * You can add extra build scripts to the `package.json` that rely on esbuild (`npm install esbuild`)
   ```json
   "scripts": {
       "build": "tsc && npm run build:preload && npm run build:renderer",
       "build:preload": "esbuild src/preload.ts --bundle --outfile=dist/preload.js --external:electron",
-      "build:renderer": "esbuild src/renderer.ts --bundle --outfile=dist/renderer.js",
+      "build:renderer": "esbuild src/renderer.ts --bundle --outfile=dist/renderer.js"
   }
   ```
 * Be sure to call the `npm run build:preload` and the `npm run build:renderer` scripts in your build process!
@@ -112,12 +113,17 @@ eimer.callRpc<string>('hello').then(value => { console.log('hello ' + value) });
   * `--format=cjs`
 * Check out the [examples](./examples) directory for complete projects including build configurations.
 
+## Tracing
+* eimer.js supports forwarding of tracing information
+* It ships with tooling to collect distributed tracing information across an application's entire process tree
+* For details and more info, see [docs/TRACING](docs/TRACING.md)
+
 ## Limitations
 This library is in pre-beta stage.
 
 Existing functionality mostly works and is well tested. However, performance is not optimized at all
 (for example, all messages are broadcast to all connected processes, the ids of all messages ever sent
-is kept in memory indefinitely) and features are limited (security and extensibility need improvement).
+are kept in memory indefinitely) and features are limited (security and extensibility need improvement).
 
 Also the documentation is lacking.
 

docs/TRACING.md

@@ -0,0 +1,70 @@
+# Tracing
+eimer.js makes it easy to integrate functionality that is spread out across multiple processes into a single application. One thing that becomes harder with this distributed nature of an application is keeping track of performance.
+When you click a button in a window that triggers work in a background process, how can you keep track of what work in the background process belonged to which button click?
+
+This problem is similar to how you would *trace* performance in a distributed microservices environment, consisting of multiple frontend and backend services that communicate with each other over a network.
+
+In distributed microservices, this problem is solved by **distributed tracing**. In its simplest form, the process or service that initiates an operation assigns it a *trace id* and passes it along with all calls that are part of that root-level operation. Each service that receives a call with a trace id can then measure how long it took to complete this operation and log this info, together with the trace id to some storage location. To make evaluation easier and more granular, these individual measurements of sub-operations are called *spans*. When the topology gets more complex, sub-operations themselves can have sub-operations, meaning spans can have sub-spans. This forms a tree, so it makes sense to store the *parent span* of every span.
+
+## Distributed tracing
+eimer.js takes that same approach and applies it to Inter-Process-Communication. You can attach a `traceId` and a `spanId` to every message and this info is forwarded across the entire eimer.js "network" of processes.
+
+You can then access this info via the `meta` parameter in your message handler and use it with whatever tracing approach you are taking.
+```typescript
+eimer.callRpc('rpc-method', {}, 1_000, { trace: { traceId: 'a-b-c-d', spanId: '1-2-3-4' } })
+```
+
+```typescript
+eimer.registerRpcHandler('rpc-method', async (_params, meta) => {
+    console.log(meta.trace.traceId, meta.trace.spanId);
+});
+```
+
+## Tracing eimer itself
+If you are already curious about the performance of your application and you instrument it with tracing, you are probably also curious about how much eimer itself affects this performance. And because eimer.js knows what a `traceId` and a `spanId` is, it can inject new spans around its own expensive operations relatively easily.
+
+Just add the `collectEimerTraces` flag to your metadata when making a call. Note that you must also specify a traceId and spanId.
+```typescript
+eimer.callRpc('rpc-method', {}, 1_000, { trace: { traceId: 'a-b-c-d', spanId: '1-2-3-4' }, collectEimerTraces: true });
+```
+To make this work end-to-end, every eimer.js node in your application must be able to *create new spans*. It does that through a `tracer` dependency that must fulfill the [`Tracer`](../src/eimer/Tracer.ts) interface contract. eimer.js provides a reference implementation, [`EimerTracer`](../src/tracing/EimerTracer.ts) that demonstrates how to do that but can also directly be used in real applications:
+```typescript
+const tracer = new EimerTracer();
+const eimer = new Eimer('node-name', {}, { tracer });
+```
+By default, `EimerTracer` just keeps spans in memory. And they are more useful if they are *logged* somewhere. A `Tracer` hands this off to a [`TracerBackend`](../src/eimer/TracerBackend.ts) to keep things composable. And because eimer.js already ships a [`Logger`](../src/eimer/Logger.ts) interface contract for logging with a reference implementation of [`EimerLogger`](../src/logger/EimerLogger.ts), it provides a reference `TracerBackend` that uses `EimerLogger` with [`EimerLoggerTracerBackend`](../src/tracing/EimerLoggerTracerBackend.ts).
+```typescript
+const tracer = new EimerTracer(new EimerLoggerTracerBackend());
+const eimer = new Eimer('node-name', {}, { tracer });
+```
+This setup will log all spans to the console as soon as they are completed. They include the *trace id*, *span id*, *parent span id* and measured *duration*. For a full list, see the [`TraceSpan`](../src/eimer/TraceSpan.ts) interface.
+
+## Collecting Traces
+Logging every trace to the console is nice. But if your application has exactly the distributed multi-process setup that eimer.js makes so easy to use, it's a bit annoying to collect your traces from the console outputs of different windows or processes.
+
+Wouldn't it be cool to collect them in one central place?
+
+Fortunately, eimer.js is the perfect tool to do just that. And we only need to make 2 changes to the setup we already introduced.
+
+1. A `TracerBackend` that sends traces across the eimer network instead of logging it to the console
+2. A `Subscriber` that collects all traces from the network and then logs them to the console.
+
+eimer.js ships with both.
+
+First, use the [`EimerPublishingTracerBackend`](../src/tracing/EimerPublishingTracerBackend.ts) to send all collected traces across eimer:
+```typescript
+const tracer = new EimerTracer();
+const eimer = new Eimer('node-name', {}, { tracer });
+tracer.setBackend(new EimerPublishingTracerBackend(eimer));
+```
+(note that the `EimerPublishingTracerBackend` needs a reference to an Eimer node itself, so we have to call `setBackend` *after* the Eimer object has been instantiated)
+
+Second, use [`EimerTraceSubscriber`](../src/tracing/EimerTraceSubscriber.ts) to collect the traces again. It supports any other `TracerBackend` to handle them.
+```typescript
+const traceSubscriber = new EimerTraceSubscriber(eimer, new ConsoleLoggingTracerBackend());
+```
+
+The most convenient approach for this is to use the [`ConsoleLoggingTracerBackend`](../src/tracing/ConsoleLoggingTracerBackend.ts) in the renderer process - it `console.log`s the traces as nested groups into the Developer Tool's Console.
+
+## Example
+You can find an example application that illustrates all of these concepts in [`examples/tracing`](../examples/tracing/). Check the [`README.md`](../examples/README.md) in the examples directory for how to use it.

examples/README.md

@@ -141,7 +141,7 @@ const worker = new Worker(__dirname + '/worker');
 eimer.connect(new EimerWorkerThreadTransport(worker));
 ```
 
-Then, we create a [`worker.ts`](./worker-thread/worker.ts) where we paste the counter code we removed from main.ts. The only thing left is to connect the worker thread to an instance of [`Eimer`](../src/eimer/Eimer.ts). For that, we use an [`EimerMessagePortTransport`](../src/transports/EimerMessagePortTransport.ts) with the `parentPort` of our worker thread:
+Then, we create a [`worker.ts`](./worker-thread/src/worker.ts) where we paste the counter code we removed from main.ts. The only thing left is to connect the worker thread to an instance of [`Eimer`](../src/eimer/Eimer.ts). For that, we use an [`EimerMessagePortTransport`](../src/transports/EimerMessagePortTransport.ts) with the `parentPort` of our worker thread:
 ```typescript
 const eimer = new Eimer('worker');
 eimer.connect(new EimerMessagePortTransport(parentPort as MessagePort));
@@ -152,3 +152,57 @@ npm ci
 npm run dev
 ```
 The familiar window with the counter and `+` and `-` buttons should open. Clicking the buttons works as before, but you can notice in the CLI console output that the counter state and logic are handled by the worker thread.
+
+
+## Tracing
+To trace how different parts of the application perform, eimer.js provides multiple tools for distributed tracing.
+
+Check out [docs/TRACING.md](../docs/TRACING.md) for more details.
+
+How to use them is demonstrated in the [`tracing`](./tracing/) example, which builds on the worker-thread example.
+
+First of all, we simulate "expensive" operations by randomly sleeping inside [`worker.ts`](./tracing/src/worker.ts):
+```typescript
+const sleep = async (ms:number) => {
+  return new Promise((resolve, _reject) => {
+    setTimeout(resolve, ms);
+  })
+};
+
+await sleep(Math.round(Math.random() * 100));
+```
+
+And then, we measure how long we actually slept by instrumenting these sleep calls with `EimerTracer`:
+```typescript
+const trace = tracer.startSpan('expensive decrement operation', {}, meta.trace);
+await sleep(Math.round(Math.random() * 100));
+tracer.endSpan(trace.spanId);
+```
+Inside the worker, we attach this trace information to a parent trace we receive over eimer - and the *root* trace is started inside [`renderer.ts`](./tracing/src/renderer.ts):
+```typescript
+const trace = tracer.startSpan('counter.decrement');
+await eimer.callRpc('counter.decrement', {}, 30_000, { trace });
+```
+
+We do this in both the *increment* as well as the *decrement* operation.
+
+To make it all work, we add a `Tracer` that uses `EimerPublishingTracerBackend` to send collected traces across eimer to *all* of our processes:
+```typescript
+const tracer = new EimerTracer();
+const eimer = new Eimer('renderer|preload|main|worker', {}, { tracer });
+tracer.setBackend(new EimerPublishingTracerBackend(eimer));
+```
+And back in [`renderer.ts`](./tracing/src/renderer.ts), we place an `EimerTraceSubscriber` that prints traces as nested `console.log` groups to the developer tools console:
+```typescript
+const traceSubscriber = new EimerTraceSubscriber(eimer, new ConsoleLoggingTracerBackend());
+```
+
+The decrement operation simply collects a trace for the entire operation as well as the simulated sleep inside the worker. The increment operation also tells eimer to collect traces about itself, so the trace will be much more detailed.
+```typescript
+await eimer.callRpc('counter.increment', {}, 30_000, { trace, collectEimerTraces: true });
+```
+You can run the example by executing the following commands in [`tracing`](./tracing/):
+```shell
+npm ci
+npm run dev
+```