feat: add instance_id tag to active call metric (#71)

Co-authored-by: Quan HL <quanluuhoang8@gmail.com>

.eslintrc.json

@@ -8,7 +8,7 @@
       "jsx": false,
       "modules": false
     },
-    "ecmaVersion": 2018
+    "ecmaVersion": 2020
   },
   "plugins": ["promise"],
   "rules": {

.github/workflows/build.yml

@@ -1,17 +1,15 @@
 name: CI
 
-on:
-  push:
-  workflow_dispatch:
+on: [push, pull_request]
 
 jobs:
   build:
     runs-on: ubuntu-latest
     steps:
-      - uses: actions/checkout@v2
-      - uses: actions/setup-node@v1
+      - uses: actions/checkout@v3
+      - uses: actions/setup-node@v3
         with:
-          node-version: 14.x
+          node-version: lts/*
       - run: npm ci
       - run: npm run jslint
       - run: npm test

.github/workflows/docker-publish.yml

@@ -20,7 +20,7 @@ jobs:
     if: github.event_name == 'push'
 
     steps:
-      - uses: actions/checkout@v2
+      - uses: actions/checkout@v3
 
       - name: Build image
         run: docker build . --file Dockerfile --tag $IMAGE_NAME

Dockerfile

@@ -1,4 +1,4 @@
-FROM --platform=linux/amd64 node:18.9.0-alpine3.16 as base
+FROM --platform=linux/amd64 node:18.14.1-alpine3.16 as base
 
 RUN apk --update --no-cache add --virtual .builds-deps build-base python3
 
@@ -20,4 +20,4 @@ ARG NODE_ENV
 
 ENV NODE_ENV $NODE_ENV
 
-CMD [ "node", "app.js" ]
+CMD [ "node", "app.js" ]

app.js

@@ -65,6 +65,8 @@ const {
 }, logger);
 
 const activeCallIds = new Map();
+const Emitter = require('events');
+const idleEmitter = new Emitter();
 
 srf.locals = {...srf.locals,
   stats,
@@ -76,6 +78,7 @@ srf.locals = {...srf.locals,
   AlertType,
   queryCdrs,
   activeCallIds,
+  idleEmitter,
   dbHelpers: {
     ping,
     performLcr,
@@ -179,12 +182,12 @@ if (process.env.K8S || process.env.HTTP_PORT) {
 if ('test' !== process.env.NODE_ENV) {
   /* update call stats periodically */
   setInterval(() => {
-    stats.gauge('sbc.sip.calls.count', activeCallIds.size, ['direction:outbound']);
-  }, 5000);
+    stats.gauge('sbc.sip.calls.count', activeCallIds.size, ['direction:outbound',
+      `instance_id:${process.env.INSTANCE_ID || 0}`]);
+  }, 20000);
 }
 
 const lookupRtpServiceEndpoints = (lookup, serviceName) => {
-  logger.debug(`dns lookup for ${serviceName}..`);
   lookup(serviceName, {family: 4, all: true}, (err, addresses) => {
     if (err) {
       logger.error({err}, `Error looking up ${serviceName}`);
@@ -239,4 +242,20 @@ else {
 
 pingMsTeamsGateways(logger, srf);
 
+process.on('SIGUSR2', handle.bind(null));
+process.on('SIGTERM', handle.bind(null));
+
+function handle(signal) {
+  logger.info(`got signal ${signal}`);
+  if (process.env.K8S) {
+    if (0 === activeCallIds.size) {
+      logger.info('exiting immediately since we have no calls in progress');
+      process.exit(0);
+    }
+    else {
+      idleEmitter.once('idle', () => process.exit(0));
+    }
+  }
+}
+
 module.exports = {srf};

lib/call-session.js

@@ -13,10 +13,17 @@ const makeInviteInProgressKey = (callid) => `sbc-out-iip${callid}`;
  */
 const createBLegFromHeader = (req, teams) => {
   const from = req.getParsedHeader('From');
-  const host = teams ? req.get('X-MS-Teams-Tenant-FQDN') : 'localhost';
   const uri = parseUri(from.uri);
-  if (uri && uri.user) return `sip:${uri.user}@${host}`;
-  return `sip:anonymous@${host}`;
+  let user = uri.user || 'anonymous';
+  let host = 'localhost';
+  if (teams) {
+    host = req.get('X-MS-Teams-Tenant-FQDN');
+  }
+  else if (req.has('X-Preferred-From-User') || req.has('X-Preferred-From-Host')) {
+    user = req.get('X-Preferred-From-User') || user;
+    host = req.get('X-Preferred-From-Host') || host;
+  }
+  return `sip:${user}@${host}`;
 };
 const createBLegToHeader = (req, teams) => {
   const to = req.getParsedHeader('To');
@@ -33,11 +40,13 @@ const initCdr = (srf, req) => {
   const to = arr ? arr[1] : req.calledNumber;
   arr = regex.exec(req.callingNumber);
   const from = arr ? arr[1] : req.callingNumber;
+  const applicationSid = req.get('X-Application-Sid');
 
   return {
     account_sid: req.get('X-Account-Sid'),
     call_sid: req.get('X-Call-Sid'),
     sip_callid: req.get('Call-ID'),
+    ...(applicationSid && {application_sid: applicationSid}),
     from,
     to,
     duration: 0,
@@ -68,6 +77,7 @@ class CallSession extends Emitter {
     this.logger = logger.child({callId: req.get('Call-ID')});
     this.useWss = req.locals.registration && req.locals.registration.protocol === 'wss';
     this.stats = this.srf.locals.stats;
+    this.idleEmitter = this.srf.locals.idleEmitter;
     this.activeCallIds = this.srf.locals.activeCallIds;
     this.writeCdrs = this.srf.locals.writeCdrs;
 
@@ -97,6 +107,20 @@ class CallSession extends Emitter {
     return this._mediaReleased;
   }
 
+  subscribeForDTMF(dlg) {
+    if (!this._subscribedForDTMF) {
+      this._subscribedForDTMF = true;
+      this.subscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag,
+        this._onDTMF.bind(this, dlg));
+    }
+  }
+  unsubscribeForDTMF() {
+    if (this._subscribedForDTMF) {
+      this._subscribedForDTMF = false;
+      this.unsubscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag);
+    }
+  }
+
   async connect() {
     const teams = this.teams = this.req.locals.target === 'teams';
     const engine = this.srf.locals.getRtpEngine();
@@ -315,13 +339,14 @@ class CallSession extends Emitter {
               '-X-MS-Teams-FQDN',
               '-X-MS-Teams-Tenant-FQDN',
               '-X-Trace-ID',
-              'X-CID',
               '-Allow',
               '-Session-Expires',
               '-X-Requested-Carrier-Sid',
               '-X-Jambonz-Routing',
               '-X-Jambonz-FS-UUID',
-              'Min-SE'
+              '-X-Preferred-From-User',
+              'X-Preferred-From-Host',
+              '-X-Jambonz-FS-UUID',
             ],
             proxyResponseHeaders: [
               'all',
@@ -360,7 +385,10 @@ class CallSession extends Emitter {
                 else if (this.req.locals.registration) trunk = 'user';
                 else trunk = 'sipUri';
               }
-              if (!this.req.locals.account.disable_cdrs) {
+              if (this.req.locals.account?.disable_cdrs) {
+                this.logger.debug('cdrs disabled for this account');
+              }
+              else {
                 this.req.locals.cdr = {
                   ...initCdr(this.req.srf, inv),
                   service_provider_sid: this.req.locals.service_provider_sid,
@@ -421,6 +449,7 @@ class CallSession extends Emitter {
                 sip_status: status
               }).catch((err) => this.logger.error({err}, 'Error writing cdr for call failure'));
             }
+            return;
           }
           else {
             this.logger.info(`got ${err.status}, cranking back to next destination`);
@@ -454,7 +483,8 @@ class CallSession extends Emitter {
         const other = dlg.other;
         this.rtpEngineResource.destroy();
         this.activeCallIds.delete(this.req.get('Call-ID'));
-        this.unsubscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag);
+        this.unsubscribeForDTMF();
+        //this.unsubscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag);
         try {
           await other.destroy();
         } catch (err) {}
@@ -490,14 +520,20 @@ class CallSession extends Emitter {
         dlg.other = null;
         other.other = null;
 
-        this.logger.info(`call ended with normal termination, there are ${this.activeCallIds.size} active`);
+        if (this.srsClient) {
+          this.srsClient.stop();
+          this.srsClient = null;
+        }
 
+        this.logger.info(`call ended with normal termination, there are ${this.activeCallIds.size} active`);
+        if (this.activeCallIds.size === 0) this.idleEmitter.emit('idle');
         this.srf.endSession(this.req);
       });
     });
 
-    this.subscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag,
-      this._onDTMF.bind(this, uas));
+    this.subscribeForDTMF(uas);
+    //this.subscribeDTMF(this.logger, this.req.get('Call-ID'), this.rtpEngineOpts.uac.tag,
+    //  this._onDTMF.bind(this, uas));
 
     uas.on('modify', this._onReinvite.bind(this, uas));
     uac.on('modify', this._onReinvite.bind(this, uac));
@@ -579,7 +615,8 @@ Duration=${payload.duration} `
         direction,
         sdp: req.body,
       };
-      if (reason && opts.flags && !opts.flags.includes('reset')) opts.flags.push('reset');
+      // DH: this was restarting ICE, which we don't want to do
+      //if (reason && opts.flags && !opts.flags.includes('reset')) opts.flags.push('reset');
 
       let response = await this.offer(opts);
       if ('ok' !== response.result) {
@@ -727,7 +764,7 @@ Duration=${payload.duration} `
         }
       }
       else if (dlg.type === 'uac' && ['application/dtmf-relay', 'application/dtmf'].includes(contentType)) {
-        const arr = /Signal=\s*([1-9#*])/.exec(req.body);
+        const arr = /Signal=\s*([0-9#*])/.exec(req.body);
         if (!arr) {
           this.logger.info({body: req.body}, '_onInfo: invalid INFO dtmf request');
           throw new Error(`_onInfo: no dtmf in body for ${contentType}`);
@@ -817,6 +854,7 @@ Duration=${payload.duration} `
         this.logger.info('call ended with normal termination');
         this.rtpEngineResource.destroy();
         this.activeCallIds.delete(this.req.get('Call-ID'));
+        if (this.activeCallIds.size === 0) this.idleEmitter.emit('idle');
         this.uas.other.destroy();
         this.srf.endSession(this.req);
       });

lib/middleware.js

@@ -194,8 +194,8 @@ module.exports = (srf, logger, opts) => {
     logger.info(`received outbound INVITE to ${req.uri} from server at ${req.server.hostport}`);
     const uri = parseUri(req.uri);
     const desiredRouting = req.get('X-Jambonz-Routing');
-
-    if (!uri || !uri.user || !uri.host) {
+    const validUri = uri && uri.user && uri.host;
+    if (['user', 'sip'].includes(desiredRouting) && !validUri) {
       logger.info({uri: req.uri}, 'invalid request-uri on outbound call, rejecting');
       res.send(400, {
         headers: {

lib/utils.js

@@ -17,7 +17,8 @@ function makeRtpEngineOpts(req, srcIsUsingSrtp, dstIsUsingSrtp, teams = false) {
   }
   const common = {
     'call-id': req.get('Call-ID'),
-    'replace': ['origin', 'session-connection']
+    'replace': ['origin', 'session-connection'],
+    'record call': process.env.JAMBONES_RECORD_ALL_CALLS ? 'yes' : 'no'
   };
   return {
     common,

package.json

@@ -1,6 +1,6 @@
 {
   "name": "sbc-outbound",
-  "version": "v0.7.7",
+  "version": "v0.8.1",
   "main": "app.js",
   "engines": {
     "node": ">= 12.0.0"
@@ -27,18 +27,18 @@
     "jslint": "eslint app.js lib"
   },
   "dependencies": {
-    "@jambonz/db-helpers": "^0.6.19",
+    "@jambonz/db-helpers": "^0.7.4",
+    "@jambonz/realtimedb-helpers": "^0.7.0",
     "@jambonz/http-health-check": "^0.0.1",
     "@jambonz/mw-registrar": "0.2.2",
-    "@jambonz/realtimedb-helpers": "^0.4.29",
-    "@jambonz/rtpengine-utils": "^0.3.10",
-    "@jambonz/siprec-client-utils": "^0.1.4",
+    "@jambonz/rtpengine-utils": "^0.4.3",
+    "@jambonz/siprec-client-utils": "^0.2.4",
     "@jambonz/stats-collector": "^0.1.6",
     "@jambonz/time-series": "^0.2.5",
     "cidr-matcher": "^2.1.1",
     "debug": "^4.3.4",
     "drachtio-fn-b2b-sugar": "^0.0.12",
-    "drachtio-srf": "^4.5.1",
+    "drachtio-srf": "^4.5.21",
     "express": "^4.18.1",
     "pino": "^7.11.0",
     "sdp-transform": "^2.14.1"

test/scenarios/uac-pcap-carrier-success-k8s.xml

@@ -0,0 +1,91 @@
+<?xml version="1.0" encoding="ISO-8859-1" ?>
+<!DOCTYPE scenario SYSTEM "sipp.dtd">
+
+<scenario name="UAC with media">
+
+  <send retrans="500">
+    <![CDATA[
+
+      INVITE sip:16173333456@sbc-sip:5060 SIP/2.0
+      Via: SIP/2.0/[transport] [local_ip]:[local_port];branch=[branch]
+      From: sipp <sip:sipp@[local_ip]:[local_port]>;tag=[pid]SIPpTag09[call_number]
+      To: <sip:16173333456@sbc-sip:5060>
+      Call-ID: [call_id]
+      CSeq: 1 INVITE
+      Contact: sip:sipp@[local_ip]:[local_port]
+      Max-Forwards: 70
+      X-Account-Sid: ed649e33-e771-403a-8c99-1780eabbc803
+      X-Call-Sid: fff49e33-e771-403a-8c99-1780eabbc803
+      X-Jambonz-Routing: phone
+      Subject: uac-pcap-carrier-success
+      Content-Type: application/sdp
+      Content-Length: [len]
+
+      v=0
+      o=user1 53655765 2353687637 IN IP[local_ip_type] [local_ip]
+      s=-
+      c=IN IP[local_ip_type] [local_ip]
+      t=0 0
+      m=audio [auto_media_port] RTP/AVP 8 101
+      a=rtpmap:8 PCMA/8000
+      a=rtpmap:101 telephone-event/8000
+      a=fmtp:101 0-11,16
+
+    ]]>
+  </send>
+
+  <recv response="100" optional="true">
+  </recv>
+
+  <recv response="180" optional="true">
+  </recv>
+
+  <recv response="200" rtd="true" crlf="true">
+  </recv>
+
+  <send>
+    <![CDATA[
+
+      ACK sip:sip:+16173333456@sbc-sip:5060 SIP/2.0
+      Via: SIP/2.0/[transport] [local_ip]:[local_port];branch=[branch]
+      From: sipp <sip:sipp@[local_ip]:[local_port]>;tag=[pid]SIPpTag09[call_number]
+      To: <sip:sip:+16173333456@sbc-sip:5060>[peer_tag_param]
+      Call-ID: [call_id]
+      CSeq: 1 ACK
+      Subject: uac-pcap-carrier-success
+      Content-Length: 0
+
+    ]]>
+  </send>
+
+  <!-- Play a pre-recorded PCAP file (RTP stream)                       -->
+  <nop>
+    <action>
+      <exec play_pcap_audio="pcap/g711a.pcap"/>
+    </action>
+  </nop>
+
+  <!-- Pause briefly      -->
+  <pause milliseconds="2000"/>
+
+  <!-- The 'crlf' option inserts a blank line in the statistics report. -->
+  <send retrans="500">
+    <![CDATA[
+
+      BYE sip:sip:+16173333456@sbc-sip:5060 SIP/2.0
+      Via: SIP/2.0/[transport] [local_ip]:[local_port];branch=[branch]
+      From: sipp <sip:sipp@[local_ip]:[local_port]>;tag=[pid]SIPpTag09[call_number]
+      To: <sip:sip:+16173333456@sbc-sip:5060>[peer_tag_param]
+      Call-ID: [call_id]
+      CSeq: 2 BYE
+      Max-Forwards: 70
+      Subject: uac-pcap-carrier-success
+      Content-Length: 0
+
+    ]]>
+  </send>
+
+  <recv response="200" crlf="true">
+  </recv>
+
+</scenario>

test/sip-tests.js

@@ -42,7 +42,11 @@ test('sbc-outbound tests', async(t) => {
 
     /* call to PSTN with no lcr configured */
     await sippUac('uac-pcap-carrier-success.xml');
-    t.pass('successfully completed outbound call to configured sip trunk');
+    t.pass('successfully completed outbound call to sip trunk');
+
+    /* call to PSTN with request uri we see in kubernetes */
+    await sippUac('uac-pcap-carrier-success-k8s.xml');
+    t.pass('successfully completed outbound call to sip trunk (k8S req uri)');
 
     // re-rack test data
     execSync(`mysql -h 127.0.0.1 -u root  --protocol=tcp -D jambones_test < ${__dirname}/db/jambones-sql.sql`);
@@ -80,10 +84,10 @@ test('sbc-outbound tests', async(t) => {
     await sippUac('uac-pcap-carrier-fail-limits.xml');
     t.pass('fails when max calls in progress');
       
-    await waitFor(10);
+    await waitFor(25);
 
     const res = await queryCdrs({account_sid: 'ed649e33-e771-403a-8c99-1780eabbc803'});
-    //console.log(`cdrs: ${JSON.stringify(res)}`);
+    console.log(`cdrs: ${JSON.stringify(res)}`);
     t.ok(res.total === 6, 'wrote 6 cdrs');
 
     srf.disconnect();