fix: Prevent expired storage cleanup from crashing the server

Author: joachimvh

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';

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> {

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);
+}

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);
+    });
+  });
+});