From be9c3406c175143d4181985531188231c2a7999a Mon Sep 17 00:00:00 2001 From: Dave Horton Date: Tue, 25 Jun 2024 12:25:55 -0400 Subject: [PATCH] fix bug where play incorrectly plays again after response received (#786) * fix bug where play incorrectly plays again after response received * wip * fix race condition where bot delay audio kcks off same instant we receive commands --- lib/utils/action-hook-delay.js | 21 +++++++++++++++++++-- 1 file changed, 19 insertions(+), 2 deletions(-) diff --git a/lib/utils/action-hook-delay.js b/lib/utils/action-hook-delay.js index b5176b30..acc63956 100644 --- a/lib/utils/action-hook-delay.js +++ b/lib/utils/action-hook-delay.js @@ -2,6 +2,7 @@ const makeTask = require('../tasks/make_task'); const Emitter = require('events'); const { normalizeJambones } = require('@jambonz/verb-specifications'); const {TaskName} = require('../utils/constants'); +const assert = require('assert'); /** * ActionHookDelayProcessor @@ -21,6 +22,7 @@ class ActionHookDelayProcessor extends Emitter { super(); this.logger = logger; this.cs = cs; + this._active = false; const enabled = this.init(opts); if (enabled && (!this.actions || !Array.isArray(this.actions) || this.actions.length === 0)) { @@ -60,10 +62,12 @@ class ActionHookDelayProcessor extends Emitter { start() { this.logger.debug('ActionHookDelayProcessor#start'); - if (this._noResponseTimer) { + if (this._active) { this.logger.debug('ActionHookDelayProcessor#start: already started due to prior gather which is continuing'); return; } + assert(!this._noResponseTimer); + this._active = true; this._retryCount = 0; const timeoutMs = this.noResponseTimeout === 0 ? 1 : this.noResponseTimeout * 1000; this._noResponseTimer = setTimeout(this._onNoResponseTimer.bind(this), timeoutMs); @@ -76,6 +80,8 @@ class ActionHookDelayProcessor extends Emitter { async stop() { this.logger.debug('ActionHookDelayProcessor#stop'); + this._active = false; + if (this._noResponseTimer) { clearTimeout(this._noResponseTimer); this._noResponseTimer = null; @@ -127,6 +133,16 @@ class ActionHookDelayProcessor extends Emitter { return; } + this.ep.once('playback-start', (evt) => { + this.logger.debug({evt}, 'got playback-start'); + if (!this._active) { + this.logger.info({evt}, 'ActionHookDelayProcessor#_onNoResponseTimer: killing audio immediately'); + this.ep.api('uuid_break', this.ep.uuid) + .catch((err) => this.logger.info(err, + 'ActionHookDelayProcessor#_onNoResponseTimer Error killing audio')); + } + }); + this.ep.once('playback-stop', (evt) => { this._taskInProgress = null; if (this._sayResolver) { @@ -137,7 +153,7 @@ class ActionHookDelayProcessor extends Emitter { } else { /* possibly start the no response timer again */ - if (this.retries > 0 && this._retryCount < this.retries && this.noResponseTimeout > 0) { + if (this._active && this.retries > 0 && this._retryCount < this.retries && this.noResponseTimeout > 0) { this.logger.debug({evt}, 'ActionHookDelayProcessor#_onNoResponseTimer: playback-stop on play/say action'); const timeoutMs = this.noResponseTimeout * 1000; this._noResponseTimer = setTimeout(this._onNoResponseTimer.bind(this), timeoutMs); @@ -149,6 +165,7 @@ class ActionHookDelayProcessor extends Emitter { } _onNoResponseGiveUpTimer() { + this._active = false; this.logger.info('ActionHookDelayProcessor#_onNoResponseGiveUpTimer'); this.stop().catch((err) => {}); this.emit('giveup');