enh: log tail fixes and enhancements

packages/daemon/package.json

@@ -19,6 +19,7 @@
   "dependencies": {
     "@pockethost/common": "0.0.1",
     "@swc/core": "^1.3.86",
+    "@types/tail": "^2.2.2",
     "ajv": "^8.11.2",
     "boolean": "^3.2.0",
     "bottleneck": "^2.19.5",
@@ -40,6 +41,7 @@
     "semver": "^7.3.8",
     "sqlite": "^4.1.2",
     "sqlite3": "^5.1.6",
+    "tail": "^2.2.6",
     "tmp": "^0.2.1",
     "tsup": "^7.2.0",
     "tsx": "^3.11.0",

packages/daemon/src/services/InstanceLoggerService/index.ts

@@ -1,5 +1,7 @@
-import { mkInstanceDataPath } from '$constants'
+import { mkInstanceDataPath, PUBLIC_DEBUG } from '$constants'
+import { LoggerService } from '@pockethost/common'
 import * as fs from 'fs'
+import { Tail } from 'tail'
 import * as winston from 'winston'
 
 type UnsubFunc = () => void
@@ -50,26 +52,38 @@ function createOrGetLogger(instanceId: string, target: string): winston.Logger {
 export function InstanceLogger(instanceId: string, target: string) {
   const logger = createOrGetLogger(instanceId, target)
 
-  return {
+  const api = {
     info: (msg: string) => {
       logger.info(msg)
     },
     error: (msg: string) => {
       logger.error(msg)
     },
-    tail: (linesBack: number, data: (line: string) => void): UnsubFunc => {
+    tail: (
-      const stream = logger.stream({ start: -linesBack })
+      linesBack: number,
-      const listener = (log: winston.LogEntry) => {
+      data: (line: winston.LogEntry) => void,
-        data(JSON.stringify(log))
+    ): UnsubFunc => {
-      }
+      const logFile = mkInstanceDataPath(instanceId, `logs`, `${target}.log`)
-      stream.on('log', listener)
+
+      const tail = new Tail(logFile, { nLines: linesBack })
+
+      tail.on('line', (line) => {
+        const entry = JSON.parse(line)
+        data(entry)
+      })
 
       // Return an unsubscribe function to remove the listener when done
       return () => {
-        stream.removeListener('log', listener)
+        tail.unwatch()
       }
     },
   }
+  if (PUBLIC_DEBUG) {
+    const { dbg } = LoggerService().create(`Logger:${instanceId}`)
+    api.tail(0, dbg)
+  }
+
+  return api
 }
 
 // // Example usage

packages/daemon/src/services/InstanceService/InstanceService.ts

@@ -277,6 +277,9 @@ export const instanceService = mkSingleton(
             return cp
           } catch (e) {
             warn(`Error spawning: ${e}`)
+            userInstanceLogger.error(
+              `Could not launch PocketBase ${instance.version}. It may be time to upgrade.`,
+            )
             throw new Error(
               `Could not launch PocketBase ${instance.version}. It may be time to upgrade.`,
             )

packages/daemon/src/services/PocketBaseService/PocketBaseService.ts

@@ -4,6 +4,7 @@ import {
   mkInstanceDataPath,
   PUBLIC_DEBUG,
 } from '$constants'
+import { port as getPort } from '$services'
 import { assert, mkInternalUrl, tryFetch } from '$util'
 import {
   createCleanupManager,
@@ -17,7 +18,6 @@ import {
 import { map } from '@s-libs/micro-dash'
 import Docker, { Container, ContainerCreateOptions } from 'dockerode'
 import { existsSync } from 'fs'
-import getPort from 'get-port'
 import MemoryStream from 'memorystream'
 import { dirname } from 'path'
 import { gte } from 'semver'
@@ -69,9 +69,15 @@ export const createPocketbaseService = async (
   const _spawn = async (cfg: SpawnConfig, context?: AsyncContext) => {
     const logger = (context?.logger || _serviceLogger).create('spawn')
     const { dbg, warn, error } = logger
+    const defaultPort = await (async () => {
+      if (cfg.port) return cfg.port
+      const [defaultPort, freeDefaultPort] = await getPort.alloc()
+      cm.add(freeDefaultPort)
+      return defaultPort
+    })()
     const _cfg: Required<SpawnConfig> = {
       version: maxVersion,
-      port: cfg.port || (await getPort()),
+      port: defaultPort,
       isMothership: false,
       env: {},
       stderr: new MemoryStream(),
@@ -90,6 +96,8 @@ export const createPocketbaseService = async (
       stderr,
       stdout,
     } = _cfg
+    const iLogger = InstanceLogger(slug, 'exec')
+
     const _version = version || maxVersion // If _version is blank, we use the max version available
     const realVersion = await getVersion(_version)
     const binPath = realVersion.binPath
@@ -128,13 +136,11 @@ export const createPocketbaseService = async (
     let isRunning = true
 
     const docker = new Docker()
-    const iLogger = InstanceLogger(slug, 'exec')
     iLogger.info(`Starting instance`)
 
     const _stdoutData = (data: Buffer) => {
       const lines = data.toString().split(/\n/)
       lines.forEach((line) => {
-        dbg(`${slug} stdout: ${line}`)
         iLogger.info(line)
       })
     }
@@ -142,7 +148,6 @@ export const createPocketbaseService = async (
     const _stdErrData = (data: Buffer) => {
       const lines = data.toString().split(/\n/)
       lines.forEach((line) => {
-        warn(`${slug} stderr: ${line}`)
         iLogger.error(line)
       })
     }
@@ -178,7 +183,8 @@ export const createPocketbaseService = async (
         [`8090/tcp`]: {},
       },
     }
-    dbg(`Spawning ${slug}`, { args, createOptions })
+    logger.info(`Spawning ${slug}`)
+    dbg({ args, createOptions })
 
     let container: Container | undefined = undefined
     const exited = new Promise<number>(async (resolveExit) => {
@@ -191,16 +197,19 @@ export const createPocketbaseService = async (
             createOptions,
             (err, data) => {
               const { StatusCode } = data || {}
-              dbg(`${slug} closed with code ${StatusCode}`, { err, data })
+              iLogger.info(`${slug} closed with code ${StatusCode}`)
+              dbg({ err, data })
               isRunning = false
               if (StatusCode > 0 || err) {
-                if (err?.json) {
+                iLogger.error(
-                  error(`Error: ${err.json.message}`)
+                  `Unexpected stop with code ${StatusCode} and error ${err}`,
-                  dbg(`${slug} stopped unexpectedly with code ${err}`, data)
+                )
-                }
+                error(`${slug} stopped unexpectedly with code ${err}`, data)
                 onUnexpectedStop?.(StatusCode)
-              }
+                resolveExit(StatusCode || 999)
+              } else {
                 resolveExit(0)
+              }
             },
           )
           .on('container', (container: Container) => {
@@ -208,14 +217,29 @@ export const createPocketbaseService = async (
             resolve(container)
           })
       })
+      if (container) {
         cm.add(async () => {
           dbg(`Stopping ${slug} for cleanup`)
+          iLogger.info(`Stopping instance`)
           await container
             ?.stop()
-          .catch((err) => warn(`Possible error stopping container: ${err}`))
+            .then(() => {
+              iLogger.info(`Instance stopped`)
+            })
+            .catch((err) => {
+              iLogger.error(`Error stopping instance`)
+              warn(`Possible error stopping container: ${err}`)
+            })
+
           stderr.off('data', _stdErrData)
           stdout.off('data', _stdoutData)
         })
+      } else {
+        iLogger.error(`Could not start container`)
+        error(`${slug} could not start container`)
+        onUnexpectedStop?.(999)
+        resolveExit(999)
+      }
     })
 
     const url = mkInternalUrl(port)

packages/daemon/src/services/RealtimeLog.ts

@@ -107,10 +107,8 @@ export const realtimeLog = mkSingleton(async (config: RealtimeLogConfig) => {
         'Cache-Control': 'no-store',
       })
 
-      const unsub = instanceLogger.tail(100, (line) => {
+      const unsub = instanceLogger.tail(100, (entry) => {
-        const obj = JSON.parse(line)
+        const evt = mkEvent(`log`, entry)
-        const evt = mkEvent(`log`, obj)
-        dbg(`****sending ${evt}`)
         res.write(evt)
       })
 

packages/daemon/src/services/index.ts

@@ -1,6 +1,7 @@
 export * from './FtpService/FtpService'
 export * from './InstanceService/InstanceService'
 export * from './PocketBaseService/PocketBaseService'
+export * from './PortManager'
 export * from './ProxyService'
 export * from './RealtimeLog'
 export * from './RpcService/RpcService'

packages/dashboard/src/routes/app/instances/[instanceId]/Logging.svelte

@@ -79,7 +79,7 @@
     <div class="modal-box max-w-[90vw] h-[90vh]">
       <h3 class="font-bold text-lg">Instance Logging</h3>
 
-      <div class="py-4 h-[80vh] overflow-y-scroll flex flex-col-reverse gap-3">
+      <div class="py-4 h-[80vh] overflow-y-scroll flex flex-col gap-3">
         {#each $logs as log}
           <div
             class="px-4 text-[11px] font-mono flex align-center"
@@ -112,7 +112,7 @@
       on:click={handleFullScreenModal}
       >Fullscreen <i class="fa-regular fa-arrows-maximize"></i></button
     >
-    <div class="h-[450px] flex flex-col-reverse overflow-y-scroll gap-3">
+    <div class="h-[450px] flex flex-col overflow-y-scroll gap-3">
       {#each $logs as log}
         <div
           class="px-4 text-[11px] font-mono flex align-center"

yarn.lock

@@ -843,6 +843,11 @@
   dependencies:
     "@types/node" "^18.11.18"
 
+"@types/tail@^2.2.2":
+  version "2.2.2"
+  resolved "https://registry.yarnpkg.com/@types/tail/-/tail-2.2.2.tgz#3b59bcd0bc91aa2cf50838fcbc62d1071a3ab72d"
+  integrity sha512-+CjjgMFjIVgTYsJXWNpAKVRerFWc9c+GTMzY/336fSW6BhY5TJwo2CNYJiNq7mO9rBHmtmpceKf2DnkrnaR3Vg==
+
 "@types/tmp@^0.2.1":
   version "0.2.3"
   resolved "https://registry.yarnpkg.com/@types/tmp/-/tmp-0.2.3.tgz#908bfb113419fd6a42273674c00994d40902c165"
@@ -6301,6 +6306,11 @@ swap-case@^1.1.0:
     lower-case "^1.1.1"
     upper-case "^1.1.1"
 
+tail@^2.2.6:
+  version "2.2.6"
+  resolved "https://registry.yarnpkg.com/tail/-/tail-2.2.6.tgz#24abd701963639b896c42496d5f416216ec0b558"
+  integrity sha512-IQ6G4wK/t8VBauYiGPLx+d3fA5XjSVagjWV5SIYzvEvglbQjwEcukeYI68JOPpdydjxhZ9sIgzRlSmwSpphHyw==
+
 tailwindcss@^3, tailwindcss@^3.3.3:
   version "3.3.3"
   resolved "https://registry.yarnpkg.com/tailwindcss/-/tailwindcss-3.3.3.tgz#90da807393a2859189e48e9e7000e6880a736daf"