Rotating log file

[iowillhoit]

Outcome of this SPIKE

@W-10745422@

Implements the rotating log stream supported in Bunyan into sfdx-core's logger

Testing instructions

• Pull this branch
• Run yarn link
• cd to local sfdx-cli
• Run yarn link @salesforce/core
• Run a command that will log
  • Example: SFDX_LOG_ROTATION_PERIOD='5000ms' ./bin/run force:org:list --loglevel=trace
    • Note ./bin/run
• Run command a few more times
• Notice that you now have multiple log files in your home directory (sfdx.log, sfdx.log.0, sfdx.log.1, sfdx.log.2)
• Notice how logs move to "next" log file as commands are ran.
  • Watch files with tail -f sfdx.log

Worth noting

• There is a potential for orphaned log files (conversation)
• Existing huge log files will be automatically cleaned up with this change. The only downside is that when an existing large log files gets removed (on the 3rd day with current defaults), it will potentially take a very long time to remove the file and the user will have no indication as to what is happening.
  • This can be tested by creating a large file in place of sfdx.log and run commands until is is removed.
    • Create large file on mac: mkfile 30g ./sfdx.log
    • Then time how long commands take until it is removed. In my testing time bin/run force:org:list typically took about 5 seconds to run but when my 30gb was cleared it took close to 15 seconds.
• The ms interval does not behave exactly like the other intervals. Hourly, Daily, Weekly, etc will "switch" log files at the start of a new period (e.g. daily happens at midnight). Docs on "period" here. Milliseconds will rotate logs on each command regardless. This can be tested a little more accurately by modifying Bunyan's code slightly.
  • In your linked core directory (sfdx-cli/node_modules/@salesforce/core/node_modules/@salesforce/bunyan/lib/bunyan.js) change:

  var m = /^([1-9][0-9]*)([hdwmy]|ms)$/.exec(period);
  // to
  var m = /^([1-9][0-9]*)([hdwmy]|ms|min)$/.exec(period);

  • And then add the following to the switch statement on line 1314:

  case 'min':
      if (this.rotAt) {
          rotAt = this.rotAt + this.periodNum * 60 * 60 * 60 * 1000 * periodOffset;
      } else {
          // First time: top of the next hour.
          rotAt = Date.UTC(d.getUTCFullYear(), d.getUTCMonth(),
              d.getUTCDate(), d.getUTCHours(), d.getUTCMinutes() + periodOffset);
      }
      break;

  • You can now use min intervals and the logs will rotate at the start of each new minute
    • SFDX_LOG_ROTATION_PERIOD='1min' ./bin/run force:org:list --loglevel=trace

[WillieRuemmele]

code changes look straight-forward to me

[RodEsp]

Windows QA

✔️ Tested this with a 2 GB sized log files on Windows and there was no perceptible performance degradation for commands!