diff --git a/bun.lockb b/bun.lockb index a221f10..2d8e18c 100755 Binary files a/bun.lockb and b/bun.lockb differ diff --git a/bunfig.toml b/bunfig.toml index 119113b..5c38fc6 100644 --- a/bunfig.toml +++ b/bunfig.toml @@ -1,4 +1,4 @@ [test] - # always enable coverage -coverage = true \ No newline at end of file +coverage = true + diff --git a/package.json b/package.json index ba3d809..cc7dc1d 100644 --- a/package.json +++ b/package.json @@ -15,8 +15,20 @@ "typescript": "^5.0.0" }, "dependencies": { + "@opentelemetry/api": "^1.9.0", + "@opentelemetry/auto-instrumentations-node": "^0.47.0", + "@opentelemetry/exporter-logs-otlp-http": "^0.52.0", + "@opentelemetry/exporter-metrics-otlp-http": "^0.52.0", + "@opentelemetry/instrumentation-express": "^0.40.1", + "@opentelemetry/instrumentation-http": "^0.52.0", + "@opentelemetry/instrumentation-winston": "^0.38.0", + "@opentelemetry/sdk-metrics": "^1.25.0", + "@opentelemetry/sdk-node": "^0.52.0", + "@opentelemetry/sdk-trace-node": "^1.25.0", + "@opentelemetry/winston-transport": "^0.4.0", "env-var": "^7.5.0", - "express": "^4.19.2" + "express": "^4.19.2", + "winston": "^3.13.0" }, "scripts": { "prepare": "if test \"$NODE_ENV\" != \"production\" ; then husky ; fi" diff --git a/src/app.ts b/src/app.ts index e8ae60b..0dceebf 100644 --- a/src/app.ts +++ b/src/app.ts @@ -1,19 +1,37 @@ -import express from "express"; +import express, { Router } from "express"; import { config } from "./init/config"; +import { initOtel } from "./init/otel"; +import { getLogger } from "./init/logger"; +import { getOTELMiddleware, getRequestErrorHandler } from "./middleware"; +import { getReqMetrics } from "./init/metrics"; export const app = express(); -app.get("/", (req, res) => { - res.send("Hello World!"); -}); +export function start() { + initOtel(); + const logger = getLogger(); + const reqMetrics = getReqMetrics(); -app.get("/metadata", (req, res) => { - res.json({ - gitSHA: config.gitSHA, + const router = Router(); + router.use(getOTELMiddleware(logger, reqMetrics)); + router.get("/", (req, res) => { + res.send("Hello World!"); }); -}); -export function start() { + router.get("/metadata/:id", (req, res) => { + res.status(200).json({ + gitSHA: config.gitSHA, + }); + }); + + router.get("/error", (req, res, next) => { + next(new Error("This is a test error")); + }); + + router.use(getRequestErrorHandler(logger)); + + app.use("/", router); + app.listen(config.port, () => { console.log(`Server is running on port ${config.port}`); }); diff --git a/src/init/logger.ts b/src/init/logger.ts new file mode 100644 index 0000000..da612e6 --- /dev/null +++ b/src/init/logger.ts @@ -0,0 +1,8 @@ +import { createLogger } from "winston"; +import { OpenTelemetryTransportV3 } from "@opentelemetry/winston-transport"; + +export function getLogger() { + return createLogger({ + transports: [new OpenTelemetryTransportV3()], + }); +} diff --git a/src/init/metrics.ts b/src/init/metrics.ts new file mode 100644 index 0000000..cce14b0 --- /dev/null +++ b/src/init/metrics.ts @@ -0,0 +1,16 @@ +import { metrics, type Counter, type UpDownCounter } from "@opentelemetry/api"; + +export interface RequestMetrics { + totalRequestsCounter: Counter; + totalErrorsCounter: Counter; + inProgressRequestsGauge: UpDownCounter; +} + +export function getReqMetrics(): RequestMetrics { + const meter = metrics.getMeter("request"); + return { + totalRequestsCounter: meter.createCounter("requests.total"), + totalErrorsCounter: meter.createCounter("requests.errors"), + inProgressRequestsGauge: meter.createUpDownCounter("requests.in_progress"), + }; +} diff --git a/src/init/otel/index.ts b/src/init/otel/index.ts new file mode 100644 index 0000000..71a5a01 --- /dev/null +++ b/src/init/otel/index.ts @@ -0,0 +1,47 @@ +import { Resource } from "@opentelemetry/resources"; +import os from "os"; +import { + SEMRESATTRS_SERVICE_NAME, + SEMRESATTRS_DEPLOYMENT_ENVIRONMENT, + SEMRESATTRS_HOST_NAME, + SEMRESATTRS_HOST_ARCH, + SEMRESATTRS_SERVICE_VERSION, + SEMRESATTRS_PROCESS_PID, + SEMRESATTRS_PROCESS_EXECUTABLE_NAME, + SEMRESATTRS_PROCESS_EXECUTABLE_PATH, + SEMRESATTRS_PROCESS_COMMAND_ARGS, + SEMRESATTRS_PROCESS_RUNTIME_VERSION, + SEMRESATTRS_PROCESS_RUNTIME_NAME, + SEMRESATTRS_PROCESS_RUNTIME_DESCRIPTION, + SEMRESATTRS_PROCESS_COMMAND, + SEMRESATTRS_PROCESS_OWNER, +} from "@opentelemetry/semantic-conventions"; +import { initLogging } from "./logs"; +import { initMetrics } from "./metrics"; +import { initTracing } from "./traces"; + +const resource = Resource.default().merge( + new Resource({ + [SEMRESATTRS_SERVICE_NAME]: process.env.SERVICE_NAME, + [SEMRESATTRS_DEPLOYMENT_ENVIRONMENT]: process.env.DEPLOYMENT_ENVIRONMENT, + [SEMRESATTRS_HOST_NAME]: os.hostname(), + [SEMRESATTRS_HOST_ARCH]: os.arch(), + [SEMRESATTRS_SERVICE_VERSION]: process.env.GIT_SHA, + [SEMRESATTRS_PROCESS_PID]: process.pid, + [SEMRESATTRS_PROCESS_EXECUTABLE_NAME]: process.title, + [SEMRESATTRS_PROCESS_EXECUTABLE_PATH]: process.argv[0], + [SEMRESATTRS_PROCESS_COMMAND_ARGS]: process.argv.slice(1), + [SEMRESATTRS_PROCESS_RUNTIME_VERSION]: process.version, + [SEMRESATTRS_PROCESS_RUNTIME_NAME]: "bun", + [SEMRESATTRS_PROCESS_RUNTIME_DESCRIPTION]: + "Node.js compatible runtime for bun.", + [SEMRESATTRS_PROCESS_COMMAND]: process.argv.join(" "), + [SEMRESATTRS_PROCESS_OWNER]: os.userInfo().username, + }), +); + +export function initOtel() { + initLogging(resource); + initMetrics(resource); + initTracing(resource); +} diff --git a/src/init/otel/logs.ts b/src/init/otel/logs.ts new file mode 100644 index 0000000..dd737f4 --- /dev/null +++ b/src/init/otel/logs.ts @@ -0,0 +1,24 @@ +import * as logsAPI from "@opentelemetry/api-logs"; +import { Resource } from "@opentelemetry/resources"; +import { + LoggerProvider, + SimpleLogRecordProcessor, + BatchLogRecordProcessor, + ConsoleLogRecordExporter, +} from "@opentelemetry/sdk-logs"; +import { OTLPLogExporter } from "@opentelemetry/exporter-logs-otlp-http"; + +export function initLogging(resource: Resource) { + const isProduction = process.env.NODE_ENV === "production"; + const loggerProvider = new LoggerProvider({ resource }); + const exporter = isProduction + ? new OTLPLogExporter() + : new ConsoleLogRecordExporter(); + + const processor = isProduction + ? new BatchLogRecordProcessor(exporter) + : new SimpleLogRecordProcessor(exporter); + + loggerProvider.addLogRecordProcessor(processor); + logsAPI.logs.setGlobalLoggerProvider(loggerProvider); +} diff --git a/src/init/otel/metrics.ts b/src/init/otel/metrics.ts new file mode 100644 index 0000000..f7cd17b --- /dev/null +++ b/src/init/otel/metrics.ts @@ -0,0 +1,26 @@ +import opentelemetry from "@opentelemetry/api"; +import { + ConsoleMetricExporter, + MeterProvider, + PeriodicExportingMetricReader, +} from "@opentelemetry/sdk-metrics"; +import { Resource } from "@opentelemetry/resources"; +import { OTLPMetricExporter } from "@opentelemetry/exporter-metrics-otlp-http"; + +export function initMetrics(resource: Resource) { + const isProduction = process.env.NODE_ENV === "production"; + const exporter = isProduction + ? new OTLPMetricExporter() + : new ConsoleMetricExporter(); + + const metricReader = new PeriodicExportingMetricReader({ + exporter, + }); + + const meterProvider = new MeterProvider({ + resource: resource, + readers: [metricReader], + }); + + opentelemetry.metrics.setGlobalMeterProvider(meterProvider); +} diff --git a/src/init/otel/traces.ts b/src/init/otel/traces.ts new file mode 100644 index 0000000..0a55a29 --- /dev/null +++ b/src/init/otel/traces.ts @@ -0,0 +1,23 @@ +import { Resource } from "@opentelemetry/resources"; +import { + SimpleSpanProcessor, + ConsoleSpanExporter, + BatchSpanProcessor, +} from "@opentelemetry/sdk-trace-base"; +import { NodeTracerProvider } from "@opentelemetry/sdk-trace-node"; +import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http"; + +export function initTracing(resource: Resource) { + const traceProvider = new NodeTracerProvider({ resource }); + const isProduction = process.env.NODE_ENV === "production"; + const exporter = isProduction + ? new OTLPTraceExporter() + : new ConsoleSpanExporter(); + + const spanProcessor = isProduction + ? new BatchSpanProcessor(exporter) + : new SimpleSpanProcessor(exporter); + + traceProvider.addSpanProcessor(spanProcessor); + traceProvider.register(); +} diff --git a/src/middleware/errorLogger.ts b/src/middleware/errorLogger.ts new file mode 100644 index 0000000..e76c118 --- /dev/null +++ b/src/middleware/errorLogger.ts @@ -0,0 +1,15 @@ +import type { ErrorRequestHandler } from "express"; +import type { Logger } from "winston"; + +export function getRequestErrorHandler(logger: Logger): ErrorRequestHandler { + return function (err: Error, req, res, next) { + logger.error("request error", { + method: req.method, + path: req.route?.path, + code: 500, + error: err.message, + stackTrace: err.stack, + }); + res.status(500).send("Something broke!"); + }; +} diff --git a/src/middleware/index.ts b/src/middleware/index.ts new file mode 100644 index 0000000..4220bbe --- /dev/null +++ b/src/middleware/index.ts @@ -0,0 +1,2 @@ +export { getRequestErrorHandler } from "./errorLogger"; +export { getOTELMiddleware } from "./otel"; diff --git a/src/middleware/otel/getReqAttributes.ts b/src/middleware/otel/getReqAttributes.ts new file mode 100644 index 0000000..ff30c87 --- /dev/null +++ b/src/middleware/otel/getReqAttributes.ts @@ -0,0 +1,16 @@ +import type { Request } from "express"; +import type { Attributes } from "@opentelemetry/api"; + +export function getReqAttributes(req: Request): Attributes { + return { + "http.method": req.method, + "http.scheme": req.protocol, + "http.host": req.get("host"), + "http.target": req.originalUrl, + "http.user_agent": req.get("user-agent"), + "http.flavor": req.httpVersion, + "http.status_code": req.statusCode, + "http.status_text": req.statusMessage, + "express.matched_route": `${req.method} ${req.route?.path}`, + }; +} diff --git a/src/middleware/otel/index.ts b/src/middleware/otel/index.ts new file mode 100644 index 0000000..c98524f --- /dev/null +++ b/src/middleware/otel/index.ts @@ -0,0 +1,69 @@ +import type { Handler } from "express"; +import type { Span } from "@opentelemetry/api"; +import opentelemetry, { SpanStatusCode } from "@opentelemetry/api"; +import { Logger } from "winston"; +import { getReqAttributes } from "./getReqAttributes"; +import type { RequestMetrics } from "../../init/metrics"; + +export const getOTELMiddleware = ( + logger: Logger, + reqMetrics: RequestMetrics, +): Handler => { + return function (req, res, next) { + const start = process.hrtime(); + const { + totalRequestsCounter, + totalErrorsCounter, + inProgressRequestsGauge, + } = reqMetrics; + const tracer = opentelemetry.trace.getTracer("http-request"); + inProgressRequestsGauge.add(1); + + /** + * start an active span with an empty name. this is because the matched route path is not available on the + * the request object (req.route.path) until the request is fully executed by the route handler. + * we update the span name in the res.on("finish") event listener below. + */ + tracer.startActiveSpan("", (span: Span) => { + /** + * TODO: check if bun runtime's issue with triggering req.on("end") has been resolved. + * this should ideally be req.on("end"). However, bun runtime has issues with triggering the end event. + * the res.on("finish") is being used as a workaround. + */ + res.on("finish", () => { + const [_, timeInNanoSeconds] = process.hrtime(start); + + const method = req.method; + const path = req.route?.path; + const attributes = getReqAttributes(req); + const reqPath = `${method} ${path}`; + span.updateName(reqPath); + totalRequestsCounter.add(1, attributes); + const code = res.statusCode; + if (code >= 500) { + span.setStatus({ code: SpanStatusCode.ERROR }); + totalErrorsCounter.add(1, attributes); + logger.error("request", { + method, + path: req.path, + code, + }); + } else { + span.setStatus({ code: SpanStatusCode.OK }); + logger.info("request", { + method, + path: req.path, + code, + }); + } + + span.setAttributes(attributes); + inProgressRequestsGauge.add(-1); + span.end(); + }); + + // call the next middleware + next(); + }); + }; +};