Fix: Feature server REFER (#114)

* Update _onFeatureServerTransfer to fix REFER case

* Add INFO listener

---------

Co-authored-by: Matt Preskett <matt.preskett@netcall.com>

lib/aws-sns-lifecycle.js

@@ -6,15 +6,20 @@ const {LifeCycleEvents} = require('./constants');
 const express = require('express');
 const app = express();
 const getString = bent('string');
-const AWS = require('aws-sdk');
-const sns = new AWS.SNS({apiVersion: '2010-03-31'});
-const autoscaling = new AWS.AutoScaling({apiVersion: '2011-01-01'});
+const {
+  SNSClient,
+  SubscribeCommand,
+  UnsubscribeCommand } = require('@aws-sdk/client-sns');
+const snsClient = new SNSClient({ region: process.env.AWS_REGION, apiVersion: '2010-03-31' });
+const {
+  AutoScalingClient,
+  DescribeAutoScalingGroupsCommand,
+  CompleteLifecycleActionCommand } = require('@aws-sdk/client-auto-scaling');
+const autoScalingClient = new AutoScalingClient({ region: process.env.AWS_REGION, apiVersion: '2011-01-01' });
 const {Parser} = require('xml2js');
 const parser = new Parser();
 const {validatePayload} = require('verify-aws-sns-signature');
 
-AWS.config.update({region: process.env.AWS_REGION});
-
 class SnsNotifier extends Emitter {
   constructor(logger) {
     super();
@@ -64,7 +69,7 @@ class SnsNotifier extends Emitter {
             subscriptionRequestId: this.subscriptionRequestId
           }, 'response from SNS SubscribeURL');
           const data = await this.describeInstance();
-          this.lifecycleState = data.AutoScalingInstances[0].LifecycleState;
+          this.lifecycleState = data.AutoScalingGroups[0].Instances[0].LifecycleState;
           this.emit('SubscriptionConfirmation', {publicIp: this.publicIp});
           break;
 
@@ -130,11 +135,12 @@ class SnsNotifier extends Emitter {
 
   async subscribe() {
     try {
-      const response = await sns.subscribe({
+      const params = {
         Protocol: 'http',
         TopicArn: process.env.AWS_SNS_TOPIC_ARM,
         Endpoint: this.snsEndpoint
-      }).promise();
+      };
+      const response = await snsClient.send(new SubscribeCommand(params));
       this.logger.info({response}, `response to SNS subscribe to ${process.env.AWS_SNS_TOPIC_ARM}`);
     } catch (err) {
       this.logger.error({err}, `Error subscribing to SNS topic arn ${process.env.AWS_SNS_TOPIC_ARM}`);
@@ -144,9 +150,10 @@ class SnsNotifier extends Emitter {
   async unsubscribe() {
     if (!this.subscriptionArn) throw new Error('SnsNotifier#unsubscribe called without an active subscription');
     try {
-      const response = await sns.unsubscribe({
+      const params = {
         SubscriptionArn: this.subscriptionArn
-      }).promise();
+      };
+      const response = await snsClient.send(new UnsubscribeCommand(params));
       this.logger.info({response}, `response to SNS unsubscribe to ${process.env.AWS_SNS_TOPIC_ARM}`);
     } catch (err) {
       this.logger.error({err}, `Error unsubscribing to SNS topic arn ${process.env.AWS_SNS_TOPIC_ARM}`);
@@ -155,26 +162,29 @@ class SnsNotifier extends Emitter {
 
   completeScaleIn() {
     assert(this.scaleInParams);
-    autoscaling.completeLifecycleAction(this.scaleInParams, (err, response) => {
-      if (err) return this.logger.error({err}, 'Error completing scale-in');
-      this.logger.info({response}, 'Successfully completed scale-in action');
-    });
+    autoScalingClient.send(new CompleteLifecycleActionCommand(this.scaleInParams))
+      .then((data) => {
+        return this.logger.info({data}, 'Successfully completed scale-in action');
+      })
+      .catch((err) => {
+        this.logger.error({err}, 'Error completing scale-in');
+      });
   }
 
   describeInstance() {
     return new Promise((resolve, reject) => {
       if (!this.instanceId) return reject('instance-id unknown');
-      autoscaling.describeAutoScalingInstances({
+      autoScalingClient.send(new DescribeAutoScalingGroupsCommand({
         InstanceIds: [this.instanceId]
-      }, (err, data) => {
-        if (err) {
+      }))
+        .then((data) => {
+          this.logger.info({data}, 'SnsNotifier: describeInstance');
+          return resolve(data);
+        })
+        .catch((err) => {
           this.logger.error({err}, 'Error describing instances');
           reject(err);
-        } else {
-          this.logger.info({data}, 'SnsNotifier: describeInstance');
-          resolve(data);
-        }
-      });
+        });
     });
   }
 
@@ -188,7 +198,7 @@ module.exports = async function(logger) {
   process.on('SIGHUP', async() => {
     try {
       const data = await notifier.describeInstance();
-      const state = data.AutoScalingInstances[0].LifecycleState;
+      const state = data.AutoScalingGroups[0].Instances[0].LifecycleState;
       if (state !== notifier.lifecycleState) {
         notifier.lifecycleState = state;
         switch (state) {

lib/call-session.js

@@ -64,6 +64,7 @@ class CallSession extends Emitter {
     this.application_sid = req.locals.application_sid;
     this.account_sid = req.locals.account_sid;
     this.service_provider_sid = req.locals.service_provider_sid;
+    this.srsClients = [];
   }
 
   get isFromMSTeams() {
@@ -317,10 +318,7 @@ class CallSession extends Emitter {
       this.activeCallIds.delete(callId);
       if (dlg.other && dlg.other.connected) dlg.other.destroy().catch((e) => {});
 
-      if (this.srsClient) {
-        this.srsClient.stop();
-        this.srsClient = null;
-      }
+      this._stopRecording();
 
       this.srf.endSession(this.req);
     });
@@ -329,6 +327,13 @@ class CallSession extends Emitter {
     dlg.on('modify', this._onReinvite.bind(this, dlg));
   }
 
+  _stopRecording() {
+    if (this.srsClients.length) {
+      this.srsClients.forEach((c) => c.stop());
+      this.srsClients = [];
+    }
+  }
+
   _setHandlers({uas, uac}) {
     this.emit('connected');
     const callStart = Date.now();
@@ -412,10 +417,7 @@ class CallSession extends Emitter {
         dlg.other = null;
         other.other = null;
 
-        if (this.srsClient) {
-          this.srsClient.stop();
-          this.srsClient = null;
-        }
+        this._stopRecording();
 
         this.logger.info(`call ended with normal termination, there are ${this.activeCallIds.size} active`);
         this.srf.endSession(this.req);
@@ -689,6 +691,7 @@ Duration=${payload.duration} `
             const to = this.req.getParsedHeader('To');
             const aorFrom = from.uri;
             const aorTo = to.uri;
+            const headers = contentType === 'application/json' && req.body ? JSON.parse(req.body) : {};
             this.logger.info({to, from}, 'startCallRecording request for a call');
 
             const srsUrl = req.get('X-Srs-Url');
@@ -696,7 +699,7 @@ Duration=${payload.duration} `
             const callSid = req.get('X-Call-Sid');
             const accountSid = req.get('X-Account-Sid');
             const applicationSid = req.get('X-Application-Sid');
-            if (this.srsClient) {
+            if (this.srsClients.length) {
               res.send(400);
               this.logger.info('discarding duplicate startCallRecording request for a call');
               return;
@@ -706,13 +709,14 @@ Duration=${payload.duration} `
               res.send(400);
               return;
             }
-            this.srsClient = new SrsClient(this.logger, {
+            const arr = srsUrl.split(',');
+            this.srsClients = arr.map((url) => new SrsClient(this.logger, {
               srf: dlg.srf,
               direction: 'inbound',
               originalInvite: this.req,
               callingNumber: this.req.callingNumber,
               calledNumber: this.req.calledNumber,
-              srsUrl,
+              srsUrl: url,
               srsRecordingId,
               callSid,
               accountSid,
@@ -727,42 +731,51 @@ Duration=${payload.duration} `
               del: this.del,
               blockMedia: this.blockMedia,
               unblockMedia: this.unblockMedia,
-              unsubscribe: this.unsubscribe
-            });
+              unsubscribe: this.unsubscribe,
+              headers
+            }));
             try {
-              succeeded = await this.srsClient.start();
+              succeeded = (await Promise.all(
+                this.srsClients.map((c) => c.start())
+              )).every((r) => r);
             } catch (err) {
               this.logger.error({err}, 'Error starting SipRec call recording');
             }
           }
           else if (reason === 'stopCallRecording') {
-            if (!this.srsClient) {
+            if (!this.srsClients.length) {
               res.send(400);
               this.logger.info('discarding stopCallRecording request because we are not recording');
               return;
             }
             try {
-              succeeded = await this.srsClient.stop();
+              succeeded = (await Promise.all(
+                this.srsClients.map((c) => c.stop())
+              )).every((r) => r);
             } catch (err) {
               this.logger.error({err}, 'Error stopping SipRec call recording');
             }
-            this.srsClient = null;
+            this.srsClients = [];
           }
           else if (reason === 'pauseCallRecording') {
-            if (!this.srsClient || this.srsClient.paused) {
+            if (!this.srsClients.length || this.srsClients.every((c) => c.paused)) {
               this.logger.info('discarding invalid pauseCallRecording request');
               res.send(400);
               return;
             }
-            succeeded = await this.srsClient.pause();
+            succeeded = (await Promise.all(
+              this.srsClients.map((c) => c.pause())
+            )).every((r) => r);
           }
           else if (reason === 'resumeCallRecording') {
-            if (!this.srsClient || !this.srsClient.paused) {
+            if (!this.srsClients.length || !this.srsClients.every((c) => c.paused)) {
               res.send(400);
               this.logger.info('discarding invalid resumeCallRecording request');
               return;
             }
-            succeeded = await this.srsClient.resume();
+            succeeded = (await Promise.all(
+              this.srsClients.map((c) => c.resume())
+            )).every((r) => r);
           }
           res.send(succeeded ? 200 : 503);
         }
@@ -815,8 +828,8 @@ Duration=${payload.duration} `
         res.send(response.status, {headers: responseHeaders, body: response.body});
       }
     } catch (err) {
-      if (this.srsClient) {
-        this.srsClient = null;
+      if (this.srsClients.length) {
+        this.srsClients = [];
       }
       res.send(500);
       this.logger.info({err}, `Error handing INFO request on ${dlg.type} leg`);
@@ -891,6 +904,7 @@ Duration=${payload.duration} `
       this.uac = uac;
       uac.other = this.uas;
       this.uas.other = uac;
+      uac.on('info', this._onInfo.bind(this, uac));
       uac.on('modify', this._onReinvite.bind(this, uac));
       uac.on('refer', this._onFeatureServerTransfer.bind(this, uac));
       uac.on('destroy', () => {
@@ -900,19 +914,22 @@ Duration=${payload.duration} `
         uac.other.destroy();
         this.srf.endSession(this.req);
       });
-      // now we can destroy the old dialog
-      dlg.destroy().catch(() => {});
 
-      // modify rtpengine to stream to new feature server
-      const opts = Object.assign({sdp: uac.remote.sdp, 'to-tag': res.getParsedHeader('To').params.tag},
-        this.rtpEngineOpts.answer);
+      const opts = {
+        ...this.rtpEngineOpts.common,
+        'from-tag': this.rtpEngineOpts.uas.tag,
+        'to-tag': this.rtpEngineOpts.uac.tag,
+        sdp: uac.remote.sdp,
+        flags: ['port latching']
+      };
       const response = await this.answer(opts);
       if ('ok' !== response.result) {
-        res.send(488);
-        throw new Error(`_onFeatureServerTransfer: rtpengine failed: ${JSON.stringify(response)}`);
+        throw new Error(`_onFeatureServerTransfer: rtpengine answer failed: ${JSON.stringify(response)}`);
       }
+      dlg.destroy().catch(() => {});
       this.logger.info('successfully moved call to new feature server');
     } catch (err) {
+      res.send(488);
       this.logger.error(err, 'Error handling refer from feature server');
     }
   }

lib/middleware.js

@@ -129,7 +129,7 @@ module.exports = function(srf, logger) {
           logger.info('identifyAccount: rejecting call from carrier because DID has not been provisioned');
           return res.send(404, 'Number Not Provisioned');
         }
-        logger.debug({gateway}, 'identifyAccount: incoming call from gateway');
+        logger.info({gateway}, 'identifyAccount: incoming call from gateway');
 
         let sid;
         if (siprec) {
@@ -156,7 +156,7 @@ module.exports = function(srf, logger) {
         };
       }
       else if (msProxyIps.includes(req.source_address)) {
-        logger.debug({source_address: req.source_address}, 'identifyAccount: incoming call from Microsoft Teams');
+        logger.info({source_address: req.source_address}, 'identifyAccount: incoming call from Microsoft Teams');
         const uri = parseUri(req.uri);
 
         const app = await lookupAppByTeamsTenant(uri.host);
@@ -178,7 +178,7 @@ module.exports = function(srf, logger) {
       else {
         req.locals.originator = 'user';
         const uri = parseUri(req.uri);
-        logger.debug({source_address: req.source_address, realm: uri.host},
+        logger.info({source_address: req.source_address, realm: uri.host},
           'identifyAccount: incoming user call');
         const account = await lookupAccountBySipRealm(uri.host);
         if (!account) {

package.json

@@ -1,6 +1,6 @@
 {
   "name": "sbc-inbound",
-  "version": "0.8.3",
+  "version": "0.8.4",
   "main": "app.js",
   "engines": {
     "node": ">= 12.0.0"
@@ -29,11 +29,12 @@
     "@jambonz/http-health-check": "^0.0.1",
     "@jambonz/realtimedb-helpers": "^0.8.6",
     "@jambonz/rtpengine-utils": "^0.4.3",
-    "@jambonz/siprec-client-utils": "^0.2.5",
-    "@jambonz/stats-collector": "^0.1.8",
+    "@jambonz/siprec-client-utils": "^0.2.6",
+    "@jambonz/stats-collector": "^0.1.9",
     "@jambonz/time-series": "^0.2.5",
     "@jambonz/digest-utils": "^0.0.3",
-    "aws-sdk": "^2.1354.0",
+    "@aws-sdk/client-sns": "^3.360.0",
+    "@aws-sdk/client-auto-scaling": "^3.360.0",
     "bent": "^7.3.12",
     "cidr-matcher": "^2.1.1",
     "debug": "^4.3.4",