try fix logging again

package.json

@@ -60,6 +60,7 @@
     "vm2": "^3.9.19",
     "winston": "^3.8.2",
     "winston-daily-rotate-file": "^4.7.1",
+    "winston-transport": "^4.7.0",
     "ws": "^8.12.1",
     "yargs": "^17.7.0"
   },

src/hypervisor/hypervisor.ts

@@ -91,19 +91,18 @@ export class Hypervisor extends TypedEmitter<HypervisorEvents> {
         let sys_file = cfg.system_file;
         sys_file ||= path.join(this.operations_directory, "logs", "%DATE%.log");
 
-        const transport_cache = {};
+        this._logger?.close();
 
         this._logger = createDomainLogger({
             level: cfg.system,
             domain: chalk.cyan`Hypervisor`,
             file: path.resolve(this.working_directory, sys_file),
-            transport_cache,
         });
+
         setFallbackLogger(
             createDomainLogger({
                 domain: chalk.yellow("???"),
                 file: path.resolve(this.working_directory, sys_file),
-                transport_cache,
             })
         );
     }
@@ -231,7 +230,7 @@ export class Hypervisor extends TypedEmitter<HypervisorEvents> {
 
         // Release file watchers and other cleanup
         this.logMessage("info", "Cleaning up");
-        await this.cleanupTasks.cleanup()
+        await this.cleanupTasks.cleanup();
     }
 
     protected async findAndLoadConfig() {

src/hypervisor/logging.ts

@@ -10,7 +10,6 @@ require('winston-daily-rotate-file');
 
 import { mapStackTrace } from "../app_transformer/source_maps";
 import { pojso } from "../common/util";
-import { cacheOn } from "../util";
 import { current } from "./current";
 import { HyperWrapper } from "./managed_apps";
 import { PluginInstance } from "./plugin_instance";
@@ -110,7 +109,6 @@ export interface LoggerOptions {
     domain?: string;
     level?: LogLevel;
     file?: string;
-    transport_cache?: any;
 }
 
 export type Logger = winston.Logger;
@@ -119,6 +117,84 @@ export interface ExtendedLoger extends winston.Logger {
     logMessage: (level: LogLevel, message: any[], meta?: any) => void;
 }
 
+const LOGGER_INT_CONSOLE = { debug: (msg: string) => null }
+
+const rotating_streams: Record<string, { ref_count: number, stream: any, kill_timer?: any }> = {};
+function getRotatedStream(filename: string) {
+    if (!rotating_streams[filename]) {
+        const stream = new (winston.transports as any).DailyRotateFile({
+            filename,
+            auditFile: path.join(path.dirname(filename), ".log_audit.json"),
+            datePattern: 'YYYY-MM-DD',
+            // zippedArchive: true,
+            maxSize: '1m',
+            maxFiles: '14',
+        });
+
+        stream.on("finish", () => {
+            LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} CLOSED`);
+        });
+
+        rotating_streams[filename] = { ref_count: 0, stream }
+    }
+
+    const sdef = rotating_streams[filename];
+    if (sdef.kill_timer) {
+        clearTimeout(sdef.kill_timer);
+        LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} RESURECTED`);
+        sdef.kill_timer = null;
+    }
+
+    sdef.ref_count += 1;
+    sdef.kill_timer = null;
+
+    let derefed = false;
+    const dreference = () => {
+        if (derefed) return;
+        LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} DEREF`);
+        derefed = true;
+        sdef.ref_count -= 1;
+        if (sdef.ref_count < 1) {
+            LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} DIED`);
+            const timer = setTimeout(() => {
+                if (sdef.ref_count < 1) {
+                    sdef.stream.close();
+                    delete rotating_streams[filename];
+                    LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} CLOSING`);
+                } else {
+                    LOGGER_INT_CONSOLE.debug(`ROTATING STREAM ${filename} RESURECTED`);
+                }
+            }, 3000);
+            sdef.kill_timer = timer;
+            timer.unref();
+        }
+    }
+
+    return {
+        stream: sdef.stream,
+        dreference,
+    }
+}
+
+import WinstonTransport = require("winston-transport");
+class ForwardTransport extends WinstonTransport {
+    constructor(private readonly backend: ReturnType<typeof getRotatedStream>) {
+        super();
+    }
+
+    close() {
+        this.backend.dreference();
+    }
+
+    log(...rest) {
+        return this.backend.stream.log(...rest);
+    }
+
+    query(...rest) {
+        return this.backend.stream.query(...rest);
+    }
+}
+
 export function createDomainLogger(opts: LoggerOptions) {
     const transports: winston.transport[] = [
         new winston.transports.Console({
@@ -135,20 +211,13 @@ export function createDomainLogger(opts: LoggerOptions) {
             if (!hasExt) filename += ".log";
         }
 
-        const file_transport = cacheOn(opts.transport_cache, filename, () => new (winston.transports as any).DailyRotateFile({
-            filename,
-            auditFile: path.join(path.dirname(filename), ".log_audit.json"),
-            datePattern: 'YYYY-MM-DD',
-            // zippedArchive: true,
-            maxSize: '1m',
-            maxFiles: '14',
-            format: fmt.combine(
-                timed_formatter,
-                fmt.uncolorize({}),
-            ),
-        }));
-
-        transports.push(file_transport);
+        const rs = getRotatedStream(filename);
+        const ftransport = new ForwardTransport(rs);
+        ftransport.format = fmt.combine(
+            timed_formatter,
+            fmt.uncolorize({}),
+        );
+        transports.push(ftransport);
     }
 
     const logger = winston.createLogger({
@@ -207,7 +276,7 @@ export function createDomainLogger(opts: LoggerOptions) {
         return logger.log(level, message.join(' '), meta);
     }
 
-    logger.on("finish", () => ORIGINAL_CONSOLE.log("END", opts.file))
+    // logger.on("close", () => ORIGINAL_CONSOLE.log("END", opts.file))
 
     return logger;
 }
@@ -242,6 +311,7 @@ export function logHVMessage(level: LogLevel, ...rest: any[]) {
 
 export let UNKNOWN_LOGGER = createDomainLogger({ domain: chalk.yellow("???") });
 export function setFallbackLogger(logger: ExtendedLoger) {
+    UNKNOWN_LOGGER?.close();
     UNKNOWN_LOGGER = logger;
 }
 

src/hypervisor/managed_apps.ts

@@ -93,6 +93,14 @@ export abstract class BaseInstance<C, A extends BaseInstanceClient<any> = BaseIn
         this.transitionState('stopping')
         await this.invoke(() => this.cleanups.cleanup())
         this.transitionState('stopped')
+
+        this._logger?.close();
+        this._userSpaceLogger?.close();
+
+        // await new Promise(resolve => {
+        //     this._logger.once("close", resolve)
+        //     // setTimeout(resolve, 5000)
+        // });
     }
 
     logMessage(level: LogLevel, ...rest) {
@@ -105,22 +113,22 @@ export abstract class BaseInstance<C, A extends BaseInstanceClient<any> = BaseIn
 
     protected _updateLogConfig() {
         const { tag: domain, manager, user, ...rest } = this.loggerOptions();
-        const transport_cache = {};
+
+        this._logger?.close();
+        this._userSpaceLogger?.close();
 
         this._logger = createDomainLogger({
             level: "warn",
             domain,
             ...rest,
             ...manager,
-            transport_cache,
         })
 
         this._userSpaceLogger = createDomainLogger({
             level: "debug",
             domain,
             ...rest,
             ...user,
-            transport_cache,
         })
     }
 

yarn.lock

@@ -3653,6 +3653,15 @@ winston-transport@^4.5.0:
     readable-stream "^3.6.0"
     triple-beam "^1.3.0"
 
+winston-transport@^4.7.0:
+  version "4.7.0"
+  resolved "https://registry.yarnpkg.com/winston-transport/-/winston-transport-4.7.0.tgz#e302e6889e6ccb7f383b926df6936a5b781bd1f0"
+  integrity sha512-ajBj65K5I7denzer2IYW6+2bNIVqLGDHqDw3Ow8Ohh+vdW+rv4MZ6eiDvHoKhfJFZ2auyN8byXieDDJ96ViONg==
+  dependencies:
+    logform "^2.3.2"
+    readable-stream "^3.6.0"
+    triple-beam "^1.3.0"
+
 winston@^3.8.2:
   version "3.8.2"
   resolved "https://registry.yarnpkg.com/winston/-/winston-3.8.2.tgz#56e16b34022eb4cff2638196d9646d7430fdad50"