service-core/test/log.test.mjs

import { Eltro as t, assert, stub } from 'eltro'
import fs from 'fs/promises'
import getLog from '../core/log.mjs'

t.describe('#constructor', function() {
  t.afterEach(function() {
    process.env.NODE_ENV = null
  })


  t.after(function() {
    return Promise.all([
      fs.rm('./log.log', { recursive: true, force: true }),
    ])
  })

  t.test('should add name', function() {
    const assertName = 'Stray Cat'
    let logger = getLog(assertName)
    assert.strictEqual(logger.fields.name, assertName)

    process.env.NODE_ENV = 'production'
    logger = getLog(assertName)
    assert.strictEqual(logger.fields.name, assertName)
  })

  t.test('should add default stdout streams in normal environment', function() {
    let logger = getLog('app', null)
    assert.strictEqual(logger.streams.length, 4)
    assert.strictEqual(logger.streams[0].stream, process.stdout)
    assert.strictEqual(logger.streams[0].level, 20)
  })

  t.test('should add default file log stream in production environment', function() {
    process.env.NODE_ENV = 'production'

    let logger = getLog('app', null)
    assert.strictEqual(logger.streams.length, 4)
    assert.strictEqual(logger.streams[0].path, 'log.log')
    assert.strictEqual(logger.streams[0].level, 30)
  })

  t.test('should not add default stream if empty array', function() {
    let logger = getLog('app', [])
    assert.strictEqual(logger.streams.length, 3)

    process.env.NODE_ENV = 'production'
    logger = getLog('app', [])
    assert.strictEqual(logger.streams.length, 3)
  })

  t.test('should replace process.stdout with actual process', function() {
    let logger = getLog('app', [{ stream: 'process.stdout', level: 'info' }])
    assert.strictEqual(logger.streams.length, 4)
    assert.strictEqual(logger.streams[0].stream, process.stdout)

    process.env.NODE_ENV = 'production'
    logger = getLog('app', [{ stream: 'process.stdout', level: 'info' }])
    assert.strictEqual(logger.streams.length, 4)
    assert.strictEqual(logger.streams[0].stream, process.stdout)
  })
})

t.describe('ringbuffer', function() {
  let logger

  t.beforeEach(function() {
    logger = getLog('app', [])
  })
  
  t.test('should have ringbuffer for info', function() {
    const assertMessage = 'Oitachi'

    assert.strictEqual(logger.ringbuffer.records.length, 0)
    logger.info(assertMessage)
    assert.strictEqual(logger.ringbuffer.records.length, 1)
    assert.strictEqual(logger.ringbuffer.records[0].level, 30)
    assert.strictEqual(logger.ringbuffer.records[0].msg, assertMessage)
    logger.debug(assertMessage)
    assert.strictEqual(logger.ringbuffer.records.length, 1)
    logger.warn(assertMessage)
    assert.strictEqual(logger.ringbuffer.records.length, 2)
    assert.strictEqual(logger.ringbuffer.records[1].level, 40)
    assert.strictEqual(logger.ringbuffer.records[1].msg, assertMessage)
  })

  t.test('should keep it limited to max 100 records', function() {
    const assertPrefix = 'In memory of Keiten'

    for (let i = 1; i <= 101; i++) {
      logger.info(assertPrefix + i)
    }
    assert.strictEqual(logger.ringbuffer.records.length, 100)
    assert.strictEqual(logger.ringbuffer.records[0].msg, assertPrefix + '2')
    
    logger.info(assertPrefix)
    
    assert.strictEqual(logger.ringbuffer.records.length, 100)
    assert.strictEqual(logger.ringbuffer.records[0].msg, assertPrefix + '3')
  })
})

t.describe('ringbufferwarn', function() {
  let logger

  t.beforeEach(function() {
    logger = getLog('app', [])
  })
  
  t.test('should have ringbufferwarn for info', function() {
    const assertMessage = 'Oitachi'

    assert.strictEqual(logger.ringbufferwarn.records.length, 0)
    logger.warn(assertMessage)
    assert.strictEqual(logger.ringbufferwarn.records.length, 1)
    assert.strictEqual(logger.ringbufferwarn.records[0].level, 40)
    assert.strictEqual(logger.ringbufferwarn.records[0].msg, assertMessage)
    logger.info(assertMessage)
    assert.strictEqual(logger.ringbufferwarn.records.length, 1)
    logger.error(assertMessage)
    assert.strictEqual(logger.ringbufferwarn.records.length, 2)
    assert.strictEqual(logger.ringbufferwarn.records[1].level, 50)
    assert.strictEqual(logger.ringbufferwarn.records[1].msg, assertMessage)
  })

  t.test('should keep it limited to max 100 records', function() {
    const assertPrefix = 'In memory of Keiten'

    for (let i = 1; i <= 101; i++) {
      logger.warn(assertPrefix + i)
    }
    assert.strictEqual(logger.ringbufferwarn.records.length, 100)
    assert.strictEqual(logger.ringbufferwarn.records[0].msg, assertPrefix + '2')
    
    logger.warn(assertPrefix)
    
    assert.strictEqual(logger.ringbufferwarn.records.length, 100)
    assert.strictEqual(logger.ringbufferwarn.records[0].msg, assertPrefix + '3')
  })
})

t.describe('event', function() {
  t.test('should call import if not in production', async function() {
    let stubImport = stub()
    stubImport.rejects(new Error('should not be seen'))

    let logger = getLog('app', [], { import: stubImport })

    let first = new Promise(function(res, rej) {
      setImmediate(function() { logger.event.warn('text message here').then(res, rej) })
    })
    let second = new Promise(function(res, rej) {
      setImmediate(function() { logger.event.warn('new message here').then(res, rej) })
    })

    await Promise.all([
      first, second,
    ])

    assert.notOk(stubImport.called)
  })

  t.test('should call import correctly if in production and fail only once', async function() {
    process.env.NODE_ENV = 'production'

    let stubImport = stub()
    stubImport.rejects(new Error('should not be seen'))

    let logger = getLog('app', [], { import: stubImport })

    let first = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.warn('first').then(res, rej) } catch (err) { rej(err) } })
    })
    let second = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.warn('second').then(res, rej) } catch (err) { rej(err) } })
    })

    await Promise.all([
      first, second,
    ])

    assert.ok(stubImport.called)
    assert.strictEqual(stubImport.callCount, 1)
    assert.strictEqual(stubImport.firstCall[0], 'node-windows')

    await new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.warn('third').then(res, rej) } catch (err) { rej(err) } })
    })
  })

  t.test('should call event on imported object correctly', async function() {
    const assertName = 'It is going to be The Special'
    let checkName = ''
    let stubInfo = stub().returnWith(function(msg, code, cb) { setTimeout(cb, 20) })
    let stubWarn = stub().returnWith(function(msg, code, cb) { setTimeout(cb, 20) })
    let stubError = stub().returnWith(function(msg, code, cb) { setTimeout(cb, 20) })
    process.env.NODE_ENV = 'production'

    let stubImport = stub().resolves({
      default: {
        EventLogger: function(name) {
          checkName = name
          this.info = stubInfo
          this.warn = stubWarn
          this.error = stubError
        },
      },
    })

    let logger = getLog(assertName, [], { import: stubImport })

    let first = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.info('first', 1010).then(res, rej) } catch (err) { rej(err) } })
    })
    let second = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.warn('second', 1020).then(res, rej) } catch (err) { rej(err) } })
    })

    await Promise.all([
      first, second,
    ])

    assert.strictEqual(checkName, assertName)
    assert.ok(stubInfo.called)
    assert.strictEqual(stubInfo.firstCall[0], 'first')
    assert.strictEqual(stubInfo.firstCall[1], 1010)
    assert.ok(stubWarn.called)
    assert.strictEqual(stubWarn.firstCall[0], 'second')
    assert.strictEqual(stubWarn.firstCall[1], 1020)
    assert.notOk(stubError.called)

    await new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.error('third', 1030).then(res, rej) } catch (err) { rej(err) } })
    })

    assert.ok(stubError.called)
    assert.strictEqual(stubError.firstCall[0], 'third')
    assert.strictEqual(stubError.firstCall[1], 1030)
  })

  t.test('should work even if it were to throw', async function() {
    const assertName = 'It is going to be The Special'
    let checkName = ''
    let stubInfo = stub().returnWith(function() { throw new Error('not to be seen') })
    let stubWarn = stub().returnWith(function() { throw new Error('not to be seen') })
    let stubError = stub().returnWith(function() { throw new Error('not to be seen') })
    process.env.NODE_ENV = 'production'

    let stubImport = stub().resolves({
      default: {
        EventLogger: function(name) {
          checkName = name
          this.info = stubInfo
          this.warn = stubWarn
          this.error = stubError
        },
      },
    })

    let logger = getLog(assertName, [], { import: stubImport })

    let first = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.info().then(res, rej) } catch (err) { rej(err) } })
    })
    let second = new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.warn().then(res, rej) } catch (err) { rej(err) } })
    })

    await Promise.all([
      first, second,
    ])

    assert.strictEqual(checkName, assertName)
    assert.ok(stubInfo.called)
    assert.ok(stubWarn.called)
    assert.notOk(stubError.called)

    await new Promise(function(res, rej) {
      setImmediate(function() { try { logger.event.error().then(res, rej) } catch (err) { rej(err) } })
    })

    assert.ok(stubError.called)
  })

  t.test('should work without stub', async function() {
    let res = await import('node-windows').catch(function() {})
    if (!res) { return }

    process.env.NODE_ENV = 'production'
    let logger = getLog('service-core-unit-test', [])

    await logger.event.info('Hello from service-core log.event unit test')
  })
})