Merge pull request #3405 from mikiher/logger-fixes

Log non-strings into log file like console.log does

server/Logger.js

@@ -1,5 +1,6 @@
 const date = require('./libs/dateAndTime')
 const { LogLevel } = require('./utils/constants')
+const util = require('util')
 
 class Logger {
   constructor() {
@@ -69,27 +70,29 @@ class Logger {
   /**
    *
    * @param {number} level
+   * @param {string} levelName
    * @param {string[]} args
    * @param {string} src
    */
-  async handleLog(level, args, src) {
+  async #logToFileAndListeners(level, levelName, args, src) {
+    const expandedArgs = args.map((arg) => (typeof arg !== 'string' ? util.inspect(arg) : arg))
     const logObj = {
       timestamp: this.timestamp,
       source: src,
-      message: args.join(' '),
+      message: expandedArgs.join(' '),
-      levelName: this.getLogLevelString(level),
+      levelName,
       level
     }
 
     // Emit log to sockets that are listening to log events
     this.socketListeners.forEach((socketListener) => {
-      if (socketListener.level <= level) {
+      if (level >= LogLevel.FATAL || level >= socketListener.level) {
         socketListener.socket.emit('log', logObj)
       }
     })
 
     // Save log to file
-    if (level >= this.logLevel) {
+    if (level >= LogLevel.FATAL || level >= this.logLevel) {
       await this.logManager?.logToFile(logObj)
     }
   }
@@ -99,50 +102,50 @@ class Logger {
     this.debug(`Set Log Level to ${this.levelString}`)
   }
 
+  static ConsoleMethods = {
+    TRACE: 'trace',
+    DEBUG: 'debug',
+    INFO: 'info',
+    WARN: 'warn',
+    ERROR: 'error',
+    FATAL: 'error',
+    NOTE: 'log'
+  }
+
+  #log(levelName, source, ...args) {
+    const level = LogLevel[levelName]
+    if (level < LogLevel.FATAL && level < this.logLevel) return
+    const consoleMethod = Logger.ConsoleMethods[levelName]
+    console[consoleMethod](`[${this.timestamp}] ${levelName}:`, ...args)
+    this.#logToFileAndListeners(level, levelName, args, source)
+  }
+
   trace(...args) {
-    if (this.logLevel > LogLevel.TRACE) return
+    this.#log('TRACE', this.source, ...args)
-    console.trace(`[${this.timestamp}] TRACE:`, ...args)
-    this.handleLog(LogLevel.TRACE, args, this.source)
   }
 
   debug(...args) {
-    if (this.logLevel > LogLevel.DEBUG) return
+    this.#log('DEBUG', this.source, ...args)
-    console.debug(`[${this.timestamp}] DEBUG:`, ...args, `(${this.source})`)
-    this.handleLog(LogLevel.DEBUG, args, this.source)
   }
 
   info(...args) {
-    if (this.logLevel > LogLevel.INFO) return
+    this.#log('INFO', this.source, ...args)
-    console.info(`[${this.timestamp}] INFO:`, ...args)
-    this.handleLog(LogLevel.INFO, args, this.source)
   }
 
   warn(...args) {
-    if (this.logLevel > LogLevel.WARN) return
+    this.#log('WARN', this.source, ...args)
-    console.warn(`[${this.timestamp}] WARN:`, ...args, `(${this.source})`)
-    this.handleLog(LogLevel.WARN, args, this.source)
   }
 
   error(...args) {
-    if (this.logLevel > LogLevel.ERROR) return
+    this.#log('ERROR', this.source, ...args)
-    console.error(`[${this.timestamp}] ERROR:`, ...args, `(${this.source})`)
-    this.handleLog(LogLevel.ERROR, args, this.source)
   }
 
-  /**
-   * Fatal errors are ones that exit the process
-   * Fatal logs are saved to crash_logs.txt
-   *
-   * @param  {...any} args
-   */
   fatal(...args) {
-    console.error(`[${this.timestamp}] FATAL:`, ...args, `(${this.source})`)
+    this.#log('FATAL', this.source, ...args)
-    return this.handleLog(LogLevel.FATAL, args, this.source)
   }
 
   note(...args) {
-    console.log(`[${this.timestamp}] NOTE:`, ...args)
+    this.#log('NOTE', this.source, ...args)
-    this.handleLog(LogLevel.NOTE, args, this.source)
   }
 }
 module.exports = new Logger()

test/server/Logger.test.js

@@ -0,0 +1,285 @@
+const { expect } = require('chai')
+const sinon = require('sinon')
+const Logger = require('../../server/Logger') // Adjust the path as needed
+const { LogLevel } = require('../../server/utils/constants')
+const date = require('../../server/libs/dateAndTime')
+const util = require('util')
+
+describe('Logger', function () {
+  let consoleTraceStub
+  let consoleDebugStub
+  let consoleInfoStub
+  let consoleWarnStub
+  let consoleErrorStub
+  let consoleLogStub
+
+  beforeEach(function () {
+    // Stub the date format function to return a consistent timestamp
+    sinon.stub(date, 'format').returns('2024-09-10 12:34:56.789')
+    // Stub the source getter to return a consistent source
+    sinon.stub(Logger, 'source').get(() => 'some/source.js')
+    // Stub the console methods used in Logger
+    consoleTraceStub = sinon.stub(console, 'trace')
+    consoleDebugStub = sinon.stub(console, 'debug')
+    consoleInfoStub = sinon.stub(console, 'info')
+    consoleWarnStub = sinon.stub(console, 'warn')
+    consoleErrorStub = sinon.stub(console, 'error')
+    consoleLogStub = sinon.stub(console, 'log')
+    // Initialize the Logger's logManager as a mock object
+    Logger.logManager = {
+      logToFile: sinon.stub().resolves()
+    }
+  })
+
+  afterEach(function () {
+    sinon.restore()
+  })
+
+  describe('logging methods', function () {
+    it('should have a method for each log level defined in the static block', function () {
+      const loggerMethods = Object.keys(LogLevel).map((key) => key.toLowerCase())
+
+      loggerMethods.forEach((method) => {
+        expect(Logger).to.have.property(method).that.is.a('function')
+      })
+    })
+
+    it('should call console.trace for trace logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.trace('Test message')
+
+      // Assert
+      expect(consoleTraceStub.calledOnce).to.be.true
+    })
+
+    it('should call console.debug for debug logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.debug('Test message')
+
+      // Assert
+      expect(consoleDebugStub.calledOnce).to.be.true
+    })
+
+    it('should call console.info for info logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.info('Test message')
+
+      // Assert
+      expect(consoleInfoStub.calledOnce).to.be.true
+    })
+
+    it('should call console.warn for warn logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.warn('Test message')
+
+      // Assert
+      expect(consoleWarnStub.calledOnce).to.be.true
+    })
+
+    it('should call console.error for error logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.error('Test message')
+
+      // Assert
+      expect(consoleErrorStub.calledOnce).to.be.true
+    })
+
+    it('should call console.error for fatal logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.fatal('Test message')
+
+      // Assert
+      expect(consoleErrorStub.calledOnce).to.be.true
+    })
+
+    it('should call console.log for note logging', function () {
+      // Arrange
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.note('Test message')
+
+      // Assert
+      expect(consoleLogStub.calledOnce).to.be.true
+    })
+  })
+
+  describe('#log', function () {
+    it('should log to console and file if level is high enough', async function () {
+      // Arrange
+      const logArgs = ['Test message']
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      Logger.debug(...logArgs)
+
+      expect(consoleDebugStub.calledOnce).to.be.true
+      expect(consoleDebugStub.calledWithExactly('[2024-09-10 12:34:56.789] DEBUG:', ...logArgs)).to.be.true
+      expect(Logger.logManager.logToFile.calledOnce).to.be.true
+      expect(
+        Logger.logManager.logToFile.calledWithExactly({
+          timestamp: '2024-09-10 12:34:56.789',
+          source: 'some/source.js',
+          message: 'Test message',
+          levelName: 'DEBUG',
+          level: LogLevel.DEBUG
+        })
+      ).to.be.true
+    })
+
+    it('should not log if log level is too low', function () {
+      // Arrange
+      const logArgs = ['This log should not appear']
+      // Set log level to ERROR, so DEBUG log should be ignored
+      Logger.logLevel = LogLevel.ERROR
+
+      // Act
+      Logger.debug(...logArgs)
+
+      // Verify console.debug is not called
+      expect(consoleDebugStub.called).to.be.false
+      expect(Logger.logManager.logToFile.called).to.be.false
+    })
+
+    it('should emit log to all connected sockets with appropriate log level', async function () {
+      // Arrange
+      const socket1 = { id: '1', emit: sinon.spy() }
+      const socket2 = { id: '2', emit: sinon.spy() }
+      Logger.addSocketListener(socket1, LogLevel.DEBUG)
+      Logger.addSocketListener(socket2, LogLevel.ERROR)
+      const logArgs = ['Socket test']
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      await Logger.debug(...logArgs)
+
+      // socket1 should receive the log, but not socket2
+      expect(socket1.emit.calledOnce).to.be.true
+      expect(
+        socket1.emit.calledWithExactly('log', {
+          timestamp: '2024-09-10 12:34:56.789',
+          source: 'some/source.js',
+          message: 'Socket test',
+          levelName: 'DEBUG',
+          level: LogLevel.DEBUG
+        })
+      ).to.be.true
+
+      expect(socket2.emit.called).to.be.false
+    })
+
+    it('should log fatal messages to console and file regardless of log level', async function () {
+      // Arrange
+      const logArgs = ['Fatal error']
+      // Set log level to NOTE + 1, so nothing should be logged
+      Logger.logLevel = LogLevel.NOTE + 1
+
+      // Act
+      await Logger.fatal(...logArgs)
+
+      // Assert
+      expect(consoleErrorStub.calledOnce).to.be.true
+      expect(consoleErrorStub.calledWithExactly('[2024-09-10 12:34:56.789] FATAL:', ...logArgs)).to.be.true
+      expect(Logger.logManager.logToFile.calledOnce).to.be.true
+      expect(
+        Logger.logManager.logToFile.calledWithExactly({
+          timestamp: '2024-09-10 12:34:56.789',
+          source: 'some/source.js',
+          message: 'Fatal error',
+          levelName: 'FATAL',
+          level: LogLevel.FATAL
+        })
+      ).to.be.true
+    })
+
+    it('should log note messages to console and file regardless of log level', async function () {
+      // Arrange
+      const logArgs = ['Note message']
+      // Set log level to NOTE + 1, so nothing should be logged
+      Logger.logLevel = LogLevel.NOTE + 1
+
+      // Act
+      await Logger.note(...logArgs)
+
+      // Assert
+      expect(consoleLogStub.calledOnce).to.be.true
+      expect(consoleLogStub.calledWithExactly('[2024-09-10 12:34:56.789] NOTE:', ...logArgs)).to.be.true
+      expect(Logger.logManager.logToFile.calledOnce).to.be.true
+      expect(
+        Logger.logManager.logToFile.calledWithExactly({
+          timestamp: '2024-09-10 12:34:56.789',
+          source: 'some/source.js',
+          message: 'Note message',
+          levelName: 'NOTE',
+          level: LogLevel.NOTE
+        })
+      ).to.be.true
+    })
+
+    it('should log util.inspect(arg) for non-string objects', async function () {
+      // Arrange
+      const obj = { key: 'value' }
+      const logArgs = ['Logging object:', obj]
+      Logger.logLevel = LogLevel.TRACE
+
+      // Act
+      await Logger.debug(...logArgs)
+
+      // Assert
+      expect(consoleDebugStub.calledOnce).to.be.true
+      expect(consoleDebugStub.calledWithExactly('[2024-09-10 12:34:56.789] DEBUG:', 'Logging object:', obj)).to.be.true
+      expect(Logger.logManager.logToFile.calledOnce).to.be.true
+      expect(Logger.logManager.logToFile.firstCall.args[0].message).to.equal('Logging object: ' + util.inspect(obj))
+    })
+  })
+
+  describe('socket listeners', function () {
+    it('should add and remove socket listeners', function () {
+      // Arrange
+      const socket1 = { id: '1', emit: sinon.spy() }
+      const socket2 = { id: '2', emit: sinon.spy() }
+
+      // Act
+      Logger.addSocketListener(socket1, LogLevel.DEBUG)
+      Logger.addSocketListener(socket2, LogLevel.ERROR)
+      Logger.removeSocketListener('1')
+
+      // Assert
+      expect(Logger.socketListeners).to.have.lengthOf(1)
+      expect(Logger.socketListeners[0].id).to.equal('2')
+    })
+  })
+
+  describe('setLogLevel', function () {
+    it('should change the log level and log the new level', function () {
+      // Arrange
+      const debugSpy = sinon.spy(Logger, 'debug')
+
+      // Act
+      Logger.setLogLevel(LogLevel.WARN)
+
+      // Assert
+      expect(Logger.logLevel).to.equal(LogLevel.WARN)
+      expect(debugSpy.calledOnce).to.be.true
+      expect(debugSpy.calledWithExactly('Set Log Level to WARN')).to.be.true
+    })
+  })
+})

test/server/finders/BookFinder.test.js

@@ -22,7 +22,7 @@ describe('TitleCandidates', () => {
     })
 
     describe('single add', () => {
-      [
+      ;[
         ['adds candidate', 'anna karenina', ['anna karenina']],
         ['adds lowercased candidate', 'ANNA KARENINA', ['anna karenina']],
         ['adds candidate, removing redundant spaces', 'anna    karenina', ['anna karenina']],
@@ -40,23 +40,27 @@ describe('TitleCandidates', () => {
         ['adds candidate + variant, removing preceding/trailing numbers', '1 anna karenina 2', ['anna karenina', '1 anna karenina 2']],
         ['does not add empty candidate', '', []],
         ['does not add spaces-only candidate', '   ', []],
-        ['does not add empty variant', '1984', ['1984']],
+        ['does not add empty variant', '1984', ['1984']]
-      ].forEach(([name, title, expected]) => it(name, () => {
+      ].forEach(([name, title, expected]) =>
-        titleCandidates.add(title)
+        it(name, () => {
-        expect(titleCandidates.getCandidates()).to.deep.equal(expected)
+          titleCandidates.add(title)
-      }))
+          expect(titleCandidates.getCandidates()).to.deep.equal(expected)
+        })
+      )
     })
 
     describe('multiple adds', () => {
-      [
+      ;[
         ['demotes digits-only candidates', ['01', 'anna karenina'], ['anna karenina', '01']],
         ['promotes transformed variants', ['title1 1', 'title2 1'], ['title1', 'title2', 'title1 1', 'title2 1']],
         ['orders by position', ['title2', 'title1'], ['title2', 'title1']],
-        ['dedupes candidates', ['title1', 'title1'], ['title1']],
+        ['dedupes candidates', ['title1', 'title1'], ['title1']]
-      ].forEach(([name, titles, expected]) => it(name, () => {
+      ].forEach(([name, titles, expected]) =>
-        for (const title of titles) titleCandidates.add(title)
+        it(name, () => {
-        expect(titleCandidates.getCandidates()).to.deep.equal(expected)
+          for (const title of titles) titleCandidates.add(title)
-      }))
+          expect(titleCandidates.getCandidates()).to.deep.equal(expected)
+        })
+      )
     })
   })
 
@@ -69,12 +73,12 @@ describe('TitleCandidates', () => {
     })
 
     describe('single add', () => {
-      [
+      ;[['adds a candidate', 'leo tolstoy', ['leo tolstoy']]].forEach(([name, title, expected]) =>
-        ['adds a candidate', 'leo tolstoy', ['leo tolstoy']],
+        it(name, () => {
-      ].forEach(([name, title, expected]) => it(name, () => {
+          titleCandidates.add(title)
-        titleCandidates.add(title)
+          expect(titleCandidates.getCandidates()).to.deep.equal(expected)
-        expect(titleCandidates.getCandidates()).to.deep.equal(expected)
+        })
-      }))
+      )
     })
   })
 })
@@ -82,11 +86,7 @@ describe('TitleCandidates', () => {
 describe('AuthorCandidates', () => {
   let authorCandidates
   const audnexus = {
-    authorASINsRequest: sinon.stub().resolves([
+    authorASINsRequest: sinon.stub().resolves([{ name: 'Leo Tolstoy' }, { name: 'Nikolai Gogol' }, { name: 'J. K. Rowling' }])
-      { name: 'Leo Tolstoy' },
-      { name: 'Nikolai Gogol' },
-      { name: 'J. K. Rowling' },
-    ]),
   }
 
   describe('cleanAuthor is null', () => {
@@ -95,15 +95,15 @@ describe('AuthorCandidates', () => {
     })
 
     describe('no adds', () => {
-      [
+      ;[['returns empty author candidate', []]].forEach(([name, expected]) =>
-        ['returns empty author candidate', []],
+        it(name, async () => {
-      ].forEach(([name, expected]) => it(name, async () => {
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
-      }))
+      )
     })
 
     describe('single add', () => {
-      [
+      ;[
         ['adds recognized candidate', 'nikolai gogol', ['nikolai gogol']],
         ['does not add unrecognized candidate', 'fyodor dostoevsky', []],
         ['adds recognized author if candidate is a superstring', 'dr. nikolai gogol', ['nikolai gogol']],
@@ -112,21 +112,25 @@ describe('AuthorCandidates', () => {
         ['does not add candidate if edit distance from any recognized author is large', 'nikolai google', []],
         ['adds normalized recognized candidate (contains redundant spaces)', 'nikolai    gogol', ['nikolai gogol']],
         ['adds normalized recognized candidate (et al removed)', 'nikolai gogol et al.', ['nikolai gogol']],
-        ['adds normalized recognized candidate (normalized initials)', 'j.k. rowling', ['j. k. rowling']],
+        ['adds normalized recognized candidate (normalized initials)', 'j.k. rowling', ['j. k. rowling']]
-      ].forEach(([name, author, expected]) => it(name, async () => {
+      ].forEach(([name, author, expected]) =>
-        authorCandidates.add(author)
+        it(name, async () => {
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+          authorCandidates.add(author)
-      }))
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
+      )
     })
 
     describe('multi add', () => {
-      [
+      ;[
         ['adds recognized author candidates', ['nikolai gogol', 'leo tolstoy'], ['nikolai gogol', 'leo tolstoy']],
-        ['dedupes author candidates', ['nikolai gogol', 'nikolai gogol'], ['nikolai gogol']],
+        ['dedupes author candidates', ['nikolai gogol', 'nikolai gogol'], ['nikolai gogol']]
-      ].forEach(([name, authors, expected]) => it(name, async () => {
+      ].forEach(([name, authors, expected]) =>
-        for (const author of authors) authorCandidates.add(author)
+        it(name, async () => {
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+          for (const author of authors) authorCandidates.add(author)
-      }))
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
+      )
     })
   })
 
@@ -138,21 +142,23 @@ describe('AuthorCandidates', () => {
     })
 
     describe('no adds', () => {
-      [
+      ;[['adds cleanAuthor as candidate', [cleanAuthor]]].forEach(([name, expected]) =>
-        ['adds cleanAuthor as candidate', [cleanAuthor]],
+        it(name, async () => {
-      ].forEach(([name, expected]) => it(name, async () => {
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
-      }))
+      )
     })
 
     describe('single add', () => {
-      [
+      ;[
         ['adds recognized candidate', 'nikolai gogol', [cleanAuthor, 'nikolai gogol']],
-        ['does not add candidate if it is a dupe of cleanAuthor', cleanAuthor, [cleanAuthor]],
+        ['does not add candidate if it is a dupe of cleanAuthor', cleanAuthor, [cleanAuthor]]
-      ].forEach(([name, author, expected]) => it(name, async () => {
+      ].forEach(([name, author, expected]) =>
-        authorCandidates.add(author)
+        it(name, async () => {
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+          authorCandidates.add(author)
-      }))
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
+      )
     })
   })
 
@@ -164,43 +170,47 @@ describe('AuthorCandidates', () => {
     })
 
     describe('no adds', () => {
-      [
+      ;[['adds cleanAuthor as candidate', [cleanAuthor]]].forEach(([name, expected]) =>
-        ['adds cleanAuthor as candidate', [cleanAuthor]],
+        it(name, async () => {
-      ].forEach(([name, expected]) => it(name, async () => {
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
-      }))
+      )
     })
 
     describe('single add', () => {
-      [
+      ;[
         ['adds recognized candidate and removes cleanAuthor', 'nikolai gogol', ['nikolai gogol']],
-        ['does not add unrecognized candidate', 'jackie chan', [cleanAuthor]],
+        ['does not add unrecognized candidate', 'jackie chan', [cleanAuthor]]
-      ].forEach(([name, author, expected]) => it(name, async () => {
+      ].forEach(([name, author, expected]) =>
-        authorCandidates.add(author)
+        it(name, async () => {
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+          authorCandidates.add(author)
-      }))
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
+      )
     })
   })
 
   describe('cleanAuthor is unrecognized and dirty', () => {
     describe('no adds', () => {
-      [
+      ;[
         ['adds aggressively cleaned cleanAuthor', 'fyodor dostoevsky, translated by jackie chan', ['fyodor dostoevsky']],
-        ['adds cleanAuthor if aggresively cleaned cleanAuthor is empty', ', jackie chan', [', jackie chan']],
+        ['adds cleanAuthor if aggresively cleaned cleanAuthor is empty', ', jackie chan', [', jackie chan']]
-      ].forEach(([name, cleanAuthor, expected]) => it(name, async () => {
+      ].forEach(([name, cleanAuthor, expected]) =>
-        authorCandidates = new bookFinder.constructor.AuthorCandidates(cleanAuthor, audnexus)
+        it(name, async () => {
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+          authorCandidates = new bookFinder.constructor.AuthorCandidates(cleanAuthor, audnexus)
-      }))
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
+      )
     })
 
     describe('single add', () => {
-      [
+      ;[['adds recognized candidate and removes cleanAuthor', 'fyodor dostoevsky, translated by jackie chan', 'nikolai gogol', ['nikolai gogol']]].forEach(([name, cleanAuthor, author, expected]) =>
-        ['adds recognized candidate and removes cleanAuthor', 'fyodor dostoevsky, translated by jackie chan', 'nikolai gogol', ['nikolai gogol']],
+        it(name, async () => {
-      ].forEach(([name, cleanAuthor, author, expected]) => it(name, async () => {
+          authorCandidates = new bookFinder.constructor.AuthorCandidates(cleanAuthor, audnexus)
-        authorCandidates = new bookFinder.constructor.AuthorCandidates(cleanAuthor, audnexus)
+          authorCandidates.add(author)
-        authorCandidates.add(author)
+          expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
-        expect(await authorCandidates.getCandidates()).to.deep.equal([...expected, ''])
+        })
-      }))
+      )
     })
   })
 })
@@ -211,16 +221,21 @@ describe('search', () => {
   const u = 'unrecognized'
   const r = ['book']
 
-  const runSearchStub = sinon.stub(bookFinder, 'runSearch')
+  let runSearchStub
-  runSearchStub.resolves([])
+  let audnexusStub
-  runSearchStub.withArgs(t, a).resolves(r)
-  runSearchStub.withArgs(t, u).resolves(r)
-
-  const audnexusStub = sinon.stub(bookFinder.audnexus, 'authorASINsRequest')
-  audnexusStub.resolves([{ name: a }])
 
   beforeEach(() => {
-    bookFinder.runSearch.resetHistory()
+    runSearchStub = sinon.stub(bookFinder, 'runSearch')
+    runSearchStub.resolves([])
+    runSearchStub.withArgs(t, a).resolves(r)
+    runSearchStub.withArgs(t, u).resolves(r)
+
+    audnexusStub = sinon.stub(bookFinder.audnexus, 'authorASINsRequest')
+    audnexusStub.resolves([{ name: a }])
+  })
+
+  afterEach(() => {
+    sinon.restore()
   })
 
   describe('search title is empty', () => {
@@ -238,50 +253,26 @@ describe('search', () => {
   })
 
   describe('search title contains recognized title and search author is a recognized author', () => {
-    [
+    ;[[`${t} -`], [`${t} - ${a}`], [`${a} - ${t}`], [`${t}- ${a}`], [`${t} -${a}`], [`${t} ${a}`], [`${a} - ${t} (unabridged)`], [`${a} - ${t} (subtitle) - mp3`], [`${t} {narrator} - series-01 64kbps 10:00:00`], [`${a} - ${t} (2006) narrated by narrator [unabridged]`], [`${t} - ${a} 2022 mp3`], [`01 ${t}`], [`2022_${t}_HQ`]].forEach(([searchTitle]) => {
-      [`${t} -`],
-      [`${t} - ${a}`],
-      [`${a} - ${t}`],
-      [`${t}- ${a}`],
-      [`${t} -${a}`],
-      [`${t} ${a}`],
-      [`${a} - ${t} (unabridged)`],
-      [`${a} - ${t} (subtitle) - mp3`],
-      [`${t} {narrator} - series-01 64kbps 10:00:00`],
-      [`${a} - ${t} (2006) narrated by narrator [unabridged]`],
-      [`${t} - ${a} 2022 mp3`],
-      [`01 ${t}`],
-      [`2022_${t}_HQ`],
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '${a}') returns non-empty result (with 1 fuzzy search)`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, a)).to.deep.equal(r)
         sinon.assert.callCount(bookFinder.runSearch, 2)
       })
-    });
+    })
-
+    ;[[`s-01 - ${t} (narrator) 64kbps 10:00:00`], [`${a} - series 01 - ${t}`]].forEach(([searchTitle]) => {
-    [
-      [`s-01 - ${t} (narrator) 64kbps 10:00:00`],
-      [`${a} - series 01 - ${t}`],
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '${a}') returns non-empty result (with 2 fuzzy searches)`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, a)).to.deep.equal(r)
         sinon.assert.callCount(bookFinder.runSearch, 3)
       })
-    });
+    })
-
+    ;[[`${t}-${a}`], [`${t} junk`]].forEach(([searchTitle]) => {
-    [
-      [`${t}-${a}`],
-      [`${t} junk`],
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '${a}') returns an empty result`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, a)).to.deep.equal([])
       })
     })
 
     describe('maxFuzzySearches = 0', () => {
-      [
+      ;[[`${t} - ${a}`]].forEach(([searchTitle]) => {
-        [`${t} - ${a}`],
-      ].forEach(([searchTitle]) => {
         it(`search('${searchTitle}', '${a}') returns an empty result (with no fuzzy searches)`, async () => {
           expect(await bookFinder.search(null, '', searchTitle, a, null, null, { maxFuzzySearches: 0 })).to.deep.equal([])
           sinon.assert.callCount(bookFinder.runSearch, 1)
@@ -290,10 +281,7 @@ describe('search', () => {
     })
 
     describe('maxFuzzySearches = 1', () => {
-      [
+      ;[[`s-01 - ${t} (narrator) 64kbps 10:00:00`], [`${a} - series 01 - ${t}`]].forEach(([searchTitle]) => {
-        [`s-01 - ${t} (narrator) 64kbps 10:00:00`],
-        [`${a} - series 01 - ${t}`],
-      ].forEach(([searchTitle]) => {
         it(`search('${searchTitle}', '${a}') returns an empty result (1 fuzzy search)`, async () => {
           expect(await bookFinder.search(null, '', searchTitle, a, null, null, { maxFuzzySearches: 1 })).to.deep.equal([])
           sinon.assert.callCount(bookFinder.runSearch, 2)
@@ -303,21 +291,13 @@ describe('search', () => {
   })
 
   describe('search title contains recognized title and search author is empty', () => {
-    [
+    ;[[`${t} - ${a}`], [`${a} - ${t}`]].forEach(([searchTitle]) => {
-      [`${t} - ${a}`],
-      [`${a} - ${t}`],
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '') returns a non-empty result (1 fuzzy search)`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, '')).to.deep.equal(r)
         sinon.assert.callCount(bookFinder.runSearch, 2)
       })
-    });
+    })
-
+    ;[[`${t}`], [`${t} - ${u}`], [`${u} - ${t}`]].forEach(([searchTitle]) => {
-    [
-      [`${t}`],
-      [`${t} - ${u}`],
-      [`${u} - ${t}`]
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '') returns an empty result`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, '')).to.deep.equal([])
       })
@@ -325,19 +305,13 @@ describe('search', () => {
   })
 
   describe('search title contains recognized title and search author is an unrecognized author', () => {
-    [
+    ;[[`${t} - ${u}`], [`${u} - ${t}`]].forEach(([searchTitle]) => {
-      [`${t} - ${u}`],
-      [`${u} - ${t}`]
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '${u}') returns a non-empty result (1 fuzzy search)`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, u)).to.deep.equal(r)
         sinon.assert.callCount(bookFinder.runSearch, 2)
       })
-    });
+    })
-
+    ;[[`${t}`]].forEach(([searchTitle]) => {
-    [
-      [`${t}`]
-    ].forEach(([searchTitle]) => {
       it(`search('${searchTitle}', '${u}') returns a non-empty result (no fuzzy search)`, async () => {
         expect(await bookFinder.search(null, '', searchTitle, u)).to.deep.equal(r)
         sinon.assert.callCount(bookFinder.runSearch, 1)
@@ -346,16 +320,19 @@ describe('search', () => {
   })
 
   describe('search provider results have duration', () => {
-    const  libraryItem = { media: { duration: 60 * 1000 } }
+    const libraryItem = { media: { duration: 60 * 1000 } }
     const provider = 'audible'
     const unsorted = [{ duration: 3000 }, { duration: 2000 }, { duration: 1000 }, { duration: 500 }]
     const sorted = [{ duration: 1000 }, { duration: 500 }, { duration: 2000 }, { duration: 3000 }]
-    runSearchStub.withArgs(t, a, provider).resolves(unsorted)
+
+    beforeEach(() => {
+      runSearchStub.withArgs(t, a, provider).resolves(unsorted)
+    })
 
     it('returns results sorted by library item duration diff', async () => {
       expect(await bookFinder.search(libraryItem, provider, t, a)).to.deep.equal(sorted)
     })
-    
+
     it('returns unsorted results if library item is null', async () => {
       expect(await bookFinder.search(null, provider, t, a)).to.deep.equal(unsorted)
     })
@@ -365,10 +342,10 @@ describe('search', () => {
     })
 
     it('returns unsorted results if library item media is undefined', async () => {
-      expect(await bookFinder.search({ }, provider, t, a)).to.deep.equal(unsorted)
+      expect(await bookFinder.search({}, provider, t, a)).to.deep.equal(unsorted)
     })
 
-    it ('should return a result last if it has no duration', async () => {
+    it('should return a result last if it has no duration', async () => {
       const unsorted = [{}, { duration: 3000 }, { duration: 2000 }, { duration: 1000 }, { duration: 500 }]
       const sorted = [{ duration: 1000 }, { duration: 500 }, { duration: 2000 }, { duration: 3000 }, {}]
       runSearchStub.withArgs(t, a, provider).resolves(unsorted)