From 91ac4fc86ef2934ce1527aa3542301ef3050a004 Mon Sep 17 00:00:00 2001 From: burgerni10 Date: Sat, 22 Oct 2022 09:02:17 +0200 Subject: [PATCH] fix(north): fix file cache stat eperm error --- src/engine/cache/file-cache.js | 88 ++++++++++++++++++---------- src/engine/cache/file-cache.spec.js | 89 ++++++++++++++++++++++++++++- src/north/north-connector.js | 4 +- 3 files changed, 149 insertions(+), 32 deletions(-) diff --git a/src/engine/cache/file-cache.js b/src/engine/cache/file-cache.js index 734b85ab8e..935a58d5f9 100644 --- a/src/engine/cache/file-cache.js +++ b/src/engine/cache/file-cache.js @@ -54,18 +54,28 @@ class FileCache extends BaseCache { await createFolder(this.fileFolder) await createFolder(this.errorFolder) - const files = await fs.readdir(this.fileFolder) - if (files.length > 0) { - this.logger.debug(`${files.length} files in cache.`) - } else { - this.logger.debug('No files in cache.') + try { + const files = await fs.readdir(this.fileFolder) + if (files.length > 0) { + this.logger.debug(`${files.length} files in cache.`) + } else { + this.logger.debug('No files in cache.') + } + } catch (error) { + // If the folder does not exist, an error is logged but OIBus keep going to check errors and archive folders + this.logger.error(error) } - const errorFiles = await fs.readdir(this.errorFolder) - if (errorFiles.length > 0) { - this.logger.warn(`${errorFiles.length} files in error cache.`) - } else { - this.logger.debug('No error files in cache.') + try { + const errorFiles = await fs.readdir(this.errorFolder) + if (errorFiles.length > 0) { + this.logger.warn(`${errorFiles.length} files in error cache.`) + } else { + this.logger.debug('No error files in cache.') + } + } catch (error) { + // If the folder does not exist, an error is logged but not thrown if the file cache folder is accessible + this.logger.error(error) } if (this.archiveFiles) { @@ -122,24 +132,25 @@ class FileCache extends BaseCache { return null } - const sortedFiles = fileNames - .map(async (fileName) => { - // Retrieve file state to retrieve the oldest one from the cache - let fileState = null + const fileStats = [] + // Get file stats one after the other + await fileNames.reduce((promise, fileName) => promise.then( + async () => { try { - // Error triggered when a file is being written (from a South) - fileState = await fs.stat(path.resolve(this.fileFolder, fileName)) + const stat = await fs.stat(path.resolve(this.fileFolder, fileName)) + fileStats.push({ + path: path.resolve(this.fileFolder, fileName), + timestamp: stat.mtime.getTime(), + }) } catch (error) { + // If a file is being written or corrupted, the stat method can fail + // An error is logged and the cache goes through the other files this.logger.error(error) } - return { - path: path.resolve(this.fileFolder, fileName), - timestamp: fileState ? fileState.mtime.getTime() : null, - } - }) - // filter out files that are not completely written - .filter((file) => file.timestamp !== null) - .sort((a, b) => a.timestamp - b.timestamp) + }, + ), Promise.resolve()) + + const sortedFiles = fileStats.sort((a, b) => a.timestamp - b.timestamp) return sortedFiles[0] } @@ -195,7 +206,13 @@ class FileCache extends BaseCache { * @returns {Boolean} - Cache empty or not */ async isEmpty() { - const files = await fs.readdir(this.fileFolder) + let files = [] + try { + files = await fs.readdir(this.fileFolder) + } catch (error) { + // Log an error if the folder does not exist (removed by the user while OIBus is running for example) + this.logger.error(error) + } return files.length === 0 } @@ -210,9 +227,16 @@ class FileCache extends BaseCache { clearTimeout(this.archiveTimeout) } - const files = await fs.readdir(this.archiveFolder) - const referenceDate = new Date().getTime() + let files = [] + try { + files = await fs.readdir(this.archiveFolder) + } catch (error) { + // If the archive folder doest not exist (removed by the user for example), an error is logged + this.logger.error(error) + } if (files.length > 0) { + const referenceDate = new Date().getTime() + // Map each file to a promise and remove files sequentially await files.reduce((promise, file) => promise.then( async () => this.removeFileIfTooOld(file, referenceDate, this.archiveFolder), @@ -231,8 +255,14 @@ class FileCache extends BaseCache { * @returns {Promise} - The result promise */ async removeFileIfTooOld(filePath, referenceDate, archiveFolder) { - const stats = await fs.stat(path.join(archiveFolder, filePath)) - if (stats.mtimeMs + this.retentionDuration < referenceDate) { + let stats + try { + // If a file is being written or corrupted, the stat method can fail an error is logged + stats = await fs.stat(path.join(archiveFolder, filePath)) + } catch (error) { + this.logger.error(error) + } + if (stats && stats.mtimeMs + this.retentionDuration < referenceDate) { try { await fs.unlink(path.join(archiveFolder, filePath)) this.logger.debug(`File "${path.join(archiveFolder, filePath)}" removed from archive.`) diff --git a/src/engine/cache/file-cache.spec.js b/src/engine/cache/file-cache.spec.js index 0c4fd93f34..56f47d7176 100644 --- a/src/engine/cache/file-cache.spec.js +++ b/src/engine/cache/file-cache.spec.js @@ -61,6 +61,20 @@ describe('FileCache', () => { expect(cache.refreshArchiveFolder).not.toHaveBeenCalled() }) + it('should be properly initialized with a readdir error', async () => { + cache.refreshArchiveFolder = jest.fn() + fs.readdir.mockImplementation(() => { + throw new Error('readdir error') + }) + cache.retentionDuration = 0 + await cache.init() + + expect(logger.error).toHaveBeenCalledWith(new Error('readdir error')) + expect(logger.error).toHaveBeenCalledTimes(2) + + expect(cache.refreshArchiveFolder).not.toHaveBeenCalled() + }) + it('should be properly initialized without archive files', async () => { cache.archiveFiles = false cache.refreshArchiveFolder = jest.fn() @@ -93,6 +107,21 @@ describe('FileCache', () => { expect(logger.debug).toHaveBeenCalledWith(`File "myFile.csv" cached in "${path.resolve('myCacheFolder', 'files', 'myFile-1580608922222.csv')}".`) }) + it('should properly managed cache file error', async () => { + fs.copyFile.mockImplementation(() => { + throw new Error('copy file') + }) + + let error + try { + await cache.cacheFile('myFile.csv') + } catch (copyError) { + error = copyError + } + + expect(error).toEqual(new Error('copy file')) + }) + it('should properly retrieve file from cache', async () => { fs.readdir.mockImplementationOnce(() => []).mockImplementation(() => ['myFile1', 'myFile2']) fs.stat.mockImplementation(() => ({ mtime: new Date() })) @@ -107,6 +136,33 @@ describe('FileCache', () => { }) }) + it('should properly manage error when retrieving file from cache', async () => { + fs.readdir.mockImplementation(() => { + throw new Error('readdir error') + }) + + const noFile = await cache.retrieveFileFromCache() + expect(noFile).toEqual(null) + expect(logger.error).toHaveBeenCalledWith(new Error('readdir error')) + }) + + it('should properly retrieve file from cache and manage file error', async () => { + fs.readdir.mockImplementation(() => ['myFile1', 'myFile2', 'myFile3']) + fs.stat.mockImplementationOnce(() => ({ mtime: new Date() })) + .mockImplementationOnce(() => { + throw new Error('stat error') + }) + .mockImplementationOnce(() => ({ mtime: new Date('2010-02-01T02:02:02.222Z') })) + + const oneFile = await cache.retrieveFileFromCache() + expect(oneFile).toEqual({ + path: path.resolve(cache.fileFolder, 'myFile3'), + timestamp: 1264989722222, + }) + expect(logger.error).toHaveBeenCalledTimes(1) + expect(logger.error).toHaveBeenCalledWith(new Error('stat error')) + }) + it('should properly manage error files', async () => { fs.rename.mockImplementationOnce(() => {}).mockImplementationOnce(() => { throw new Error('rename error') @@ -144,11 +200,20 @@ describe('FileCache', () => { }) it('should check if cache is empty', async () => { - fs.readdir.mockImplementationOnce(() => []).mockImplementation(() => ['myFile1', 'myFile2']) + fs.readdir.mockImplementationOnce(() => []) + .mockImplementationOnce(() => ['myFile1', 'myFile2']) + .mockImplementationOnce(() => { + throw new Error('readdir error') + }) const empty = await cache.isEmpty() expect(empty).toBeTruthy() const notEmpty = await cache.isEmpty() expect(notEmpty).toBeFalsy() + + const emptyBecauseOfError = await cache.isEmpty() + expect(emptyBecauseOfError).toBeTruthy() + expect(logger.error).toHaveBeenCalledTimes(1) + expect(logger.error).toHaveBeenCalledWith(new Error('readdir error')) }) it('should refresh archive folder', async () => { @@ -168,6 +233,17 @@ describe('FileCache', () => { expect(cache.removeFileIfTooOld).toHaveBeenCalledTimes(2) }) + it('should manage archive folder readdir error', async () => { + fs.readdir.mockImplementationOnce(() => { + throw new Error('readdir error') + }) + cache.removeFileIfTooOld = jest.fn() + + await cache.refreshArchiveFolder() + expect(cache.removeFileIfTooOld).not.toHaveBeenCalled() + expect(logger.error).toHaveBeenCalledWith(new Error('readdir error')) + }) + it('should remove file if too old', async () => { fs.stat.mockImplementationOnce(() => ({ mtimeMs: new Date('2020-02-01T02:02:02.222Z').getTime() })) .mockImplementationOnce(() => ({ mtimeMs: new Date('2020-02-02T02:02:01.222Z').getTime() })) @@ -189,4 +265,15 @@ describe('FileCache', () => { await cache.removeFileIfTooOld('myOldFile.csv', new Date(), 'archiveFolder') expect(logger.error).toHaveBeenCalledWith(new Error('unlink error')) }) + + it('should log an error if a problem occur accessing the file', async () => { + fs.stat.mockImplementationOnce(() => { + throw new Error('stat error') + }) + + await cache.removeFileIfTooOld('myOldFile.csv', new Date(), 'archiveFolder') + expect(fs.unlink).not.toHaveBeenCalled() + expect(logger.error).toHaveBeenCalledWith(new Error('stat error')) + expect(logger.error).toHaveBeenCalledTimes(1) + }) }) diff --git a/src/north/north-connector.js b/src/north/north-connector.js index 73c14c68d9..4bed007b0d 100644 --- a/src/north/north-connector.js +++ b/src/north/north-connector.js @@ -205,7 +205,7 @@ class NorthConnector { if (this.valuesRetryCount < this.caching.retryCount || this.shouldRetry(error)) { this.valuesRetryCount += 1 - this.logger.debug(`Retrying in ${this.caching.retryInterval}. Retry count: ${this.valuesRetryCount}`) + this.logger.debug(`Retrying in ${this.caching.retryInterval} ms. Retry count: ${this.valuesRetryCount}`) } else { this.logger.debug('Too many retries. Moving values to error cache...') this.valueCache.manageErroredValues(values) @@ -268,7 +268,7 @@ class NorthConnector { this.logger.error(error) if (this.filesRetryCount < this.caching.retryCount || this.shouldRetry(error)) { this.filesRetryCount += 1 - this.logger.debug(`Retrying in ${this.caching.retryInterval}. Retry count: ${this.filesRetryCount}`) + this.logger.debug(`Retrying in ${this.caching.retryInterval} ms. Retry count: ${this.filesRetryCount}`) } else { this.logger.debug('Too many retries. Moving file to error cache...') await this.fileCache.manageErroredFiles(fileToSend.path)