From f08cdf75f76d7e23b5d3277aae4a113380e245a7 Mon Sep 17 00:00:00 2001
From: Joachim Van Herwegen <joachimvh@gmail.com>
Date: Thu, 31 Mar 2022 12:46:31 +0200
Subject: [PATCH] fix: Prevent expired storage cleanup from crashing the server

---
 src/index.ts                                  |  1 +
 .../keyvalue/WrappedExpiringStorage.ts        |  6 +-
 src/util/TimerUtil.ts                         | 23 ++++++++
 test/unit/util/TimerUtil.test.ts              | 59 +++++++++++++++++++
 4 files changed, 88 insertions(+), 1 deletion(-)
 create mode 100644 src/util/TimerUtil.ts
 create mode 100644 test/unit/util/TimerUtil.test.ts

diff --git a/src/index.ts b/src/index.ts
index 404eda3f8..b2470a6fa 100644
--- a/src/index.ts
+++ b/src/index.ts
@@ -435,4 +435,5 @@ export * from './util/RecordObject';
 export * from './util/ResourceUtil';
 export * from './util/StreamUtil';
 export * from './util/TermUtil';
+export * from './util/TimerUtil';
 export * from './util/Vocabularies';
diff --git a/src/storage/keyvalue/WrappedExpiringStorage.ts b/src/storage/keyvalue/WrappedExpiringStorage.ts
index 6ac9cc3c8..d94196a2f 100644
--- a/src/storage/keyvalue/WrappedExpiringStorage.ts
+++ b/src/storage/keyvalue/WrappedExpiringStorage.ts
@@ -1,6 +1,7 @@
 import type { Finalizable } from '../../init/final/Finalizable';
 import { getLoggerFor } from '../../logging/LogUtil';
 import { InternalServerError } from '../../util/errors/InternalServerError';
+import { setSafeInterval } from '../../util/TimerUtil';
 import type { ExpiringStorage } from './ExpiringStorage';
 import type { KeyValueStorage } from './KeyValueStorage';
 
@@ -23,7 +24,10 @@ export class WrappedExpiringStorage<TKey, TValue> implements ExpiringStorage<TKe
    */
   public constructor(source: KeyValueStorage<TKey, Expires<TValue>>, timeout = 60) {
     this.source = source;
-    this.timer = setInterval(this.removeExpiredEntries.bind(this), timeout * 60 * 1000);
+    this.timer = setSafeInterval(this.logger,
+      'Failed to remove expired entries',
+      this.removeExpiredEntries.bind(this),
+      timeout * 60 * 1000);
   }
 
   public async get(key: TKey): Promise<TValue | undefined> {
diff --git a/src/util/TimerUtil.ts b/src/util/TimerUtil.ts
new file mode 100644
index 000000000..75d25b746
--- /dev/null
+++ b/src/util/TimerUtil.ts
@@ -0,0 +1,23 @@
+import type { Logger } from '../logging/Logger';
+import { createErrorMessage } from './errors/ErrorUtil';
+
+/**
+ * Wraps the callback for {@link setInterval} so errors get caught and logged.
+ * Parameters are identical to the {@link setInterval} parameters starting from the 3rd argument.
+ * The logger and message will be used when the callback throws an error.
+ * Supports asynchronous callback functions.
+ */
+export function setSafeInterval(logger: Logger, message: string, callback: (...cbArgs: any[]) => void, ms?: number,
+  ...args: any[]): NodeJS.Timeout {
+  async function safeCallback(...cbArgs: any[]): Promise<void> {
+    try {
+      // We don't know if the callback is async or not so this way we make sure
+      // the full function execution is done in the try block.
+      // eslint-disable-next-line @typescript-eslint/await-thenable
+      return await callback(...cbArgs);
+    } catch (error: unknown) {
+      logger.error(`Error during interval callback: ${message} - ${createErrorMessage(error)}`);
+    }
+  }
+  return setInterval(safeCallback, ms, ...args);
+}
diff --git a/test/unit/util/TimerUtil.test.ts b/test/unit/util/TimerUtil.test.ts
new file mode 100644
index 000000000..5f6abb94d
--- /dev/null
+++ b/test/unit/util/TimerUtil.test.ts
@@ -0,0 +1,59 @@
+import type { Logger } from '../../../src/logging/Logger';
+import { setSafeInterval } from '../../../src/util/TimerUtil';
+import { flushPromises } from '../../util/Util';
+
+jest.useFakeTimers();
+
+describe('TimerUtil', (): void => {
+  describe('#setSafeInterval', (): void => {
+    let logger: jest.Mocked<Logger>;
+    let callback: jest.Mock<(...cbArgs: any[]) => void>;
+
+    beforeEach(async(): Promise<void> => {
+      logger = { error: jest.fn() } as any;
+      callback = jest.fn();
+    });
+
+    it('creates a working interval.', async(): Promise<void> => {
+      const timer = setSafeInterval(logger, 'message', callback, 1000, 'argument');
+
+      jest.advanceTimersByTime(1000);
+
+      expect(callback).toHaveBeenCalledTimes(1);
+      expect(callback).toHaveBeenLastCalledWith('argument');
+      expect(logger.error).toHaveBeenCalledTimes(0);
+
+      clearInterval(timer);
+    });
+
+    it('logs an error if something went wrong in the callback.', async(): Promise<void> => {
+      const timer = setSafeInterval(logger, 'message', callback, 1000, 'argument');
+      callback.mockImplementationOnce((): never => {
+        throw new Error('callback error');
+      });
+
+      jest.advanceTimersByTime(1000);
+
+      expect(callback).toHaveBeenCalledTimes(1);
+      expect(callback).toHaveBeenLastCalledWith('argument');
+      expect(logger.error).toHaveBeenCalledTimes(1);
+      expect(logger.error).toHaveBeenLastCalledWith('Error during interval callback: message - callback error');
+
+      clearInterval(timer);
+    });
+
+    it('correctly handles errors in async callbacks.', async(): Promise<void> => {
+      const promCallback = jest.fn().mockRejectedValue(new Error('callback error'));
+      const timer = setSafeInterval(logger, 'message', promCallback, 1000, 'argument');
+
+      jest.advanceTimersByTime(1000);
+      await flushPromises();
+
+      expect(promCallback).toHaveBeenCalledTimes(1);
+      expect(logger.error).toHaveBeenCalledTimes(1);
+      expect(logger.error).toHaveBeenLastCalledWith('Error during interval callback: message - callback error');
+
+      clearInterval(timer);
+    });
+  });
+});