[Fix/Refactor] Make all logs async (#3507)

* Make all logs async

* Remove correct LogWriter in stopLogger

* Fix tests

* Uncomment test

* Handle getPath throwing error if invalid logs path

src/backend/launcher.ts

@@ -17,12 +17,7 @@ import {
 // This handles launching games, prefix creation etc..
 
 import i18next from 'i18next'
-import {
-  existsSync,
-  mkdirSync,
-  appendFileSync,
-  writeFileSync
-} from 'graceful-fs'
+import { existsSync, mkdirSync } from 'graceful-fs'
 import { join, normalize } from 'path'
 
 import {
@@ -46,6 +41,11 @@ import {
   sendGameStatusUpdate
 } from './utils'
 import {
+  appendFileLog,
+  appendGameLog,
+  appendRunnerLog,
+  initFileLog,
+  initGameLog,
   logDebug,
   logError,
   logInfo,
@@ -873,7 +873,7 @@ async function runWineCommand({
       }
 
       if (options?.logFile && existsSync(options.logFile)) {
-        appendFileSync(
+        appendFileLog(
           options.logFile,
           `Wine Command: ${bin} ${commandParts.join(' ')}\n\nGame Log:\n`
         )
@@ -885,7 +885,7 @@ async function runWineCommand({
 
     child.stdout.on('data', (data: string) => {
       if (!logsDisabled && options?.logFile) {
-        appendFileSync(options.logFile, data)
+        appendFileLog(options.logFile, data)
       }
 
       if (options?.onOutput) {
@@ -897,7 +897,7 @@ async function runWineCommand({
 
     child.stderr.on('data', (data: string) => {
       if (!logsDisabled && options?.logFile) {
-        appendFileSync(options.logFile, data)
+        appendFileLog(options.logFile, data)
       }
 
       if (options?.onOutput) {
@@ -974,14 +974,18 @@ async function callRunner(
     }
 
     if (options?.verboseLogFile) {
-      appendFileSync(
-        options.verboseLogFile,
+      appendRunnerLog(
+        runner.name,
         `[${new Date().toLocaleString()}] ${safeCommand}\n`
       )
     }
 
-    if (options?.logFile && existsSync(options.logFile)) {
-      writeFileSync(options.logFile, '')
+    if (options?.logFile) {
+      if (appName) {
+        initGameLog(appName)
+      } else {
+        initFileLog(options.logFile)
+      }
     }
   }
 
@@ -1017,11 +1021,15 @@ async function callRunner(
 
       if (!logsDisabled) {
         if (options?.logFile) {
-          appendFileSync(options.logFile, stringToLog)
+          if (appName) {
+            appendGameLog(appName, stringToLog)
+          } else {
+            appendFileLog(options.logFile, stringToLog)
+          }
         }
 
         if (options?.verboseLogFile) {
-          appendFileSync(options.verboseLogFile, stringToLog)
+          appendRunnerLog(runner.name, stringToLog)
         }
       }
 
@@ -1040,11 +1048,15 @@ async function callRunner(
 
       if (!logsDisabled) {
         if (options?.logFile) {
-          appendFileSync(options.logFile, stringToLog)
+          if (appName) {
+            appendGameLog(appName, stringToLog)
+          } else {
+            appendFileLog(options.logFile, stringToLog)
+          }
         }
 
         if (options?.verboseLogFile) {
-          appendFileSync(options.verboseLogFile, stringToLog)
+          appendRunnerLog(runner.name, stringToLog)
         }
       }
 

src/backend/logger/__tests__/logfile.test.ts

@@ -4,7 +4,7 @@ import { join } from 'path'
 import { app } from 'electron'
 import { configStore } from '../../constants'
 import * as logfile from '../logfile'
-import { logError } from '../logger'
+import * as logger from '../logger'
 import { describeSkipOnWindows } from 'backend/__tests__/skip'
 
 jest.mock('electron')
@@ -26,26 +26,20 @@ describeSkipOnWindows('logger/logfile.ts', () => {
   })
 
   test('createNewLogFileAndClearOldOnes fails because logDir does not exist', () => {
-    const spyAppGetPath = jest.spyOn(app, 'getPath').mockReturnValue('invalid')
-    const spyOpenSync = jest.spyOn(graceful_fs, 'openSync')
-
-    logfile.createNewLogFileAndClearOldOnes()
+    jest.spyOn(app, 'getPath').mockImplementation(() => {
+      throw Error('Some error message from getPath')
+    })
+    const consoleSpy = jest.spyOn(console, 'log')
 
-    const year = `${new Date().getFullYear()}`
+    const logs = logfile.createNewLogFileAndClearOldOnes()
 
-    expect(spyOpenSync).toBeCalledWith(
-      expect.stringContaining(`invalid/${year}-`),
-      'w'
-    )
-    expect(spyAppGetPath).toBeCalledWith('logs')
-    expect(logError).toBeCalledWith(
-      [
-        expect.stringContaining(`Open invalid/${year}-`),
-        expect.objectContaining(
-          Error(`ENOENT: no such file or directory, open 'invalid/${year}-`)
-        )
-      ],
-      { prefix: 'Backend', skipLogToFile: true }
+    expect(logs.currentLogFile).toBe('')
+    expect(logs.gogdlLogFile).toBe('')
+    expect(logs.lastLogFile).toBe('')
+    expect(logs.legendaryLogFile).toBe('')
+    expect(logs.nileLogFile).toBe('')
+    expect(consoleSpy).toBeCalledWith(
+      "Could not get 'logs' directory. Error: Some error message from getPath"
     )
   })
 
@@ -61,7 +55,7 @@ describeSkipOnWindows('logger/logfile.ts', () => {
 
     const data = logfile.createNewLogFileAndClearOldOnes()
 
-    expect(logError).not.toBeCalled()
+    expect(logger.logError).not.toBeCalled()
     expect(data).toStrictEqual({
       currentLogFile: expect.any(String),
       lastLogFile: 'old/log/path/file.log',
@@ -89,7 +83,7 @@ describeSkipOnWindows('logger/logfile.ts', () => {
 
     logfile.createNewLogFileAndClearOldOnes()
 
-    expect(logError).toBeCalledWith(
+    expect(logger.logError).toBeCalledWith(
       [
         expect.stringContaining('Removing old logs in /tmp/'),
         Error('unlink failed')
@@ -121,7 +115,7 @@ describeSkipOnWindows('logger/logfile.ts', () => {
 
     logfile.createNewLogFileAndClearOldOnes()
 
-    expect(logError).not.toBeCalled()
+    expect(logger.logError).not.toBeCalled()
     expect(graceful_fs.existsSync(monthOutdatedLogFile)).toBeFalsy()
     expect(graceful_fs.existsSync(yearOutdatedLogFile)).toBeFalsy()
   })
@@ -137,40 +131,12 @@ describeSkipOnWindows('logger/logfile.ts', () => {
     )
   })
 
-  test('appendMessageToLogFile success', () => {
-    const appendFileSyncSpy = jest
-      .spyOn(graceful_fs, 'appendFileSync')
-      .mockReturnValue()
-
-    logfile.appendMessageToLogFile('Hello World')
-    expect(appendFileSyncSpy).toBeCalledWith('current.log', 'Hello World\n')
-  })
-
-  test('appendMessageToLogFile logfile undefined', () => {
-    const appendFileSyncSpy = jest
-      .spyOn(graceful_fs, 'appendFileSync')
+  test('appendMessageToLogFile success', async () => {
+    const appendHeroicLogSpy = jest
+      .spyOn(logger, 'appendHeroicLog')
       .mockReturnValue()
 
-    const mockConstants = jest.requireMock('../../constants')
-    const defaultCurrentLogName = mockConstants.currentLogFile
-    mockConstants.currentLogFile = ''
-
     logfile.appendMessageToLogFile('Hello World')
-
-    mockConstants.currentLogFile = defaultCurrentLogName
-
-    expect(appendFileSyncSpy).not.toBeCalled()
-  })
-
-  test('appendMessageToLogFile fails', () => {
-    jest.spyOn(graceful_fs, 'appendFileSync').mockImplementation(() => {
-      throw Error('append failed')
-    })
-
-    logfile.appendMessageToLogFile('Hello World')
-    expect(logError).toBeCalledWith(
-      ['Writing log file failed with', Error('append failed')],
-      { prefix: 'Backend', skipLogToFile: true }
-    )
+    expect(appendHeroicLogSpy).toBeCalledWith('Hello World\n')
   })
 })

src/backend/logger/__tests__/logger.test.ts

@@ -43,7 +43,7 @@ function getStringPassedToLogFile(type: logLevel, skipMessagePrefix = false) {
 describeSkipOnWindows('logger/logger.ts', () => {
   afterEach(jest.restoreAllMocks)
 
-  test('log invokes console', () => {
+  test('log invokes console', async () => {
     const spyConsoleError = jest
       .spyOn(global.console, 'error')
       .mockImplementation()

src/backend/logger/logfile.ts

@@ -1,15 +1,12 @@
-import {
-  existsSync,
-  openSync,
-  readdirSync,
-  unlinkSync,
-  appendFileSync
-} from 'graceful-fs'
-
-import { configStore, currentLogFile } from '../constants'
+import { existsSync, readdirSync, unlinkSync } from 'graceful-fs'
+
+import { configStore } from '../constants'
 import { app } from 'electron'
 import { join } from 'path'
 import {
+  appendHeroicLog,
+  initHeroicLog,
+  initRunnerLog,
   lastPlayLogFileLocation,
   logError,
   LogPrefix,
@@ -27,25 +24,27 @@ interface createLogFileReturn {
 let longestPrefix = 0
 export const getLongestPrefix = (): number => longestPrefix
 
-const createLogFile = (filePath: string) => {
-  try {
-    openSync(filePath, 'w')
-  } catch (error) {
-    logError([`Open ${filePath} failed with`, error], {
-      prefix: LogPrefix?.Backend,
-      skipLogToFile: true
-    })
-  }
-}
-
 /**
  * Creates a new log file in heroic config path under folder Logs.
  * It also removes old logs every new month.
  * @returns path to current log file
  */
 export function createNewLogFileAndClearOldOnes(): createLogFileReturn {
   const date = new Date()
-  const logDir = app.getPath('logs')
+  let logDir = ''
+  try {
+    logDir = app.getPath('logs')
+  } catch (error) {
+    console.log(`Could not get 'logs' directory. ${error}`)
+    return {
+      currentLogFile: '',
+      lastLogFile: '',
+      legendaryLogFile: '',
+      gogdlLogFile: '',
+      nileLogFile: ''
+    }
+  }
+
   const fmtDate = date
     .toISOString()
     .replaceAll(':', '_')
@@ -55,10 +54,10 @@ export function createNewLogFileAndClearOldOnes(): createLogFileReturn {
   const newGogdlLogFile = join(logDir, `${fmtDate}-gogdl.log`)
   const newNileLogFile = join(logDir, `${fmtDate}-nile.log`)
 
-  createLogFile(newLogFile)
-  createLogFile(newLegendaryLogFile)
-  createLogFile(newGogdlLogFile)
-  createLogFile(newNileLogFile)
+  initHeroicLog(newLogFile)
+  initRunnerLog('legendary', newLegendaryLogFile)
+  initRunnerLog('gog', newGogdlLogFile)
+  initRunnerLog('nile', newNileLogFile)
 
   const logs = configStore.get('general-logs', {
     currentLogFile: '',
@@ -150,8 +149,8 @@ export function getLogFile(appNameOrRunner: string): string {
  */
 export function appendMessageToLogFile(message: string) {
   try {
-    if (!logsDisabled && currentLogFile) {
-      appendFileSync(currentLogFile, `${message}\n`)
+    if (!logsDisabled) {
+      appendHeroicLog(`${message}\n`)
     }
   } catch (error) {
     logError(['Writing log file failed with', error], {