A4 (#85)

* removed dayjs, debuggified winston, removed bundledDependencies

* this is a good commit

* bump to latest @lando/prepare-release-action@v3

* fix tests

* fix tests part 2

.github/workflows/pr-core-tests.yml

@@ -58,7 +58,7 @@ jobs:
       - name: Install dependencies
         run: npm clean-install --prefer-offline --frozen-lockfile
       - name: Bundle Deps
-        uses: lando/prepare-release-action@v2
+        uses: lando/prepare-release-action@v3
         with:
           lando-plugin: true
           version: dev

.github/workflows/pr-plugin-tests.yml

@@ -60,7 +60,7 @@ jobs:
       - name: Install dependencies
         run: npm clean-install --prefer-offline --frozen-lockfile
       - name: Bundle Deps
-        uses: lando/prepare-release-action@v2
+        uses: lando/prepare-release-action@v3
         with:
           lando-plugin: true
           version: dev

.github/workflows/release.yml

@@ -17,6 +17,7 @@ jobs:
           - ubuntu-20.04
         node-version:
           - "18"
+
     steps:
       # Install deps and cache
       - name: Checkout code
@@ -36,7 +37,7 @@ jobs:
       - name: Run unit tests
         run: npm run test:unit
       - name: Prepare Release
-        uses: lando/prepare-release-action@v2
+        uses: lando/prepare-release-action@v3
         with:
           lando-plugin: true
 

CHANGELOG.md

@@ -23,12 +23,15 @@
 ### Internal
 
 * Added `app.addMessage` for more granular and accessible post-start app status reporting
+* Changed `lando.log` and `app.log` to be more like `debug`
 * Bumped minimum `node` version to `18`
-* Bumped supported Docker Desktop version to `>4 <4.26`
+* Bumped supported Docker Desktop version to `>4 <4.27`
 * Removed lingering and dangling should-now-be-in-plugins code eg `_drupaly.js`
 * Reorganized core to be more like `@lando/core-next` (eg Lando 4)
 * Switched (fully, finally) from `github` to `@octokit/rest`
 * Switched plugin package manager to `npm`
+* Removed `bundledDependencies` from `package.json`, now handled by `@lando/prepare-release-action@v3`
+* Removed `dayjs` dependency
 * Removed `github` dependency
 * Removed `mkdirp` dependency
 

components/plugin.js

@@ -270,7 +270,7 @@ class Plugin {
   async check4Update() {
     // if plugin is not updateable then immediately return
     if (!this.isUpdateable) {
-      this.debug('%o is not updateable, update manually', this.name);
+      this.debug('is not updateable, update manually');
       return this;
     }
 
@@ -295,7 +295,7 @@ class Plugin {
 
       // if the hv is lte to what we have then no update is available
       if (semver.lte(hv, this.version)) {
-        this.debug('%o cannot be updated on channel %o (%o <= %o)', this.package, channel, hv, this.version);
+        this.debug('cannot be updated on channel %o (%o <= %o)', this.package, channel, hv, this.version);
         return this;
 
       // otherwise update is available
@@ -304,7 +304,7 @@ class Plugin {
         this.update = await Plugin.info(this.updateAvailable);
         this.update.channel = hc;
         this.debug(
-          '%o can be updated to %o on channel %o (%o > %o) ',
+          'can be updated to %o on channel %o (%o > %o) ',
           this.package,
           this.updateAvailable,
           channel,

examples/base/README.md

@@ -87,11 +87,12 @@ lando info -vv | grep VERBOSE || echo $? | grep 1
 lando info -vvv | grep DEBUG || echo $? | grep 1
 lando info -vvvv | grep SILLY || echo $? | grep 1
 
-# Should run with specified verbosity on stderr
-lando info -v 2>&1 | grep INFO
-lando info -vv 2>&1 | grep VERBOSE
-lando info -vvv 2>&1 | grep DEBUG
-lando info -vvvv 2>&1 | grep SILLY
+# Should run all log levels on stderr
+lando info -v 2>&1 | grep lando | grep + | grep ms
+lando info -vv 2>&1 | grep lando | grep + | grep ms
+lando info -vvv 2>&1 | grep lando | grep + | grep ms
+lando info -vvvv 2>&1 | grep lando | grep + | grep ms
+lando info --debug 2>&1 | grep lando | grep + | grep ms
 
 # Should run lando config without error
 lando config

hooks/app-check-for-updates.js

@@ -3,6 +3,11 @@
 module.exports = async (app, lando) => {
   if (lando.config.channel !== 'none' && !lando.cache.get('updates-2')) {
     lando.log.debug('checking for updates...');
+    // add the plugins and install dir
+    const dir = lando.config.pluginDirs.find(dir => dir.type === require('../utils/get-plugin-type')());
+    lando.updates.plugins = lando.config.plugins;
+    lando.updates.dir = dir ? dir.dir : undefined;
+
     const tasks = await lando.updates.getUpdateTasks();
     // next check in a day
     const expires = Date.now() + 60 * 60 * 24 * 1000;

index.js

@@ -86,10 +86,10 @@ module.exports = async lando => {
   lando.events.on('almost-ready', 2, async () => await require('./hooks/lando-get-compat')(lando));
 
   // throw error if engine/orchestrator is not available
-  lando.events.on('engine-autostart', 1, async () => await require('./hooks/lando-dep-check')(lando));
+  lando.events.once('pre-engine-autostart', async () => await require('./hooks/lando-dep-check')(lando));
 
   // autostart docker if we need to
-  lando.events.on('engine-autostart', 2, async () => await require('./hooks/lando-autostart-engine')(lando));
+  lando.events.once('engine-autostart', async () => await require('./hooks/lando-autostart-engine')(lando));
 
   // Make sure we have a host-exposed root ca if we don't already
   // NOTE: we don't run this on the caProject otherwise infinite loop happens!

lib/lando.js

@@ -89,11 +89,6 @@ const bootstrapConfig = async lando => {
   // log
   if (!_.isEmpty(removed)) lando.log.debug('removed duplicate plugin entries %o', removed);
 
-  // add the plugins and install dir
-  const dir = lando.config.pluginDirs.find(dir => dir.type === require('../utils/get-plugin-type')());
-  lando.updates.plugins = plugins;
-  lando.updates.dir = dir ? dir.dir : undefined;
-
   // he who remains
   return plugins;
 };

lib/logger.js

@@ -2,12 +2,11 @@
 
 // Modules
 const _ = require('lodash');
-const dayjs = require('dayjs');
 const fs = require('fs');
 const path = require('path');
 const serialize = require('winston/lib/winston/common').serialize;
-const util = require('util');
 const winston = require('winston');
+const util = require('util');
 
 // Constants
 const logLevels = {
@@ -28,12 +27,10 @@ const logColors = {
   timestamp: 'magenta',
   lando: 'cyan',
   app: 'green',
+  extra: 'dim',
 };
 const userLevels = ['warn', 'error'];
 
-// Maxsize
-let fcw = 0;
-
 // Rewriters
 const keySanitizer = sanitizeKey => (level, msg, meta) => {
   // start with a deep clone of meta so we dont mutate important underlying data
@@ -143,34 +140,44 @@ const keySanitizer = sanitizeKey => (level, msg, meta) => {
  * lando.log.warning('Something is up with app %s in directory %s', appName, dir);
  */
 module.exports = class Log extends winston.Logger {
-  constructor({logDir, logLevelConsole = 'warn', logLevel = 'debug', logName = 'lando'} = {}) {
+  constructor({logDir, extra, logLevelConsole = 'warn', logLevel = 'debug', logName = 'lando'} = {}) {
     // If loglevelconsole is numeric lets map it!
     if (_.isInteger(logLevelConsole)) logLevelConsole = logLevels[logLevelConsole];
 
     // The default console transport
     const transports = [
       new winston.transports.Console({
-        timestamp: () => dayjs().format('HH:mm:ss'),
+        timestamp: () => Date.now(),
         formatter: options => {
           // Get da prefixes
           const element = (logName === 'lando') ? 'lando' : logName;
           const elementColor = (logName === 'lando') ? 'lando' : 'app';
-          // Set the leftmost column width
-          fcw = _.max([fcw, _.size(element)]);
-          // Default output
-          const output = [
-            winston.config.colorize(elementColor, _.padEnd(element.toLowerCase(), fcw)),
-            winston.config.colorize('timestamp', options.timestamp()),
-            winston.config.colorize(options.level, options.level.toUpperCase()),
-            '==>',
-            util.format(options.message),
-            serialize(options.meta),
-          ];
-          // If this is a warning or error and we aren't verbose then omit prefixes
+
+          //  approximate debug mod timestamp
+          const curr = Number(new Date());
+          const ms = curr - (this.lasttime || curr);
+          this.lasttime = curr;
+
+          // build useful things first
+          const prefix = winston.config.colorize(elementColor, element.toLowerCase());
+          const level = winston.config.colorize(options.level, options.level.toUpperCase());
+          const msg = util.format(options.message);
+          const meta = serialize(options.meta);
+          const timestamp = winston.config.colorize(elementColor, `+${ms}ms`);
+
+          // If this is a warning or error and we aren't verbose then we have more "normal" output
           if (_.includes(userLevels, options.level) && _.includes(userLevels, logLevelConsole)) {
-            return _.drop(output, 2).join(' ');
+            return [level, '==>', msg].join(' ');
           }
-          return output.join(' ');
+
+          // debug output
+          const output = [prefix, msg, meta, timestamp];
+          // if we have extra stuff
+          if (typeof extra === 'string') output.splice(1, 0, winston.config.colorize('extra', extra.toLowerCase()));
+          // if error or warning then try to make it more obvious by splicing in the level
+          if (_.includes(userLevels, options.level)) output.splice(1, 0, level);
+          // return
+          return `  ${output.join(' ')}`;
         },
         label: logName,
         level: logLevelConsole,
@@ -204,10 +211,15 @@ module.exports = class Log extends winston.Logger {
     // Get the winston logger
     super({transports: transports, exitOnError: true, colors: logColors});
 
+    // set initial timestamp
+    this.lasttime = Date.now();
     // Extend with special lando things
     this.sanitizedKeys = ['auth', 'token', 'password', 'key', 'api_key', 'secret', 'machine_token'];
     // Loop through our sanitizedKeys and add sanitation
     _.forEach(this.sanitizedKeys, key => this.rewriters.push(keySanitizer(key)));
+
+    // save the initial config for shiming
+    this.shim = {logDir, extra, logLevelConsole, logLevel, logName};
   };
 
   // Method to help other things add sanitizations

lib/plugins.js

@@ -139,13 +139,13 @@ module.exports = class Plugins {
     try {
       plugin.data = dynamicRequire()(file)(...injected);
     } catch (e) {
-      this.log.error('problem loading plugin %s from %s: %s', plugin.name, file, e.stack);
+      this.log.error('problem loading plugin %o from %o: %o', plugin.name, file, e.stack);
     }
 
     // Register, log, return
     this.registry.push(plugin);
-    this.log.debug('plugin %s loaded from %s', plugin.name, file);
-    this.log.silly('plugin %s has', plugin.name, plugin.data);
+    this.log.debug('plugin %o loaded from %s', plugin.name, file);
+    this.log.silly('plugin %o has', plugin.name, plugin.data);
 
     // merge promise magix so we can await or not
     return require('./../utils/merge-promise')(plugin, async () => {

lib/router.js

@@ -24,7 +24,8 @@ const retryEach = (data, run) => Promise.each(normalizer(data), datum => run(dat
 
 // Helper to run engine event commands
 exports.eventWrapper = (name, daemon, events, data, run) =>
-  events.emit('engine-autostart', data)
+  events.emit('pre-engine-autostart', data)
+  .then(() => events.emit('engine-autostart', data))
   .then(() => daemon.up())
   .then(() => events.emit(`pre-engine-${name}`, data))
   .then(() => run(data))

lib/updates.js

@@ -21,6 +21,15 @@ const getOS = () => {
   }
 };
 
+// just want to wrap the require so we shave time off of bootstrap
+const getPluginClass = ({channel, config, debug} = {}) => {
+  const Plugin = require('../components/plugin');
+  Plugin.channel = channel;
+  Plugin.config = config;
+  Plugin.debug = debug;
+  return Plugin;
+};
+
 module.exports = class UpdateManager {
   constructor({
     config = {},
@@ -33,34 +42,19 @@ module.exports = class UpdateManager {
     // set things
     this._plugins = plugins;
     this.channel = channel;
+    this.cli = cli;
     this.config = config;
     this.dir = dir;
     this.debug = debug;
-    this.Plugin = require('../components/plugin');
-
-    // reset Plugin static defaults for v3 purposes
-    this.Plugin.channel = channel;
-    this.Plugin.config = config;
-    this.Plugin.debug = debug;
-
-    // special handling for CLI
-    // @NOTE: we pretend its a plugin just to get some object consistency between our things
-    if (cli && cli.plugin) {
-      this._cli = new this.Plugin(cli.plugin);
-      this._cli.isCli = true;
-      this._cli.isUpdateable = cli.packaged && !cli.source;
-      this._cli.installPath = cli.installPath;
-      this.internalCore = cli.coreBase;
-      this.internalCoreVersion = cli.coreBaseVersion;
-    }
 
     // some state stuff
     this.hasChecked = false;
   };
 
   // translate set plugins when they are set
   set plugins(plugins) {
-    this._plugins = plugins.map(plugin => new this.Plugin(plugin.dir));
+    const Plugin = getPluginClass({channel: this.channel, config: this.config, debug: this.debug});
+    this._plugins = plugins.map(plugin => new Plugin(plugin.dir));
     // if we are cli corebase then we need to reset core plugin stuff
     if (this.internalCore && this.internalCoreVersion) {
       this._plugins.forEach(plugin => {
@@ -91,18 +85,35 @@ module.exports = class UpdateManager {
       }
     });
 
-    // push cli check here
-    if (this._cli && this._cli.isCli) {
+    // special handling for CLI, push cli check here
+    if (this.cli && this.cli.plugin) {
+      const Plugin = getPluginClass({channel: this.channel, config: this.config, debug: this.debug});
+      const cli = this.cli;
+      this._cli = new Plugin(cli.plugin);
+      this._cli.isCli = true;
+      this._cli.isUpdateable = cli.packaged && !cli.source;
+      this._cli.installPath = cli.installPath;
+      this.internalCore = cli.coreBase;
+      this.internalCoreVersion = cli.coreBaseVersion;
+
       checks.push(new Promise(async resolve => {
         // summon the katkraken
         const octokit = new Octokit({auth: get(process, 'env.GITHUB_TOKEN')});
         // check internet connection
         const online = await require('is-online')();
         // throw error if not online
         if (!online) throw new Error('Cannot detect connection to internet!');
+        // just a helper to give consistent prez
+        const extra = color.dim('@lando/cli');
 
         // go for it
         try {
+          if (!this._cli.isUpdateable) {
+            this.debug(`${extra} is not updateable, update manually`);
+            resolve(this._cli);
+            return;
+          }
+
           const {data, status, url} = await octokit.rest.repos.listReleases({owner: 'lando', repo: 'cli'});
           this.debug('retrieved cli information from %o [%o]', url, status);
 
@@ -119,8 +130,9 @@ module.exports = class UpdateManager {
 
           // cli cannot be updated
           if (semver.lte(hv, this._cli.version)) {
-            this.debug(`'@lando/cli' cannot be updated on channel %o (%o <= %o)`, this.channel, hv, this._cli.version);
+            this.debug(`${extra} cannot be updated on channel %o (%o <= %o)`, this.channel, hv, this._cli.version);
             resolve(this._cli);
+            return;
 
           // otherwise update is available
           } else {
@@ -141,7 +153,7 @@ module.exports = class UpdateManager {
             this._cli.updateAvailable = `@lando/cli@${hv}`;
             this._cli.update = release;
             this.debug(
-              `'@lando/cli' can be updated to %o on channel %o (%o > %o)`,
+              `${extra} can be updated to %o on channel %o (%o > %o)`,
               release.download,
               this.channel,
               hv,
@@ -154,7 +166,7 @@ module.exports = class UpdateManager {
         } catch (error) {
           if (error.status) error.message = `${error.message} [${error.status}]`;
           if (error.response && error.response.url) error.message = `${error.message} (${error.response.url})`;
-          this.debug(`'@lando/cli' could not get update info, error: %o`, error.message);
+          this.debug(`${extra} could not get update info, error: %o`, error.message);
           this.debug('%j', error);
           this._cli.isUpdateable = false;
           this._cli.updateAvailable = false;