Switch to pino logger and add Loki backend

Author: MrTalon63

bun.lock

@@ -20,13 +20,16 @@
 		"typescript": "^5"
 	},
 	"dependencies": {
+		"@bogeychan/elysia-logger": "^0.1.10",
 		"@elysiajs/html": "^1.4.0",
 		"@keyv/redis": "^5.1.6",
 		"elysia": "^1.4.26",
 		"keyv": "^5.6.0",
 		"keyv-file": "^5.3.3",
+		"pino": "^10.3.1",
+		"pino-loki": "^3.0.0",
+		"pino-pretty": "^13.1.3",
 		"prom-client": "^15.1.3",
-		"tle": "^3.0.1",
-		"winston": "^3.19.0"
+		"tle": "^3.0.1"
 	}
 }

package.json

@@ -1,5 +1,6 @@
 import { Elysia } from "elysia";
 import { html } from "@elysiajs/html";
+import { wrap } from "@bogeychan/elysia-logger";
 
 import tleRoute from "./routes/tle";
 import noradRoute from "./routes/norad";
@@ -10,6 +11,7 @@ import config from "./utils/config";
 import log from "./utils/logger";
 
 new Elysia()
+	.use(wrap(log))
 	// Use HTML plugin for rendering the index page
 	.use(html())
 	.get("/styles.css", () => new Response(Bun.file(new URL("./pub/styles.css", import.meta.url)), { headers: { "Content-Type": "text/css" } }))

src/main.ts

@@ -24,26 +24,26 @@ const tleRoute = new Elysia({ prefix: "/tle" })
 		const lastFetchedHeader = new Date(ctx.request.headers.get("If-Modified-Since") || 0).getTime();
 
 		if (lastFetchedHeader && timestamp && lastFetchedHeader <= timestamp && !isStale) {
-			log.info(`TLEs for group "${group}" not modified since last fetch. Returning 304.`);
+			log.debug(`TLEs for group "${group}" not modified since last fetch. Returning 304.`);
 			return new Response(null, { status: 304, headers: { "Last-Modified": new Date(timestamp).toUTCString(), "Cache-Control": `max-age=${group === "active" ? Math.ceil((config.cacheActiveDuration - (now - timestamp)) / 1000) : Math.ceil((config.cacheDuration - (now - timestamp)) / 1000)}` } });
 		}
 
 		let tle = await kv.get(group);
 
 		if (!tle) {
-			log.info(`No cached TLEs for group "${group}". Fetching from Celestrak...`);
+			log.debug(`No cached TLEs for group "${group}". Fetching from Celestrak...`);
 			tle = await tleFetcher(group);
 			timestamp = now;
 			kv.set(group, tle);
 			kv.set(`${group}_timestamp`, timestamp);
 		} else if (isStale) {
-			log.info(`TLEs for group "${group}" are stale. Fetching fresh TLEs...`);
+			log.debug(`TLEs for group "${group}" are stale. Fetching fresh TLEs...`);
 			tle = await tleFetcher(group);
 			timestamp = now;
 			kv.set(group, tle);
 			kv.set(`${group}_timestamp`, timestamp);
 		} else {
-			log.info(`Serving cached TLEs for group "${group}".`);
+			log.debug(`Serving cached TLEs for group "${group}".`);
 		}
 
 		return new Response(tle, {

src/routes/tle.ts

@@ -2,6 +2,10 @@ const config = {
 	allowedGroups: process.env.ALLOWED_GROUPS ? process.env.ALLOWED_GROUPS.split(",").concat("active") : ["active"],
 	logLevel: process.env.LOG_LEVEL || "info",
 	port: process.env.PORT ? parseInt(process.env.PORT) : 3000,
+	redisUri: process.env.REDIS_URI || null,
+	kvFile: process.env.KV_FILE || "./data/kv.json",
+	lokiUri: process.env.LOKI_URI || null,
+	lokiAuth: process.env.LOKI_AUTH || undefined,
 	rateLimitWindow: process.env.RATE_LIMIT_WINDOW ? parseInt(process.env.RATE_LIMIT_WINDOW) * 1000 : 60 * 1000,
 	rateLimitMaxRequests: process.env.RATE_LIMIT_MAX_REQUESTS ? parseInt(process.env.RATE_LIMIT_MAX_REQUESTS) : 60,
 	cacheDuration: process.env.CACHE_DURATION ? parseInt(process.env.CACHE_DURATION) * 1000 : 24 * 60 * 60 * 1000,

src/utils/config.ts

@@ -2,32 +2,33 @@ import Keyv from "keyv";
 import { KeyvFile } from "keyv-file";
 import KeyvRedis from "@keyv/redis";
 
+import config from "./config";
 import log from "./logger";
 
 let kv: Keyv<any>;
 
-if (process.env.REDIS_URI) {
+if (config.redisUri) {
 	log.info("Using Redis for key-value storage.");
 
 	kv = new Keyv({
-		store: new KeyvRedis(process.env.REDIS_URL),
+		store: new KeyvRedis(config.redisUri),
 	});
 
 	kv.on("error", (err) => {
-		log.error(`Keyv Redis error: ${err}`);
+		log.child(err).error("Keyv Redis error:");
 	});
 } else {
 	log.info("Using file-based storage for key-value storage.");
 
 	kv = new Keyv({
 		store: new KeyvFile({
-			filename: process.env.KV_FILE || "./data/kv.json",
+			filename: config.kvFile,
 			writeDelay: 100,
 		}),
 	});
 
 	kv.on("error", (err) => {
-		log.error(`Keyv File error: ${err}`);
+		log.child(err).error("Keyv File error:");
 	});
 }
 

src/utils/kv.ts

@@ -1,17 +1,36 @@
-import winston from "winston";
+import pino from "pino";
 
 import config from "./config";
 
-const log = winston.createLogger({
-	level: config.logLevel,
-	format: winston.format.combine(
-		winston.format.timestamp(),
-		winston.format.colorize(),
-		winston.format.printf(({ timestamp, level, message }) => {
-			return `${timestamp} [${level}]: ${message}`;
-		}),
-	),
-	transports: [new winston.transports.Console()],
-});
+let transport: pino.DestinationStream;
+
+if (config.lokiUri) {
+	transport = pino.transport({
+		target: "pino-loki",
+		options: {
+			host: config.lokiUri,
+			basicAuth: config.lokiAuth,
+			labels: { app: "retlector" },
+			json: true,
+		},
+	});
+} else {
+	transport = pino.transport({
+		target: "pino-pretty",
+		options: {
+			colorize: true,
+			translateTime: "yyyy-mm-dd HH:MM:ss.l o",
+			ignore: "pid,hostname",
+		},
+	});
+}
+
+const log = pino({ level: config.logLevel }, transport);
+
+if (config.lokiUri) {
+	log.info("Logging to Loki at " + config.lokiUri);
+} else {
+	log.info("Logging to console");
+}
 
 export default log;

src/utils/logger.ts

@@ -23,7 +23,7 @@ const limiter = new Elysia({ name: "rate-limiter" }).onRequest(async (ctx) => {
 		if (now - clientInfo.startTime < windowSize) {
 			clientInfo.count++;
 			if (clientInfo.count > maxRequests) {
-				log.info(`Rate limit exceeded for IP ${ip}`);
+				log.debug(`Rate limit exceeded for IP ${ip}`);
 				return new Response("Too Many Requests", {
 					status: 429,
 					headers: {

src/utils/ratelimiter.ts

@@ -5,7 +5,7 @@ import { version } from "../../package.json";
 
 async function fetchTle(group: string) {
 	const url = `https://celestrak.org/NORAD/elements/gp.php?GROUP=${group}&FORMAT=tle`;
-	log.info(`Fetching TLEs for group "${group}" from Celestrak...`);
+	log.debug(`Fetching TLEs for group "${group}" from Celestrak...`);
 	try {
 		const lastFetch = await kv.get(`${group}_timestamp`);
 		const response = await fetch(url, {
@@ -20,10 +20,14 @@ async function fetchTle(group: string) {
 		const tleData = await response.text();
 		await kv.set(group, tleData);
 		await kv.set(`${group}_timestamp`, Date.now());
-		log.info(`Successfully cached TLEs for group "${group}".`);
+		log.debug(`Successfully cached TLEs for group "${group}".`);
 		return tleData;
 	} catch (error) {
-		log.error(`Error fetching TLEs for group "${group}": ${error}`);
+		if (error instanceof Error) {
+			log.child(error).error(`Error fetching TLEs for group "${group}":`);
+		} else {
+			log.error(`Error fetching TLEs for group "${group}": ${error}`);
+		}
 		throw error;
 	}
 }

src/utils/tleFetcher.ts

@@ -45,7 +45,7 @@ async function getObjectsTle(noradId: number) {
 
 	// If we're here then active group doesn't contain the requested NORAD ID, try fetching the TLE directly from Celestrak, but be aware of rate limits so we don't get blocked
 	if (!tleData) {
-		log.verbose(`NORAD ID ${noradId} not found in active group. Attempting to fetch directly from Celestrak...`);
+		log.debug(`NORAD ID ${noradId} not found in active group. Attempting to fetch directly from Celestrak...`);
 		const url = `https://celestrak.org/NORAD/elements/gp.php?CATNR=${noradId}&FORMAT=tle`;
 		try {
 			let tries: number = (await kv.get(`celestrakTries`)) || 0;
@@ -71,17 +71,21 @@ async function getObjectsTle(noradId: number) {
 			});
 
 			if (!response.ok) {
-				log.error(`Failed to fetch TLE from Celestrak: ${response.status} ${response.statusText}`);
+				log.child({ status: response.status, statusText: response.statusText }).error(`Failed to fetch TLE for NORAD ID ${noradId} from Celestrak`);
 				throw new Error(`Failed to fetch TLE from Celestrak`);
 			}
 
 			tleData = (await response.text()) as string;
 			await kv.set(`tle_${noradId}`, tleData);
 			await kv.set(`celestrakTries`, tries + 1);
 			await kv.set(`celestrakLastTry`, Date.now());
-			log.info(`Successfully fetched TLE for NORAD ID ${noradId} from Celestrak.`);
+			log.debug(`Successfully fetched TLE for NORAD ID ${noradId} from Celestrak.`);
 		} catch (error) {
-			log.error(`Error fetching TLE for NORAD ID ${noradId}: ${error}`);
+			if (error instanceof Error) {
+				log.child(error).error(`Error fetching TLE for NORAD ID ${noradId}:`);
+			} else {
+				log.error(`Error fetching TLE for NORAD ID ${noradId}: ${error}`);
+			}
 			throw error;
 		}
 	}