| 123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247 |
- const os = require('node:os')
- const { join, dirname, basename } = require('node:path')
- const fsMiniPass = require('fs-minipass')
- const fs = require('node:fs/promises')
- const { log } = require('proc-log')
- const { formatWithOptions } = require('./format')
- const padZero = (n, length) => n.toString().padStart(length.toString().length, '0')
- class LogFiles {
- // Default to an array so we can buffer
- // initial writes before we know the cache location
- #logStream = []
- // We cap log files at a certain number of log events per file.
- // Note that each log event can write more than one line to the file.
- // Then we rotate log files once this number of events is reached
- #MAX_LOGS_PER_FILE = null
- // Now that we write logs continuously we need to have a backstop here for infinite loops that still log.
- // This is also partially handled by the config.get('max-files') option, but this is a failsafe to prevent runaway log file creation
- #MAX_FILES_PER_PROCESS = null
- #fileLogCount = 0
- #totalLogCount = 0
- #path = null
- #logsMax = null
- #files = []
- #timing = false
- constructor ({
- maxLogsPerFile = 50_000,
- maxFilesPerProcess = 5,
- } = {}) {
- this.#MAX_LOGS_PER_FILE = maxLogsPerFile
- this.#MAX_FILES_PER_PROCESS = maxFilesPerProcess
- this.on()
- }
- on () {
- process.on('log', this.#logHandler)
- }
- off () {
- process.off('log', this.#logHandler)
- this.#endStream()
- }
- load ({ command, path, logsMax = Infinity, timing } = {}) {
- if (['completion'].includes(command)) {
- return
- }
- // dir is user configurable and is required to exist so this can error if the dir is missing or not configured correctly
- this.#path = path
- this.#logsMax = logsMax
- this.#timing = timing
- // Log stream has already ended
- if (!this.#logStream) {
- return
- }
- log.verbose('logfile', `logs-max:${logsMax} dir:${this.#path}`)
- // Write the contents of our array buffer to our new file stream and set that as the new log logstream for future writes
- // if logs max is 0 then the user does not want a log file
- if (this.#logsMax > 0) {
- const initialFile = this.#openLogFile()
- if (initialFile) {
- for (const item of this.#logStream) {
- const formatted = this.#formatLogItem(...item)
- if (formatted !== null) {
- initialFile.write(formatted)
- }
- }
- this.#logStream = initialFile
- }
- }
- log.verbose('logfile', this.files[0] || 'no logfile created')
- // Kickoff cleaning process, even if we aren't writing a logfile.
- // This is async but it will always ignore the current logfile
- // Return the result so it can be awaited in tests
- return this.#cleanLogs()
- }
- get files () {
- return this.#files
- }
- get #isBuffered () {
- return Array.isArray(this.#logStream)
- }
- #endStream (output) {
- if (this.#logStream && !this.#isBuffered) {
- this.#logStream.end(output)
- this.#logStream = null
- }
- }
- #logHandler = (level, ...args) => {
- // Ignore pause and resume events since we write everything to the log file
- if (level === 'pause' || level === 'resume') {
- return
- }
- // If the stream is ended then do nothing
- if (!this.#logStream) {
- return
- }
- if (this.#isBuffered) {
- // Cant do anything but buffer the output if we don't have a file stream yet
- this.#logStream.push([level, ...args])
- return
- }
- const logOutput = this.#formatLogItem(level, ...args)
- if (logOutput === null) {
- return
- }
- // Open a new log file if we've written too many logs to this one
- if (this.#fileLogCount >= this.#MAX_LOGS_PER_FILE) {
- // Write last chunk to the file and close it
- this.#endStream(logOutput)
- if (this.#files.length >= this.#MAX_FILES_PER_PROCESS) {
- // but if its way too many then we just stop listening
- this.off()
- } else {
- // otherwise we are ready for a new file for the next event
- this.#logStream = this.#openLogFile()
- }
- } else {
- this.#logStream.write(logOutput)
- }
- }
- #formatLogItem (level, title, ...args) {
- // Only right timing logs to logfile if explicitly requests
- if (level === log.KEYS.timing && !this.#timing) {
- return null
- }
- this.#fileLogCount += 1
- const prefix = [this.#totalLogCount++, level, title || null]
- return formatWithOptions({ prefix, eol: os.EOL, colors: false }, ...args)
- }
- #getLogFilePath (count = '') {
- return `${this.#path}debug-${count}.log`
- }
- #openLogFile () {
- // Count in filename will be 0 indexed
- const count = this.#files.length
- try {
- // Pad with zeros so that our log files are always sorted properly
- // We never want to write files ending in `-9.log` and `-10.log` because log file cleaning is done by deleting the oldest.
- // So in this example `-10.log` would be deleted next.
- const f = this.#getLogFilePath(padZero(count, this.#MAX_FILES_PER_PROCESS))
- // Some effort was made to make the async, but we need to write logs during process.on('exit') which has to be synchronous.
- // So in order to never drop log messages, it is easiest to make it sync all the time and this was measured to be about 1.5% slower for 40k lines of output
- const logStream = new fsMiniPass.WriteStreamSync(f, { flags: 'a' })
- if (count > 0) {
- // Reset file log count if we are opening after our first file
- this.#fileLogCount = 0
- }
- this.#files.push(logStream.path)
- return logStream
- } catch (e) {
- // If the user has a readonly logdir then we don't want to warn this on every command so it should be verbose
- log.verbose('logfile', `could not be created: ${e}`)
- }
- }
- async #cleanLogs () {
- // module to clean out the old log files this is a best-effort attempt.
- // if a rm fails, we just log a message about it and move on.
- // We do return a Promise that succeeds when we've tried to delete everything, just for the benefit of testing this function properly.
- try {
- const logPath = this.#getLogFilePath()
- const patternFileName = basename(logPath)
- // tell glob to only match digits
- .replace(/\d/g, 'd')
- // Handle the old (prior to 8.2.0) log file names which did not have a counter suffix
- .replace('-.log', '')
- let files = await fs.readdir(
- dirname(logPath), {
- withFileTypes: true,
- encoding: 'utf-8',
- })
- files = files.sort((a, b) => basename(a.name).localeCompare(basename(b.name), 'en'))
- const logFiles = []
- for (const file of files) {
- if (!file.isFile()) {
- continue
- }
- const genericFileName = file.name.replace(/\d/g, 'd')
- const filePath = join(dirname(logPath), basename(file.name))
- // Always ignore the currently written files
- if (
- genericFileName.includes(patternFileName)
- && genericFileName.endsWith('.log')
- && !this.#files.includes(filePath)
- ) {
- logFiles.push(filePath)
- }
- }
- const toDelete = logFiles.length - this.#logsMax
- if (toDelete <= 0) {
- return
- }
- log.silly('logfile', `start cleaning logs, removing ${toDelete} files`)
- for (const file of logFiles.slice(0, toDelete)) {
- try {
- await fs.rm(file, { force: true })
- } catch (e) {
- log.silly('logfile', 'error removing log file', file, e)
- }
- }
- } catch (e) {
- // Disable cleanup failure warnings when log writing is disabled
- if (this.#logsMax > 0) {
- log.verbose('logfile', 'error cleaning log files', e)
- }
- } finally {
- log.silly('logfile', 'done cleaning log files')
- }
- }
- }
- module.exports = LogFiles
|