bugfix: create spans for nested tasks in gather, rasa, and dial; fix gather bug not starting transcribe after say completes

lib/tasks/dial.js

@@ -226,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) {

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);
         });
       }
@@ -171,6 +185,8 @@ class TaskGather extends Task {
     this.ep.removeAllListeners('dtmf');
     clearTimeout(this.interDigitTimer);
     this._resolve('killed');
+    this.playTask?.span.end();
+    this.sayTask?.span.end();
   }
 
   updateTimeout(timeout) {

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/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/task.js

@@ -81,6 +81,15 @@ class Task extends Emitter {
     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};
+  }
+
   /**
    * when a subclass Task has completed its work, it should call this method
    */