Log timing

packages/nano-remix/src/nanoRemix.ts

@@ -8,6 +8,11 @@ type Options = {
   disableCache?: boolean // Disable caching for development
 }
 export const nanoRemix = async (req: Request, options: Options = {}) => {
+  const requestStart = performance.now()
+  const url = new URL(req.url)
+  console.log(`🚀 Request started: ${req.method} ${url.pathname}`)
+
+  const setupStart = performance.now()
   const nanoRemixDir = join(process.cwd(), ".nano-remix")
   const defaultDistDir = join(nanoRemixDir, "dist")
   const defaultRoutesDir = "./src/routes"
@@ -15,14 +20,19 @@ export const nanoRemix = async (req: Request, options: Options = {}) => {
   const routesDir = options.routesDir || defaultRoutesDir
   const distDir = options.distDir || defaultDistDir
   const router = new Bun.FileSystemRouter({ style: "nextjs", dir: routesDir })
-  const url = new URL(req.url)
+  const setupEnd = performance.now()
+  console.log(`⚙️  Setup: ${(setupEnd - setupStart).toFixed(2)}ms`)
 
   // I want to request the css and js files directly, so we detect the extension
+  const routingStart = performance.now()
   const ext = extname(url.pathname)
   const basename = ext ? url.pathname.slice(0, -ext.length) : url.pathname
   const route = router.match(basename)
+  const routingEnd = performance.now()
+  console.log(`🗺️  Routing: ${(routingEnd - routingStart).toFixed(2)}ms`)
 
   if (!route) {
+    console.log(`❌ Route not found: ${url.pathname}`)
     return new Response("Route Not Found", {
       status: 404,
       headers: { "Content-Type": "text/plain" },
@@ -33,22 +43,42 @@ export const nanoRemix = async (req: Request, options: Options = {}) => {
 
   // If the the route includes an extension it is a static file that we serve from the distDir
   if (!ext) {
+    console.log(`📄 Serving page route: ${routeName}`)
+
+    const buildStart = performance.now()
     await buildRoute({
       distDir,
       routeName,
       filepath: route.filePath,
       force: options.disableCache, // Force rebuild if cache is disabled
     })
-    return await renderServer(req, route)
+    const buildEnd = performance.now()
+    console.log(`🔨 Build step: ${(buildEnd - buildStart).toFixed(2)}ms`)
+
+    const renderStart = performance.now()
+    const response = await renderServer(req, route)
+    const renderEnd = performance.now()
+    console.log(`🎨 Render step: ${(renderEnd - renderStart).toFixed(2)}ms`)
+
+    const totalTime = performance.now() - requestStart
+    console.log(`✅ Total request time: ${totalTime.toFixed(2)}ms\n`)
+
+    return response
   } else {
+    console.log(`📁 Serving static file: ${routeName + ext}`)
+    const fileStart = performance.now()
     const file = Bun.file(join(distDir, routeName + ext))
 
     if (!(await file.exists())) {
+      console.log(`❌ Static file not found: ${routeName + ext}`)
       return new Response("File Not Found", {
         status: 404,
         headers: { "Content-Type": "text/plain" },
       })
     }
+    const fileEnd = performance.now()
+    console.log(`📁 Static file served: ${(fileEnd - fileStart).toFixed(2)}ms`)
+
     return new Response(file)
   }
 }

packages/nano-remix/src/renderServer.tsx

@@ -1,32 +1,65 @@
 import type { Action, Loader } from "@/main"
 export const renderServer = async (req: Request, route: Bun.MatchedRoute) => {
+  const renderStart = performance.now()
+  console.log(`  🎨 RenderServer started for ${route.name}`)
+
   const contentType = req.headers.get("Content-Type")
 
   if (contentType?.startsWith("multipart/form-data;")) {
-    return await handleAction(req, route)
+    console.log(`  📝 Handling action request`)
+    const result = await handleAction(req, route)
+    const renderEnd = performance.now()
+    console.log(`  ✅ Action handled in ${(renderEnd - renderStart).toFixed(2)}ms`)
+    return result
   } else {
-    return await renderHtml(req, route)
+    console.log(`  📄 Rendering HTML`)
+    const result = await renderHtml(req, route)
+    const renderEnd = performance.now()
+    console.log(`  ✅ HTML rendered in ${(renderEnd - renderStart).toFixed(2)}ms`)
+    return result
   }
 }
 
 const handleAction = async (req: Request, route: Bun.MatchedRoute) => {
+  const actionStart = performance.now()
+  console.log(`    📝 Starting action handling`)
+
+  const importStart = performance.now()
   const { action, loader } = (await import(route.filePath)) as {
     action: Action
     loader?: Loader<any>
   }
+  const importEnd = performance.now()
+  console.log(`    📦 Action import: ${(importEnd - importStart).toFixed(2)}ms`)
 
   if (typeof action !== "function") {
+    console.log(`    ❌ No action function found`)
     return Response.json(
       { error: `Route at "${route.pathname}" does not export an "action" function` },
       { status: 400 }
     )
   }
 
+  const actionExecStart = performance.now()
   const actionData = await action(req, route.params)
-  if (actionData instanceof Response) return actionData // This should only happen if the action wants to redirect
+  const actionExecEnd = performance.now()
+  console.log(`    ⚡ Action execution: ${(actionExecEnd - actionExecStart).toFixed(2)}ms`)
+
+  if (actionData instanceof Response) {
+    console.log(`    🔄 Action returned redirect response`)
+    return actionData // This should only happen if the action wants to redirect
+  }
+
+  const loaderStart = performance.now()
   const loaderData = await loader?.(req, route.params)
+  const loaderEnd = performance.now()
+  console.log(`    📊 Action loader execution: ${(loaderEnd - loaderStart).toFixed(2)}ms`)
+
   const result = { actionData, loaderData }
 
+  const totalActionTime = performance.now() - actionStart
+  console.log(`    ✅ Total action handling: ${totalActionTime.toFixed(2)}ms`)
+
   return new Response(JSON.stringify(result), {
     status: 200,
     headers: { "Content-Type": "application/json" },
@@ -34,12 +67,23 @@ const handleAction = async (req: Request, route: Bun.MatchedRoute) => {
 }
 
 const renderHtml = async (req: Request, route: Bun.MatchedRoute) => {
+  const htmlStart = performance.now()
+  console.log(`    📄 Starting HTML rendering`)
+
+  const importStart = performance.now()
   const component = await import(route.filePath)
+  const importEnd = performance.now()
+  console.log(`    📦 Component import: ${(importEnd - importStart).toFixed(2)}ms`)
+
+  const loaderStart = performance.now()
   const loader = component.loader as Loader<any>
   const loaderData = loader ? await loader(req, route.params) : {}
+  const loaderEnd = performance.now()
+  console.log(`    ⚡ Loader execution: ${(loaderEnd - loaderStart).toFixed(2)}ms`)
 
   const routeName = route.name === "/" ? "/index" : route.name
 
+  const dataProcessStart = performance.now()
   // Remove any < characters from the loader data to prevent XSS attacks
   const escapedLoaderData = JSON.stringify(loaderData).replace(/</g, "\\u003c")
   const headLinks = component.head?.links?.map(
@@ -48,8 +92,16 @@ const renderHtml = async (req: Request, route: Bun.MatchedRoute) => {
   const headScripts = component.head?.scripts?.map(
     (script: any) => `<script src="${script.src}" ${script.type ? `type="${script.type}"` : ""}></script>`
   )
-  return new Response(
-    `<!DOCTYPE html>
+  const dataProcessEnd = performance.now()
+  console.log(`    🔧 Data processing: ${(dataProcessEnd - dataProcessStart).toFixed(2)}ms`)
+
+  const componentRenderStart = performance.now()
+  const renderedComponent = component.default(loaderData)
+  const componentRenderEnd = performance.now()
+  console.log(`    🖼️  Component render: ${(componentRenderEnd - componentRenderStart).toFixed(2)}ms`)
+
+  const htmlBuildStart = performance.now()
+  const htmlContent = `<!DOCTYPE html>
       <html lang="en">
         <head>
           <meta charset="UTF-8" />
@@ -61,14 +113,19 @@ const renderHtml = async (req: Request, route: Bun.MatchedRoute) => {
           <script id="__LOADER_DATA__" type="application/json">${escapedLoaderData}</script>
         </head>
         <body>
-          <div id="root">${component.default(loaderData)}</div>
+          <div id="root">${renderedComponent}</div>
           <script type="module" src="${routeName + ".js"}"></script>
         </body>
-      </html>`,
-    {
-      headers: {
-        "Content-Type": "text/html; charset=utf-8",
-      },
-    }
-  )
+      </html>`
+  const htmlBuildEnd = performance.now()
+  console.log(`    📝 HTML building: ${(htmlBuildEnd - htmlBuildStart).toFixed(2)}ms`)
+
+  const totalHtmlTime = performance.now() - htmlStart
+  console.log(`    ✅ Total HTML rendering: ${totalHtmlTime.toFixed(2)}ms`)
+
+  return new Response(htmlContent, {
+    headers: {
+      "Content-Type": "text/html; charset=utf-8",
+    },
+  })
 }