import type RudderStack from '@rudderstack/rudder-sdk-node'; import { Telemetry } from '@/telemetry'; import config from '@/config'; import { flushPromises } from './Helpers'; import { PostHogClient } from '@/posthog'; import { mock } from 'jest-mock-extended'; import { InstanceSettings } from 'n8n-core'; import { mockInstance } from '../shared/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(); mockRudderStack.track.mockImplementation(function (_, cb) { cb?.(); return this; }); 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; };