1const t = require('tap')
2const _fs = require('fs')
3const fs = _fs.promises
4const path = require('path')
5const os = require('os')
6const fsMiniPass = require('fs-minipass')
7const tmock = require('../../fixtures/tmock')
8const LogFile = require('../../../lib/utils/log-file.js')
9const { cleanCwd, cleanDate } = require('../../fixtures/clean-snapshot')
10
11t.cleanSnapshot = (s) => cleanDate(cleanCwd(s))
12
13const getId = (d = new Date()) => d.toISOString().replace(/[.:]/g, '_')
14const last = arr => arr[arr.length - 1]
15const range = (n) => Array.from(Array(n).keys())
16const makeOldLogs = (count, oldStyle) => {
17  const d = new Date()
18  d.setHours(-1)
19  d.setSeconds(0)
20  return range(oldStyle ? count : (count / 2)).reduce((acc, i) => {
21    const cloneDate = new Date(d.getTime())
22    cloneDate.setSeconds(i)
23    const dateId = getId(cloneDate)
24    if (oldStyle) {
25      acc[`${dateId}-debug.log`] = 'hello'
26    } else {
27      acc[`${dateId}-debug-0.log`] = 'hello'
28      acc[`${dateId}-debug-1.log`] = 'hello'
29    }
30    return acc
31  }, {})
32}
33
34const cleanErr = (message) => {
35  const err = new Error(message)
36  const stack = err.stack.split('\n')
37  err.stack = stack[0] + '\n' + range(10)
38    .map((__, i) => stack[1].replace(/^(\s+at\s).*/, `$1stack trace line ${i}`))
39    .join('\n')
40  return err
41}
42
43const loadLogFile = async (t, { buffer = [], mocks, testdir = {}, ...options } = {}) => {
44  const root = t.testdir(testdir)
45
46  const MockLogFile = tmock(t, '{LIB}/utils/log-file.js', mocks)
47  const logFile = new MockLogFile(Object.keys(options).length ? options : undefined)
48
49  buffer.forEach((b) => logFile.log(...b))
50
51  const id = getId()
52  await logFile.load({ path: path.join(root, `${id}-`), ...options })
53
54  t.teardown(() => logFile.off())
55  return {
56    root,
57    logFile,
58    LogFile,
59    readLogs: async () => {
60      const logDir = await fs.readdir(root)
61      const logFiles = logDir.map((f) => path.join(root, f))
62        .filter((f) => _fs.existsSync(f))
63      return Promise.all(logFiles.map(async (f) => {
64        const content = await fs.readFile(f, 'utf8')
65        const rawLogs = content.split(os.EOL)
66        return {
67          filename: f,
68          content,
69          rawLogs,
70          logs: rawLogs.filter(Boolean),
71        }
72      }))
73    },
74  }
75}
76
77t.test('init', async t => {
78  const maxLogsPerFile = 10
79  const { root, logFile, readLogs } = await loadLogFile(t, {
80    maxLogsPerFile,
81    maxFilesPerProcess: 20,
82    buffer: [['error', 'buffered']],
83  })
84
85  for (const i of range(50)) {
86    logFile.log('error', `log ${i}`)
87  }
88
89  // Ignored
90  logFile.log('pause')
91  logFile.log('resume')
92  logFile.log('pause')
93
94  for (const i of range(50)) {
95    logFile.log('verb', `log ${i}`)
96  }
97
98  logFile.off()
99  logFile.log('error', 'ignored')
100
101  const logs = await readLogs()
102  t.equal(logs.length, 11, 'total log files')
103  t.ok(logs.slice(0, 10).every(f => f.logs.length === maxLogsPerFile), 'max logs per file')
104  t.ok(last(logs).logs.length, 1, 'last file has remaining logs')
105  t.ok(logs.every(f => last(f.rawLogs) === ''), 'all logs end with newline')
106  t.strictSame(
107    logFile.files,
108    logs.map((l) => path.resolve(root, l.filename))
109  )
110})
111
112t.test('max files per process', async t => {
113  const maxLogsPerFile = 10
114  const maxFilesPerProcess = 5
115  const { logFile, readLogs } = await loadLogFile(t, {
116    maxLogsPerFile,
117    maxFilesPerProcess,
118  })
119
120  for (const i of range(maxLogsPerFile * maxFilesPerProcess)) {
121    logFile.log('error', `log ${i}`)
122  }
123
124  for (const i of range(5)) {
125    logFile.log('verbose', `ignored after maxlogs hit ${i}`)
126  }
127
128  const logs = await readLogs()
129  t.equal(logs.length, maxFilesPerProcess, 'total log files')
130  t.match(last(last(logs).logs), /49 error log \d+/)
131})
132
133t.test('stream error', async t => {
134  let times = 0
135  const { logFile, readLogs } = await loadLogFile(t, {
136    maxLogsPerFile: 1,
137    maxFilesPerProcess: 99,
138    mocks: {
139      'fs-minipass': {
140        WriteStreamSync: class {
141          constructor (...args) {
142            if (times >= 5) {
143              throw new Error('bad stream')
144            }
145            times++
146            return new fsMiniPass.WriteStreamSync(...args)
147          }
148        },
149      },
150    },
151  })
152
153  for (const i of range(10)) {
154    logFile.log('verbose', `log ${i}`)
155  }
156
157  const logs = await readLogs()
158  t.equal(logs.length, 5, 'total log files')
159})
160
161t.test('initial stream error', async t => {
162  const { logFile, readLogs } = await loadLogFile(t, {
163    mocks: {
164      'fs-minipass': {
165        WriteStreamSync: class {
166          constructor (...args) {
167            throw new Error('no stream')
168          }
169        },
170      },
171    },
172  })
173
174  for (const i of range(10)) {
175    logFile.log('verbose', `log ${i}`)
176  }
177
178  const logs = await readLogs()
179  t.equal(logs.length, 0, 'total log files')
180})
181
182t.test('turns off', async t => {
183  const { logFile, readLogs } = await loadLogFile(t)
184
185  logFile.log('error', 'test')
186  logFile.off()
187  logFile.log('error', 'test2')
188  logFile.load()
189
190  const logs = await readLogs()
191  t.match(last(last(logs).logs), /^\d+ error test$/)
192})
193
194t.test('cleans logs', async t => {
195  const logsMax = 5
196  const { readLogs } = await loadLogFile(t, {
197    logsMax,
198    testdir: makeOldLogs(10),
199  })
200
201  const logs = await readLogs()
202  t.equal(logs.length, logsMax + 1)
203})
204
205t.test('doesnt clean current log by default', async t => {
206  const logsMax = 1
207  const { readLogs, logFile } = await loadLogFile(t, {
208    logsMax,
209    testdir: makeOldLogs(10),
210  })
211
212  logFile.log('error', 'test')
213
214  const logs = await readLogs()
215  t.match(last(logs).content, /\d+ error test/)
216})
217
218t.test('negative logs max', async t => {
219  const logsMax = -10
220  const { readLogs, logFile } = await loadLogFile(t, {
221    logsMax,
222    testdir: makeOldLogs(10),
223  })
224
225  logFile.log('error', 'test')
226
227  const logs = await readLogs()
228  t.equal(logs.length, 0)
229})
230
231t.test('doesnt need to clean', async t => {
232  const logsMax = 20
233  const oldLogs = 10
234  const { readLogs } = await loadLogFile(t, {
235    logsMax,
236    testdir: makeOldLogs(oldLogs),
237  })
238
239  const logs = await readLogs()
240  t.equal(logs.length, oldLogs + 1)
241})
242
243t.test('glob error', async t => {
244  const { readLogs } = await loadLogFile(t, {
245    logsMax: 5,
246    mocks: {
247      glob: { glob: () => {
248        throw new Error('bad glob')
249      } },
250    },
251  })
252
253  const logs = await readLogs()
254  t.equal(logs.length, 1)
255  t.match(last(logs).content, /error cleaning log files .* bad glob/)
256})
257
258t.test('do not log cleaning errors when logging is disabled', async t => {
259  const { readLogs } = await loadLogFile(t, {
260    logsMax: 0,
261    mocks: {
262      glob: () => {
263        throw new Error('should not be logged')
264      },
265    },
266  })
267
268  const logs = await readLogs()
269  t.equal(logs.length, 0)
270})
271
272t.test('cleans old style logs too', async t => {
273  const logsMax = 5
274  const oldLogs = 10
275  const { readLogs } = await loadLogFile(t, {
276    logsMax,
277    testdir: makeOldLogs(oldLogs, true),
278  })
279
280  const logs = await readLogs()
281  t.equal(logs.length, logsMax + 1)
282})
283
284t.test('rimraf error', async t => {
285  const logsMax = 5
286  const oldLogs = 10
287  let count = 0
288  const { readLogs } = await loadLogFile(t, {
289    logsMax,
290    testdir: makeOldLogs(oldLogs),
291    mocks: {
292      'fs/promises': {
293        rm: async (...args) => {
294          if (count >= 3) {
295            throw new Error('bad rimraf')
296          }
297          count++
298          return fs.rm(...args)
299        },
300      },
301    },
302  })
303
304  const logs = await readLogs()
305  t.equal(logs.length, oldLogs - 3 + 1)
306  t.match(last(logs).content, /error removing log file .* bad rimraf/)
307})
308
309t.test('delete log file while open', async t => {
310  const { logFile, root, readLogs } = await loadLogFile(t)
311
312  logFile.log('error', '', 'log 1')
313  const [log] = await readLogs(true)
314  t.match(log.content, /\d+ error log 1/)
315
316  await fs.unlink(path.resolve(root, log.filename))
317
318  logFile.log('error', '', 'log 2')
319  const logs = await readLogs()
320
321  // XXX: do some retry logic after error?
322  t.strictSame(logs, [], 'logs arent written after error')
323})
324
325t.test('snapshot', async t => {
326  const { logFile, readLogs } = await loadLogFile(t, { logsMax: 10 })
327
328  logFile.log('error', '', 'no prefix')
329  logFile.log('error', 'prefix', 'with prefix')
330  logFile.log('error', 'prefix', 1, 2, 3)
331
332  const nestedObj = { obj: { with: { many: { props: 1 } } } }
333  logFile.log('verbose', '', nestedObj)
334  logFile.log('verbose', '', JSON.stringify(nestedObj))
335  logFile.log('verbose', '', JSON.stringify(nestedObj, null, 2))
336
337  const arr = ['test', 'with', 'an', 'array']
338  logFile.log('verbose', '', arr)
339  logFile.log('verbose', '', JSON.stringify(arr))
340  logFile.log('verbose', '', JSON.stringify(arr, null, 2))
341
342  const nestedArr = ['test', ['with', ['an', ['array']]]]
343  logFile.log('verbose', '', nestedArr)
344  logFile.log('verbose', '', JSON.stringify(nestedArr))
345  logFile.log('verbose', '', JSON.stringify(nestedArr, null, 2))
346
347  // XXX: multiple errors are hard to parse visually
348  // the second error should start on a newline
349  logFile.log(...[
350    'error',
351    'pre',
352    'has',
353    'many',
354    'errors',
355    cleanErr('message'),
356    cleanErr('message2'),
357  ])
358
359  const err = new Error('message')
360  delete err.stack
361  logFile.log(...[
362    'error',
363    'nostack',
364    err,
365  ])
366
367  const logs = await readLogs()
368  t.matchSnapshot(logs.map(l => l.content).join('\n'))
369})
370