From 74ceb2fa1b1dfcda0d5eaabd2da99e4c65a78cb2 Mon Sep 17 00:00:00 2001 From: KernelDeimos <7225168+KernelDeimos@users.noreply.github.com> Date: Tue, 7 Oct 2025 14:01:45 -0400 Subject: [PATCH] devex: move more init logs to debug Removes init/construct logs, moves many boot logs to debug level, introduces debug level in BootLogger, moves "CONFIGURATION MUTATED AT RUNTIME" message to debug level and allows config.js to output logs to the standard logger in context. --- src/backend/doc/extensions/builtins/data.md | 2 +- src/backend/src/Kernel.js | 2 +- src/backend/src/boot/BootLogger.js | 4 ++++ src/backend/src/boot/RuntimeEnvironment.js | 12 +++++----- src/backend/src/config.js | 23 +++++++++++++++++-- src/backend/src/config/ConfigLoader.js | 2 +- .../src/extension/RuntimeModuleRegistry.js | 1 - src/backend/src/modules/core/LogService.js | 4 ++-- .../src/modules/core/ParameterService.js | 2 +- .../src/modules/selfhosted/MinLogService.js | 3 ++- src/backend/src/services/CommandService.js | 2 +- src/backend/src/services/Container.js | 3 --- .../repositories/DBKVStore/DBKVStore.mjs | 2 ++ src/backend/src/util/context.js | 5 ++-- 14 files changed, 45 insertions(+), 22 deletions(-) diff --git a/src/backend/doc/extensions/builtins/data.md b/src/backend/doc/extensions/builtins/data.md index 351efe54..cb2611f9 100644 --- a/src/backend/doc/extensions/builtins/data.md +++ b/src/backend/doc/extensions/builtins/data.md @@ -85,7 +85,7 @@ This key will persist for 20 minutes, even if the server restarts. ```javascript kv.expire({ key: 'some-key', - ttl: 1000 * 60 * 20, // 1 minute + ttl: 1000 * 60 * 20, // 20 minutes }); ``` diff --git a/src/backend/src/Kernel.js b/src/backend/src/Kernel.js index 02a1d3c5..0595dadd 100644 --- a/src/backend/src/Kernel.js +++ b/src/backend/src/Kernel.js @@ -569,7 +569,7 @@ class Kernel extends AdvancedBase { }; const data_json = JSON.stringify(data); - console.log('WRITING TO', path_.join(mod_path, 'package.json')); + this.bootLogger.debug('WRITING TO: ' + path_.join(mod_path, 'package.json')); await fs.promises.writeFile(path_.join(mod_path, 'package.json'), data_json); return data; diff --git a/src/backend/src/boot/BootLogger.js b/src/backend/src/boot/BootLogger.js index ff2819ef..0cad37dc 100644 --- a/src/backend/src/boot/BootLogger.js +++ b/src/backend/src/boot/BootLogger.js @@ -28,6 +28,10 @@ class BootLogger { ...args, ); } + debug (...args) { + if ( ! process.env.DEBUG ) return; + console.log('\x1B[37m[BOOT/DEBUG]', ...args, '\x1B[0m'); + } error (...args) { console.log( '\x1B[31;1m[BOOT/ERROR]\x1B[0m', diff --git a/src/backend/src/boot/RuntimeEnvironment.js b/src/backend/src/boot/RuntimeEnvironment.js index 102e56db..be547202 100644 --- a/src/backend/src/boot/RuntimeEnvironment.js +++ b/src/backend/src/boot/RuntimeEnvironment.js @@ -266,7 +266,7 @@ class RuntimeEnvironment extends AdvancedBase { generated_values.private_uid_secret = crypto.randomBytes(24).toString('hex'); generated_values.private_uid_namespace = crypto.randomUUID(); if ( using_config ) { - this.logger.info( + this.logger.debug( `Overwriting ${quot(using_config)} because ` + `${hl('--overwrite-config')} is set` ); @@ -302,7 +302,7 @@ class RuntimeEnvironment extends AdvancedBase { let config_to_load = 'config.json'; if ( process.env.PUTER_CONFIG_PROFILE ) { - this.logger.info( + this.logger.debug( hl('PROFILE') + ' ' + quot(process.env.PUTER_CONFIG_PROFILE) + ' ' + `because $PUTER_CONFIG_PROFILE is set` @@ -330,7 +330,7 @@ class RuntimeEnvironment extends AdvancedBase { if ( ! config.config_name ) { throw new Error('config_name is required'); } - this.logger.info(hl(`config name`) + ` ${quot(config.config_name)}`); + this.logger.debug(hl(`config name`) + ` ${quot(config.config_name)}`); const mod_paths = []; environment.mod_paths = mod_paths; @@ -359,18 +359,18 @@ class RuntimeEnvironment extends AdvancedBase { get_first_suitable_path_ (meta, paths, last_checks) { for ( const entry of paths ) { const checks = [...(entry.checks ?? []), ...last_checks]; - this.logger.info( + this.logger.debug( `Checking path ${quot(entry.label ?? entry.path)} for ${meta.pathFor}...` ); let checks_pass = true; for ( const check of checks ) { - this.logger.info( + this.logger.debug( `-> doing ${quot(check.name)} on path ${quot(entry.path)}...` ); const result = check(entry); if ( result === false ) { - this.logger.info( + this.logger.debug( `-> ${quot(check.name)} doesn't like this path` ); checks_pass = false; diff --git a/src/backend/src/config.js b/src/backend/src/config.js index 3bf55bfc..617fbadb 100644 --- a/src/backend/src/config.js +++ b/src/backend/src/config.js @@ -123,6 +123,7 @@ config.legacy_token_migrate = true; // === OS Information === const os = require('os'); const fs = require('fs'); +const { Context, context_config } = require('./util/context'); config.os = {}; config.os.platform = os.platform(); @@ -244,9 +245,10 @@ const config_pointer = {}; // confusing issues, so we log any time this happens config_to_export = new Proxy(config_to_export, { set: (target, prop, value, receiver) => { - console.log( + const logger = Context.get('logger', { allow_fallback: true }); + logger.debug( '\x1B[36;1mCONFIGURATION MUTATED AT RUNTIME\x1B[0m', - prop, 'to', value + { prop, value }, ); target[prop] = value; return true; @@ -254,4 +256,21 @@ const config_pointer = {}; }) } +// We configure the behavior in context.js from here to avoid a cyclic +// mutual dependency between it and this file. +// +// Previously we had this: +// context --(are we in "dev" environment?)--> config +// +// So we could not add this: +// config --(where is the logger?) --> context +// +// So instead we now have: +// config --(read this property to determine 'strict' mode)--> context +// config --(where is the logger?) --> context +// +Object.defineProperty(context_config, 'strict', { + get: () => config_to_export.env === 'dev', +}); + module.exports = config_to_export; diff --git a/src/backend/src/config/ConfigLoader.js b/src/backend/src/config/ConfigLoader.js index c49387b5..12958125 100644 --- a/src/backend/src/config/ConfigLoader.js +++ b/src/backend/src/config/ConfigLoader.js @@ -47,7 +47,7 @@ class ConfigLoader extends AdvancedBase { delete config_values.$requires; this.apply_requires(this.path, config_list, { by: name }); } - this.logger.info( + this.logger.debug( `Applying config: ${path_.relative(this.path, config_path)}` + (meta.by ? ` (required by ${meta.by})` : '') ); diff --git a/src/backend/src/extension/RuntimeModuleRegistry.js b/src/backend/src/extension/RuntimeModuleRegistry.js index fe28c844..59ac1a90 100644 --- a/src/backend/src/extension/RuntimeModuleRegistry.js +++ b/src/backend/src/extension/RuntimeModuleRegistry.js @@ -16,7 +16,6 @@ class RuntimeModuleRegistry extends AdvancedBase { if ( this.modules_.hasOwnProperty(uniqueName) ) { throw new Error(`duplicate runtime module: ${uniqueName}`); } - console.log(`registering with name... ${uniqueName}`); this.modules_[uniqueName] = extensionModule; extensionModule.runtimeModuleRegistry = this; } diff --git a/src/backend/src/modules/core/LogService.js b/src/backend/src/modules/core/LogService.js index bfd2a8ea..1a6f9643 100644 --- a/src/backend/src/modules/core/LogService.js +++ b/src/backend/src/modules/core/LogService.js @@ -21,10 +21,10 @@ const logSeverity = (ordinal, label, esc, winst) => ({ ordinal, label, esc, wins const LOG_LEVEL_ERRO = logSeverity(0, 'ERRO', '31;1', 'error'); const LOG_LEVEL_WARN = logSeverity(1, 'WARN', '33;1', 'warn'); const LOG_LEVEL_INFO = logSeverity(2, 'INFO', '36;1', 'info'); -const LOG_LEVEL_TICK = logSeverity(10, 'TICK', '34;1', 'info'); -const LOG_LEVEL_DEBU = logSeverity(4, 'DEBU', '37;1', 'debug'); const LOG_LEVEL_NOTICEME = logSeverity(3, 'NOTICE_ME', '33;1', 'error'); const LOG_LEVEL_SYSTEM = logSeverity(3, 'SYSTEM', '33;1', 'system'); +const LOG_LEVEL_DEBU = logSeverity(4, 'DEBU', '37', 'debug'); +const LOG_LEVEL_TICK = logSeverity(10, 'TICK', '34;1', 'info'); const winston = require('winston'); const { Context } = require('../../util/context'); diff --git a/src/backend/src/modules/core/ParameterService.js b/src/backend/src/modules/core/ParameterService.js index 8f26d994..cbd9d536 100644 --- a/src/backend/src/modules/core/ParameterService.js +++ b/src/backend/src/modules/core/ParameterService.js @@ -47,7 +47,7 @@ class ParameterService extends BaseService { createParameters(serviceName, parameters, opt_instance) { for (const parameter of parameters) { - this.log.info(`registering parameter ${serviceName}:${parameter.id}`); + this.log.debug(`registering parameter ${serviceName}:${parameter.id}`); this.parameters_.push(new Parameter({ ...parameter, id: `${serviceName}:${parameter.id}`, diff --git a/src/backend/src/modules/selfhosted/MinLogService.js b/src/backend/src/modules/selfhosted/MinLogService.js index d00fb70b..0d5b7581 100644 --- a/src/backend/src/modules/selfhosted/MinLogService.js +++ b/src/backend/src/modules/selfhosted/MinLogService.js @@ -7,7 +7,7 @@ class MinLogService extends BaseService { ` _construct () { - this.on = true; + this.on = false; this.visible = new Set(); this.widget_ = null; @@ -44,6 +44,7 @@ class MinLogService extends BaseService { if ( ! svc_devConsole ) return; this.widget_ = () => { + if ( ! this.on ) return ['minlog is off']; const lines = [ `\x1B[31;1mSome logs hidden! Type minlog:off to see all logs.\x1B[0m` ]; diff --git a/src/backend/src/services/CommandService.js b/src/backend/src/services/CommandService.js index e1c5d5ce..20ff47bd 100644 --- a/src/backend/src/services/CommandService.js +++ b/src/backend/src/services/CommandService.js @@ -129,7 +129,7 @@ class CommandService extends BaseService { registerCommands(serviceName, commands) { if ( ! this.log ) process.exit(1); for (const command of commands) { - this.log.info(`registering command ${serviceName}:${command.id}`); + this.log.debug(`registering command ${serviceName}:${command.id}`); this.commands_.push(new Command({ ...command, id: `${serviceName}:${command.id}`, diff --git a/src/backend/src/services/Container.js b/src/backend/src/services/Container.js index 4214d2ac..79d23a49 100644 --- a/src/backend/src/services/Container.js +++ b/src/backend/src/services/Container.js @@ -175,18 +175,15 @@ class Container { async init () { for ( const k in this.instances_ ) { if ( ! this.instances_[k]._run_as_early_as_possible ) continue; - this.logger.info(`very early hooks for ${k}`); await this.instances_[k].run_as_early_as_possible(); } for ( const k in this.instances_ ) { - this.logger.info(`constructing ${k}`); await this.instances_[k].construct(); } const init_failures = []; const promises = []; const PARALLEL = config.experimental_parallel_init; for ( const k in this.instances_ ) { - this.logger.info(`initializing ${k}`); try { if ( PARALLEL ) promises.push(this.instances_[k].init()); else await this.instances_[k].init(); diff --git a/src/backend/src/services/repositories/DBKVStore/DBKVStore.mjs b/src/backend/src/services/repositories/DBKVStore/DBKVStore.mjs index aeefc75d..db00a00f 100644 --- a/src/backend/src/services/repositories/DBKVStore/DBKVStore.mjs +++ b/src/backend/src/services/repositories/DBKVStore/DBKVStore.mjs @@ -285,6 +285,7 @@ export class DBKVStore { for ( const [path, amount] of Object.entries(pathAndAmountMap) ){ const pathParts = path.split('.'); let obj = currVal; + if ( obj === null ) continue; for ( let i = 0; i < pathParts.length - 1; i++ ){ const part = pathParts[i]; if ( !obj[part] ){ @@ -295,6 +296,7 @@ export class DBKVStore { } obj = obj[part]; } + if ( obj === null ) continue; const lastPart = pathParts[pathParts.length - 1]; if ( !obj[lastPart] ){ obj[lastPart] = 0; diff --git a/src/backend/src/util/context.js b/src/backend/src/util/context.js index 733448bc..57e42586 100644 --- a/src/backend/src/util/context.js +++ b/src/backend/src/util/context.js @@ -17,7 +17,7 @@ * along with this program. If not, see . */ const { AsyncLocalStorage } = require('async_hooks'); -const config = require('../config'); +const context_config = {}; class Context { static USE_NAME_FALLBACK = {}; @@ -46,7 +46,7 @@ class Context { static get (k, { allow_fallback } = {}) { let x = this.contextAsyncLocalStorage.getStore()?.get('context'); if ( ! x ) { - if ( config.env === 'dev' && ! allow_fallback ) { + if ( context_config.strict && ! allow_fallback ) { throw new Error( 'FAILED TO GET THE CORRECT CONTEXT' ); @@ -246,4 +246,5 @@ class ContextExpressMiddleware { module.exports = { Context, ContextExpressMiddleware, + context_config, };