test(core): Move unit tests closer to testable components (no-changelog) (#10287)

packages/cli/src/telemetry/__tests__/telemetry.test.ts

@@ -0,0 +1,431 @@
+import type RudderStack from '@rudderstack/rudder-sdk-node';
+import { Telemetry } from '@/telemetry';
+import config from '@/config';
+import { flushPromises } from '@test/flushPromises';
+import { PostHogClient } from '@/posthog';
+import { mock } from 'jest-mock-extended';
+import { InstanceSettings } from 'n8n-core';
+import { mockInstance } from '@test/mocking';
+
+jest.unmock('@/telemetry');
+jest.mock('@/posthog');
+
+describe('Telemetry', () => {
+	let startPulseSpy: jest.SpyInstance;
+	const spyTrack = jest.spyOn(Telemetry.prototype, 'track').mockName('track');
+
+	const mockRudderStack = mock<RudderStack>();
+
+	let telemetry: Telemetry;
+	const instanceId = 'Telemetry unit test';
+	const testDateTime = new Date('2022-01-01 00:00:00');
+	const instanceSettings = mockInstance(InstanceSettings, { instanceId });
+
+	beforeAll(() => {
+		// @ts-expect-error Spying on private method
+		startPulseSpy = jest.spyOn(Telemetry.prototype, 'startPulse').mockImplementation(() => {});
+
+		jest.useFakeTimers();
+		jest.setSystemTime(testDateTime);
+		config.set('diagnostics.enabled', true);
+		config.set('deployment.type', 'n8n-testing');
+	});
+
+	afterAll(async () => {
+		jest.clearAllTimers();
+		jest.useRealTimers();
+		startPulseSpy.mockRestore();
+		await telemetry.trackN8nStop();
+	});
+
+	beforeEach(async () => {
+		spyTrack.mockClear();
+
+		const postHog = new PostHogClient(instanceSettings);
+		await postHog.init();
+
+		telemetry = new Telemetry(mock(), postHog, mock(), instanceSettings, mock());
+		// @ts-expect-error Assigning to private property
+		telemetry.rudderStack = mockRudderStack;
+	});
+
+	afterEach(async () => {
+		await telemetry.trackN8nStop();
+	});
+
+	describe('trackN8nStop', () => {
+		test('should call track method', async () => {
+			await telemetry.trackN8nStop();
+			expect(spyTrack).toHaveBeenCalledTimes(1);
+		});
+	});
+
+	describe('trackWorkflowExecution', () => {
+		beforeEach(() => {
+			jest.setSystemTime(testDateTime);
+		});
+
+		test('should count executions correctly', async () => {
+			const payload = {
+				workflow_id: '1',
+				is_manual: true,
+				success: true,
+				error_node_type: 'custom-nodes-base.node-type',
+			};
+
+			payload.is_manual = true;
+			payload.success = true;
+			const execTime1 = fakeJestSystemTime('2022-01-01 12:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = false;
+			payload.success = true;
+			const execTime2 = fakeJestSystemTime('2022-01-01 13:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = true;
+			payload.success = false;
+			const execTime3 = fakeJestSystemTime('2022-01-01 14:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = false;
+			payload.success = false;
+			const execTime4 = fakeJestSystemTime('2022-01-01 15:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+
+			const execBuffer = telemetry.getCountsBuffer();
+
+			expect(execBuffer['1'].manual_success?.count).toBe(2);
+			expect(execBuffer['1'].manual_success?.first).toEqual(execTime1);
+			expect(execBuffer['1'].prod_success?.count).toBe(2);
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime2);
+			expect(execBuffer['1'].manual_error?.count).toBe(2);
+			expect(execBuffer['1'].manual_error?.first).toEqual(execTime3);
+			expect(execBuffer['1'].prod_error?.count).toBe(2);
+			expect(execBuffer['1'].prod_error?.first).toEqual(execTime4);
+		});
+
+		test('should fire "Workflow execution errored" event for failed executions', async () => {
+			const payload = {
+				workflow_id: '1',
+				is_manual: true,
+				success: false,
+				error_node_type: 'custom-nodes-base.node-type',
+			};
+
+			const execTime1 = fakeJestSystemTime('2022-01-01 12:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			let execBuffer = telemetry.getCountsBuffer();
+
+			// should not fire event for custom nodes
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+			expect(execBuffer['1'].manual_error?.count).toBe(2);
+			expect(execBuffer['1'].manual_error?.first).toEqual(execTime1);
+
+			payload.error_node_type = 'n8n-nodes-base.node-type';
+			fakeJestSystemTime('2022-01-01 13:00:00');
+			telemetry.trackWorkflowExecution(payload);
+			fakeJestSystemTime('2022-01-01 12:30:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			execBuffer = telemetry.getCountsBuffer();
+
+			// should fire event for custom nodes
+			expect(spyTrack).toHaveBeenCalledTimes(2);
+			expect(spyTrack).toHaveBeenCalledWith('Workflow execution errored', payload);
+			expect(execBuffer['1'].manual_error?.count).toBe(4);
+			expect(execBuffer['1'].manual_error?.first).toEqual(execTime1);
+		});
+
+		test('should track production executions count correctly', async () => {
+			const payload = {
+				workflow_id: '1',
+				is_manual: false,
+				success: true,
+				error_node_type: 'node_type',
+			};
+
+			// successful execution
+			const execTime1 = fakeJestSystemTime('2022-01-01 12:00:00');
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+
+			let execBuffer = telemetry.getCountsBuffer();
+			expect(execBuffer['1'].manual_error).toBeUndefined();
+			expect(execBuffer['1'].manual_success).toBeUndefined();
+			expect(execBuffer['1'].prod_error).toBeUndefined();
+
+			expect(execBuffer['1'].prod_success?.count).toBe(1);
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime1);
+
+			// successful execution n8n node
+			payload.error_node_type = 'n8n-nodes-base.merge';
+			payload.workflow_id = '2';
+
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+
+			execBuffer = telemetry.getCountsBuffer();
+			expect(execBuffer['1'].manual_error).toBeUndefined();
+			expect(execBuffer['1'].manual_success).toBeUndefined();
+			expect(execBuffer['1'].prod_error).toBeUndefined();
+
+			expect(execBuffer['1'].prod_success?.count).toBe(1);
+			expect(execBuffer['2'].prod_success?.count).toBe(1);
+
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime1);
+			expect(execBuffer['2'].prod_success?.first).toEqual(execTime1);
+
+			// additional successful execution
+			payload.error_node_type = 'n8n-nodes-base.merge';
+			payload.workflow_id = '2';
+
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.error_node_type = 'n8n-nodes-base.merge';
+			payload.workflow_id = '1';
+
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+			execBuffer = telemetry.getCountsBuffer();
+
+			expect(execBuffer['1'].manual_error).toBeUndefined();
+			expect(execBuffer['1'].manual_success).toBeUndefined();
+			expect(execBuffer['1'].prod_error).toBeUndefined();
+			expect(execBuffer['2'].manual_error).toBeUndefined();
+			expect(execBuffer['2'].manual_success).toBeUndefined();
+			expect(execBuffer['2'].prod_error).toBeUndefined();
+
+			expect(execBuffer['1'].prod_success?.count).toBe(2);
+			expect(execBuffer['2'].prod_success?.count).toBe(2);
+
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime1);
+			expect(execBuffer['2'].prod_success?.first).toEqual(execTime1);
+
+			// failed execution
+			const execTime2 = fakeJestSystemTime('2022-01-01 12:00:00');
+			payload.error_node_type = 'custom-package.custom-node';
+			payload.success = false;
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+
+			execBuffer = telemetry.getCountsBuffer();
+
+			expect(execBuffer['1'].manual_error).toBeUndefined();
+			expect(execBuffer['1'].manual_success).toBeUndefined();
+			expect(execBuffer['2'].manual_error).toBeUndefined();
+			expect(execBuffer['2'].manual_success).toBeUndefined();
+			expect(execBuffer['2'].prod_error).toBeUndefined();
+
+			expect(execBuffer['1'].prod_error?.count).toBe(1);
+			expect(execBuffer['1'].prod_success?.count).toBe(2);
+			expect(execBuffer['2'].prod_success?.count).toBe(2);
+
+			expect(execBuffer['1'].prod_error?.first).toEqual(execTime2);
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime1);
+			expect(execBuffer['2'].prod_success?.first).toEqual(execTime1);
+
+			// failed execution n8n node
+			payload.success = false;
+			payload.error_node_type = 'n8n-nodes-base.merge';
+			payload.is_manual = true;
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(1);
+
+			execBuffer = telemetry.getCountsBuffer();
+
+			expect(execBuffer['1'].manual_error?.count).toBe(1);
+			expect(execBuffer['1'].manual_success).toBeUndefined();
+			expect(execBuffer['2'].manual_error).toBeUndefined();
+			expect(execBuffer['2'].manual_success).toBeUndefined();
+			expect(execBuffer['2'].prod_error).toBeUndefined();
+			expect(execBuffer['1'].prod_success?.count).toBe(2);
+			expect(execBuffer['1'].prod_error?.count).toBe(1);
+			expect(execBuffer['2'].prod_success?.count).toBe(2);
+
+			expect(execBuffer['1'].prod_error?.first).toEqual(execTime2);
+			expect(execBuffer['1'].prod_success?.first).toEqual(execTime1);
+			expect(execBuffer['2'].prod_success?.first).toEqual(execTime1);
+		});
+	});
+
+	describe('pulse', () => {
+		let pulseSpy: jest.SpyInstance;
+		beforeAll(() => {
+			startPulseSpy.mockRestore();
+		});
+
+		beforeEach(() => {
+			fakeJestSystemTime(testDateTime);
+			pulseSpy = jest.spyOn(Telemetry.prototype as any, 'pulse').mockName('pulseSpy');
+		});
+
+		afterEach(() => {
+			pulseSpy.mockClear();
+		});
+
+		xtest('should trigger pulse in intervals', async () => {
+			expect(pulseSpy).toBeCalledTimes(0);
+
+			jest.advanceTimersToNextTimer();
+			await flushPromises();
+
+			expect(pulseSpy).toBeCalledTimes(1);
+			expect(spyTrack).toHaveBeenCalledTimes(1);
+			expect(spyTrack).toHaveBeenCalledWith('pulse', {
+				plan_name_current: 'Community',
+				quota: -1,
+				usage: 0,
+			});
+
+			jest.advanceTimersToNextTimer();
+
+			await flushPromises();
+
+			expect(pulseSpy).toBeCalledTimes(2);
+			expect(spyTrack).toHaveBeenCalledTimes(2);
+			expect(spyTrack).toHaveBeenCalledWith('pulse', {
+				plan_name_current: 'Community',
+				quota: -1,
+				usage: 0,
+			});
+		});
+
+		xtest('should track workflow counts correctly', async () => {
+			expect(pulseSpy).toBeCalledTimes(0);
+
+			let execBuffer = telemetry.getCountsBuffer();
+
+			// expect clear counters on start
+			expect(Object.keys(execBuffer).length).toBe(0);
+
+			const payload = {
+				workflow_id: '1',
+				is_manual: true,
+				success: true,
+				error_node_type: 'custom-nodes-base.node-type',
+			};
+
+			telemetry.trackWorkflowExecution(payload);
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = false;
+			payload.success = true;
+			telemetry.trackWorkflowExecution(payload);
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = true;
+			payload.success = false;
+			telemetry.trackWorkflowExecution(payload);
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.is_manual = false;
+			payload.success = false;
+			telemetry.trackWorkflowExecution(payload);
+			telemetry.trackWorkflowExecution(payload);
+
+			payload.workflow_id = '2';
+			telemetry.trackWorkflowExecution(payload);
+			telemetry.trackWorkflowExecution(payload);
+
+			expect(spyTrack).toHaveBeenCalledTimes(0);
+			expect(pulseSpy).toBeCalledTimes(0);
+
+			jest.advanceTimersToNextTimer();
+
+			execBuffer = telemetry.getCountsBuffer();
+
+			await flushPromises();
+
+			expect(pulseSpy).toBeCalledTimes(1);
+			expect(spyTrack).toHaveBeenCalledTimes(3);
+			expect(spyTrack).toHaveBeenNthCalledWith(
+				1,
+				'Workflow execution count',
+				{
+					event_version: '2',
+					workflow_id: '1',
+					user_id: undefined,
+					manual_error: {
+						count: 2,
+						first: testDateTime,
+					},
+					manual_success: {
+						count: 2,
+						first: testDateTime,
+					},
+					prod_error: {
+						count: 2,
+						first: testDateTime,
+					},
+					prod_success: {
+						count: 2,
+						first: testDateTime,
+					},
+				},
+				{ withPostHog: true },
+			);
+			expect(spyTrack).toHaveBeenNthCalledWith(
+				2,
+				'Workflow execution count',
+				{
+					event_version: '2',
+					workflow_id: '2',
+					user_id: undefined,
+					prod_error: {
+						count: 2,
+						first: testDateTime,
+					},
+				},
+				{ withPostHog: true },
+			);
+			expect(spyTrack).toHaveBeenNthCalledWith(3, 'pulse', {
+				plan_name_current: 'Community',
+				quota: -1,
+				usage: 0,
+			});
+			expect(Object.keys(execBuffer).length).toBe(0);
+
+			// Adding a second step here because we believe PostHog may use timers for sending data
+			// and adding posthog to the above metric was causing the pulseSpy timer to not be ran
+			jest.advanceTimersToNextTimer();
+
+			execBuffer = telemetry.getCountsBuffer();
+			expect(Object.keys(execBuffer).length).toBe(0);
+
+			// @TODO: Flushing promises here is not working
+
+			// expect(pulseSpy).toBeCalledTimes(2);
+			// expect(spyTrack).toHaveBeenCalledTimes(4);
+			// expect(spyTrack).toHaveBeenNthCalledWith(4, 'pulse', {
+			// 	plan_name_current: 'Community',
+			// 	quota: -1,
+			// 	usage: 0,
+			// });
+		});
+	});
+});
+
+const fakeJestSystemTime = (dateTime: string | Date): Date => {
+	const dt = new Date(dateTime);
+	jest.setSystemTime(dt);
+	return dt;
+};