gather: restart if we get an empty transcript (looking at you, Azure)

* initial adds for otel tracing

* initial basic testing

* basic tracing for incoming calls

* linting

* add traceId to the webhook params

* trace webhook calls

* tracing: add new commands as tags when receiving async commands over websocket

* tracing new commands

* add summary for config verb

* trace async commands

* bugfix: undefined ref

* tracing: give time for final webhooks before closing root span

* tracing bugfix: span for background gather was not ended

* tracing - minor tag changes

* tracing - add span atttribute for reason call ended

* trace call status webhooks, add app version to trace output

* config: add support for automatically re-enabling

* env var to customize service name in tracing UI

* config: change to use 'sticky' attribute to re-enable bargein automatically

* fix warnings

* when adulting create a new root span

* when background gather triggers bargein via vad clear queue of tasks

* additional trace attributes for dial and refer

* fix dial tracing

* add better summary for dial

* fix prev commit

* add exponential backoff to WsRequestor reconnection logic

* add calling number to log metadata, as this will be frequently the key data given for troubleshooting

* add accountSid to log metadata

* make handshake timeout for ws connections configurable with default 1.5 secs

* rename env var

* fix bug prev checkin

* logging fixes

* consistent env naming

Dockerfile

@@ -1,4 +1,4 @@
-FROM node:17.4-slim
+FROM node:17.7.1-slim
 WORKDIR /opt/app/
 COPY package.json ./
 RUN npm install

app.js

@@ -11,6 +11,10 @@ assert.ok(process.env.JAMBONES_NETWORK_CIDR || process.env.K8S, 'missing JAMBONE
 
 const Srf = require('drachtio-srf');
 const srf = new Srf();
+const tracer = require('./tracer')(process.env.JAMBONES_OTEL_SERVICE_NAME || 'jambonz-feature-server');
+const api = require('@opentelemetry/api');
+srf.locals = {...srf.locals, otel: {tracer, api}};
+
 const PORT = process.env.HTTP_PORT || 3000;
 const opts = {
   timestamp: () => {return `, "time": "${new Date().toISOString()}"`;},
@@ -23,6 +27,7 @@ installSrfLocals(srf, logger);
 
 const {
   initLocals,
+  createRootSpan,
   getAccountDetails,
   normalizeNumbers,
   retrieveApplication,
@@ -62,6 +67,7 @@ if (process.env.NODE_ENV === 'test') {
 
 srf.use('invite', [
   initLocals,
+  createRootSpan,
   getAccountDetails,
   normalizeNumbers,
   retrieveApplication,

lib/http-routes/api/create-call.js

@@ -8,6 +8,7 @@ const SipError = require('drachtio-srf').SipError;
 const sysError = require('./error');
 const HttpRequestor = require('../../utils/http-requestor');
 const WsRequestor = require('../../utils/ws-requestor');
+const RootSpan = require('../../utils/call-tracer');
 const dbUtils = require('../../utils/db-utils');
 
 router.post('/', async(req, res) => {
@@ -131,8 +132,14 @@ router.post('/', async(req, res) => {
     try {
       const dlg = await srf.createUAC(uri, {...opts,  followRedirects: true, keepUriOnRedirect: true}, {
         cbRequest: (err, inviteReq) => {
-          /* in case of 302 redirect, this gets called twice, ignore the second */
-          if (res.headersSent) return;
+          /* in case of 302 redirect, this gets called twice, ignore the second
+              except to update the req so that it can later be canceled if need be
+          */
+          if (res.headersSent) {
+            logger.info(`create-call: got redirect, updating request to new call-id ${req.get('Call-ID')}`);
+            if (cs) cs.req = inviteReq;
+            return;
+          }
 
           if (err) {
             logger.error(err, 'createCall Error creating call');
@@ -143,6 +150,7 @@ router.post('/', async(req, res) => {
           /* ok our outbound INVITE is in flight */
 
           const tasks = [restDial];
+          const rootSpan = new RootSpan('rest-call', req);
           const callInfo = new CallInfo({
             direction: CallDirection.Outbound,
             req: inviteReq,
@@ -150,9 +158,20 @@ router.post('/', async(req, res) => {
             tag: app.tag,
             callSid,
             accountSid: req.body.account_sid,
-            applicationSid: app.application_sid
+            applicationSid: app.application_sid,
+            traceId: this.rootSpan.traceId
+          });
+          cs = new RestCallSession({
+            logger,
+            application: app,
+            srf,
+            req: inviteReq,
+            ep,
+            tasks,
+            callInfo,
+            accountInfo,
+            rootSpan
           });
-          cs = new RestCallSession({logger, application: app, srf, req: inviteReq, ep, tasks, callInfo, accountInfo});
           cs.exec(req);
 
           res.status(201).json({sid: cs.callSid});

lib/middleware.js

@@ -7,6 +7,8 @@ const makeTask = require('./tasks/make_task');
 const parseUri = require('drachtio-srf').parseUri;
 const normalizeJambones = require('./utils/normalize-jambones');
 const dbUtils = require('./utils/db-utils');
+const RootSpan = require('./utils/call-tracer');
+const listTaskNames = require('./utils/summarize-tasks');
 
 module.exports = function(srf, logger) {
   const {
@@ -17,15 +19,18 @@ module.exports = function(srf, logger) {
     lookupAppByTeamsTenant
   }  = srf.locals.dbHelpers;
   const {lookupAccountDetails} = dbUtils(logger, srf);
+
   function initLocals(req, res, next) {
+    if (!req.has('X-Account-Sid')) {
+      logger.info('getAccountDetails - rejecting call due to missing X-Account-Sid header');
+      return res.send(500);
+    }
     const callSid = req.has('X-Retain-Call-Sid') ? req.get('X-Retain-Call-Sid') : uuidv4();
-    req.locals = {
-      callSid,
-      logger: logger.child({callId: req.get('Call-ID'), callSid})
-    };
+    const account_sid = req.get('X-Account-Sid');
+    req.locals = {callSid, account_sid};
     if (req.has('X-Application-Sid')) {
       const application_sid = req.get('X-Application-Sid');
-      req.locals.logger.debug(`got application from X-Application-Sid header: ${application_sid}`);
+      logger.debug(`got application from X-Application-Sid header: ${application_sid}`);
       req.locals.application_sid = application_sid;
     }
     if (req.has('X-Authenticated-User')) req.locals.originatingUser = req.get('X-Authenticated-User');
@@ -34,19 +39,50 @@ module.exports = function(srf, logger) {
     next();
   }
 
+  function createRootSpan(req, res, next) {
+    const {callSid, account_sid} = req.locals;
+    const rootSpan = new RootSpan('incoming-call', req);
+    const traceId = rootSpan.traceId;
+
+    req.locals = {
+      ...req.locals,
+      traceId,
+      logger: logger.child({
+        callId: req.get('Call-ID'),
+        callSid,
+        accountSid: account_sid,
+        callingNumber: req.callingNumber,
+        calledNumber: req.calledNumber,
+        traceId}),
+      rootSpan
+    };
+
+    /**
+     * end the span on final failure or cancel from caller;
+     * otherwise it will be closed when sip dialog is destroyed
+    */
+    req.once('cancel', () => {
+      rootSpan.setAttributes({finalStatus: 487});
+      rootSpan.end();
+    });
+    res.once('finish', () => {
+      rootSpan.setAttributes({finalStatus: res.statusCode});
+      res.statusCode >= 300 && rootSpan.end();
+    });
+
+    next();
+  }
+
   /**
    * retrieve account information for the incoming call
    */
   async function getAccountDetails(req, res, next) {
+    const {rootSpan, account_sid} = req.locals;
 
-    if (!req.has('X-Account-Sid')) {
-      logger.info('getAccountDetails - rejecting call due to missing X-Account-Sid header');
-      return res.send(500);
-    }
-    const account_sid = req.locals.account_sid = req.get('X-Account-Sid');
-
+    const {span} = rootSpan.startChildSpan('lookupAccountDetails');
     try {
       req.locals.accountInfo = await lookupAccountDetails(account_sid);
+      span.end();
       if (!req.locals.accountInfo.account.is_active) {
         logger.info(`Account is inactive or suspended ${account_sid}`);
         // TODO: alert
@@ -55,6 +91,7 @@ module.exports = function(srf, logger) {
       logger.debug({accountInfo: req.locals?.accountInfo?.account}, `retrieved account info for ${account_sid}`);
       next();
     } catch (err) {
+      span.end();
       logger.info({err}, `Error retrieving account details for account ${account_sid}`);
       res.send(503, {headers: {'X-Reason': `No Account exists for sid ${account_sid}`}});
     }
@@ -86,7 +123,8 @@ module.exports = function(srf, logger) {
    */
   async function retrieveApplication(req, res, next) {
     const logger = req.locals.logger;
-    const {accountInfo, account_sid} = req.locals;
+    const {accountInfo, account_sid, rootSpan} = req.locals;
+    const {span} = rootSpan.startChildSpan('lookupApplication');
     try {
       let app;
       if (req.locals.application_sid) app = await lookupAppBySid(req.locals.application_sid);
@@ -130,6 +168,11 @@ module.exports = function(srf, logger) {
         }
       }
 
+      span.setAttributes({
+        'app.hook': app?.call_hook?.url,
+        'application_sid': req.locals.application_sid
+      });
+      span.end();
       if (!app || !app.call_hook || !app.call_hook.url) {
         logger.info(`rejecting call to ${req.locals.calledNumber}: no application or webhook url`);
         return res.send(480, {
@@ -163,9 +206,15 @@ module.exports = function(srf, logger) {
       // eslint-disable-next-line no-unused-vars
       const {call_hook, call_status_hook, ...appInfo} = obj;  // mask sensitive data like user/pass on webhook
       logger.info({app: appInfo}, `retrieved application for incoming call to ${req.locals.calledNumber}`);
-      req.locals.callInfo = new CallInfo({req, app, direction: CallDirection.Inbound});
+      req.locals.callInfo = new CallInfo({
+        req,
+        app,
+        direction: CallDirection.Inbound,
+        traceId: rootSpan.traceId
+      });
       next();
     } catch (err) {
+      span.end();
       logger.error(err, `${req.get('Call-ID')} Error looking up application for ${req.calledNumber}`);
       res.send(500);
     }
@@ -176,9 +225,9 @@ module.exports = function(srf, logger) {
    */
   async function invokeWebCallback(req, res, next) {
     const logger = req.locals.logger;
-    const app = req.locals.application;
+    const {rootSpan, application:app} = req.locals;
+    let span;
     try {
-
       if (app.tasks) {
         app.tasks = normalizeJambones(logger, app.tasks).map((tdata) => makeTask(logger, tdata));
         if (0 === app.tasks.length) throw new Error('no application provided');
@@ -187,11 +236,22 @@ module.exports = function(srf, logger) {
       /* retrieve the application to execute for this inbound call */
       const params = Object.assign(['POST', 'WS'].includes(app.call_hook.method) ? {sip: req.msg} : {},
         req.locals.callInfo);
-      const json = await app.requestor.request('session:new', app.call_hook, params);
+      const obj = rootSpan.startChildSpan('performAppWebhook');
+      span = obj.span;
+      const b3 = rootSpan.getTracingPropagation();
+      const httpHeaders = b3 && {b3};
+      const json = await app.requestor.request('session:new', app.call_hook, params, httpHeaders);
       app.tasks = normalizeJambones(logger, json).map((tdata) => makeTask(logger, tdata));
+      span.setAttributes({
+        'http.statusCode': 200,
+        'app.tasks': listTaskNames(app.tasks)
+      });
+      span.end();
       if (0 === app.tasks.length) throw new Error('no application provided');
       next();
     } catch (err) {
+      span?.setAttributes({webhookStatus: err.statusCode});
+      span?.end();
       logger.info({err}, `Error retrieving or parsing application: ${err?.message}`);
       res.send(480, {headers: {'X-Reason': err?.message || 'unknown'}});
       app.requestor.close();
@@ -200,6 +260,7 @@ module.exports = function(srf, logger) {
 
   return {
     initLocals,
+    createRootSpan,
     getAccountDetails,
     normalizeNumbers,
     retrieveApplication,

lib/session/call-info.js

@@ -10,6 +10,7 @@ class CallInfo {
     let from ;
     let srf;
     this.direction = opts.direction;
+    this.traceId = opts.traceId;
     if (opts.req) {
       const u = opts.req.getParsedHeader('from');
       const uri = parseUri(u.uri);
@@ -114,6 +115,7 @@ class CallInfo {
       callStatus: this.callStatus,
       callerId: this.callerId,
       accountSid: this.accountSid,
+      traceId: this.traceId,
       applicationSid: this.applicationSid,
       fsSipAddress: this.localSipAddress
     };

lib/session/call-session.js

@@ -35,7 +35,7 @@ class CallSession extends Emitter {
    * @param {array} opts.tasks - tasks we are to execute
    * @param {callInfo} opts.callInfo - information about the call
    */
-  constructor({logger, application, srf, tasks, callInfo, accountInfo, memberId, confName, confUuid}) {
+  constructor({logger, application, srf, tasks, callInfo, accountInfo, rootSpan, memberId, confName, confUuid}) {
     super();
     this.logger = logger;
     this.application = application;
@@ -50,6 +50,9 @@ class CallSession extends Emitter {
     this.stackIdx = 0;
     this.callGone = false;
     this.notifiedComplete = false;
+    this.rootSpan = rootSpan;
+
+    assert(rootSpan);
 
     this.tmpFiles = new Set();
 
@@ -65,6 +68,7 @@ class CallSession extends Emitter {
     this._pool = srf.locals.dbHelpers.pool;
 
     this.requestor.on('command', this._onCommand.bind(this));
+    this.requestor.on('connection-dropped', this._onWsConnectionDropped.bind(this));
   }
 
   /**
@@ -226,26 +230,40 @@ class CallSession extends Emitter {
     return this.backgroundGatherTask;
   }
 
-  async enableBotMode(gather) {
+  get b3() {
+    return this.rootSpan?.getTracingPropagation();
+  }
+
+  async enableBotMode(gather, autoEnable) {
     try {
       const t = normalizeJambones(this.logger, [gather]);
       this.backgroundGatherTask = makeTask(this.logger, t[0]);
       this.backgroundGatherTask
         .on('dtmf', this._clearTasks.bind(this))
+        .on('vad', this._clearTasks.bind(this))
         .on('transcription', this._clearTasks.bind(this))
         .on('timeout', this._clearTasks.bind(this));
       this.logger.info({gather}, 'CallSession:enableBotMode - starting background gather');
       const resources = await this._evaluatePreconditions(this.backgroundGatherTask);
+      const {span, ctx} = this.rootSpan.startChildSpan(`background-gather:${this.backgroundGatherTask.summary}`);
+      this.backgroundGatherTask.span = span;
+      this.backgroundGatherTask.ctx = ctx;
       this.backgroundGatherTask.exec(this, resources)
         .then(() => {
           this.logger.info('CallSession:enableBotMode: gather completed');
           this.backgroundGatherTask && this.backgroundGatherTask.removeAllListeners();
+          this.backgroundGatherTask && this.backgroundGatherTask.span.end();
           this.backgroundGatherTask = null;
+          if (autoEnable && !this.callGone) {
+            this.logger.info('CallSession:enableBotMode: restarting background gather');
+            setImmediate(() => this.enableBotMode(gather, true));
+          }
           return;
         })
         .catch((err) => {
           this.logger.info({err}, 'CallSession:enableBotMode: gather threw error');
           this.backgroundGatherTask && this.backgroundGatherTask.removeAllListeners();
+          this.backgroundGatherTask && this.backgroundGatherTask.span.end();
           this.backgroundGatherTask = null;
         });
     } catch (err) {
@@ -362,11 +380,16 @@ class CallSession extends Emitter {
           this.backgroundGatherTask.updateTimeout(timeout);
         }
         else {
+          const {span, ctx} = this.rootSpan.startChildSpan(`verb:${task.summary}`);
+          task.span = span;
+          task.ctx = ctx;
           await task.exec(this, resources);
+          task.span.end();
         }
         this.currentTask = null;
         this.logger.info(`CallSession:exec completed task #${stackNum}:${taskNum}: ${task.name}`);
       } catch (err) {
+        task.span?.end();
         this.currentTask = null;
         if (err.message?.includes(BADPRECONDITIONS)) {
           this.logger.info(`CallSession:exec task #${stackNum}:${taskNum}: ${task.name}: ${err.message}`);
@@ -378,10 +401,19 @@ class CallSession extends Emitter {
       }
 
       if (0 === this.tasks.length && this.hasStableDialog && this.requestor instanceof WsRequestor) {
+        let span;
         try {
-          await this._awaitCommandsOrHangup();
+          const {span} = this.rootSpan.startChildSpan('waiting for commands');
+          const {reason, queue, command} = await this._awaitCommandsOrHangup();
+          span.setAttributes({
+            'completion.reason': reason,
+            'async.request.queue': queue,
+            'async.request.command': command
+          });
+          span.end();
           if (!this.hasStableDialog || this.callGone) break;
         } catch (err) {
+          span.end();
           this.logger.info(err, 'CallSession:exec - error waiting for new commands');
           break;
         }
@@ -438,17 +470,15 @@ class CallSession extends Emitter {
    * this is called to clean up when the call is released from one side or another
    */
   _callReleased() {
-    this.logger.debug('CallSession:_callReleased - caller hung up');
     this.callGone = true;
     if (this.currentTask) {
       this.currentTask.kill(this);
       this.currentTask = null;
     }
     if (this.wakeupResolver) {
-      this.wakeupResolver();
+      this.wakeupResolver({reason: 'session ended'});
       this.wakeupResolver = null;
     }
-    this.requestor && this.requestor.close();
   }
 
   /**
@@ -486,17 +516,20 @@ class CallSession extends Emitter {
   async _lccCallHook(opts) {
     const webhooks = [];
     let sd, tasks, childTasks;
+    const b3 = this.b3;
+    const httpHeaders = b3 && {b3};
 
     if (opts.call_hook || opts.child_call_hook) {
       if (opts.call_hook) {
-        webhooks.push(this.requestor.request('session:redirect', opts.call_hook, this.callInfo.toJSON()));
+        webhooks.push(this.requestor.request('session:redirect', opts.call_hook, this.callInfo.toJSON(), httpHeaders));
       }
       if (opts.child_call_hook) {
         /* child call hook only allowed from a connected Dial state */
         const task = this.currentTask;
         sd = task.sd;
         if (task && TaskName.Dial === task.name && sd) {
-          webhooks.push(this.requestor.request('session:redirect', opts.child_call_hook, sd.callInfo.toJSON()));
+          webhooks.push(this.requestor.request(
+            'session:redirect', opts.child_call_hook, sd.callInfo.toJSON(), httpHeaders));
         }
       }
       const [tasks1, tasks2] = await Promise.all(webhooks);
@@ -615,6 +648,8 @@ class CallSession extends Emitter {
   async _lccWhisper(opts, callSid) {
     const {whisper} = opts;
     let tasks;
+    const b3 = this.b3;
+    const httpHeaders = b3 && {b3};
 
     // this whole thing requires us to be in a Dial verb
     const task = this.currentTask;
@@ -625,7 +660,7 @@ class CallSession extends Emitter {
     // allow user to provide a url object, a url string, an array of tasks, or a single task
     if (typeof whisper === 'string' || (typeof whisper === 'object' && whisper.url)) {
       // retrieve a url
-      const json = await this.requestor(opts.call_hook, this.callInfo.toJSON());
+      const json = await this.requestor(opts.call_hook, this.callInfo.toJSON(), httpHeaders);
       tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
     }
     else if (Array.isArray(whisper)) {
@@ -728,6 +763,7 @@ class CallSession extends Emitter {
 
   _onCommand({msgid, command, call_sid, queueCommand, data}) {
     this.logger.info({msgid, command, queueCommand}, 'CallSession:_onCommand - received command');
+    const resolution = {reason: 'received command', queue: queueCommand, command};
     switch (command) {
       case 'redirect':
         if (Array.isArray(data)) {
@@ -742,6 +778,7 @@ class CallSession extends Emitter {
             this.tasks.push(...t);
             this.logger.debug({tasks: listTaskNames(this.tasks)}, 'CallSession:_onCommand - updated task list');
           }
+          resolution.command = listTaskNames(t);
         }
         else this._lccCallHook(data);
         break;
@@ -781,10 +818,24 @@ class CallSession extends Emitter {
         this.logger.info(`CallSession:_onCommand - invalid command ${command}`);
     }
     if (this.wakeupResolver) {
-      this.logger.info('CallSession:_onCommand - got commands, waking up..');
-      this.wakeupResolver();
+      this.logger.debug({resolution}, 'CallSession:_onCommand - got commands, waking up..');
+      this.wakeupResolver(resolution);
       this.wakeupResolver = null;
     }
+    else {
+      const {span} = this.rootSpan.startChildSpan('async command');
+      const {queue, command} = resolution;
+      span.setAttributes({
+        'async.request.queue': queue,
+        'async.request.command': command
+      });
+      span.end();
+    }
+  }
+
+  _onWsConnectionDropped() {
+    const {stats} = this.srf.locals;
+    stats.increment('app.hook.remote_close');
   }
 
   _evaluatePreconditions(task) {
@@ -928,6 +979,8 @@ class CallSession extends Emitter {
     }
     this.tmpFiles.clear();
     this.requestor && this.requestor.close();
+
+    this.rootSpan && this.rootSpan.end();
   }
 
   /**
@@ -960,7 +1013,13 @@ class CallSession extends Emitter {
   async propagateAnswer() {
     if (!this.dlg) {
       assert(this.ep);
-      this.dlg = await this.srf.createUAS(this.req, this.res, {localSdp: this.ep.local.sdp});
+      this.dlg = await this.srf.createUAS(this.req, this.res, {
+        headers: {
+          'X-Trace-ID': this.req.locals.traceId,
+          'X-Call-Sid': this.req.locals.callSid
+        },
+        localSdp: this.ep.local.sdp
+      });
       this.logger.debug('answered call');
       this.dlg.on('destroy', this._callerHungup.bind(this));
       this.wrapDialog(this.dlg);
@@ -1148,9 +1207,10 @@ class CallSession extends Emitter {
         const duration = moment().diff(this.dlg.connectTime, 'seconds');
         this.emit('callStatusChange', {callStatus: CallStatus.Completed, duration});
         this.logger.debug('CallSession: call terminated by jambones');
+        this.rootSpan.setAttributes({'call.termination': 'hangup by jambonz'});
         origDestroy();
         if (this.wakeupResolver) {
-          this.wakeupResolver();
+          this.wakeupResolver({reason: 'session ended'});
           this.wakeupResolver = null;
         }
       }
@@ -1210,9 +1270,15 @@ class CallSession extends Emitter {
 
     this.callInfo.updateCallStatus(callStatus, sipStatus, sipReason);
     if (typeof duration === 'number') this.callInfo.duration = duration;
+    const {span} = this.rootSpan.startChildSpan(`call-status:${this.callInfo.callStatus}`);
+    span.setAttributes(this.callInfo.toJSON());
     try {
-      this.notifier.request('call:status', this.call_status_hook, this.callInfo.toJSON());
+      const b3 = this.b3;
+      const httpHeaders = b3 && {b3};
+      this.notifier.request('call:status', this.call_status_hook, this.callInfo.toJSON(), httpHeaders);
+      span.end();
     } catch (err) {
+      span.end();
       this.logger.info(err, `CallSession:_notifyCallStatusChange error sending ${callStatus} ${sipStatus}`);
     }
 

lib/session/confirm-call-session.js

@@ -8,7 +8,7 @@ const CallSession = require('./call-session');
 
  */
 class ConfirmCallSession extends CallSession {
-  constructor({logger, application, dlg, ep, tasks, callInfo, accountInfo, memberId, confName}) {
+  constructor({logger, application, dlg, ep, tasks, callInfo, accountInfo, memberId, confName, rootSpan}) {
     super({
       logger,
       application,
@@ -18,7 +18,8 @@ class ConfirmCallSession extends CallSession {
       callInfo,
       accountInfo,
       memberId,
-      confName
+      confName,
+      rootSpan
     });
     this.dlg = dlg;
     this.ep = ep;

lib/session/inbound-call-session.js

@@ -16,7 +16,8 @@ class InboundCallSession extends CallSession {
       application: req.locals.application,
       callInfo: req.locals.callInfo,
       accountInfo: req.locals.accountInfo,
-      tasks: req.locals.application.tasks
+      tasks: req.locals.application.tasks,
+      rootSpan: req.locals.rootSpan
     });
     this.req = req;
     this.res = res;
@@ -32,6 +33,7 @@ class InboundCallSession extends CallSession {
   }
 
   _onCancel() {
+    this.rootSpan.setAttributes({'call.termination': 'caller abandoned'});
     this._notifyCallStatusChange({
       callStatus: CallStatus.NoAnswer,
       sipStatus: 487,
@@ -43,6 +45,7 @@ class InboundCallSession extends CallSession {
   _onTasksDone() {
     if (!this.res.finalResponseSent) {
       if (this._mediaServerFailure) {
+        this.rootSpan.setAttributes({'call.termination': 'media server failure'});
         this.logger.info('InboundCallSession:_onTasksDone generating 480 due to media server failure');
         this.res.send(480, {
           headers: {
@@ -51,6 +54,7 @@ class InboundCallSession extends CallSession {
         });
       }
       else {
+        this.rootSpan.setAttributes({'call.termination': 'tasks completed without answering call'});
         this.logger.info('InboundCallSession:_onTasksDone auto-generating non-success response to invite');
         this.res.send(603);
       }
@@ -64,11 +68,12 @@ class InboundCallSession extends CallSession {
   _callerHungup() {
     assert(this.dlg.connectTime);
     const duration = moment().diff(this.dlg.connectTime, 'seconds');
+    this.rootSpan.setAttributes({'call.termination': 'hangup by caller'});
     this.emit('callStatusChange', {
       callStatus: CallStatus.Completed,
       duration
     });
-    this.logger.debug('InboundCallSession: caller hung up');
+    this.logger.info('InboundCallSession: caller hung up');
     this._callReleased();
     this.req.removeAllListeners('cancel');
   }

lib/session/rest-call-session.js

@@ -8,7 +8,7 @@ const moment = require('moment');
  * @extends CallSession
  */
 class RestCallSession extends CallSession {
-  constructor({logger, application, srf, req, ep, tasks, callInfo, accountInfo}) {
+  constructor({logger, application, srf, req, ep, tasks, callInfo, accountInfo, rootSpan}) {
     super({
       logger,
       application,
@@ -16,7 +16,8 @@ class RestCallSession extends CallSession {
       callSid: callInfo.callSid,
       tasks,
       callInfo,
-      accountInfo
+      accountInfo,
+      rootSpan
     });
     this.req = req;
     this.ep = ep;

lib/tasks/conference.js

@@ -529,7 +529,9 @@ class Conference extends Task {
 
   async _playHook(cs, dlg, hook, allowed = [TaskName.Play, TaskName.Say, TaskName.Pause]) {
     assert(!this._playSession);
-    const json = await cs.application.requestor.request('verb:hook', hook, cs.callInfo);
+    const b3 = this.getTracingPropagation();
+    const httpHeaders = b3 && {b3};
+    const json = await cs.application.requestor.request('verb:hook', hook, cs.callInfo, httpHeaders);
     const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
 
     const allowedTasks = tasks.filter((t) => allowed.includes(t.name));
@@ -582,11 +584,14 @@ class Conference extends Task {
 
   _notifyConferenceEvent(cs, eventName, params = {}) {
     if (this.statusEvents.includes(eventName)) {
+      const b3 = this.getTracingPropagation();
+      const httpHeaders = b3 && {b3};
       params.event = eventName;
       params.duration = (Date.now() - this.conferenceStartTime.getTime()) / 1000;
       if (!params.time) params.time = (new Date()).toISOString();
       if (!params.members && typeof this.participantCount === 'number') params.members = this.participantCount;
-      cs.application.requestor.request('verb:hook', this.statusHook, Object.assign(params, this.statusParams))
+      cs.application.requestor
+        .request('verb:hook', this.statusHook, Object.assign(params, this.statusParams, httpHeaders))
         .catch((err) => this.logger.info(err, 'Conference:notifyConferenceEvent - error'));
     }
   }

lib/tasks/config.js

@@ -24,6 +24,7 @@ class TaskConfig extends Task {
       ].forEach((k) => {
         if (this.bargeIn[k]) this.gatherOpts[k] = this.bargeIn[k];
       });
+      if (this.bargeIn.sticky) this.autoEnable = true;
     }
     this.preconditions = this.hasBargeIn ? TaskPreconditions.Endpoint : TaskPreconditions.None;
   }
@@ -36,6 +37,22 @@ class TaskConfig extends Task {
 
   get hasBargeIn() { return Object.keys(this.bargeIn).length; }
 
+  get summary() {
+    const phrase = [];
+    if (this.hasBargeIn) phrase.push('enable barge-in');
+    if (this.hasSynthesizer) {
+      const {vendor:v, language:l, voice} = this.synthesizer;
+      const s = `{${v},${l},${voice}}`;
+      phrase.push(`set synthesizer${s}`);
+    }
+    if (this.hasRecognizer) {
+      const {vendor:v, language:l} = this.recognizer;
+      const s = `{${v},${l}}`;
+      phrase.push(`set recognizer${s}`);
+    }
+    return  `${this.name}{${phrase.join(',')}`;
+  }
+
   async exec(cs) {
     await super.exec(cs);
 
@@ -58,12 +75,13 @@ class TaskConfig extends Task {
       cs.speechRecognizerLanguage = this.recognizer.language !== 'default'
         ? this.recognizer.language
         : cs.speechRecognizerLanguage;
+      this.gatherOpts.recognizer = this.recognizer;
       this.logger.info({recognizer: this.recognizer}, 'Config: updated recognizer');
     }
     if (this.hasBargeIn) {
       if (this.gatherOpts) {
         this.logger.debug({opts: this.gatherOpts}, 'Config: enabling bargeIn');
-        cs.enableBotMode(this.gatherOpts);
+        cs.enableBotMode(this.gatherOpts, this.autoEnable);
       }
       else {
         this.logger.debug('Config: disabling bargeIn');

lib/tasks/dial.js

@@ -138,7 +138,20 @@ class TaskDial extends Task {
   }
 
   get summary() {
-    if (this.target.length === 1) return `${this.name}{type=${this.target[0].type}}`;
+    if (this.target.length === 1) {
+      const target = this.target[0];
+      switch (target.type) {
+        case 'phone':
+        case 'teams':
+          return `${this.name}{type=${target.type},number=${target.number}}`;
+        case 'user':
+          return `${this.name}{type=${target.type},name=${target.name}}`;
+        case 'sip':
+          return `${this.name}{type=${target.type},sipUri=${target.sipUri}}`;
+        default:
+          return `${this.name}`;
+      }
+    }
     else return `${this.name}{${this.target.length} targets}`;
   }
 
@@ -213,7 +226,11 @@ class TaskDial extends Task {
       this.logger.debug('Dial:whisper executing tasks');
       while (tasks.length && !cs.callGone) {
         const task = tasks.shift();
+        const {span, ctx} = this.startChildSpan(`whisper:${this.sayTask.summary}`);
+        task.span = span;
+        task.ctx = ctx;
         await task.exec(cs, callSid === this.callSid ? this.ep : this.epOther);
+        span.end();
       }
       this.logger.debug('Dial:whisper tasks complete');
       if (!cs.callGone && this.epOther) {
@@ -254,6 +271,9 @@ class TaskDial extends Task {
         const referring_call_sid = isChild ? callInfo.callSid : cs.callSid;
         const referred_call_sid = isChild ? callInfo.parentCallSid : this.sd.callSid;
 
+        const b3 = this.getTracingPropagation();
+        const httpHeaders = b3 && {b3};
+
         const to = parseUri(req.getParsedHeader('Refer-To').uri);
         const by = parseUri(req.getParsedHeader('Referred-By').uri);
         this.logger.info({to}, 'refer to parsed');
@@ -268,7 +288,7 @@ class TaskDial extends Task {
             referring_call_sid,
             referred_call_sid
           }
-        });
+        }, httpHeaders);
         res.send(202);
         this.logger.info('DialTask:handleRefer - sent 202 Accepted');
       } catch (err) {
@@ -328,8 +348,10 @@ class TaskDial extends Task {
     const key = arr[1];
     const match = dtmfDetector.keyPress(key);
     if (match) {
+      const b3 = this.getTracingPropagation();
+      const httpHeaders = b3 && {b3};
       this.logger.info({callSid}, `Dial:_onInfo triggered dtmf match: ${match}`);
-      requestor.request('verb:hook', this.dtmfHook, {dtmf: match, ...callInfo.toJSON()})
+      requestor.request('verb:hook', this.dtmfHook, {dtmf: match, ...callInfo.toJSON(), httpHeaders})
         .catch((err) => this.logger.info(err, 'Dial:_onDtmf - error'));
     }
   }
@@ -384,6 +406,7 @@ class TaskDial extends Task {
       this._killOutdials();
     }, this.timeout * 1000);
 
+    this.span.setAttributes('dial.target', JSON.stringify(this.target));
     this.target.forEach(async(t) => {
       try {
         t.url = t.url || this.confirmUrl;
@@ -420,7 +443,9 @@ class TaskDial extends Task {
           target: t,
           opts,
           callInfo: cs.callInfo,
-          accountInfo: cs.accountInfo
+          accountInfo: cs.accountInfo,
+          rootSpan: cs.rootSpan,
+          startSpan: this.startSpan.bind(this)
         });
         this.dials.set(sd.callSid, sd);
 

lib/tasks/dialogflow/index.js

@@ -453,7 +453,10 @@ class Dialogflow extends Task {
   }
 
   async _performHook(cs, hook, results = {}) {
-    const json = await this.cs.requestor.request('verb:hook', hook, {...results, ...cs.callInfo.toJSON()});
+    const b3 = this.getTracingPropagation();
+    const httpHeaders = b3 && {b3};
+    const json = await this.cs.requestor.request('verb:hook', hook,
+      {...results, ...cs.callInfo.toJSON()}, httpHeaders);
     if (json && Array.isArray(json)) {
       const makeTask = require('../make_task');
       const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));

lib/tasks/enqueue.js

@@ -302,6 +302,8 @@ class TaskEnqueue extends Task {
 
   async _playHook(cs, dlg, hook, allowed = [TaskName.Play, TaskName.Say, TaskName.Pause, TaskName.Leave]) {
     const {lengthOfList, getListPosition} = cs.srf.locals.dbHelpers;
+    const b3 = this.getTracingPropagation();
+    const httpHeaders = b3 && {b3};
 
     assert(!this._playSession);
     if (this.killed) return [];
@@ -317,7 +319,7 @@ class TaskEnqueue extends Task {
     } catch (err) {
       this.logger.error({err}, `TaskEnqueue:_playHook error retrieving list info for queue ${this.queueName}`);
     }
-    const json = await cs.application.requestor.request('verb:hook', hook, params);
+    const json = await cs.application.requestor.request('verb:hook', hook, params, httpHeaders);
     const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
 
     const allowedTasks = tasks.filter((t) => allowed.includes(t.name));

lib/tasks/gather.js

@@ -59,8 +59,12 @@ class TaskGather extends Task {
     this.digitBuffer = '';
     this._earlyMedia = this.data.earlyMedia === true;
 
-    if (this.say) this.sayTask = makeTask(this.logger, {say: this.say}, this);
-    if (this.play) this.playTask = makeTask(this.logger, {play: this.play}, this);
+    if (this.say) {
+      this.sayTask = makeTask(this.logger, {say: this.say}, this);
+    }
+    if (this.play) {
+      this.playTask = makeTask(this.logger, {play: this.play}, this);
+    }
     if (!this.sayTask && !this.playTask) this.listenDuringPrompt = false;
 
     this.parentTask = parentTask;
@@ -125,16 +129,26 @@ class TaskGather extends Task {
 
     try {
       if (this.sayTask) {
+        const {span, ctx} = this.startChildSpan(`nested:${this.sayTask.summary}`);
+        this.sayTask.span = span;
+        this.sayTask.ctx = ctx;
         this.sayTask.exec(cs, ep);  // kicked off, _not_ waiting for it to complete
         this.sayTask.on('playDone', (err) => {
-          if (err) return this.logger.error({err}, 'Gather:exec Error playing tts');
-          this.logger.debug('Gather: say task completed');
+          span.end();
+          if (err) this.logger.error({err}, 'Gather:exec Error playing tts');
+          this.logger.debug('Gather: nested say task completed');
+          if (!this.killed) startListening(cs, ep);
         });
       }
       else if (this.playTask) {
+        const {span, ctx} = this.startChildSpan(`nested:${this.playTask.summary}`);
+        this.playTask.span = span;
+        this.playTask.ctx = ctx;
         this.playTask.exec(cs, ep);  // kicked off, _not_ waiting for it to complete
         this.playTask.on('playDone', (err) => {
-          if (err) return this.logger.error({err}, 'Gather:exec Error playing url');
+          span.end();
+          if (err) this.logger.error({err}, 'Gather:exec Error playing url');
+          this.logger.debug('Gather: nested play task completed');
           if (!this.killed) startListening(cs, ep);
         });
       }
@@ -170,11 +184,13 @@ class TaskGather extends Task {
     this._killAudio(cs);
     this.ep.removeAllListeners('dtmf');
     clearTimeout(this.interDigitTimer);
+    this.playTask?.span.end();
+    this.sayTask?.span.end();
     this._resolve('killed');
   }
 
   updateTimeout(timeout) {
-    this.logger.info(`TaskGather:updateTimout - updating timeout to ${timeout}`);
+    this.logger.info(`TaskGather:updateTimeout - updating timeout to ${timeout}`);
     this.timeout = timeout;
     this._startTimer();
   }
@@ -210,6 +226,7 @@ class TaskGather extends Task {
     if (this.vad?.enable) {
       opts.START_RECOGNIZING_ON_VAD = 1;
       if (this.vad.voiceMs) opts.RECOGNIZER_VAD_VOICE_MS = this.vad.voiceMs;
+      else opts.RECOGNIZER_VAD_VOICE_MS = 125;
       if (this.vad.mode >= 0 && this.vad.mode <= 3) opts.RECOGNIZER_VAD_MODE = this.vad.mode;
     }
 
@@ -267,6 +284,7 @@ class TaskGather extends Task {
       if (this.profanityOption && this.profanityOption !== 'raw') opts.AZURE_PROFANITY_OPTION = this.profanityOption;
       if (this.azureServiceEndpoint) opts.AZURE_SERVICE_ENDPOINT = this.azureServiceEndpoint;
       if (this.initialSpeechTimeoutMs > 0) opts.AZURE_INITIAL_SPEECH_TIMEOUT_MS = this.initialSpeechTimeoutMs;
+      else if (this.timeout === 0) opts.AZURE_INITIAL_SPEECH_TIMEOUT_MS = 120000;  // lengthy
       opts.AZURE_USE_OUTPUT_FORMAT_DETAILED = 1;
 
       ep.addCustomEventListener(AzureTranscriptionEvents.Transcription, this._onTranscription.bind(this, cs, ep));
@@ -301,6 +319,10 @@ class TaskGather extends Task {
 
   _startTimer() {
     if (0 === this.timeout) return;
+    if (this._timeoutTimer) {
+      clearTimeout(this._timeoutTimer);
+      this._timeoutTimer = null;
+    }
     assert(!this._timeoutTimer);
     this.logger.debug(`Gather:_startTimer: timeout ${this.timeout}`);
     this._timeoutTimer = setTimeout(() => this._resolve('timeout'), this.timeout);
@@ -340,7 +362,7 @@ class TaskGather extends Task {
     if ('microsoft' === this.vendor) {
       const final = evt.RecognitionStatus === 'Success';
       if (final) {
-        const nbest = evt.NBest;
+        const nbest = evt.NBest.sort((a, b) => b.Confidence - a.Confidence);
         evt = {
           is_final: true,
           alternatives: [
@@ -362,7 +384,13 @@ class TaskGather extends Task {
         };
       }
     }
-    if (evt.is_final) this._resolve('speech', evt);
+    if (evt.is_final) {
+      if (evt.alternatives[0].transcript === '') {
+        this.logger.info({evt}, 'TaskGather:_onTranscription - got empty transcript, listen again');
+        return this._startTranscribing(ep);
+      }
+      this._resolve('speech', evt);
+    }
     else {
       /* google has a measure of stability:
         https://cloud.google.com/speech-to-text/docs/basics#streaming_responses
@@ -378,7 +406,10 @@ class TaskGather extends Task {
         this._killAudio(cs);
       }
       if (this.partialResultHook) {
-        this.cs.requestor.request(this.partialResultHook,  Object.assign({speech: evt}, this.cs.callInfo));
+        const b3 = this.getTracingPropagation();
+        const httpHeaders = b3 && {b3};
+        this.cs.requestor.request(this.partialResultHook,  Object.assign({speech: evt},
+          this.cs.callInfo, httpHeaders));
       }
     }
   }
@@ -397,6 +428,7 @@ class TaskGather extends Task {
     if (this.bargein && this.minBargeinWordCount === 0) {
       this.logger.debug('TaskGather:_onVadDetected');
       this._killAudio(cs);
+      this.emit('vad');
     }
   }
 
@@ -406,10 +438,13 @@ class TaskGather extends Task {
 
   async _resolve(reason, evt) {
     if (this.resolved) return;
+    if (this.callSession && this.callSession.callGone) return;
+
     this.resolved = true;
-    this.logger.debug(`TaskGather:resolve with reason ${reason}`);
+    this.logger.info(`TaskGather:resolve with reason ${reason}`);
     clearTimeout(this.interDigitTimer);
 
+    this.span.setAttributes({'stt.resolve': reason, 'stt.result': JSON.stringify(evt)});
     if (this.ep && this.ep.connected) {
       this.ep.stopTranscription({vendor: this.vendor})
         .catch((err) => this.logger.error({err}, 'Error stopping transcription'));

lib/tasks/lex.js

@@ -289,7 +289,9 @@ class Lex extends Task {
   }
 
   async _performHook(cs, hook, results) {
-    const json = await this.cs.requestor.request('verb:hook', hook, results);
+    const b3 = this.getTracingPropagation();
+    const httpHeaders = b3 && {b3};
+    const json = await this.cs.requestor.request('verb:hook', hook, results, httpHeaders);
     if (json && Array.isArray(json)) {
       const makeTask = require('./make_task');
       const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));

lib/tasks/listen.js

@@ -38,7 +38,12 @@ class TaskListen extends Task {
       if (this.playBeep) await this._playBeep(ep);
       if (this.transcribeTask) {
         this.logger.debug('TaskListen:exec - starting nested transcribe task');
-        this.transcribeTask.exec(cs, ep);
+        const {span, ctx} = this.startChildSpan(`nested:${this.transcribeTask.summary}`);
+        this.transcribeTask.span = span;
+        this.transcribeTask.ctx = ctx;
+        this.transcribeTask.exec(cs, ep)
+          .then((result) => span.end())
+          .catch((err) => span.end());
       }
       await this._startListening(cs, ep);
       await this.awaitTaskDone();

lib/tasks/play.js

@@ -13,6 +13,10 @@ class TaskPlay extends Task {
 
   get name() { return TaskName.Play; }
 
+  get summary() {
+    return `${this.name}:{url=${this.url}}`;
+  }
+
   async exec(cs, ep) {
     await super.exec(cs);
     this.ep = ep;

lib/tasks/rasa.js

@@ -31,8 +31,15 @@ class Rasa extends Task {
 
       /* start the first gather */
       this.gatherTask = this._makeGatherTask(this.prompt);
+      const {span, ctx} = this.startChildSpan(`nested:${this.gatherTask.summary}`);
+      this.gatherTask.span = span;
+      this.gatherTask.ctx = ctx;
       this.gatherTask.exec(cs, ep, this)
-        .catch((err) => this.logger.info({err}, 'Rasa gather task returned error'));
+        .then(() => span.end())
+        .catch((err) => {
+          span.end();
+          this.logger.info({err}, 'Rasa gather task returned error');
+        });
 
       await this.awaitTaskDone();
     } catch (err) {
@@ -118,8 +125,15 @@ class Rasa extends Task {
       if (botUtterance) {
         this.logger.debug({botUtterance}, 'Rasa:_onTranscription: got user utterance');
         this.gatherTask = this._makeGatherTask(botUtterance);
+        const {span, ctx} = this.startChildSpan(`nested:${this.gatherTask.summary}`);
+        this.gatherTask.span = span;
+        this.gatherTask.ctx = ctx;
         this.gatherTask.exec(cs, ep, this)
-          .catch((err) => this.logger.info({err}, 'Rasa gather task returned error'));
+          .then(() => span.end())
+          .catch((err) => {
+            span.end();
+            this.logger.info({err}, 'Rasa gather task returned error');
+          });
         if (this.eventHook) {
           this.performHook(cs, this.eventHook, {event: 'botMessage', message: response})
             .then((redirected) => {

lib/tasks/rest_dial.js

@@ -48,7 +48,9 @@ class TaskRestDial extends Task {
     cs.setDialog(dlg);
 
     try {
-      const tasks = await cs.requestor.request('verb:hook', this.call_hook, cs.callInfo);
+      const b3 = this.getTracingPropagation();
+      const httpHeaders = b3 && {b3};
+      const tasks = await cs.requestor.request('verb:hook', this.call_hook, cs.callInfo, httpHeaders);
       if (tasks && Array.isArray(tasks)) {
         this.logger.debug({tasks: tasks}, `TaskRestDial: replacing application with ${tasks.length} tasks`);
         cs.replaceApplication(normalizeJambones(this.logger, tasks).map((tdata) => makeTask(this.logger, tdata)));

lib/tasks/say.js

@@ -19,7 +19,7 @@ class TaskSay extends Task {
       if (this.text[i].startsWith('silence_stream')) continue;
       return `${this.name}{text=${this.text[i].slice(0, 15)}${this.text[i].length > 15 ? '...' : ''}}`;
     }
-    return this.text[0];
+    return `${this.name}{${this.text[0]}}`;
   }
 
   async exec(cs, ep) {
@@ -55,6 +55,15 @@ class TaskSay extends Task {
       }
       // synthesize all of the text elements
       let lastUpdated = false;
+
+      /* otel: trace time for tts */
+      const {span} = this.startChildSpan('tts-generation', {
+        'tts.vendor': vendor,
+        'tts.language': language,
+        'tts.voice': voice
+      });
+      this.ttsSpan = span;
+
       const filepath = (await Promise.all(this.text.map(async(text) => {
         if (this.killed) return;
         if (text.startsWith('silence_stream://')) return text;
@@ -82,9 +91,10 @@ class TaskSay extends Task {
           updateSpeechCredentialLastUsed(credentials.speech_credential_sid)
             .catch(() => {/*already logged error */});
         }
+        this.ttsSpan.setAttributes({'tts.cached': servedFromCache});
         return filePath;
       }))).filter((fp) => fp && fp.length);
-
+      this.ttsSpan?.end();
       this.logger.debug({filepath}, 'synthesized files for tts');
 
       while (!this.killed && (this.loop === 'forever' || this.loop--) && this.ep?.connected) {
@@ -102,6 +112,7 @@ class TaskSay extends Task {
         } while (!this.killed && ++segment < filepath.length);
       }
     } catch (err) {
+      this.ttsSpan?.end();
       this.logger.info(err, 'TaskSay:exec error');
     }
     this.emit('playDone');

lib/tasks/sip_refer.js

@@ -26,6 +26,12 @@ class TaskSipRefer extends Task {
     try {
       this.notifyHandler = this._handleNotify.bind(this, cs, dlg);
       dlg.on('notify', this.notifyHandler);
+      /* otel: trace time for tts */
+      this.referSpan = this.startSpan('send-refer', {
+        'refer.refer_to': referTo,
+        'refer.referred_by': referredBy
+      });
+
       const response = await dlg.request({
         method: 'REFER',
         headers: {
@@ -35,16 +41,20 @@ class TaskSipRefer extends Task {
         }
       });
       this.referStatus = response.status;
+      this.referSpan.setAttributes({'refer.status_code': response.status});
       this.logger.info(`TaskSipRefer:exec - received ${this.referStatus} to REFER`);
 
       /* if we fail, fall through to next verb.  If success, we should get BYE from far end */
       if (this.referStatus === 202) {
         await this.awaitTaskDone();
       }
-      else await this.performAction({refer_status: this.referStatus});
+      else {
+        await this.performAction({refer_status: this.referStatus});
+      }
     } catch (err) {
       this.logger.info({err}, 'TaskSipRefer:exec - error sending REFER');
     }
+    this.referSpan?.end();
   }
 
   async kill(cs) {
@@ -66,9 +76,13 @@ class TaskSipRefer extends Task {
         const status = arr[1];
         this.logger.debug(`TaskSipRefer:_handleNotify: call got status ${status}`);
         if (this.eventHook) {
-          await cs.requestor.request('verb:hook', this.eventHook, {event: 'transfer-status', call_status: status});
+          const b3 = this.getTracingPropagation();
+          const httpHeaders = b3 && {b3};
+          await cs.requestor.request('verb:hook', this.eventHook,
+            {event: 'transfer-status', call_status: status}, httpHeaders);
         }
         if (status >= 200) {
+          this.referSpan.setAttributes({'refer.finalNotify': status});
           await this.performAction({refer_status: 202, final_referred_call_status: status});
           this.notifyTaskDone();
         }

lib/tasks/specs.json

@@ -32,6 +32,7 @@
   "bargeIn": {
     "properties": {
       "enable": "boolean",
+      "sticky": "boolean",
       "actionHook": "object|string",
       "input": "array",
       "finishOnKey": "string",

lib/tasks/task.js

@@ -4,6 +4,7 @@ const debug = require('debug')('jambonz:feature-server');
 const assert = require('assert');
 const {TaskPreconditions} = require('../utils/constants');
 const normalizeJambones = require('../utils/normalize-jambones');
+const {trace} = require('@opentelemetry/api');
 const specs = new Map();
 const _specData = require('./specs');
 for (const key in _specData) {specs.set(key, _specData[key]);}
@@ -71,6 +72,34 @@ class Task extends Emitter {
     setImmediate(() => this.parentTask = null);
   }
 
+  startSpan(name, attributes) {
+    const {srf} = require('../..');
+    const {tracer} = srf.locals.otel;
+    const span = tracer.startSpan(name, undefined, this.ctx);
+    if (attributes) span.setAttributes(attributes);
+    trace.setSpan(this.ctx, span);
+    return span;
+  }
+
+  startChildSpan(name, attributes) {
+    const {srf} = require('../..');
+    const {tracer} = srf.locals.otel;
+    const span = tracer.startSpan(name, undefined, this.ctx);
+    if (attributes) span.setAttributes(attributes);
+    const ctx = trace.setSpan(this.ctx, span);
+    return {span, ctx};
+  }
+
+  getTracingPropagation(encoding, span) {
+    // TODO: support encodings beyond b3 https://github.com/openzipkin/b3-propagation
+    if (span) {
+      return `${span.spanContext().traceId}-${span.spanContext().spanId}-1`;
+    }
+    if (this.span) {
+      return `${this.span.spanContext().traceId}-${this.span.spanContext().spanId}-1`;
+    }
+  }
+
   /**
    * when a subclass Task has completed its work, it should call this method
    */
@@ -111,29 +140,53 @@ class Task extends Emitter {
   async performAction(results, expectResponse = true) {
     if (this.actionHook) {
       const params = results ? Object.assign(results, this.cs.callInfo.toJSON()) : this.cs.callInfo.toJSON();
-      const json = await this.cs.requestor.request('verb:hook', this.actionHook, params);
-      if (expectResponse && json && Array.isArray(json)) {
-        const makeTask = require('./make_task');
-        const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
-        if (tasks && tasks.length > 0) {
-          this.logger.info({tasks: tasks}, `${this.name} replacing application with ${tasks.length} tasks`);
-          this.callSession.replaceApplication(tasks);
+      const span = this.startSpan('verb:hook', {'hook.url': this.actionHook});
+      const b3 = this.getTracingPropagation('b3', span);
+      const httpHeaders = b3 && {b3};
+      span.setAttributes({'http.body': JSON.stringify(params)});
+      try {
+        const json = await this.cs.requestor.request('verb:hook', this.actionHook, params, httpHeaders);
+        span.setAttributes({'http.statusCode': 200});
+        span.end();
+        if (expectResponse && json && Array.isArray(json)) {
+          const makeTask = require('./make_task');
+          const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
+          if (tasks && tasks.length > 0) {
+            this.logger.info({tasks: tasks}, `${this.name} replacing application with ${tasks.length} tasks`);
+            this.callSession.replaceApplication(tasks);
+          }
         }
+      } catch (err) {
+        span.setAttributes({'http.statusCode': err.statusCode});
+        span.end();
+        throw err;
       }
     }
   }
 
   async performHook(cs, hook, results) {
-    const json = await cs.requestor.request('verb:hook', hook, results);
-    if (json && Array.isArray(json)) {
-      const makeTask = require('./make_task');
-      const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
-      if (tasks && tasks.length > 0) {
-        this.redirect(cs, tasks);
-        return true;
+    const span = this.startSpan('verb:hook', {'hook.url': hook});
+    const b3 = this.getTracingPropagation('b3', span);
+    const httpHeaders = b3 && {b3};
+    span.setAttributes({'http.body': JSON.stringify(results)});
+    try {
+      const json = await cs.requestor.request('verb:hook', hook, results, httpHeaders);
+      span.setAttributes({'http.statusCode': 200});
+      span.end();
+      if (json && Array.isArray(json)) {
+        const makeTask = require('./make_task');
+        const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
+        if (tasks && tasks.length > 0) {
+          this.redirect(cs, tasks);
+          return true;
+        }
       }
+      return false;
+    } catch (err) {
+      span.setAttributes({'http.statusCode': err.statusCode});
+      span.end();
+      throw err;
     }
-    return false;
   }
 
   redirect(cs, tasks) {

lib/tasks/transcribe.js

@@ -254,7 +254,10 @@ class TaskTranscribe extends Task {
     }
 
     if (this.transcriptionHook) {
-      this.cs.requestor.request('verb:hook', this.transcriptionHook, Object.assign({speech: evt}, this.cs.callInfo))
+      const b3 = this.getTracingPropagation();
+      const httpHeaders = b3 && {b3};
+      this.cs.requestor.request('verb:hook', this.transcriptionHook,
+        Object.assign({speech: evt}, this.cs.callInfo), httpHeaders)
         .catch((err) => this.logger.info(err, 'TranscribeTask:_onTranscription error'));
     }
     if (this.parentTask) {

lib/utils/call-tracer.js

@@ -0,0 +1,78 @@
+const {context, trace} = require('@opentelemetry/api');
+const {Dialog} = require('drachtio-srf');
+class RootSpan {
+  constructor(callType, req) {
+    let tracer, callSid, linkedSpanId;
+
+    if (req instanceof Dialog) {
+      const dlg = req;
+      tracer = dlg.srf.locals.otel.tracer;
+      callSid = dlg.callSid;
+      linkedSpanId = dlg.linkedSpanId;
+    }
+    else {
+      tracer = req.srf.locals.otel.tracer;
+      callSid = req.locals.callSid;
+    }
+    this._span = tracer.startSpan(callType || 'incoming-call');
+    if (req instanceof Dialog) {
+      const dlg = req;
+      this._span.setAttributes({
+        linkedSpanId,
+        callId: dlg.sip.callId
+      });
+    }
+    else {
+      this._span.setAttributes({
+        callSid,
+        accountSid: req.get('X-Account-Sid'),
+        applicationSid: req.locals.application_sid,
+        callId: req.get('Call-ID'),
+        externalCallId: req.get('X-CID')
+      });
+    }
+
+    this._ctx = trace.setSpan(context.active(), this._span);
+    this.tracer = tracer;
+  }
+
+  get context() {
+    return this._ctx;
+  }
+
+  get traceId() {
+    return this._span.spanContext().traceId;
+  }
+
+  get spanId() {
+    return this._span.spanContext().spanId;
+  }
+
+  get traceFlags() {
+    return this._span.spanContext().traceFlags;
+  }
+
+  getTracingPropagation(encoding) {
+    // TODO: support encodings beyond b3 https://github.com/openzipkin/b3-propagation
+    if (this._span  && this.traceId !== '00000000000000000000000000000000') {
+      return `${this.traceId}-${this.spanId}-1`;
+    }
+  }
+
+  setAttributes(attrs) {
+    this._span.setAttributes(attrs);
+  }
+
+  end() {
+    this._span.end();
+  }
+
+  startChildSpan(name, attributes) {
+    const span = this.tracer.startSpan(name, attributes, this._ctx);
+    const ctx = trace.setSpan(context.active(), span);
+    return {span, ctx};
+  }
+}
+
+module.exports = RootSpan;
+

lib/utils/db-utils.js

@@ -48,6 +48,7 @@ module.exports = (logger, srf) => {
   const pp = pool.promise();
 
   const lookupAccountDetails = async(account_sid) => {
+
     const [r] = await pp.query({sql: sqlAccountDetails, nestTables: true}, account_sid);
     if (0 === r.length) throw new Error(`invalid accountSid: ${account_sid}`);
     const [r2] = await pp.query(sqlSpeechCredentials, account_sid);

lib/utils/http-requestor.js

@@ -49,7 +49,7 @@ class HttpRequestor extends BaseRequestor {
    * @param {string} [hook.password] - if basic auth is protecting the endpoint
    * @param {object} [params] - request parameters
    */
-  async request(type, hook, params) {
+  async request(type, hook, params, httpHeaders = {}) {
     assert(HookMsgTypes.includes(type));
     const payload = params ? snakeCaseKeys(params, ['customerData', 'sip']) : null;
     const url = hook.url || hook;
@@ -64,8 +64,8 @@ class HttpRequestor extends BaseRequestor {
     let buf;
     try {
       const sigHeader = this._generateSigHeader(payload, this.secret);
-      const headers = {...sigHeader, ...this.authHeader};
-      //this.logger.info({url, headers}, 'send webhook');
+      const headers = {...sigHeader, ...this.authHeader, ...httpHeaders};
+      this.logger.debug({url, headers}, 'send webhook');
       buf = this._isRelativeUrl(url) ?
         await this.post(url, payload, headers) :
         await bent(method, 'buffer', 200, 201, 202)(url, payload, headers);

lib/utils/install-srf-locals.js

@@ -32,6 +32,7 @@ function initMS(logger, wrapper, ms) {
 function installSrfLocals(srf, logger) {
   logger.debug('installing srf locals');
   assert(!srf.locals.dbHelpers);
+  const {tracer} = srf.locals.otel;
   const {getSBC, lifecycleEmitter} = require('./sbc-pinger')(logger);
   const StatsCollector = require('@jambonz/stats-collector');
   const stats = srf.locals.stats = new StatsCollector(logger);
@@ -49,7 +50,11 @@ function installSrfLocals(srf, logger) {
         assert.ok(arr, `Invalid syntax JAMBONES_FREESWITCH: ${process.env.JAMBONES_FREESWITCH}`);
         const opts = {address: arr[1], port: arr[2], secret: arr[3]};
         if (arr.length > 4) opts.advertisedAddress = arr[4];
+        /* NB: originally for testing only, but for now all jambonz deployments
+          have freeswitch installed locally alongside this app
+        */
         if (process.env.NODE_ENV === 'test') opts.listenAddress = '0.0.0.0';
+        else if (process.env.JAMBONES_ESL_LISTEN_ADDRESS) opts.listenAddress = process.env.JAMBONES_ESL_LISTEN_ADDRESS;
         return opts;
       });
     logger.info({fsInventory}, 'freeswitch inventory');
@@ -62,7 +67,7 @@ function installSrfLocals(srf, logger) {
         initMS(logger, val, ms);
       }
       catch (err) {
-        logger.info(`failed connecting to freeswitch at ${fs.address}, will retry shortly`);
+        logger.info({err}, `failed connecting to freeswitch at ${fs.address}, will retry shortly: ${err.message}`);
       }
     }
     // retry to connect to any that were initially offline
@@ -74,7 +79,7 @@ function installSrfLocals(srf, logger) {
             const ms = await mrf.connect(val.opts);
             initMS(logger, val, ms);
           } catch (err) {
-            logger.info(`failed connecting to freeswitch at ${val.opts.address}, will retry shortly`);
+            logger.info({err}, `failed connecting to freeswitch at ${val.opts.address}, will retry shortly`);
           }
         }
       }
@@ -127,7 +132,7 @@ function installSrfLocals(srf, logger) {
     password: process.env.JAMBONES_MYSQL_PASSWORD,
     database: process.env.JAMBONES_MYSQL_DATABASE,
     connectionLimit: process.env.JAMBONES_MYSQL_CONNECTION_LIMIT || 10
-  }, logger);
+  }, logger, tracer);
   const {
     client,
     updateCallStatus,
@@ -152,7 +157,7 @@ function installSrfLocals(srf, logger) {
   } = require('@jambonz/realtimedb-helpers')({
     host: process.env.JAMBONES_REDIS_HOST,
     port: process.env.JAMBONES_REDIS_PORT || 6379
-  }, logger);
+  }, logger, tracer);
   const {
     writeAlerts,
     AlertType

lib/utils/place-outdial.js

@@ -9,10 +9,11 @@ const AdultingCallSession = require('../session/adulting-call-session');
 const deepcopy = require('deepcopy');
 const moment = require('moment');
 const stripCodecs = require('./strip-ancillary-codecs');
+const RootSpan = require('./call-tracer');
 const { v4: uuidv4 } = require('uuid');
 
 class SingleDialer extends Emitter {
-  constructor({logger, sbcAddress, target, opts, application, callInfo, accountInfo}) {
+  constructor({logger, sbcAddress, target, opts, application, callInfo, accountInfo, rootSpan, startSpan}) {
     super();
     assert(target.type);
 
@@ -22,6 +23,8 @@ class SingleDialer extends Emitter {
     this.opts = opts;
     this.application = application;
     this.confirmHook = target.confirmHook;
+    this.rootSpan = rootSpan;
+    this.startSpan = startSpan;
 
     this.bindings = logger.bindings();
 
@@ -71,7 +74,7 @@ class SingleDialer extends Emitter {
       };
     }
     this.ms = ms;
-    let uri, to;
+    let uri, to, inviteSpan;
     try {
       switch (this.target.type) {
         case 'phone':
@@ -137,13 +140,24 @@ class SingleDialer extends Emitter {
         localSdp: this.ep.local.sdp
       });
       if (this.target.auth) opts.auth = this.target.auth;
+      inviteSpan = this.startSpan('invite', {
+        'invite.uri': uri,
+        'invite.dest_type': this.target.type
+      });
+
       this.dlg = await srf.createUAC(uri, {...opts,  followRedirects: true, keepUriOnRedirect: true}, {
         cbRequest: (err, req) => {
           if (err) {
             this.logger.error(err, 'SingleDialer:exec Error creating call');
             this.emit('callCreateFail', err);
+            inviteSpan.setAttributes({
+              'invite.status_code': 500,
+              'invite.err': err.message
+            });
+            inviteSpan.end();
             return;
           }
+          inviteSpan.setAttributes({'invite.call_id': req.get('Call-ID')});
 
           /**
            * INVITE has been sent out
@@ -156,7 +170,8 @@ class SingleDialer extends Emitter {
             parentCallInfo: this.parentCallInfo,
             req,
             to,
-            callSid: this.callSid
+            callSid: this.callSid,
+            traceId: this.rootSpan.traceId
           });
           this.logger = srf.locals.parentLogger.child({
             callSid: this.callSid,
@@ -193,6 +208,9 @@ class SingleDialer extends Emitter {
       });
       this.logger.debug(`SingleDialer:exec call connected: ${this.callSid}`);
       const connectTime = this.dlg.connectTime = moment();
+      inviteSpan.setAttributes({'invite.status_code': 200});
+      inviteSpan.end();
+
 
       /* race condition: we were killed just as call was answered */
       if (this.killed) {
@@ -246,10 +264,17 @@ class SingleDialer extends Emitter {
         if (err.status === 487) status.callStatus = CallStatus.NoAnswer;
         else if ([486, 600].includes(err.status)) status.callStatus = CallStatus.Busy;
         this.logger.info(`SingleDialer:exec outdial failure ${err.status}`);
+        inviteSpan.setAttributes({'invite.status_code': err.status});
+        inviteSpan.end();
       }
       else {
         this.logger.error(err, 'SingleDialer:exec');
         status.sipStatus = 500;
+        inviteSpan.setAttributes({
+          'invite.status_code': 500,
+          'invite.err': err.message
+        });
+        inviteSpan.end();
       }
       this.emit('callStatusChange', status);
       if (this.ep) this.ep.destroy();
@@ -305,7 +330,8 @@ class SingleDialer extends Emitter {
         dlg: this.dlg,
         ep: this.ep,
         callInfo: this.callInfo,
-        tasks
+        tasks,
+        rootSpan: this.rootSpan
       });
       await cs.exec();
 
@@ -330,13 +356,18 @@ class SingleDialer extends Emitter {
     else {
       await this.reAnchorMedia();
     }
+
+    this.dlg.callSid = this.callSid;
+    this.dlg.linkedSpanId = this.rootSpan.traceId;
+    const rootSpan = new RootSpan('outbound-call', this.dlg);
     const cs = new AdultingCallSession({
       logger: this.logger,
       singleDialer: this,
       application,
       callInfo: this.callInfo,
       accountInfo: this.accountInfo,
-      tasks
+      tasks,
+      rootSpan
     });
     cs.exec();
     return cs;
@@ -387,9 +418,13 @@ class SingleDialer extends Emitter {
   }
 }
 
-function placeOutdial({logger, srf, ms, sbcAddress, target, opts, application, callInfo, accountInfo}) {
+function placeOutdial({
+  logger, srf, ms, sbcAddress, target, opts, application, callInfo, accountInfo, rootSpan, startSpan
+}) {
   const myOpts = deepcopy(opts);
-  const sd = new SingleDialer({logger, sbcAddress, target, myOpts, application, callInfo, accountInfo});
+  const sd = new SingleDialer({
+    logger, sbcAddress, target, myOpts, application, callInfo, accountInfo, rootSpan, startSpan
+  });
   sd.exec(srf, ms, myOpts);
   return sd;
 }

lib/utils/ws-requestor.js

@@ -15,6 +15,7 @@ class WsRequestor extends BaseRequestor {
     this.messagesInFlight = new Map();
     this.maliciousClient = false;
     this.closedByUs = false;
+    this.backoffMs = 500;
 
     assert(this._isAbsoluteUrl(this.url));
 
@@ -32,7 +33,7 @@ class WsRequestor extends BaseRequestor {
    * @param {string} [hook.password] - if basic auth is protecting the endpoint
    * @param {object} [params] - request parameters
    */
-  async request(type, hook, params) {
+  async request(type, hook, params, httpHeaders = {}) {
     assert(HookMsgTypes.includes(type));
     const url = hook.url || hook;
 
@@ -47,7 +48,7 @@ class WsRequestor extends BaseRequestor {
     if (this._isAbsoluteUrl(url) && url.startsWith('http')) {
       this.logger.debug({hook}, 'WsRequestor: sending a webhook (HTTP)');
       const requestor = new HttpRequestor(this.logger, this.account_sid, hook, this.secret);
-      return requestor.request(type, hook, params);
+      return requestor.request(type, hook, params, httpHeaders);
     }
 
     /* connect if necessary */
@@ -72,12 +73,14 @@ class WsRequestor extends BaseRequestor {
     assert.ok(url, 'WsRequestor:request url was not provided');
 
     const msgid = short.generate();
+    const b3 = httpHeaders?.b3 ? {b3: httpHeaders.b3} : {};
     const obj = {
       type,
       msgid,
       call_sid: this.call_sid,
       hook: type === 'verb:hook' ? url : undefined,
-      data: {...payload}
+      data: {...payload},
+      ...b3
     };
 
     //this.logger.debug({obj}, `websocket: sending (${url})`);
@@ -123,10 +126,10 @@ class WsRequestor extends BaseRequestor {
   }
 
   close() {
-    this.logger.info('WsRequestor:close closing socket');
     this.closedByUs = true;
     try {
       if (this.ws) {
+        this.logger.info('WsRequestor:close closing socket');
         this.ws.close();
         this.ws.removeAllListeners();
       }
@@ -144,10 +147,13 @@ class WsRequestor extends BaseRequestor {
   _connect() {
     assert(!this.ws);
     return new Promise((resolve, reject) => {
+      const handshakeTimeout = process.env.JAMBONES_WS_HANDSHAKE_TIMEOUT_MS ?
+        parseInt(process.env.JAMBONES_WS_HANDSHAKE_TIMEOUT_MS) :
+        1500;
       let opts = {
         followRedirects: true,
         maxRedirects: 2,
-        handshakeTimeout: 1000,
+        handshakeTimeout,
         maxPayload: 8096,
       };
       if (this.username && this.password) opts = {...opts, auth: `${this.username}:${this.password}`};
@@ -156,7 +162,7 @@ class WsRequestor extends BaseRequestor {
         .once('ready', (ws) => {
           this.ws = ws;
           this.removeAllListeners('not-ready');
-          if (this.connections++ > 0) this.request('session:reconnect', this.url);
+          if (this.connections > 0) this.request('session:reconnect', this.url);
           resolve();
         })
         .once('not-ready', (err) => {
@@ -213,8 +219,10 @@ class WsRequestor extends BaseRequestor {
 
   _onSocketClosed() {
     this.ws = null;
-    if (this.connections > 0 && this.connections < MAX_RECONNECTS && !this.closedByUs) {
-      setTimeout(this._connect.bind(this), 500);
+    this.emit('connection-dropped');
+    if (this.connections++ > 0 && this.connections < MAX_RECONNECTS && !this.closedByUs) {
+      setTimeout(this._connect.bind(this), this.backoffMs);
+      this.backoffMs = this.backoffMs < 2000 ? this.backoffMs * 2 : (this.backoffMs + 2000);
     }
   }
 

package.json

@@ -21,7 +21,7 @@
   },
   "scripts": {
     "start": "node app",
-    "test": "NODE_ENV=test JAMBONES_HOSTING=1 DRACHTIO_HOST=127.0.0.1 DRACHTIO_PORT=9060 DRACHTIO_SECRET=cymru JAMBONES_MYSQL_HOST=127.0.0.1 JAMBONES_MYSQL_PORT=3360 JAMBONES_MYSQL_USER=jambones_test JAMBONES_MYSQL_PASSWORD=jambones_test JAMBONES_MYSQL_DATABASE=jambones_test JAMBONES_REDIS_HOST=127.0.0.1 JAMBONES_REDIS_PORT=16379 JAMBONES_LOGLEVEL=error ENABLE_METRICS=0 HTTP_PORT=3000 JAMBONES_SBCS=172.38.0.10 JAMBONES_FREESWITCH=127.0.0.1:8022:ClueCon:docker-host JAMBONES_TIME_SERIES_HOST=127.0.0.1 JAMBONES_NETWORK_CIDR=172.38.0.0/16 node test/ ",
+    "test": "NODE_ENV=test JAMBONES_HOSTING=1 DRACHTIO_HOST=127.0.0.1 DRACHTIO_PORT=9060 DRACHTIO_SECRET=cymru JAMBONES_MYSQL_HOST=127.0.0.1 JAMBONES_MYSQL_PORT=3360 JAMBONES_MYSQL_USER=jambones_test JAMBONES_MYSQL_PASSWORD=jambones_test JAMBONES_MYSQL_DATABASE=jambones_test JAMBONES_REDIS_HOST=127.0.0.1 JAMBONES_REDIS_PORT=16379 JAMBONES_LOGLEVEL=info ENABLE_METRICS=0 HTTP_PORT=3000 JAMBONES_SBCS=172.38.0.10 JAMBONES_FREESWITCH=127.0.0.1:8022:ClueCon:docker-host JAMBONES_TIME_SERIES_HOST=127.0.0.1 JAMBONES_NETWORK_CIDR=172.38.0.0/16 node test/ ",
     "coverage": "./node_modules/.bin/nyc --reporter html --report-dir ./coverage npm run test",
     "jslint": "eslint app.js lib"
   },
@@ -33,6 +33,18 @@
     "@jambonz/realtimedb-helpers": "^0.4.26",
     "@jambonz/stats-collector": "^0.1.6",
     "@jambonz/time-series": "^0.1.6",
+    "@opentelemetry/api": "^1.1.0",
+    "@opentelemetry/exporter-collector": "^0.25.0",
+    "@opentelemetry/exporter-jaeger": "^1.1.0",
+    "@opentelemetry/exporter-zipkin": "^1.1.0",
+    "@opentelemetry/instrumentation": "^0.27.0",
+    "@opentelemetry/instrumentation-express": "^0.28.0",
+    "@opentelemetry/instrumentation-http": "^0.27.0",
+    "@opentelemetry/instrumentation-pino": "^0.28.1",
+    "@opentelemetry/resources": "^1.1.0",
+    "@opentelemetry/sdk-trace-base": "^1.1.0",
+    "@opentelemetry/sdk-trace-node": "^1.1.0",
+    "@opentelemetry/semantic-conventions": "^1.1.0",
     "aws-sdk": "^2.1073.0",
     "bent": "^7.3.12",
     "cidr-matcher": "^2.1.1",

tracer.js

@@ -0,0 +1,61 @@
+const opentelemetry = require('@opentelemetry/api');
+const { registerInstrumentations } = require('@opentelemetry/instrumentation');
+const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node');
+const { Resource } = require('@opentelemetry/resources');
+const { SemanticResourceAttributes } = require('@opentelemetry/semantic-conventions');
+const { BatchSpanProcessor } = require('@opentelemetry/sdk-trace-base');
+const { JaegerExporter } = require('@opentelemetry/exporter-jaeger');
+const { ZipkinExporter } = require('@opentelemetry/exporter-zipkin');
+const { CollectorTraceExporter } =  require('@opentelemetry/exporter-collector');
+//const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http');
+//const { ExpressInstrumentation } = require('@opentelemetry/instrumentation-express');
+//const { PinoInstrumentation } = require('@opentelemetry/instrumentation-pino');
+
+module.exports = (serviceName) => {
+  if (process.env.JAMBONES_OTEL_ENABLED) {
+    const {version} = require('./package.json');
+    const provider = new NodeTracerProvider({
+      resource: new Resource({
+        [SemanticResourceAttributes.SERVICE_NAME]: serviceName,
+        [SemanticResourceAttributes.SERVICE_VERSION]: version,
+      }),
+    });
+
+    let exporter;
+    if (process.env.OTEL_EXPORTER_JAEGER_AGENT_HOST) {
+      exporter = new JaegerExporter();
+    }
+    else if (process.env.OTEL_EXPORTER_ZIPKIN_URL) {
+      exporter = new ZipkinExporter({url:process.env.OTEL_EXPORTER_ZIPKIN_URL});
+    }
+    else {
+      exporter = new CollectorTraceExporter({
+        url: process.OTEL_EXPORTER_COLLECTOR_URL
+      });
+    }
+
+    provider.addSpanProcessor(new BatchSpanProcessor(exporter, {
+      // The maximum queue size. After the size is reached spans are dropped.
+      maxQueueSize: 100,
+      // The maximum batch size of every export. It must be smaller or equal to maxQueueSize.
+      maxExportBatchSize: 10,
+      // The interval between two consecutive exports
+      scheduledDelayMillis: 500,
+      // How long the export can run before it is cancelled
+      exportTimeoutMillis: 30000,
+    }));
+
+    // Initialize the OpenTelemetry APIs to use the NodeTracerProvider bindings
+    provider.register();
+    registerInstrumentations({
+      instrumentations: [
+        //new HttpInstrumentation(),
+        //new ExpressInstrumentation(),
+        //new PinoInstrumentation()
+      ],
+    });
+  }
+
+  return opentelemetry.trace.getTracer(serviceName);
+};
+