diff --git a/packages/calling/src/CallingClient/calling/call.test.ts b/packages/calling/src/CallingClient/calling/call.test.ts index 4f27d299cd9..30c8b760160 100644 --- a/packages/calling/src/CallingClient/calling/call.test.ts +++ b/packages/calling/src/CallingClient/calling/call.test.ts @@ -977,6 +977,34 @@ describe('State Machine handler tests', () => { ); }); + it('session refresh 401 emits token error and ends the call', async () => { + expect.assertions(4); + const statusPayload = ({ + statusCode: 401, + }); + + webex.request.mockReturnValue(statusPayload); + jest.spyOn(global, 'clearInterval'); + + const emitSpy = jest.spyOn(call, 'emit'); + + call.on(CALL_EVENT_KEYS.CALL_ERROR, (errObj) => { + expect(errObj.type).toStrictEqual(ERROR_TYPE.TOKEN_ERROR); + }); + + const funcSpy = jest.spyOn(call, 'postStatus').mockRejectedValue(statusPayload); + + call['handleCallEstablished']({} as CallEvent); + + jest.advanceTimersByTime(DEFAULT_SESSION_TIMER); + await Promise.resolve(); + await Promise.resolve(); + + expect(clearInterval).toHaveBeenCalledTimes(1); + expect(funcSpy).toBeCalledTimes(1); + expect(emitSpy).toHaveBeenCalledWith(CALL_EVENT_KEYS.DISCONNECT, call.getCorrelationId()); + }); + it('session refresh failure', async () => { expect.assertions(4); const statusPayload = ({ @@ -1015,6 +1043,86 @@ describe('State Machine handler tests', () => { expect(funcSpy).toBeCalledTimes(1); }); + it('session refresh 500 schedules retry via retry-after or default interval', async () => { + const errorPayload = ({ + statusCode: 500, + headers: { + 'retry-after': 1, + }, + }); + + const okPayload = ({statusCode: 200, body: {}}); + + const sendEvtSpy = jest.spyOn(call as any, 'sendCallStateMachineEvt'); + const postStatusSpy = jest + .spyOn(call as any, 'postStatus') + .mockRejectedValueOnce(errorPayload) + .mockResolvedValueOnce(okPayload); + + if (call['sessionTimer'] === undefined) { + call['handleCallEstablished']({} as CallEvent); + } + + jest.advanceTimersByTime(DEFAULT_SESSION_TIMER); + await Promise.resolve(); + await Promise.resolve(); + + expect(postStatusSpy).toHaveBeenCalledTimes(1); + expect(sendEvtSpy).toHaveBeenCalledWith({type: 'E_CALL_ESTABLISHED'}); + }); + + it('keepalive ends after reaching max retry count', async () => { + const resolvePromise = async () => { + await Promise.resolve(); + await Promise.resolve(); + }; + + const errorPayload = ({ + statusCode: 500, + headers: { + 'retry-after': 1, + }, + }); + + jest.spyOn(global, 'clearInterval'); + const warnSpy = jest.spyOn(log, 'warn'); + const postStatusSpy = jest.spyOn(call, 'postStatus').mockRejectedValue(errorPayload); + + // Put the call in the S_CALL_ESTABLISHED state and set it as connected + call['callStateMachine'].state.value = 'S_CALL_ESTABLISHED'; + call['connected'] = true; + + // Call handleCallEstablished which will setup interval + call['handleCallEstablished']({} as CallEvent); + + // Advance timer to trigger the first failure (uses DEFAULT_SESSION_TIMER) + jest.advanceTimersByTime(DEFAULT_SESSION_TIMER); + await resolvePromise(); + + // Now advance by 1 second for each of the 3 more retry attempts (retry-after: 1 second each) + // Need to do this separately to allow state machine to process and create new intervals + jest.advanceTimersByTime(1000); + await resolvePromise(); + + jest.advanceTimersByTime(1000); + await resolvePromise(); + + jest.advanceTimersByTime(1000); + await resolvePromise(); + + // The error handler should detect we're at max retry count and stop + expect(warnSpy).toHaveBeenCalledWith( + `Max call keepalive retry attempts reached for call: ${call.getCorrelationId()}`, + { + file: 'call', + method: 'handleCallEstablished', + } + ); + expect(postStatusSpy).toHaveBeenCalledTimes(4); + expect(call['callKeepaliveRetryCount']).toBe(0); + expect(call['sessionTimer']).toBeUndefined(); + }); + it('state changes during successful incoming call', async () => { const statusPayload = ({ statusCode: 200, diff --git a/packages/calling/src/CallingClient/calling/call.ts b/packages/calling/src/CallingClient/calling/call.ts index 968a710a967..3fdfec0c92f 100644 --- a/packages/calling/src/CallingClient/calling/call.ts +++ b/packages/calling/src/CallingClient/calling/call.ts @@ -45,6 +45,7 @@ import { HOLD_ENDPOINT, ICE_CANDIDATES_TIMEOUT, INITIAL_SEQ_NUMBER, + MAX_CALL_KEEPALIVE_RETRY_COUNT, MEDIA_ENDPOINT_RESOURCE, METHODS, NOISE_REDUCTION_EFFECT, @@ -169,6 +170,10 @@ export class Call extends Eventing implements ICall { private rtcMetrics: RtcMetrics; + private callKeepaliveRetryCount = 0; + + private callKeepaliveInterval?: number; + /** * Getter to check if the call is muted or not. * @@ -1501,10 +1506,12 @@ export class Call extends Eventing implements ICall { */ // eslint-disable-next-line @typescript-eslint/no-unused-vars private handleCallEstablished(event: CallEvent) { - log.info(`${METHOD_START_MESSAGE} with: ${this.getCorrelationId()}`, { + const loggerContext = { file: CALL_FILE, method: METHODS.HANDLE_CALL_ESTABLISHED, - }); + }; + + log.info(`${METHOD_START_MESSAGE} with: ${this.getCorrelationId()}`, loggerContext); this.emit(CALL_EVENT_KEYS.ESTABLISHED, this.correlationId); @@ -1515,10 +1522,8 @@ export class Call extends Eventing implements ICall { /* Session timers need to be reset at all offer/answer exchanges */ if (this.sessionTimer) { - log.log('Resetting session timer', { - file: CALL_FILE, - method: METHODS.HANDLE_CALL_ESTABLISHED, - }); + log.log('Resetting session timer', loggerContext); + clearInterval(this.sessionTimer); } @@ -1526,11 +1531,10 @@ export class Call extends Eventing implements ICall { try { // eslint-disable-next-line @typescript-eslint/no-unused-vars const res = await this.postStatus(); + this.callKeepaliveRetryCount = 0; + this.callKeepaliveInterval = undefined; - log.info(`Session refresh successful`, { - file: CALL_FILE, - method: METHODS.HANDLE_CALL_ESTABLISHED, - }); + log.info(`Session refresh successful`, loggerContext); } catch (err: unknown) { const error = err; @@ -1544,34 +1548,54 @@ export class Call extends Eventing implements ICall { clearInterval(this.sessionTimer); } - handleCallErrors( + const abort = await handleCallErrors( (callError: CallError) => { this.emit(CALL_EVENT_KEYS.CALL_ERROR, callError); this.submitCallErrorMetric(callError); }, ERROR_LAYER.CALL_CONTROL, (interval: number) => { - setTimeout(() => { - /* We first post the status and then recursively call the handler which - * starts the timer again - */ - this.postStatus(); - this.sendCallStateMachineEvt({type: 'E_CALL_ESTABLISHED'}); - }, interval * 1000); + this.callKeepaliveRetryCount += 1; + this.callKeepaliveInterval = interval * 1000; + + // If we have reached the max retry count, do not attempt to refresh the session + if (this.callKeepaliveRetryCount === MAX_CALL_KEEPALIVE_RETRY_COUNT) { + this.callKeepaliveRetryCount = 0; + clearInterval(this.sessionTimer); + this.sessionTimer = undefined; + this.callKeepaliveInterval = undefined; + + log.warn( + `Max call keepalive retry attempts reached for call: ${this.getCorrelationId()}`, + loggerContext + ); + + return; + } + + // Scheduling next keepalive attempt - calling handleCallEstablished + this.sendCallStateMachineEvt({type: 'E_CALL_ESTABLISHED'}); }, this.getCorrelationId(), error, - this.handleCallEstablished.name, + 'handleCallEstablished', CALL_FILE ); + if (abort) { + this.sendCallStateMachineEvt({type: 'E_SEND_CALL_DISCONNECT'}); + this.emit(CALL_EVENT_KEYS.DISCONNECT, this.getCorrelationId()); + this.callKeepaliveRetryCount = 0; + this.callKeepaliveInterval = undefined; + } + await uploadLogs({ correlationId: this.correlationId, callId: this.callId, broadworksCorrelationInfo: this.broadworksCorrelationInfo, }); } - }, DEFAULT_SESSION_TIMER); + }, this.callKeepaliveInterval || DEFAULT_SESSION_TIMER); } /** diff --git a/packages/calling/src/CallingClient/constants.ts b/packages/calling/src/CallingClient/constants.ts index 85cc0c34298..4c797a6379a 100644 --- a/packages/calling/src/CallingClient/constants.ts +++ b/packages/calling/src/CallingClient/constants.ts @@ -12,6 +12,7 @@ export const DEFAULT_LOCAL_CALL_ID = 'DefaultLocalId'; export const DEFAULT_REHOMING_INTERVAL_MAX = 120; export const DEFAULT_REHOMING_INTERVAL_MIN = 60; export const DEFAULT_SESSION_TIMER = 1000 * 60 * 10; +export const MAX_CALL_KEEPALIVE_RETRY_COUNT = 4; export const DEVICES_ENDPOINT_RESOURCE = 'devices'; export const DISCOVERY_URL = 'https://ds.ciscospark.com/v1/region'; export const DUMMY_METRICS = { diff --git a/packages/calling/src/common/Utils.test.ts b/packages/calling/src/common/Utils.test.ts index 2ee8bc7f117..474f7ab9c70 100644 --- a/packages/calling/src/common/Utils.test.ts +++ b/packages/calling/src/common/Utils.test.ts @@ -22,7 +22,13 @@ import { RegistrationStatus, } from './types'; import log from '../Logger'; -import {CALL_FILE, DUMMY_METRICS, UTILS_FILE, REGISTER_UTIL} from '../CallingClient/constants'; +import { + CALL_FILE, + DUMMY_METRICS, + UTILS_FILE, + REGISTER_UTIL, + DEFAULT_KEEPALIVE_INTERVAL, +} from '../CallingClient/constants'; import { CALL_ERROR_CODE, ERROR_CODE, @@ -106,6 +112,210 @@ describe('Mobius service discovery tests', () => { }); }); +describe('Call Tests - keepalive (handleCallEstablished) cases', () => { + const logObj = { + file: CALL_FILE, + method: 'handleCallErrors', + }; + + const dummyCorrelationId = '8a67806f-fc4d-446b-a131-31e71ea5b010'; + + beforeEach(() => { + jest.clearAllMocks(); + }); + + it('401 during keepalive emits token error and ends call', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 401, + headers: {trackingid: 't'}, + body: {device: {deviceId: 'd'}, errorCode: 0}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(emitted).toBe(true); + expect(abort).toBe(true); + expect(retrySpy).not.toHaveBeenCalled(); + }); + + it('403 during keepalive emits error and ends call', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 403, + headers: {trackingid: 't'}, + body: {device: {deviceId: 'd'}, errorCode: 0}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(emitted).toBe(true); + expect(abort).toBe(true); + expect(retrySpy).not.toHaveBeenCalled(); + }); + + it('500 during keepalive with retry-after triggers retryCb with interval', async () => { + let emitted = false; + const endSpy = jest.fn(); + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 500, + headers: {trackingid: 't', 'retry-after': 2}, + body: {device: {deviceId: 'd'}, errorCode: 0}, + }); + + await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file, + endSpy + ); + + expect(emitted).toBe(true); + expect(endSpy).not.toHaveBeenCalled(); + expect(retrySpy).toHaveBeenCalledWith(2); + }); + + it('500 during keepalive without retry-after triggers retryCb without args', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 500, + headers: {trackingid: 't'}, + body: {device: {deviceId: 'd'}, errorCode: 0}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(abort).toBe(false); + expect(emitted).toBe(true); + expect(retrySpy).toHaveBeenCalledWith(DEFAULT_KEEPALIVE_INTERVAL); + }); + + it('404 during keepalive emits not found and ends call (no retry)', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 404, + headers: {trackingid: 't'}, + body: {device: {deviceId: 'd'}}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(emitted).toBe(true); + expect(abort).toBe(true); + expect(retrySpy).not.toHaveBeenCalled(); + }); + + it('503 during keepalive with retry-after does not invoke emitterCb and retries with interval', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 503, + headers: {trackingid: 't', 'retry-after': 7}, + body: {device: {deviceId: 'd'}, errorCode: 0}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(abort).toBe(false); + expect(emitted).toBe(false); + expect(retrySpy).toHaveBeenCalledWith(7); + }); + + it('503 during keepalive without retry-after invokes emitterCb and triggers retryCb without args', async () => { + let emitted = false; + const retrySpy = jest.fn(); + + const payload = ({ + statusCode: 503, + headers: {trackingid: 't'}, + body: {device: {deviceId: 'd'}, errorCode: 111}, + }); + + const abort = await handleCallErrors( + () => { + emitted = true; + }, + ERROR_LAYER.CALL_CONTROL, + retrySpy, + dummyCorrelationId, + payload, + 'handleCallEstablished', + logObj.file + ); + + expect(abort).toBe(false); + expect(emitted).toBe(true); + expect(retrySpy).toHaveBeenCalledWith(DEFAULT_KEEPALIVE_INTERVAL); + }); +}); + describe('Registration Tests', () => { /** * TestCase inputs diff --git a/packages/calling/src/common/Utils.ts b/packages/calling/src/common/Utils.ts index c9e158c044e..4bd2cb3ad59 100644 --- a/packages/calling/src/common/Utils.ts +++ b/packages/calling/src/common/Utils.ts @@ -89,6 +89,8 @@ import { TYPE, URL_ENDPOINT, UTILS_FILE, + METHODS, + DEFAULT_KEEPALIVE_INTERVAL, } from '../CallingClient/constants'; import { DeleteCallHistoryRecordsResponse, @@ -564,6 +566,8 @@ export async function handleCallingClientErrors( * @param err - Error Response. * @param caller - Caller function. * @param file - File name. + * + * @returns boolean - whether to abort the call or not. */ export async function handleCallErrors( emitterCb: CallErrorEmitterCallBack, @@ -573,7 +577,9 @@ export async function handleCallErrors( err: WebexRequestPayload, caller: string, file: string -) { +): Promise { + let abort = false; + const loggerContext = { file, method: caller, @@ -584,6 +590,8 @@ export async function handleCallErrors( log.warn(`Status code: ->${errorCode}`, loggerContext); + const isKeepalive = caller === METHODS.HANDLE_CALL_ESTABLISHED; + switch (errorCode) { case ERROR_CODE.UNAUTHORIZED: { log.warn(`401 Unauthorized`, loggerContext); @@ -597,10 +605,29 @@ export async function handleCallErrors( ); emitterCb(callError); + + if (isKeepalive) { + abort = true; + } + break; } case ERROR_CODE.FORBIDDEN: + if (isKeepalive) { + abort = true; + + updateCallErrorContext( + loggerContext, + ERROR_TYPE.FORBIDDEN_ERROR, + 'An unauthorized action has been received. This action has been blocked. Please contact the administrator if this persists.', + correlationId, + callError + ); + emitterCb(callError); + break; + } + /* follow through as both 403 and 503 can have similar error codes */ case ERROR_CODE.SERVICE_UNAVAILABLE: { @@ -619,18 +646,22 @@ export async function handleCallErrors( ); emitterCb(callError); - return; + return abort; } /* Handle retry-after cases */ + // Common for keepalive and normal scenarios if (err.headers && 'retry-after' in err.headers && retryCb) { const retryInterval = Number(err.headers['retry-after'] as unknown); log.warn(`Retry Interval received: ${retryInterval}`, loggerContext); retryCb(retryInterval); - return; + return abort; + } + if (isKeepalive) { + retryCb(DEFAULT_KEEPALIVE_INTERVAL); // This is applicable only for the keepalive scenario } /* Handling various Error codes */ @@ -713,6 +744,11 @@ export async function handleCallErrors( ); emitterCb(callError); + + if (isKeepalive) { + abort = true; + } + break; } @@ -728,6 +764,16 @@ export async function handleCallErrors( ); emitterCb(callError); + + if (isKeepalive && retryCb) { + const retryInterval = + err.headers && 'retry-after' in err.headers + ? Number(err.headers['retry-after'] as unknown) + : DEFAULT_KEEPALIVE_INTERVAL; + + retryCb(retryInterval); + } + break; } @@ -735,6 +781,8 @@ export async function handleCallErrors( log.warn(`Unknown Error`, loggerContext); } } + + return abort; } /**