From ffc4aef5ba2ff85c1fb758a4f4632f382ba9aba1 Mon Sep 17 00:00:00 2001 From: joaojramia <joao@holistic.foundation> Date: Mon, 30 Jan 2023 11:30:10 -0300 Subject: [PATCH] HOLI-3035: Add structured logging --- app/deps.ts | 1 - app/logging.ts | 98 ++++++++++++++++++++++++++++++++++++---------- app/main.ts | 8 ++-- app/places.ts | 12 +++--- app/places_test.ts | 3 -- app/server.ts | 27 ++++++------- deno.lock | 11 ------ 7 files changed, 100 insertions(+), 60 deletions(-) diff --git a/app/deps.ts b/app/deps.ts index 97be817..94cdc3f 100644 --- a/app/deps.ts +++ b/app/deps.ts @@ -4,5 +4,4 @@ export { createYoga, } from "https://cdn.skypack.dev/graphql-yoga@3.0.3"; export { useResponseCache } from "https://cdn.skypack.dev/@graphql-yoga/plugin-response-cache@1.0.3"; -export * as log from "https://deno.land/std@0.165.0/log/mod.ts"; export { Parser } from "https://deno.land/x/html_parser@v0.1.3/src/mod.ts"; diff --git a/app/logging.ts b/app/logging.ts index 2f05667..823eef0 100644 --- a/app/logging.ts +++ b/app/logging.ts @@ -1,20 +1,78 @@ -import { log } from "./deps.ts"; - -const setupLogging = (environment: string) => - log.setup({ - handlers: { - default: new log.handlers.ConsoleHandler("DEBUG", { - formatter: ({ datetime, levelName, msg }) => - `${datetime.toISOString()} ${levelName} ${msg}`, - }), - }, - - loggers: { - default: { - level: environment === "development" ? "DEBUG" : "INFO", - handlers: ["default"], - }, - }, - }); - -export default setupLogging; +// Google Cloud LogSeverity levels https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#logseverity +export enum LogSeverity { + DEFAULT = "DEFAULT", + DEBUG = "DEBUG", + INFO = "INFO", + NOTICE = "NOTICE", + WARNING = "WARNING", + ERROR = "ERROR", + CRITICAL = "CRITICAL", + ALERT = "ALERT", + EMERGENCY = "EMERGENCY", +} + +/** + * The Logger class requires a setUpLogger method to be run during the app's initialization in order get the current environment. + */ +class Logger { + environment = "development"; + + setUpLogger(environment: string) { + this.environment = environment; + } + + /** + * @param severity Google Cloud's LogSeverity level + * @param message Log message + * @param options Any extra fields wanted in the structured logging JSON + * + * In a development enviroment, the logs are formatted as simple string for readability purposes. + * In other environments it should follow Google Cloud's Structured Logging formatting: https://cloud.google.com/logging/docs/structured-logging + */ + log(severity: LogSeverity, message: string, options = {}) { + const date = new Date().toISOString(); + const input = this.environment === "development" + ? `${date} ${severity} ${message}` + : JSON.stringify({ + environment: this.environment, + severity, + message, + ...options, + }); + + switch (severity) { + case LogSeverity.DEFAULT: + console.log(input); + break; + case LogSeverity.DEBUG: + console.debug(input); + break; + case LogSeverity.INFO: + case LogSeverity.NOTICE: + console.info(input); + break; + case LogSeverity.WARNING: + console.warn(input); + break; + case LogSeverity.ERROR: + case LogSeverity.CRITICAL: + case LogSeverity.ALERT: + case LogSeverity.EMERGENCY: + console.error(input); + } + } + + debug(message: string, options = {}) { + this.log(LogSeverity.DEBUG, message, options); + } + + info(message: string, options = {}) { + this.log(LogSeverity.INFO, message, options); + } + + error(message: string, options = {}) { + this.log(LogSeverity.ERROR, message, options); + } +} + +export const logger = new Logger(); diff --git a/app/main.ts b/app/main.ts index a55d68e..609938c 100644 --- a/app/main.ts +++ b/app/main.ts @@ -1,11 +1,11 @@ -import setupLogging from "./logging.ts"; +import { logger } from "./logging.ts"; import { startServer } from "./server.ts"; -setupLogging(Deno.env.get("ENVIRONMENT") || "development"); +logger.setUpLogger(Deno.env.get("ENVIRONMENT") || "development"); const serverConfigFromEnv = () => { - const asNumber = (str?: string) => str ? Number(str) : undefined; - const asBoolean = (str?: string) => str ? Boolean(str) : undefined; + const asNumber = (str?: string) => (str ? Number(str) : undefined); + const asBoolean = (str?: string) => (str ? Boolean(str) : undefined); return { port: asNumber(Deno.env.get("PORT")), cacheEnabled: asBoolean(Deno.env.get("CACHE_ENABLED")), diff --git a/app/places.ts b/app/places.ts index 99dbfee..b43d76b 100644 --- a/app/places.ts +++ b/app/places.ts @@ -1,6 +1,6 @@ import { PlacesApiResults } from "./places_api_types.ts"; import { Place, PlacesParameters } from "./types.ts"; -import { log } from "./deps.ts"; +import { logger } from "./logging.ts"; const buildPlacesUrl = ( { input }: PlacesParameters, @@ -15,9 +15,7 @@ const buildPlacesUrl = ( return url; }; -export const transformPlacesResult = ( - results: PlacesApiResults, -): Place[] => { +export const transformPlacesResult = (results: PlacesApiResults): Place[] => { return results.predictions.map((prediction) => ({ description: prediction.description, mainText: prediction.structured_formatting.main_text, @@ -33,18 +31,18 @@ export const fetchPlaces = ( ): Promise<Place[]> => { const url = buildPlacesUrl(params, placesApiKey); const start = Date.now(); - console.debug(`fetching places for search input ${params.input}`); + logger.info(`fetching places for search input ${params.input}`); return fetch(url) .then((result) => result.json()) .then(transformPlacesResult) .then((result) => { const duration = Date.now() - start; - log.debug(` fetching places took ${duration} ms`); + logger.debug(`fetching places took ${duration} ms`); return result; }) .catch((e) => { const duration = Date.now() - start; - log.error( + logger.error( `Error performing request to ${url} after ${duration} ms: ${e.message}`, ); throw e; diff --git a/app/places_test.ts b/app/places_test.ts index 41dda82..f5499c7 100644 --- a/app/places_test.ts +++ b/app/places_test.ts @@ -1,4 +1,3 @@ -import setupLogging from "./logging.ts"; import { afterEach, assertEquals, @@ -45,8 +44,6 @@ const queryPlaces = async ( return (await processGqlRequest(graphQLServer, query))?.places as Place[]; }; -setupLogging("test"); - describe("places", () => { let fetchStub: Stub; diff --git a/app/server.ts b/app/server.ts index ce3d746..33653c8 100644 --- a/app/server.ts +++ b/app/server.ts @@ -1,6 +1,7 @@ import { PlacesParameters } from "./types.ts"; import { fetchPlaces } from "./places.ts"; import { createSchema, createYoga, serve, useResponseCache } from "./deps.ts"; +import { logger } from "./logging.ts"; const typeDefs = ` type PlaceSubstringMatch { @@ -41,16 +42,16 @@ export interface ServerConfig { placesApiKey?: string; // must be given in order for places calls to work } -export const createGraphQLServer = ( - config: ServerConfig, -): GraphQLServer => { - const plugins = (config.cacheEnabled || DEFAULT_CACHE_ENABLED) - ? [useResponseCache({ - session: () => null, // global cache, shared by all users - ttlPerSchemaCoordinate: { - "Query.places": DEFAULT_CACHE_TTL_MS_PLACES, - }, - })] +export const createGraphQLServer = (config: ServerConfig): GraphQLServer => { + const plugins = config.cacheEnabled || DEFAULT_CACHE_ENABLED + ? [ + useResponseCache({ + session: () => null, // global cache, shared by all users + ttlPerSchemaCoordinate: { + "Query.places": DEFAULT_CACHE_TTL_MS_PLACES, + }, + }), + ] : []; const resolvers = createResolvers(config); return createYoga({ @@ -63,14 +64,12 @@ export const createGraphQLServer = ( // deno-lint-ignore no-explicit-any export type GraphQLServer = any; -export const startServer = ( - config: ServerConfig, -): Promise<void> => { +export const startServer = (config: ServerConfig): Promise<void> => { const graphQLServer: GraphQLServer = createGraphQLServer(config); return serve(graphQLServer.handleRequest, { port: config.port || DEFAULT_PORT, onListen({ port, hostname }) { - console.log( + logger.info( `Server started at http://${ hostname === "0.0.0.0" ? "localhost" : hostname }:${port}/graphql`, diff --git a/deno.lock b/deno.lock index b180908..c0c1f13 100644 --- a/deno.lock +++ b/deno.lock @@ -212,7 +212,6 @@ "https://cdn.skypack.dev/-/yallist@v4.0.0-zGx9utyhIe9lDU5JvFtt/dist=es2019,mode=imports/optimized/yallist.js": "4854561a2ed352e797634de4d204325dcd352d25fd70a1a5780f355347d9ee53", "https://cdn.skypack.dev/@graphql-yoga/plugin-response-cache@1.0.3": "cd62496f40e1abc1d643dd7e3bc3e0d4ff58af5ed41e57e641fb84938022f4aa", "https://cdn.skypack.dev/graphql-yoga@3.0.3": "3e581155cbe11992c40a3a95ea22c923ba105be8ff5c6510d8b3c3922af4bf2c", - "https://deno.land/std@0.165.0/_util/asserts.ts": "d0844e9b62510f89ce1f9878b046f6a57bf88f208a10304aab50efcb48365272", "https://deno.land/std@0.165.0/async/abortable.ts": "87aa7230be8360c24ad437212311c9e8d4328854baec27b4c7abb26e85515c06", "https://deno.land/std@0.165.0/async/deadline.ts": "48ac998d7564969f3e6ec6b6f9bf0217ebd00239b1b2292feba61272d5dd58d0", "https://deno.land/std@0.165.0/async/debounce.ts": "dc8b92d4a4fe7eac32c924f2b8d3e62112530db70cadce27042689d82970b350", @@ -222,18 +221,8 @@ "https://deno.land/std@0.165.0/async/mux_async_iterator.ts": "3447b28a2a582224a3d4d3596bccbba6e85040da3b97ed64012f7decce98d093", "https://deno.land/std@0.165.0/async/pool.ts": "ef9eb97b388543acbf0ac32647121e4dbe629236899586c4d4311a8770fbb239", "https://deno.land/std@0.165.0/async/tee.ts": "9af3a3e7612af75861308b52249e167f5ebc3dcfc8a1a4d45462d96606ee2b70", - "https://deno.land/std@0.165.0/bytes/bytes_list.ts": "aba5e2369e77d426b10af1de0dcc4531acecec27f9b9056f4f7bfbf8ac147ab4", - "https://deno.land/std@0.165.0/bytes/equals.ts": "3c3558c3ae85526f84510aa2b48ab2ad7bdd899e2e0f5b7a8ffc85acb3a6043a", - "https://deno.land/std@0.165.0/bytes/mod.ts": "b2e342fd3669176a27a4e15061e9d588b89c1aaf5008ab71766e23669565d179", "https://deno.land/std@0.165.0/fmt/colors.ts": "9e36a716611dcd2e4865adea9c4bec916b5c60caad4cdcdc630d4974e6bb8bd4", - "https://deno.land/std@0.165.0/fs/exists.ts": "6a447912e49eb79cc640adacfbf4b0baf8e17ede6d5bed057062ce33c4fa0d68", "https://deno.land/std@0.165.0/http/server.ts": "e99c1bee8a3f6571ee4cdeb2966efad465b8f6fe62bec1bdb59c1f007cc4d155", - "https://deno.land/std@0.165.0/io/buffer.ts": "245f1762a949082ddc0a6e9b15589d0be2d29c150266decd04320b8a8318f9f6", - "https://deno.land/std@0.165.0/io/types.d.ts": "107e1e64834c5ba917c783f446b407d33432c5d612c4b3430df64fc2b4ecf091", - "https://deno.land/std@0.165.0/log/handlers.ts": "61ab932822ba268ad42b25de6f0014892fe469df7627b14245ad32db6fd8b54d", - "https://deno.land/std@0.165.0/log/levels.ts": "82c965b90f763b5313e7595d4ba78d5095a13646d18430ebaf547526131604d1", - "https://deno.land/std@0.165.0/log/logger.ts": "b545159727b023825ee6814d9178fb2a7472f8d95d704c253b771b95c658cf8c", - "https://deno.land/std@0.165.0/log/mod.ts": "90618a3fdbb4520ed4e7d960665322a3dbfc107eebb3345fe0f36c8c8a7b7962", "https://deno.land/std@0.165.0/testing/_diff.ts": "a23e7fc2b4d8daa3e158fa06856bedf5334ce2a2831e8bf9e509717f455adb2c", "https://deno.land/std@0.165.0/testing/_format.ts": "cd11136e1797791045e639e9f0f4640d5b4166148796cad37e6ef75f7d7f3832", "https://deno.land/std@0.165.0/testing/_test_suite.ts": "2d07073d5460a4e3ec50c55ae822cd9bd136926d7363091379947fef9c73c3e4", -- GitLab