fix: improved express logger

Dockerfile

@@ -32,9 +32,13 @@ RUN --mount=type=cache,id=pnpm,target=/pnpm/store pnpm install && pnpm build
 FROM base AS pruner
 ENV NODE_ENV $NODE_ENV
 
+# Required source files
 COPY --from=builder /srv/.npmrc /srv/.npmrc
-COPY --from=builder /srv/server.js /srv/server.js
+COPY --from=builder /srv/server /srv/server
+COPY --from=builder /srv/public /srv/public
 COPY --from=builder /srv/package.json /srv/package.json
+
+# Generated files
 COPY --from=builder /srv/pnpm-lock.yaml /srv/pnpm-lock.yaml
 COPY --from=builder /srv/build/client /srv/build/client
 COPY --from=builder /srv/build/server /srv/build/server
@@ -43,7 +47,7 @@ COPY --from=builder /srv/build/server /srv/build/server
 RUN --mount=type=cache,id=pnpm,target=/pnpm/store pnpm install --prod \
     --frozen-lockfile --ignore-scripts && pnpm prune --prod \
     --ignore-scripts && pnpm dlx clean-modules clean --yes \
-    "!**/@libsql/**" && chmod +x /srv/server.js
+    "!**/@libsql/**" && chmod +x /srv/server/server.js
 
 # -----------------------------------------------------------------------------
 # Production image, copy build output files and run the application.
@@ -85,4 +89,4 @@ USER nonroot:nonroot
 EXPOSE $PORT
 
 ENTRYPOINT ["/usr/bin/tini", "--"]
-CMD ["/nodejs/bin/node", "server.js"]
+CMD ["/nodejs/bin/node", "server/server.js"]

Dockerfile.alpine

@@ -31,9 +31,13 @@ RUN --mount=type=cache,id=pnpm,target=/pnpm/store pnpm install --ignore-scripts
 FROM base AS pruner
 ENV NODE_ENV $NODE_ENV
 
+# Required source files
 COPY --from=builder /srv/.npmrc /srv/.npmrc
-COPY --from=builder /srv/server.js /srv/server.js
+COPY --from=builder /srv/server /srv/server
+COPY --from=builder /srv/public /srv/public
 COPY --from=builder /srv/package.json /srv/package.json
+
+# Generated files
 COPY --from=builder /srv/pnpm-lock.yaml /srv/pnpm-lock.yaml
 COPY --from=builder /srv/build/client /srv/build/client
 COPY --from=builder /srv/build/server /srv/build/server
@@ -42,7 +46,7 @@ COPY --from=builder /srv/build/server /srv/build/server
 RUN --mount=type=cache,id=pnpm,target=/pnpm/store pnpm install --prod \
     --frozen-lockfile --ignore-scripts && pnpm prune --prod \
     --ignore-scripts && pnpm dlx clean-modules clean --yes \
-    "!**/@libsql/**" && chmod +x /srv/server.js
+    "!**/@libsql/**" && chmod +x /srv/server/server.js
 
 # -----------------------------------------------------------------------------
 # Production image, copy build output files and run the application.
@@ -84,4 +88,4 @@ USER nonroot:nonroot
 EXPOSE $PORT
 
 ENTRYPOINT ["/sbin/tini", "--"]
-CMD ["/usr/local/bin/node", "server.js"]
+CMD ["/usr/local/bin/node", "server/server.js"]

app/routes/_index.tsx

@@ -4,6 +4,7 @@ import { useLoaderData } from '@remix-run/react'
 import { Button } from '#/components/base-ui'
 import { Link } from '#/components/link'
 import type { Site } from '#/types/site'
+import { logger } from '#/utils/common'
 import { clx } from '#/utils/ui-helper'
 
 export const loader: LoaderFunction = async ({ request }) => {
@@ -13,13 +14,13 @@ export const loader: LoaderFunction = async ({ request }) => {
   const domain = process.env.APP_DOMAIN || 'example.com'
   const baseDomain = process.env.NODE_ENV === 'development' ? 'localhost:3000' : domain
 
-  console.debug('Original host:', host)
+  logger('DEBUG', 'Original host:', host)
 
   // Check if it's a subdomain
   const isSubdomain = host.endsWith(`.${baseDomain}`) && !host.startsWith('www.')
 
   if (!isSubdomain) {
-    console.debug('Not a subdomain, returning default page')
+    logger('DEBUG', 'Not a subdomain, returning default page')
 
     const meta = [
       { title: 'Remix Start' },
@@ -32,13 +33,13 @@ export const loader: LoaderFunction = async ({ request }) => {
   // Handle localhost by replacing 'localhost' with the domain name
   if (host.includes('localhost')) {
     host = host.replace(/localhost:\d+/, domain)
-    console.debug('Transformed host for localhost:', host)
+    logger('DEBUG', 'Transformed host for localhost:', host)
   }
 
   // Extract the subdomain (slug) from the host
   if (host.endsWith(`.${domain}`)) {
     host = host.replace(`.${domain}`, '')
-    console.debug('Subdomain (slug):', host)
+    logger('DEBUG', 'Subdomain (slug):', host)
   }
 
   // Sample list of sites; ideally, this would come from a database
@@ -65,11 +66,11 @@ export const loader: LoaderFunction = async ({ request }) => {
   const currentSite = sites.find((site) => site.slug === host)
 
   if (!currentSite) {
-    console.debug('Site not found for slug:', host)
+    logger('DEBUG', 'Site not found for slug:', host)
     throw new Response(null, { status: 404, statusText: 'Not Found' })
   }
 
-  console.debug('Returning data for site:', currentSite)
+  logger('DEBUG', 'Returning data for site:', currentSite)
 
   const meta = [{ title: `@${currentSite.slug} on Remix Start` }] satisfies MetaDescriptor[]
 

app/routes/healthz.tsx

@@ -1,21 +1,23 @@
 import type { LoaderFunctionArgs } from '@remix-run/node'
+import { logger } from '#/utils/common'
 
 export async function loader({ request }: LoaderFunctionArgs) {
   const host = request.headers.get('X-Forwarded-Host') ?? request.headers.get('host')
   const url = new URL('/', `http://${host}`)
 
+  // TODO: put some real logic here
+  // if we can connect to the database and make a simple query
+  // and make a HEAD request to ourselves, then we're good.
+
   try {
-    // if we can connect to the database and make a simple query
-    // and make a HEAD request to ourselves, then we're good.
     await Promise.all([
-      // TODO: put some real logic here
       fetch(url.toString(), { method: 'HEAD' }).then((r) => {
         if (!r.ok) return Promise.reject(r)
       }),
     ])
     return new Response('🫡 All is well!')
   } catch (error: unknown) {
-    console.error('healthcheck ❌', { error })
+    logger('ERROR', 'healthcheck ❌', { error })
     return new Response('🔥 Unhealthy', { status: 500 })
   }
 }

app/utils/common.ts

@@ -0,0 +1,51 @@
+import pico from 'picocolors'
+
+export type EnumValues<Type> = Type[keyof Type]
+
+export type LogLevel = 'INFO' | 'WARN' | 'ERROR' | 'DEBUG' | 'QUERY'
+
+export function logTimestamp(date?: Date, localtime = true): string {
+  const now = date ?? new Date()
+  const useUTC = !localtime
+
+  const year = useUTC ? now.getUTCFullYear() : now.getFullYear()
+  const month = String(useUTC ? now.getUTCMonth() + 1 : now.getMonth() + 1).padStart(2, '0')
+  const day = String(useUTC ? now.getUTCDate() : now.getDate()).padStart(2, '0')
+  const hours = String(useUTC ? now.getUTCHours() : now.getHours()).padStart(2, '0')
+  const minutes = String(useUTC ? now.getUTCMinutes() : now.getMinutes()).padStart(2, '0')
+  const seconds = String(useUTC ? now.getUTCSeconds() : now.getSeconds()).padStart(2, '0')
+
+  return pico.dim(`[${year}-${month}-${day} ${hours}:${minutes}:${seconds}]`)
+}
+
+// TODO replace with `node:utils.styleText` (requires node >= 21)
+const parseLogLevel = (level: LogLevel): string => {
+  const colors = {
+    INFO: pico.green,
+    WARN: pico.yellow,
+    ERROR: pico.red,
+    DEBUG: pico.magenta,
+    QUERY: pico.blue,
+  }
+  return colors[level] ? colors[level](level) : pico.gray(level)
+}
+
+export function logger(level: LogLevel, message: string, ...args: unknown[]): void {
+  const logPrefix = `${logTimestamp()} ${parseLogLevel(level)}`
+  const logMethod = {
+    INFO: console.info,
+    WARN: console.warn,
+    ERROR: console.error,
+    DEBUG: console.debug,
+    QUERY: console.log,
+  }
+  const logFunc = logMethod[level] || console.log
+  const logMessage = level === 'INFO' || level === 'WARN' ? ` ${message}` : message
+
+  // If log level === DEBUG and env is not development, don't print the log
+  if (level === 'DEBUG' && process.env.APP_LOG_LEVEL?.toLowerCase() !== 'debug') {
+    return
+  }
+
+  logFunc(logPrefix, logMessage, ...args)
+}

app/utils/env.server.ts

@@ -5,6 +5,7 @@
 
 import 'dotenv/config'
 import * as v from 'valibot'
+import { logger } from './common'
 
 const EnvSchema = v.object({
   NODE_ENV: v.picklist(['production', 'development', 'test'] as const),
@@ -33,9 +34,9 @@ declare global {
 export function init() {
   try {
     const parsed = v.parse(EnvSchema, process.env)
-    console.debug('EnvSchema', parsed)
+    logger('DEBUG', 'EnvSchema', parsed)
   } catch (error) {
-    console.error('❌ Invalid environment variables:', error)
+    logger('ERROR', '❌ Invalid environment variables:', error)
     throw new Error('Invalid environment variables')
   }
 }

package.json

@@ -18,10 +18,10 @@
         "dev": "pnpm run --reporter-hide-prefix --color --parallel \"/dev:(?!storybook)/\"",
         "dev:remix": "remix vite:dev",
         "dev:storybook": "storybook dev -p 6006 --no-open",
-        "preview": "node --watch ./server.js",
+        "preview": "node --watch ./server/server.js",
         "start": "remix-serve ./build/server/index.js",
         "generate:key": "openssl rand -base64 500 | tr -dc 'a-zA-Z0-9' | fold -w 40 | head -n 1",
-        "docker:build": "docker build -f Dockerfile . -t $npm_package_name:latest -t $npm_package_name:$npm_package_version",
+        "docker:build": "docker build -f Dockerfile.alpine . -t $npm_package_name:latest -t $npm_package_name:$npm_package_version",
         "docker:images": "docker image list --filter reference=$npm_package_name:$npm_package_version --filter reference=$npm_package_name:latest",
         "docker:run": "docker run --add-host=localhost:host-gateway --rm -it -p 3000:3000 --env-file .env --name $npm_package_name $npm_package_name:$npm_package_version",
         "docker:shell": "docker run --add-host=localhost:host-gateway --rm -it -p 3000:3000 --env-file .env --entrypoint /bin/bash $npm_package_name:$npm_package_version",
@@ -67,6 +67,7 @@
         "isbot": "^5.1.17",
         "lucide-react": "^0.438.0",
         "morgan": "^1.10.0",
+        "picocolors": "^1.1.0",
         "react": "^18.3.1",
         "react-dom": "^18.3.1",
         "remix-flat-routes": "^0.6.5",

playwright.config.ts

@@ -45,7 +45,7 @@ export default defineConfig({
     : {
         command: 'pnpm run build && pnpm run preview',
         reuseExistingServer: !process.env.CI,
-        timeout: process.env.CI ? 10_000 : 8000,
+        timeout: 30_000,
         port: 3000,
       },
 })

server/logger.js

@@ -0,0 +1,64 @@
+import { default as pico } from 'picocolors'
+
+/**
+ * Formats the current timestamp for logs.
+ * @param {Date} [date] Optional date to use for the timestamp. Defaults to the current date.
+ * @param {boolean} [localtime=true] Whether to use local time or UTC. Defaults to local time.
+ * @returns {string} Formatted timestamp string.
+ */
+export function logTimestamp(date, localtime = true) {
+  const now = date ?? new Date()
+  const useUTC = !localtime
+
+  const year = useUTC ? now.getUTCFullYear() : now.getFullYear()
+  const month = String(useUTC ? now.getUTCMonth() + 1 : now.getMonth() + 1).padStart(2, '0')
+  const day = String(useUTC ? now.getUTCDate() : now.getDate()).padStart(2, '0')
+  const hours = String(useUTC ? now.getUTCHours() : now.getHours()).padStart(2, '0')
+  const minutes = String(useUTC ? now.getUTCMinutes() : now.getMinutes()).padStart(2, '0')
+  const seconds = String(useUTC ? now.getUTCSeconds() : now.getSeconds()).padStart(2, '0')
+
+  return pico.dim(`[${year}-${month}-${day} ${hours}:${minutes}:${seconds}]`)
+}
+
+/**
+ * Parse the log level to return a color-coded string.
+ * TODO: Replace with `node:utils.styleText` for Node >= 21.
+ * @param {string} level The log level to parse.
+ * @returns {string} A color-coded log level string.
+ */
+const parseLogLevel = (level) => {
+  const colors = {
+    INFO: pico.green,
+    WARN: pico.yellow,
+    ERROR: pico.red,
+    DEBUG: pico.magenta,
+    QUERY: pico.blue,
+  }
+  return colors[level] ? colors[level](level) : pico.gray(level)
+}
+
+/**
+ * Logs a message with a given log level and optional arguments.
+ * @param {string} level The log level (INFO, WARN, ERROR, DEBUG, QUERY).
+ * @param {string} message The message to log.
+ * @param {...any} args Additional arguments to log.
+ */
+export default function logger(level, message, ...args) {
+  const logPrefix = `${logTimestamp()} ${parseLogLevel(level)}`
+  const logMethod = {
+    INFO: console.info,
+    WARN: console.warn,
+    ERROR: console.error,
+    DEBUG: console.debug,
+    QUERY: console.log,
+  }
+  const logFunc = logMethod[level] || console.log
+  const logMessage = level === 'INFO' || level === 'WARN' ? ` ${message}` : message
+
+  // If log level is DEBUG and environment is not set to 'debug', do not print the log.
+  if (level === 'DEBUG' && process.env.APP_LOG_LEVEL?.toLowerCase() !== 'debug') {
+    return
+  }
+
+  logFunc(logPrefix, logMessage, ...args)
+}

server.js → server/server.js

@@ -19,13 +19,15 @@ import express from 'express'
 import rateLimit from 'express-rate-limit'
 import helmet from 'helmet'
 import morgan from 'morgan'
+import logger from './logger.js'
 
 installGlobals()
 
 const __filename = fileURLToPath(import.meta.url)
 const __dirname = path.dirname(__filename)
 
-const BUILD_DIR = path.join(__dirname, 'build')
+const BUILD_DIR = path.join(__dirname, '../build')
+const PUBLIC_DIR = path.join(__dirname, '../public')
 
 const staticOptions = {
   immutable: true,
@@ -91,9 +93,15 @@ app.use(express.static('build/client', staticOptions))
 
 // Everything else (like favicon.ico) is cached for an hour.
 // You may want to be more aggressive with this caching.
-app.use(express.static('public', { maxAge: '1h' }))
+app.use(express.static(PUBLIC_DIR, { maxAge: '1h' }))
 
-app.use(morgan('tiny'))
+app.use(
+  morgan('short', {
+    stream: {
+      write: (message) => logger('INFO', message.trim()),
+    },
+  })
+)
 
 app.use((_req, res, next) => {
   const nonce = Math.random().toString(36).substring(2)
@@ -145,7 +153,7 @@ app.use(
   })
 )
 app.use((err, _req, res, _next) => {
-  console.error(err.stack)
+  logger('ERROR', err.stack)
   res.status(500).send(`Something went wrong: ${err.message}`)
 })
 
@@ -174,9 +182,9 @@ const onListen = () => {
   const localUrl = `http://localhost:${PORT}`
   const networkUrl = address ? `http://${address}:${PORT}` : null
   if (networkUrl) {
-    console.info(`[remix-express] ${localUrl} (${networkUrl})`)
+    logger('INFO', `[remix-express] ${localUrl} (${networkUrl})`)
   } else {
-    console.info(`[remix-express] ${localUrl}`)
+    logger('INFO', `[remix-express] ${localUrl}`)
   }
 }
 

vite.config.ts

@@ -40,14 +40,14 @@ export default defineConfig({
     setupFiles: ['./tests/setup-test.ts'],
     includeSource: ['./app/**/*.{js,jsx,ts,tsx}'],
     exclude: ['node_modules', 'tests-e2e'],
-    reporters: process.env.CI ? ['json'] : ['default', 'html'],
+    reporters: process.env.CI ? ['html', 'github-actions'] : ['html', 'default'],
     outputFile: {
       json: './tests-results/vitest-results.json',
       html: './tests-results/index.html',
     },
     coverage: {
       provider: 'istanbul',
-      reporter: process.env.CI ? ['json'] : ['html-spa'],
+      reporter: ['html-spa', 'text-summary'],
       reportsDirectory: './tests-results/coverage',
       include: ['app/**/*.{js,jsx,ts,tsx}'],
       cleanOnRerun: true,