diff --git a/package-lock.json b/package-lock.json index fc0e82d3..eff2bf9f 100644 --- a/package-lock.json +++ b/package-lock.json @@ -6,13 +6,14 @@ "packages": { "": { "name": "puter.com", - "version": "1.0.0", + "version": "2.3.0", "hasInstallScript": true, "license": "AGPL-3.0-only", "workspaces": [ "packages/*" ], "dependencies": { + "json-colorizer": "^3.0.1", "uuid": "^9.0.1" }, "devDependencies": { @@ -7956,6 +7957,19 @@ "integrity": "sha512-4bV5BfR2mqfQTJm+V5tPPdf+ZpuhiIvTuAB5g8kcrXOZpTT/QwwVRWBywX1ozr6lEuPdbHxwaJlm9G6mI2sfSQ==", "dev": true }, + "node_modules/json-colorizer": { + "version": "3.0.1", + "resolved": "https://registry.npmjs.org/json-colorizer/-/json-colorizer-3.0.1.tgz", + "integrity": "sha512-4YyRAbD6eHeRnJD9vo0zjiU5fyY9QR6T+iYuH5DpO0XPThKWozpD4MaeY/8nLZIkHC3yEQMFLL+6P94E+JekDw==", + "dependencies": { + "colorette": "^2.0.20" + } + }, + "node_modules/json-colorizer/node_modules/colorette": { + "version": "2.0.20", + "resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz", + "integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==" + }, "node_modules/json-parse-even-better-errors": { "version": "2.3.1", "resolved": "https://registry.npmjs.org/json-parse-even-better-errors/-/json-parse-even-better-errors-2.3.1.tgz", diff --git a/package.json b/package.json index 5bac1de7..2851e5f5 100644 --- a/package.json +++ b/package.json @@ -43,6 +43,7 @@ ] }, "dependencies": { + "json-colorizer": "^3.0.1", "uuid": "^9.0.1" } } diff --git a/packages/backend/src/CoreModule.js b/packages/backend/src/CoreModule.js index 3de3ff73..d28ffe88 100644 --- a/packages/backend/src/CoreModule.js +++ b/packages/backend/src/CoreModule.js @@ -222,6 +222,9 @@ const install = async ({ services, app }) => { const { DetailProviderService } = require('./services/DetailProviderService'); services.registerService('whoami', DetailProviderService); + + const { DevTODService } = require('./services/DevTODService'); + services.registerService('__dev-tod', DevTODService); } const install_legacy = async ({ services }) => { diff --git a/packages/backend/src/Kernel.js b/packages/backend/src/Kernel.js index b92ebb9b..920897eb 100644 --- a/packages/backend/src/Kernel.js +++ b/packages/backend/src/Kernel.js @@ -42,6 +42,7 @@ class Kernel extends AdvancedBase { // Temporary logger for boot process; // LoggerService will be initialized in app.js const bootLogger = new BootLogger(); + this.bootLogger = bootLogger; // Determine config and runtime locations const runtimeEnv = new RuntimeEnvironment({ @@ -83,13 +84,14 @@ class Kernel extends AdvancedBase { // === START: Initialize Service Registry === const { Container } = require('./services/Container'); - const services = new Container(); + const services = new Container({ logger: this.bootLogger }); this.services = services; // app.set('services', services); const root_context = Context.create({ services, config, + logger: this.bootLogger, }, 'app'); globalThis.root_context = root_context; diff --git a/packages/backend/src/filesystem/FSNodeContext.js b/packages/backend/src/filesystem/FSNodeContext.js index c5ae737c..daf1a9e4 100644 --- a/packages/backend/src/filesystem/FSNodeContext.js +++ b/packages/backend/src/filesystem/FSNodeContext.js @@ -208,8 +208,7 @@ module.exports = class FSNodeContext { return; } - // NOTE: commented out for now because it's too verbose - this.log.info('fetching entry: ' + this.selector.describe(true)); + this.log.info('fetching entry: ' + this.selector.describe()); // All services at the top (DEVLOG-401) const { traceService, @@ -239,9 +238,6 @@ module.exports = class FSNodeContext { const callback = (resolver) => { // NOTE: commented out for now because it's too verbose - this.log.noticeme(`resolved by ${resolver}`, { - debug: fetch_entry_options.debug, - }); resolved = true; detachables.detach(); rslv(); @@ -273,13 +269,10 @@ module.exports = class FSNodeContext { } }); - this.log.debug('got past the promise') - if ( resourceService.getResourceInfo(this.uid) ) { entry = await fsEntryService.get(this.uid, fetch_entry_options); this.log.debug('got an entry from the future'); } else { - this.log.debug('resource is already free'); entry = await fsEntryFetcher.find( this.selector, fetch_entry_options); } @@ -734,7 +727,6 @@ module.exports = class FSNodeContext { this.log.warn('null app'); continue; } - this.log.debug('app?', { value: app }); delete app.owner_user_id; } } diff --git a/packages/backend/src/filesystem/storage/ResourceService.js b/packages/backend/src/filesystem/storage/ResourceService.js index f698cebb..64bfca49 100644 --- a/packages/backend/src/filesystem/storage/ResourceService.js +++ b/packages/backend/src/filesystem/storage/ResourceService.js @@ -74,7 +74,7 @@ class ResourceService { } free (uid) { - this.log.info(`freeing`, uid); + this.log.info(`freeing`, { uid }); const entry = this.uidToEntry[uid]; if ( ! entry ) return; delete this.uidToEntry[uid]; diff --git a/packages/backend/src/om/entitystorage/ESBuilder.js b/packages/backend/src/om/entitystorage/ESBuilder.js index d4525db8..96d43efd 100644 --- a/packages/backend/src/om/entitystorage/ESBuilder.js +++ b/packages/backend/src/om/entitystorage/ESBuilder.js @@ -25,16 +25,13 @@ class ESBuilder { let last_was_cons = false; while ( ! last_was_cons ) { const item = stack.pop(); - console.log('item?', item) if ( typeof item === 'function' ) { - console.log('last was cons') last_was_cons = true; } args.unshift(item); } const cls = args.shift(); - console.log('cls?', cls) head = new cls({ ...(args[0] ?? {}), ...(head ? { upstream: head } : {}), @@ -55,7 +52,6 @@ class ESBuilder { // Print the classes in order let current = head; while ( current ) { - console.log(current.constructor.name); current = current.upstream; } diff --git a/packages/backend/src/om/entitystorage/MaxLimitES.js b/packages/backend/src/om/entitystorage/MaxLimitES.js index 46dbfc2e..4656cae1 100644 --- a/packages/backend/src/om/entitystorage/MaxLimitES.js +++ b/packages/backend/src/om/entitystorage/MaxLimitES.js @@ -35,8 +35,6 @@ class MaxLimitES extends BaseES { options.limit = limit; - console.log('SELECT options (1)', options); - return await this.upstream.select(options); } }; diff --git a/packages/backend/src/routers/filesystem_api/batch/all.js b/packages/backend/src/routers/filesystem_api/batch/all.js index 7438334d..b367ed52 100644 --- a/packages/backend/src/routers/filesystem_api/batch/all.js +++ b/packages/backend/src/routers/filesystem_api/batch/all.js @@ -141,17 +141,13 @@ module.exports = eggspress('/batch', { return; } - // log fileinfos - console.log('HERE ARE THE FILEINFOS'); - console.log(JSON.stringify(fileinfos, null, 2)); - const indexes_to_remove = []; for ( let i=0 ; i < pending_operations.length ; i++ ) { const op_spec = pending_operations[i]; if ( ! operation_requires_file(op_spec) ) { indexes_to_remove.push(i); - console.log(`EXEUCING OP ${op_spec.op}`) + log.info(`executing ${op_spec.op}`); response_promises.push( batch_exe.exec_op(req, op_spec) ); @@ -231,7 +227,6 @@ module.exports = eggspress('/batch', { batch_widget.ic = pending_operations.length; on_first_file(); } - console.log(`GOT A FILE`) if ( fileinfos.length == 0 ) { request_errors_.push( @@ -256,7 +251,6 @@ module.exports = eggspress('/batch', { stream.on('end', () => { stream.destroy(); }); - console.log('DISCARDED A FILE'); return; } @@ -269,7 +263,7 @@ module.exports = eggspress('/batch', { }); busboy.on('close', () => { - console.log('GOT DONE READING'); + log.info('busboy close'); still_reading.resolve(); }); @@ -284,11 +278,11 @@ module.exports = eggspress('/batch', { return; } - log.noticeme('WAITING ON OPERATIONS') + log.info('waiting for operations') let responsePromises = response_promises; // let responsePromises = batch_exe.responsePromises; const results = await Promise.all(responsePromises); - log.noticeme('RESPONSE GETS SENT!'); + log.info('sending response'); frame.done(); diff --git a/packages/backend/src/routers/whoami.js b/packages/backend/src/routers/whoami.js index 02846aa5..47c96e10 100644 --- a/packages/backend/src/routers/whoami.js +++ b/packages/backend/src/routers/whoami.js @@ -41,8 +41,6 @@ const WHOAMI_GET = eggspress('/whoami', { const is_user = actor.type instanceof UserActorType; - console.log('user?', req.user); - // send user object const details = { username: req.user.username, diff --git a/packages/backend/src/services/AppInformationService.js b/packages/backend/src/services/AppInformationService.js index 9d928b2b..b473de12 100644 --- a/packages/backend/src/services/AppInformationService.js +++ b/packages/backend/src/services/AppInformationService.js @@ -170,14 +170,6 @@ class AppInformationService { [origin + '%'] ))[0]; - if ( app.uid === 'app-eeec9a28-0eb1-5b63-a2dd-b99a8a3cf4c3' ) { - console.log('app?', app); - console.log('REFERRAL COUNT', referral_count, { - sql, - index_url: app.index_url, - }); - } - kv.set(key_referral_count, referral_count); } diff --git a/packages/backend/src/services/Container.js b/packages/backend/src/services/Container.js index 341aa387..d496ffec 100644 --- a/packages/backend/src/services/Container.js +++ b/packages/backend/src/services/Container.js @@ -17,12 +17,14 @@ * along with this program. If not, see . */ const config = require("../config"); +const { Context } = require("../util/context"); const { CompositeError } = require("../util/errorutil"); const { TeePromise } = require("../util/promise"); // 17 lines of code instead of an entire dependency-injection framework class Container { - constructor () { + constructor ({ logger }) { + this.logger = logger; this.instances_ = {}; this.ready = new TeePromise(); } @@ -83,12 +85,12 @@ class Container { async init () { for ( const k in this.instances_ ) { - console.log(`constructing ${k}`); + this.logger.info(`constructing ${k}`); await this.instances_[k].construct(); } const init_failures = []; for ( const k in this.instances_ ) { - console.log(`initializing ${k}`); + this.logger.info(`initializing ${k}`); try { await this.instances_[k].init(); } catch (e) { diff --git a/packages/backend/src/services/DevConsoleService.js b/packages/backend/src/services/DevConsoleService.js index 9e9d870c..be0afada 100644 --- a/packages/backend/src/services/DevConsoleService.js +++ b/packages/backend/src/services/DevConsoleService.js @@ -57,6 +57,7 @@ class DevConsoleService extends BaseService { // if a widget throws an error we MUST remove it; // it's probably a stack overflow because it's printing. const to_remove = []; + let positions = []; for ( const w of this.widgets ) { let output; try { output = w(); @@ -66,8 +67,43 @@ class DevConsoleService extends BaseService { continue; } output = Array.isArray(output) ? output : [output]; + positions.push([this.static_lines.length, output.length]); this.static_lines.push(...output); } + + const DESIRED_MIN_OUT = 10; + const size_ok = () => + process.stdout.rows - DESIRED_MIN_OUT > this.static_lines.length; + let n_hidden = 0; + for ( let i = this.widgets.length-1 ; i >= 0 ; i-- ) { + if ( size_ok() ) break; + const w = this.widgets[i]; + if ( ! w.unimportant ) continue; + n_hidden++; + const [start, length] = positions[i]; + this.static_lines.splice(start, length); + // update positions + for ( let j = i ; j < positions.length ; j++ ) { + positions[j][0] -= length; + } + } + for ( let i = this.widgets.length-1 ; i >= 0 ; i-- ) { + if ( size_ok() ) break; + n_hidden++; + const w = this.widgets[i]; + const [start, length] = positions[i]; + this.static_lines.splice(start, length); + } + if ( n_hidden && size_ok() ) { + this.static_lines.push( + `\x1B[33m` + + this.generateEnd( + `[ ${n_hidden} widget${n_hidden === 1 ? '' : 's'} hidden ]` + ) + + `\x1B[0m` + ); + } + if (!this.arrays_equal(initialOutput, this.static_lines)) { this.mark_updated(); // Update only if outputs have changed } diff --git a/packages/backend/src/services/DevTODService.js b/packages/backend/src/services/DevTODService.js new file mode 100644 index 00000000..ed3a84c5 --- /dev/null +++ b/packages/backend/src/services/DevTODService.js @@ -0,0 +1,86 @@ +const { surrounding_box } = require("../fun/dev-console-ui-utils"); +const BaseService = require("./BaseService"); + +const SOURCE_CODE_TIPS = ` + Most services are registered in CoreModule.js + Boot sequence events are different from service events + ExpectationService exists to ensure Puter doesn't miss a step + Services are composable; StrategyService is a good example + API endpoints should be on a separate origin in production + There is some limited query-building in packages/backend/src/om +`; + +const tips = ( + // CLI tips + ` + Type \`help\` to see a list of commands + \`logs:show\` toggles log output; useful when typing long commands + \`logs:indent \` toggles indentation for some logs + \`lock:locks \` will list any active mutex locks + `, + // Source code tips + ` + Most services are registered in CoreModule.js + Boot sequence events are different from service events + ExpectationService exists to ensure Puter doesn't miss a step + Services are composable; StrategyService is a good example + API endpoints should be on a separate origin in production + These messages come from DevTODService.js + ` +).split('\n').map((line) => line.trim()) + .filter((line) => line.length) + .map(tip => { + const lines = []; + const WRAP = process.stdout.columns || 50; + while ( tip.length ) { + lines.push(tip.substring(0, WRAP)); + tip = tip.substring(WRAP); + } + return lines; + }) + +class DevTODService extends BaseService { + async _init () { + const svc_commands = this.services.get('commands'); + this._register_commands(svc_commands); + } + async ['__on_boot.consolidation'] () { + const random_tip = tips[Math.floor(Math.random() * tips.length)]; + this.tod_widget = () => { + const lines = [ + "", + "\x1B[1mTip of the Day\x1B[0m", + ...random_tip, + "Type tod:dismiss to un-stick this message", + "", + ]; + surrounding_box('33;1', lines); + return lines; + } + + this.tod_widget.unimportant = true; + + const svc_devConsole = this.services.get('dev-console', { optional: true }); + if ( ! svc_devConsole ) return; + svc_devConsole.add_widget(this.tod_widget); + } + + _register_commands (commands) { + commands.registerCommands('tod', [ + { + id: 'dismiss', + description: 'Dismiss the startup message', + handler: async (_, log) => { + const svc_devConsole = this.services.get('dev-console', { optional: true }); + if ( ! svc_devConsole ) return; + svc_devConsole.remove_widget(this.tod_widget); + const lines = this.tod_widget(); + for ( const line of lines ) log.log(line); + this.tod_widget = null; + } + } + ]); + } +} + +module.exports = { DevTODService }; \ No newline at end of file diff --git a/packages/backend/src/services/DevWatcherService.js b/packages/backend/src/services/DevWatcherService.js index d8fcdae3..aafc62e3 100644 --- a/packages/backend/src/services/DevWatcherService.js +++ b/packages/backend/src/services/DevWatcherService.js @@ -54,12 +54,18 @@ class DevWatcherService extends BaseService { // but hey at least we have this convenient event listener. async ['__on_ready.webserver'] () { const { root, commands } = this.args; + let promises = []; for ( const entry of commands ) { const { directory } = entry; const fullpath = this.modules.path.join( root, directory); - this.start_({ ...entry, fullpath }); + promises.push(this.start_({ ...entry, fullpath })); } + await Promise.all(promises); + + // It's difficult to tell when webpack is "done" its first + // run so we just wait a bit before we say we're ready. + await new Promise((resolve) => setTimeout(resolve, 3000)); } log_ (name, isErr, line) { diff --git a/packages/backend/src/services/EmailService.js b/packages/backend/src/services/EmailService.js index c328df5d..207dc847 100644 --- a/packages/backend/src/services/EmailService.js +++ b/packages/backend/src/services/EmailService.js @@ -161,7 +161,6 @@ class Emailservice extends BaseService { } _init () { - console.log('the config', this.config); } get_transport_ () { diff --git a/packages/backend/src/services/WebServerService.js b/packages/backend/src/services/WebServerService.js index dcd136ce..6f941979 100644 --- a/packages/backend/src/services/WebServerService.js +++ b/packages/backend/src/services/WebServerService.js @@ -57,6 +57,7 @@ class WebServerService extends BaseService { const services = this.services; await services.emit('start.webserver'); await services.emit('ready.webserver'); + this.print_puter_logo_(); } async ['__on_start.webserver'] () { @@ -132,7 +133,7 @@ class WebServerService extends BaseService { const lines = [ "", `Puter is now live at: ${link}`, - `Type web:dismiss to dismiss this message`, + `Type web:dismiss to un-stick this message`, "", ]; const lengths = [ @@ -149,8 +150,6 @@ class WebServerService extends BaseService { if ( svc_devConsole ) svc_devConsole.add_widget(this.startup_widget); } - this.print_puter_logo_(); - server.timeout = 1000 * 60 * 60 * 2; // 2 hours server.requestTimeout = 1000 * 60 * 60 * 2; // 2 hours server.headersTimeout = 1000 * 60 * 60 * 2; // 2 hours diff --git a/packages/backend/src/services/auth/ACLService.js b/packages/backend/src/services/auth/ACLService.js index f0b7d7dc..8b4d761e 100644 --- a/packages/backend/src/services/auth/ACLService.js +++ b/packages/backend/src/services/auth/ACLService.js @@ -100,8 +100,8 @@ class ACLService extends BaseService { `fs:${await perm_fsNode.get('uid')}:${mode}` ); if ( perm ) { - console.log('TRUE BECAUSE PERMISSION', perm) - console.log(`fs:${await perm_fsNode.get('uid')}:${mode}`) + // console.log('TRUE BECAUSE PERMISSION', perm) + // console.log(`fs:${await perm_fsNode.get('uid')}:${mode}`) return true; } } diff --git a/packages/backend/src/services/drivers/implementations/BaseImplementation.js b/packages/backend/src/services/drivers/implementations/BaseImplementation.js index af1a5ac9..7c6b4c56 100644 --- a/packages/backend/src/services/drivers/implementations/BaseImplementation.js +++ b/packages/backend/src/services/drivers/implementations/BaseImplementation.js @@ -109,8 +109,6 @@ class BaseImplementation extends AdvancedBase { sla_key ); - console.log('SLA KEY', sla_key, 'USER KEY', user_is_verified ? 'user_verified' : 'user_unverified'); - const user_method_key = `actor:${actor.uid}:${method_key}`; // short-term rate limiting diff --git a/packages/backend/src/services/runtime-analysis/LogService.js b/packages/backend/src/services/runtime-analysis/LogService.js index 4c5e3dc2..dac11194 100644 --- a/packages/backend/src/services/runtime-analysis/LogService.js +++ b/packages/backend/src/services/runtime-analysis/LogService.js @@ -119,28 +119,40 @@ class LogContext { } let log_epoch = Date.now(); -const stringify_log_entry = ({ log_lvl, crumbs, message, fields, objects }) => { - let m = `\x1B[${log_lvl.esc}m[${log_lvl.label}\x1B[0m`; +const stringify_log_entry = ({ prefix, log_lvl, crumbs, message, fields, objects }) => { + const { colorize } = require('json-colorizer'); + + let lines = [], m; + const lf = () => { + if ( ! m ) return; + lines.push(m); + m = ''; + } + + m = prefix ? `${prefix} ` : ''; + m += `\x1B[${log_lvl.esc}m[${log_lvl.label}\x1B[0m`; for ( const crumb of crumbs ) { m += `::${crumb}`; } m += `\x1B[${log_lvl.esc}m]\x1B[0m`; - for ( const k in fields ) { - if ( k === 'timestamp' ) continue; - let v; try { - v = JSON.stringify(fields[k]); - } catch (e) { - v = '' + fields[k]; - } - m += ` ${k}=${v}`; - } if ( fields.timestamp ) { // display seconds since logger epoch const n = (fields.timestamp - log_epoch) / 1000; m += ` (${n.toFixed(3)}s)`; } - m += ` ${message}`; - return m; + m += ` ${message} `; + lf(); + for ( const k in fields ) { + if ( k === 'timestamp' ) continue; + let v; try { + v = colorize(JSON.stringify(fields[k])); + } catch (e) { + v = '' + fields[k]; + } + m += ` \x1B[1m${k}:\x1B[0m ${v}`; + lf(); + } + return lines.join('\n'); }; @@ -148,6 +160,7 @@ class DevLogger { // TODO: this should eventually delegate to winston logger constructor (log, opt_delegate) { this.log = log; + this.off = false; if ( opt_delegate ) { this.delegate = opt_delegate; @@ -159,11 +172,15 @@ class DevLogger { log_lvl, crumbs, message, fields, objects, ); } + + if ( this.off ) return; + const ld = Context.get('logdent', { allow_fallback: true }) const prefix = globalThis.dev_console_indent_on ? Array(ld ?? 0).fill(' ').join('') : ''; - this.log(prefix + stringify_log_entry({ + this.log(stringify_log_entry({ + prefix, log_lvl, crumbs, message, fields, objects, })); } @@ -264,6 +281,26 @@ class LogService extends BaseService { register_log_middleware (callback) { this.loggers[0] = new CustomLogger(this.loggers[0], callback); } + ['__on_boot.consolidation'] () { + const commands = this.services.get('commands'); + commands.registerCommands('logs', [ + { + id: 'show', + description: 'toggle log output', + handler: async (args, log) => { + this.devlogger && (this.devlogger.off = ! this.devlogger.off); + } + }, + { + id: 'indent', + description: 'toggle log indentation', + handler: async (args, log) => { + globalThis.dev_console_indent_on = + ! globalThis.dev_console_indent_on; + } + } + ]); + } async _init () { const config = this.global_config; @@ -312,6 +349,8 @@ class LogService extends BaseService { logger = config.flag_no_logs // useful for profiling ? new NullLogger() : new DevLogger(console.log.bind(console), logger); + + this.devlogger = logger; } logger = new TimestampLogger(logger); @@ -321,7 +360,7 @@ class LogService extends BaseService { this.loggers.push(logger); - this.output_lvl = LOG_LEVEL_DEBU; + this.output_lvl = LOG_LEVEL_INFO; if ( config.logger ) { // config.logger.level is a string, e.g. 'debug' @@ -349,6 +388,7 @@ class LogService extends BaseService { }); this.services.logger = this.create('services-container'); + globalThis.root_context.set('logger', this.create('root-context')); } create (prefix, fields = {}) { diff --git a/packages/backend/src/services/sla/MonthlyUsageService.js b/packages/backend/src/services/sla/MonthlyUsageService.js index e38a146e..5705ff89 100644 --- a/packages/backend/src/services/sla/MonthlyUsageService.js +++ b/packages/backend/src/services/sla/MonthlyUsageService.js @@ -43,7 +43,6 @@ class MonthlyUsageService extends BaseService { year, month, key, actor.type.user.id, maybe_app_id, JSON.stringify(extra), ...this.db.case({ mysql: [JSON.stringify(extra)], otherwise: [] }), ] - console.log('VALS', vals); // UPSERT increment count try {