codekingpro/portable-devtools

1const os = require('node:os')
2const { join, dirname, basename } = require('node:path')
3const fsMiniPass = require('fs-minipass')
4const fs = require('node:fs/promises')
5const { log } = require('proc-log')
6const { formatWithOptions } = require('./format')
7
8const padZero = (n, length) => n.toString().padStart(length.toString().length, '0')
9
10class LogFiles {
11  // Default to an array so we can buffer
12  // initial writes before we know the cache location
13  #logStream = []
14
15  // We cap log files at a certain number of log events per file.
16  // Note that each log event can write more than one line to the file.
17  // Then we rotate log files once this number of events is reached
18  #MAX_LOGS_PER_FILE = null
19
20  // Now that we write logs continuously we need to have a backstop here for infinite loops that still log.
21  // This is also partially handled by the config.get('max-files') option, but this is a failsafe to prevent runaway log file creation
22  #MAX_FILES_PER_PROCESS = null
23
24  #fileLogCount = 0
25  #totalLogCount = 0
26  #path = null
27  #logsMax = null
28  #files = []
29  #timing = false
30
31  constructor ({
32    maxLogsPerFile = 50_000,
33    maxFilesPerProcess = 5,
34  } = {}) {
35    this.#MAX_LOGS_PER_FILE = maxLogsPerFile
36    this.#MAX_FILES_PER_PROCESS = maxFilesPerProcess
37    this.on()
38  }
39
40  on () {
41    process.on('log', this.#logHandler)
42  }
43
44  off () {
45    process.off('log', this.#logHandler)
46    this.#endStream()
47  }
48
49  load ({ command, path, logsMax = Infinity, timing } = {}) {
50    if (['completion'].includes(command)) {
51      return
52    }
53
54    // dir is user configurable and is required to exist so this can error if the dir is missing or not configured correctly
55    this.#path = path
56    this.#logsMax = logsMax
57    this.#timing = timing
58
59    // Log stream has already ended
60    if (!this.#logStream) {
61      return
62    }
63
64    log.verbose('logfile', `logs-max:${logsMax} dir:${this.#path}`)
65
66    // Write the contents of our array buffer to our new file stream and set that as the new log logstream for future writes
67    // if logs max is 0 then the user does not want a log file
68    if (this.#logsMax > 0) {
69      const initialFile = this.#openLogFile()
70      if (initialFile) {
71        for (const item of this.#logStream) {
72          const formatted = this.#formatLogItem(...item)
73          if (formatted !== null) {
74            initialFile.write(formatted)
75          }
76        }
77        this.#logStream = initialFile
78      }
79    }
80
81    log.verbose('logfile', this.files[0] || 'no logfile created')
82
83    // Kickoff cleaning process, even if we aren't writing a logfile.
84    // This is async but it will always ignore the current logfile
85    // Return the result so it can be awaited in tests
86    return this.#cleanLogs()
87  }
88
89  get files () {
90    return this.#files
91  }
92
93  get #isBuffered () {
94    return Array.isArray(this.#logStream)
95  }
96
97  #endStream (output) {
98    if (this.#logStream && !this.#isBuffered) {
99      this.#logStream.end(output)
100      this.#logStream = null
101    }
102  }
103
104  #logHandler = (level, ...args) => {
105    // Ignore pause and resume events since we write everything to the log file
106    if (level === 'pause' || level === 'resume') {
107      return
108    }
109
110    // If the stream is ended then do nothing
111    if (!this.#logStream) {
112      return
113    }
114
115    if (this.#isBuffered) {
116      // Cant do anything but buffer the output if we don't have a file stream yet
117      this.#logStream.push([level, ...args])
118      return
119    }
120
121    const logOutput = this.#formatLogItem(level, ...args)
122    if (logOutput === null) {
123      return
124    }
125
126    // Open a new log file if we've written too many logs to this one
127    if (this.#fileLogCount >= this.#MAX_LOGS_PER_FILE) {
128      // Write last chunk to the file and close it
129      this.#endStream(logOutput)
130      if (this.#files.length >= this.#MAX_FILES_PER_PROCESS) {
131        // but if its way too many then we just stop listening
132        this.off()
133      } else {
134        // otherwise we are ready for a new file for the next event
135        this.#logStream = this.#openLogFile()
136      }
137    } else {
138      this.#logStream.write(logOutput)
139    }
140  }
141
142  #formatLogItem (level, title, ...args) {
143    // Only right timing logs to logfile if explicitly requests
144    if (level === log.KEYS.timing && !this.#timing) {
145      return null
146    }
147
148    this.#fileLogCount += 1
149    const prefix = [this.#totalLogCount++, level, title || null]
150    return formatWithOptions({ prefix, eol: os.EOL, colors: false }, ...args)
151  }
152
153  #getLogFilePath (count = '') {
154    return `${this.#path}debug-${count}.log`
155  }
156
157  #openLogFile () {
158    // Count in filename will be 0 indexed
159    const count = this.#files.length
160
161    try {
162      // Pad with zeros so that our log files are always sorted properly
163      // We never want to write files ending in `-9.log` and `-10.log` because log file cleaning is done by deleting the oldest.
164      // So in this example `-10.log` would be deleted next.
165      const f = this.#getLogFilePath(padZero(count, this.#MAX_FILES_PER_PROCESS))
166      // Some effort was made to make the async, but we need to write logs during process.on('exit') which has to be synchronous.
167      // 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
168      const logStream = new fsMiniPass.WriteStreamSync(f, { flags: 'a' })
169      if (count > 0) {
170        // Reset file log count if we are opening after our first file
171        this.#fileLogCount = 0
172      }
173      this.#files.push(logStream.path)
174      return logStream
175    } catch (e) {
176      // If the user has a readonly logdir then we don't want to warn this on every command so it should be verbose
177      log.verbose('logfile', `could not be created: ${e}`)
178    }
179  }
180
181  async #cleanLogs () {
182    // module to clean out the old log files this is a best-effort attempt.
183    // if a rm fails, we just log a message about it and move on.
184    // We do return a Promise that succeeds when we've tried to delete everything, just for the benefit of testing this function properly.
185
186    try {
187      const logPath = this.#getLogFilePath()
188      const patternFileName = basename(logPath)
189        // tell glob to only match digits
190        .replace(/\d/g, 'd')
191        // Handle the old (prior to 8.2.0) log file names which did not have a counter suffix
192        .replace('-.log', '')
193
194      let files = await fs.readdir(
195        dirname(logPath), {
196          withFileTypes: true,
197          encoding: 'utf-8',
198        })
199      files = files.sort((a, b) => basename(a.name).localeCompare(basename(b.name), 'en'))
200
201      const logFiles = []
202
203      for (const file of files) {
204        if (!file.isFile()) {
205          continue
206        }
207
208        const genericFileName = file.name.replace(/\d/g, 'd')
209        const filePath = join(dirname(logPath), basename(file.name))
210
211        // Always ignore the currently written files
212        if (
213          genericFileName.includes(patternFileName)
214          && genericFileName.endsWith('.log')
215          && !this.#files.includes(filePath)
216        ) {
217          logFiles.push(filePath)
218        }
219      }
220
221      const toDelete = logFiles.length - this.#logsMax
222
223      if (toDelete <= 0) {
224        return
225      }
226
227      log.silly('logfile', `start cleaning logs, removing ${toDelete} files`)
228
229      for (const file of logFiles.slice(0, toDelete)) {
230        try {
231          await fs.rm(file, { force: true })
232        } catch (e) {
233          log.silly('logfile', 'error removing log file', file, e)
234        }
235      }
236    } catch (e) {
237      // Disable cleanup failure warnings when log writing is disabled
238      if (this.#logsMax > 0) {
239        log.verbose('logfile', 'error cleaning log files', e)
240      }
241    } finally {
242      log.silly('logfile', 'done cleaning log files')
243    }
244  }
245}
246
247module.exports = LogFiles
248