major refactor and simplification of actionHookDelay feature (#771)

* major refactor and simplification of actionHookDelay feature

* wip for #765

* wip

* testing

* wip

* added validity checks for actionHookDelay properties

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* wip

* fix bug where config happens before endpoint is established

* wip

* hangup and clear ws connection if nogiveuptimer expires

* wip

* wip

* wip
This commit is contained in:
Dave Horton
2024-06-14 09:24:26 -04:00
committed by GitHub
parent 76a3aa7f42
commit d9fd82fa60
7 changed files with 300 additions and 232 deletions

View File

@@ -19,6 +19,7 @@ const { normalizeJambones } = require('@jambonz/verb-specifications');
const listTaskNames = require('../utils/summarize-tasks'); const listTaskNames = require('../utils/summarize-tasks');
const HttpRequestor = require('../utils/http-requestor'); const HttpRequestor = require('../utils/http-requestor');
const WsRequestor = require('../utils/ws-requestor'); const WsRequestor = require('../utils/ws-requestor');
const ActionHookDelayProcessor = require('../utils/action-hook-delay');
const { const {
JAMBONES_INJECT_CONTENT, JAMBONES_INJECT_CONTENT,
JAMBONES_EAGERLY_PRE_CACHE_AUDIO, JAMBONES_EAGERLY_PRE_CACHE_AUDIO,
@@ -519,13 +520,6 @@ class CallSession extends Emitter {
this._actionHookDelayRetries = e; this._actionHookDelayRetries = e;
} }
get actionHookDelayActions() {
return this._actionHookDelayActions;
}
set actionHookDelayActions(e) {
this._actionHookDelayActions = e;
}
// Getter/setter for current tts vendor // Getter/setter for current tts vendor
get currentTtsVendor() { get currentTtsVendor() {
return this._currentTtsVendor; return this._currentTtsVendor;
@@ -535,6 +529,71 @@ class CallSession extends Emitter {
this._currentTtsVendor = vendor; this._currentTtsVendor = vendor;
} }
get actionHookDelayProcessor() {
return this._actionHookDelayProcessor;
}
set actionHookDelayProperties(opts) {
if (this._actionHookDelayProcessor) {
this._actionHookDelayProcessor.stop();
if (!this._actionHookDelayProcessor.init(opts)) {
this._actionHookDelayProcessor.removeAllListeners();
this._actionHookDelayProcessor = null;
}
}
else {
try {
this._actionHookDelayProcessor = new ActionHookDelayProcessor(this.logger, opts, this, this.ep);
this._actionHookDelayProcessor.on('giveup', () => {
this.logger.info('CallSession: ActionHookDelayProcessor: giveup event - hanging up call');
this._jambonzHangup();
if (this.wakeupResolver) {
this.logger.debug('CallSession: Giveup timer expired - waking up');
this.wakeupResolver({reason: 'noResponseGiveUp'});
this.wakeupResolver = null;
}
});
} catch (err) {
this.logger.error({err}, 'CallSession: Error creating ActionHookDelayProcessor');
}
}
}
async clearOrRestoreActionHookDelayProcessor() {
if (this._actionHookDelayProcessor) {
await this._actionHookDelayProcessor.stop();
if (!this.popActionHookDelayProperties()) {
//this.logger.debug('CallSession:clearOrRestoreActionHookDelayProcessor - ahd settings');
//await this.clearActionHookDelayProcessor();
}
else {
this.logger.debug('CallSession:clearOrRestoreActionHookDelayProcessor - restore ahd after gather override');
}
}
}
async clearActionHookDelayProcessor() {
if (this._actionHookDelayProcessor) {
await this._actionHookDelayProcessor.stop();
this._actionHookDelayProcessor.removeAllListeners();
this._actionHookDelayProcessor = null;
}
}
stashActionHookDelayProperties() {
this._storedActionHookDelayProperties = this._actionHookDelayProcessor.properties;
}
popActionHookDelayProperties() {
if (this._storedActionHookDelayProperties) {
this._actionHookDelayProcessor.init(this._storedActionHookDelayProperties);
this._storedActionHookDelayProperties = null;
return true;
}
return false;
}
hasGlobalSttPunctuation() { hasGlobalSttPunctuation() {
return this._globalSttPunctuation !== undefined; return this._globalSttPunctuation !== undefined;
} }
@@ -961,7 +1020,6 @@ class CallSession extends Emitter {
task.on('VerbHookSpanWaitForEnd', ({span}) => { task.on('VerbHookSpanWaitForEnd', ({span}) => {
this.verbHookSpan = span; this.verbHookSpan = span;
}); });
task.on('ActionHookDelayActionOptions', this._onActionHookDelayActions.bind(this));
try { try {
const resources = await this._evaluatePreconditions(task); const resources = await this._evaluatePreconditions(task);
let skip = false; let skip = false;
@@ -1007,6 +1065,10 @@ class CallSession extends Emitter {
) { ) {
try { try {
await this._awaitCommandsOrHangup(); await this._awaitCommandsOrHangup();
await this.clearOrRestoreActionHookDelayProcessor();
//TODO: remove filler noise code and simply create as action hook delay
if (this._isPlayingFillerNoise) { if (this._isPlayingFillerNoise) {
this._isPlayingFillerNoise = false; this._isPlayingFillerNoise = false;
this.ep.api('uuid_break', this.ep.uuid) this.ep.api('uuid_break', this.ep.uuid)
@@ -1237,9 +1299,8 @@ class CallSession extends Emitter {
this.currentTask.kill(this); this.currentTask.kill(this);
} }
this._endVerbHookSpan(); this._endVerbHookSpan();
// clear all delay action hook timeout if there is
this._clearActionHookNoResponseGiveUpTimer(); await this.clearOrRestoreActionHookDelayProcessor();
this._clearActionHookNoResponseTimer();
} }
/** /**
@@ -1753,7 +1814,7 @@ Duration=${duration} `
this._jambonzHangup(); this._jambonzHangup();
} }
_onCommand({msgid, command, call_sid, queueCommand, data}) { async _onCommand({msgid, command, call_sid, queueCommand, data}) {
this.logger.info({msgid, command, queueCommand, data}, 'CallSession:_onCommand - received command'); this.logger.info({msgid, command, queueCommand, data}, 'CallSession:_onCommand - received command');
let resolution; let resolution;
switch (command) { switch (command) {
@@ -1778,9 +1839,9 @@ Duration=${duration} `
} }
resolution = {reason: 'received command, new tasks', queue: queueCommand, command}; resolution = {reason: 'received command, new tasks', queue: queueCommand, command};
resolution.command = listTaskNames(t); resolution.command = listTaskNames(t);
// clear all delay action hook timeout if there is // clear all delay action hook timeout if there is
this._clearActionHookNoResponseGiveUpTimer(); await this.clearOrRestoreActionHookDelayProcessor();
this._clearActionHookNoResponseTimer();
} }
else this._lccCallHook(data); else this._lccCallHook(data);
break; break;
@@ -2040,8 +2101,7 @@ Duration=${duration} `
this.rootSpan && this.rootSpan.end(); this.rootSpan && this.rootSpan.end();
// close all background tasks // close all background tasks
this.backgroundTaskManager.stopAll(); this.backgroundTaskManager.stopAll();
this._clearActionHookNoResponseGiveUpTimer(); this.clearOrRestoreActionHookDelayProcessor().catch((err) => {});
this._clearActionHookNoResponseTimer();
} }
/** /**
@@ -2450,6 +2510,16 @@ Duration=${duration} `
this.logger.info('_awaitCommandsOrHangup - waiting...'); this.logger.info('_awaitCommandsOrHangup - waiting...');
this.wakeupResolver = resolve; this.wakeupResolver = resolve;
if (this._actionHookDelayProcessor) {
this._actionHookDelayProcessor.start();
}
/**
* TODO: filler noise can be handled as an ActionHookDelayProcessor -
* it's just one specific scenario for action hook delay -
* remove the code below and simply implement filler noise as an action hook delay
*/
/* start filler noise if configured while we wait for new commands */ /* start filler noise if configured while we wait for new commands */
if (this.fillerNoise?.url && this.ep?.connected && !this.ep2) { if (this.fillerNoise?.url && this.ep?.connected && !this.ep2) {
this.logger.debug('CallSession:_awaitCommandsOrHangup - playing filler noise'); this.logger.debug('CallSession:_awaitCommandsOrHangup - playing filler noise');
@@ -2494,81 +2564,6 @@ Duration=${duration} `
this.verbHookSpan = null; this.verbHookSpan = null;
} }
} }
// actionHook delay actions
_onActionHookDelayActions(options) {
this._actionHookDelayRetryCount = 0;
this._startActionHookNoResponseTimer(options);
this._startActionHookNoResponseGiveUpTimer(options);
}
_startActionHookNoResponseTimer(options) {
this._clearActionHookNoResponseTimer();
this._actionHookDelayResolved = false;
if (options.noResponseTimeoutMs) {
this.logger.debug(`CallSession:_startActionHookNoResponseTimer ${options.noResponseTimeoutMs}`);
this._actionHookNoResponseTimer = setTimeout(() => {
if (this._actionHookDelayRetryCount >= options.retries) {
this._jambonzHangup();
}
const verb = options.actions[this._actionHookDelayRetryCount % options.actions.length];
// Inject verb to main stack
const t = normalizeJambones(this.logger, [verb])
.map((tdata) => makeTask(this.logger, tdata));
if (t.length) {
t[0].on('playDone', (err) => {
if (err) this.logger.error({err}, `Call-Session:exec Error delay action, play ${verb}`);
if (!this._actionHookDelayResolved) {
this._startActionHookNoResponseTimer(options);
}
});
}
this.tasks.push(...t);
if (this.wakeupResolver) {
this.wakeupResolver({reason: 'actionHook no response, applied delay actions', verb});
this.wakeupResolver = null;
}
this.logger.debug(`CallSession:_startActionHookNoResponseTimer, executing verb ${JSON.stringify(verb)}`);
this._actionHookDelayRetryCount++;
}, options.noResponseTimeoutMs);
}
}
_clearActionHookNoResponseTimer() {
if (this._actionHookNoResponseTimer) {
// Action Hook delay is solved.
this._actionHookDelayResolved = true;
clearTimeout(this._actionHookNoResponseTimer);
// if delay action is enabled
// and bot has responded with list of new verbs
// Only kill current running play task.
//https://github.com/jambonz/jambonz-feature-server/issues/710
if (this.currentTask?.name === TaskName.Play) {
this.currentTask.kill(this);
}
}
this._actionHookNoResponseTimer = null;
}
_startActionHookNoResponseGiveUpTimer(options) {
this._clearActionHookNoResponseGiveUpTimer();
if (options.noResponseGiveUpTimeoutMs) {
this.logger.debug(`CallSession:_startActionHookNoResponseGiveUpTimer ${options.noResponseGiveUpTimeoutMs}`);
this._actionHookNoResponseGiveUpTimer = setTimeout(() => {
this.logger.debug('CallSession:_startActionHookNoResponseGiveUpTimer Timeout');
this._jambonzHangup();
this._actionHookNoResponseGiveUpTimer = null;
}, options.noResponseGiveUpTimeoutMs);
}
}
_clearActionHookNoResponseGiveUpTimer() {
if (this._actionHookNoResponseGiveUpTimer) {
clearTimeout(this._actionHookNoResponseGiveUpTimer);
}
this._actionHookNoResponseGiveUpTimer = null;
}
} }
module.exports = CallSession; module.exports = CallSession;

View File

@@ -71,7 +71,7 @@ class InboundCallSession extends CallSession {
} }
_jambonzHangup() { _jambonzHangup() {
this._hangup(); this.dlg?.destroy();
} }
_hangup(terminatedBy = 'jambonz') { _hangup(terminatedBy = 'jambonz') {

View File

@@ -262,11 +262,7 @@ class TaskConfig extends Task {
} }
} }
if (Object.keys(this.actionHookDelayAction).length !== 0) { if (Object.keys(this.actionHookDelayAction).length !== 0) {
cs.actionHookDelayEnabled = this.actionHookDelayAction.enabled || false; cs.actionHookDelayProperties = this.actionHookDelayAction;
cs.actionHookNoResponseTimeout = this.actionHookDelayAction.noResponseTimeout || 0;
cs.actionHookNoResponseGiveUpTimeout = this.actionHookDelayAction.noResponseGiveUpTimeout || 0;
cs.actionHookDelayRetries = this.actionHookDelayAction.retries || 1;
cs.actionHookDelayActions = this.actionHookDelayAction.actions || [];
} }
if (this.data.sipRequestWithinDialogHook) { if (this.data.sipRequestWithinDialogHook) {
cs.sipRequestWithinDialogHook = this.data.sipRequestWithinDialogHook; cs.sipRequestWithinDialogHook = this.data.sipRequestWithinDialogHook;

View File

@@ -117,6 +117,7 @@ class TaskGather extends SttTask {
} }
if (this.sayTask) s += ',with nested say task'; if (this.sayTask) s += ',with nested say task';
if (this.playTask) s += ',with nested play task'; if (this.playTask) s += ',with nested play task';
if (this.actionHookDelayAction) s += ',with actionHookDelayAction';
s += '}'; s += '}';
return s; return s;
} }
@@ -163,28 +164,15 @@ class TaskGather extends SttTask {
this.interim = true; this.interim = true;
this.logger.debug('Gather:exec - early hints match enabled'); this.logger.debug('Gather:exec - early hints match enabled');
} }
// actionHook delay
this._hookDelayEn = cs.actionHookDelayEnabled || !!this.actionHookDelayAction;
this._hookDelayActions = this.actionHookDelayAction?.actions || cs.actionHookDelayActions || []; // if we have actionHook delay, and the session does as well, stash the session config
if (this.actionHookDelayAction) {
// Only enable NoResponseTimeout if there is _hookDelayActions if (cs.actionHookDelayProcessor) {
this._hookNoResponseTimeout = (this._hookDelayActions?.length ? this.logger.debug('Gather:exec - stashing session-level ahd proprerties');
(this.actionHookDelayAction?.noResponseTimeout || cs.actionHookNoResponseTimeout || 0) cs.stashActionHookDelayProperties();
: 0) * 1000; }
cs.actionHookDelayProperties = this.actionHookDelayAction;
this._hookNoResponseGiveUpTimeout = (this.actionHookDelayAction?.noResponseGiveUpTimeout || }
cs.actionHookNoResponseGiveUpTimeout || 0) * 1000;
this._hookDelayRetries = this.actionHookDelayAction?.retries || cs.actionHookDelayRetries || 1;
this._hookDelayRetryCount = 0;
this.hookDelayActionOpts = {
enabled: this._hookDelayEn,
actions: this._hookDelayActions,
noResponseTimeoutMs: this._hookNoResponseTimeout,
noResponseGiveUpTimeoutMs: this._hookNoResponseGiveUpTimeout,
retries: this._hookDelayRetries
};
this._startVad(); this._startVad();
@@ -296,7 +284,6 @@ class TaskGather extends SttTask {
kill(cs) { kill(cs) {
super.kill(cs); super.kill(cs);
this._killAudio(cs); this._killAudio(cs);
this._killActionHookDelayAction();
this._clearFillerNoiseTimer(); this._clearFillerNoiseTimer();
this.ep.removeAllListeners('dtmf'); this.ep.removeAllListeners('dtmf');
clearTimeout(this.interDigitTimer); clearTimeout(this.interDigitTimer);
@@ -592,98 +579,6 @@ class TaskGather extends SttTask {
this.cs.hangup(); this.cs.hangup();
} }
_actionHookDelaySayAction(verb) {
delete verb.verb;
this.logger.debug(`_actionHookDelaySayAction ${verb}`);
this._actionHookDelaySayTask = makeTask(this.logger, {say: verb}, this);
const {span, ctx} = this.startChildSpan(`actionHookDelayAction:${this._actionHookDelaySayTask.summary}`);
this._actionHookDelaySayTask.span = span;
this._actionHookDelaySayTask.ctx = ctx;
this._actionHookDelaySayTask.exec(this.cs, {ep: this.ep});
this._actionHookDelaySayTask.on('playDone', (err) => {
this._actionHookDelaySayTask = null;
span.end();
if (err) this.logger.error({err}, 'Gather:actionHookDelay Error playing tts');
});
}
_killActionHookDelayAction() {
if (this._actionHookDelaySayTask && !this._actionHookDelaySayTask.killed) {
this._actionHookDelaySayTask.removeAllListeners('playDone');
this._actionHookDelaySayTask.kill(this.cs);
this._actionHookDelaySayTask.span.end();
this._actionHookDelaySayTask = null;
}
if (this._actionHookDelayPlayTask && !this._actionHookDelayPlayTask.killed) {
this._actionHookDelayPlayTask.removeAllListeners('playDone');
this._actionHookDelayPlayTask.kill(this.cs);
this._actionHookDelayPlayTask.span.end();
this._actionHookDelayPlayTask = null;
}
}
_actionHookDelayPlayAction(verb) {
delete verb.verb;
this.logger.debug(`_actionHookDelayPlayAction ${verb}`);
this._actionHookDelayPlayTask = makeTask(this.logger, {play: verb}, this);
const {span, ctx} = this.startChildSpan(`actionHookDelayAction:${this._actionHookDelayPlayTask.summary}`);
this._actionHookDelayPlayTask.span = span;
this._actionHookDelayPlayTask.ctx = ctx;
this._actionHookDelayPlayTask.exec(this.cs, {ep: this.ep});
this._actionHookDelayPlayTask.on('playDone', (err) => {
this._actionHookDelayPlayTask = null;
span.end();
if (err) this.logger.error({err}, 'Gather:actionHookDelay Error playing tts');
});
}
_startActionHookNoResponseTimer() {
assert(this._hookNoResponseTimeout > 0);
this._clearActionHookNoResponseTimer();
this.logger.debug('startActionHookNoResponseTimer');
this._actionHookNoResponseTimer = setTimeout(() => {
if (this._hookDelayRetryCount >= this._hookDelayRetries) {
this._hangupCall();
return;
}
const verb = this._hookDelayActions[this._hookDelayRetryCount % this._hookDelayActions.length];
if (verb.verb === 'say') {
this._actionHookDelaySayAction(verb);
} else if (verb.verb === 'play') {
this._actionHookDelayPlayAction(verb);
}
this._hookDelayRetryCount++;
this._startActionHookNoResponseTimer();
}, this._hookNoResponseTimeout);
}
_clearActionHookNoResponseTimer() {
if (this._actionHookNoResponseTimer) {
clearTimeout(this._actionHookNoResponseTimer);
}
this._actionHookNoResponseTimer = null;
}
_startActionHookNoResponseGiveUpTimer() {
assert(this._hookNoResponseGiveUpTimeout > 0);
this._clearActionHookNoResponseGiveUpTimer();
this.logger.debug('startActionHookNoResponseGiveUpTimer');
this._actionHookNoResponseGiveUpTimer = setTimeout(() => {
this._hangupCall();
}, this._hookNoResponseGiveUpTimeout);
}
_clearActionHookNoResponseGiveUpTimer() {
if (this._actionHookNoResponseGiveUpTimer) {
clearTimeout(this._actionHookNoResponseGiveUpTimer);
}
this._actionHookNoResponseGiveUpTimer = null;
}
_startFastRecognitionTimer(evt) { _startFastRecognitionTimer(evt) {
assert(this.fastRecognitionTimeout > 0); assert(this.fastRecognitionTimeout > 0);
this._clearFastRecognitionTimer(); this._clearFastRecognitionTimer();
@@ -1101,7 +996,10 @@ class TaskGather extends SttTask {
this.logger.error({err}, 'Error stopping transcription'); this.logger.error({err}, 'Error stopping transcription');
}); });
} }
if (this.resolved) return; if (this.resolved) {
this.logger.debug('TaskGather:_resolve - already resolved');
return;
}
this.resolved = true; this.resolved = true;
// If bargin is false and ws application return ack to verb:hook // If bargin is false and ws application return ack to verb:hook
@@ -1125,15 +1023,13 @@ class TaskGather extends SttTask {
return; return;
} }
// Enabled action Hook delay timer to applied actions // action hook delay
if (this._hookNoResponseTimeout > 0) { if (this.cs.actionHookDelayProcessor) {
this._startActionHookNoResponseTimer(); this.logger.debug('TaskGather:_resolve - actionHookDelayProcessor exists - starting it');
} this.cs.actionHookDelayProcessor.start();
if (this._hookNoResponseGiveUpTimeout > 0) {
this._startActionHookNoResponseGiveUpTimer();
} }
// TODO: remove and implement as actionHookDelay
if (this.hasFillerNoise && (reason.startsWith('dtmf') || reason.startsWith('speech'))) { if (this.hasFillerNoise && (reason.startsWith('dtmf') || reason.startsWith('speech'))) {
if (this.fillerNoiseStartDelaySecs > 0) { if (this.fillerNoiseStartDelaySecs > 0) {
this._startFillerNoiseTimer(); this._startFillerNoiseTimer();
@@ -1144,40 +1040,57 @@ class TaskGather extends SttTask {
} }
} }
let returnedVerbs = false;
try { try {
if (reason.startsWith('dtmf')) { if (reason.startsWith('dtmf')) {
if (this.parentTask) this.parentTask.emit('dtmf', evt); if (this.parentTask) this.parentTask.emit('dtmf', evt);
else { else {
this.emit('dtmf', evt); this.emit('dtmf', evt);
await this.performAction({digits: this.digitBuffer, reason: 'dtmfDetected'}); returnedVerbs = await this.performAction({digits: this.digitBuffer, reason: 'dtmfDetected'});
} }
} }
else if (reason.startsWith('speech')) { else if (reason.startsWith('speech')) {
if (this.parentTask) this.parentTask.emit('transcription', evt); if (this.parentTask) this.parentTask.emit('transcription', evt);
else { else {
this.emit('transcription', evt); this.emit('transcription', evt);
await this.performAction({speech: evt, reason: 'speechDetected'}); this.logger.debug('TaskGather:_resolve - invoking performAction');
returnedVerbs = await this.performAction({speech: evt, reason: 'speechDetected'});
this.logger.debug({returnedVerbs}, 'TaskGather:_resolve - back from performAction');
} }
} }
else if (reason.startsWith('timeout')) { else if (reason.startsWith('timeout')) {
if (this.parentTask) this.parentTask.emit('timeout', evt); if (this.parentTask) this.parentTask.emit('timeout', evt);
else { else {
this.emit('timeout', evt); this.emit('timeout', evt);
await this.performAction({reason: 'timeout'}); returnedVerbs = await this.performAction({reason: 'timeout'});
} }
} }
else if (reason.startsWith('stt-error')) { else if (reason.startsWith('stt-error')) {
if (this.parentTask) this.parentTask.emit('stt-error', evt); if (this.parentTask) this.parentTask.emit('stt-error', evt);
else { else {
this.emit('stt-error', evt); this.emit('stt-error', evt);
await this.performAction({reason: 'error', details: evt.error}); returnedVerbs = await this.performAction({reason: 'error', details: evt.error});
} }
} }
} catch (err) { /*already logged error*/ } } catch (err) { /*already logged error*/ }
// Gather got response from hook, cancel all delay timers if there is any // Gather got response from hook, cancel actionHookDelay processing
this._clearActionHookNoResponseTimer(); this.logger.debug('TaskGather:_resolve - checking ahd');
this._clearActionHookNoResponseGiveUpTimer(); if (this.cs.actionHookDelayProcessor) {
if (returnedVerbs) {
this.logger.debug('TaskGather:_resolve - got response from action hook, cancelling actionHookDelay');
await this.cs.actionHookDelayProcessor.stop();
if (this.actionHookDelayAction && !this.cs.popActionHookDelayProperties()) {
// no session level ahd was running when this task started, so clear it
this.cs.clearActionHookDelayProcessor();
this.logger.debug('TaskGather:_resolve - clear ahd');
}
}
else {
this.logger.debug('TaskGather:_resolve - no response from action hook, continue actionHookDelay');
}
}
this._clearFillerNoiseTimer(); this._clearFillerNoiseTimer();
this.notifyTaskDone(); this.notifyTaskDone();

View File

@@ -108,7 +108,7 @@ class TaskSay extends TtsTask {
// If vendor is changed from the previous one, then reset the cache_speech_handles flag // If vendor is changed from the previous one, then reset the cache_speech_handles flag
cs.currentTtsVendor = vendor; cs.currentTtsVendor = vendor;
if (!preCache) this.logger.info({vendor, language, voice, model}, 'TaskSay:exec'); if (!preCache && !this._disableTracing) this.logger.info({vendor, language, voice, model}, 'TaskSay:exec');
try { try {
if (!credentials) { if (!credentials) {
writeAlerts({ writeAlerts({
@@ -127,7 +127,7 @@ class TaskSay extends TtsTask {
if (text.startsWith('silence_stream://')) return text; if (text.startsWith('silence_stream://')) return text;
/* otel: trace time for tts */ /* otel: trace time for tts */
if (!preCache) { if (!preCache && !this._disableTracing) {
const {span} = this.startChildSpan('tts-generation', { const {span} = this.startChildSpan('tts-generation', {
'tts.vendor': vendor, 'tts.vendor': vendor,
'tts.language': language, 'tts.language': language,
@@ -162,7 +162,7 @@ class TaskSay extends TtsTask {
lastUpdated = true; lastUpdated = true;
updateSpeechCredentialLastUsed(credentials.speech_credential_sid).catch(() => {/* logged error */}); updateSpeechCredentialLastUsed(credentials.speech_credential_sid).catch(() => {/* logged error */});
} }
if (!servedFromCache && rtt && !preCache) { if (!servedFromCache && rtt && !preCache && !this._disableTracing) {
this.notifyStatus({ this.notifyStatus({
event: 'synthesized-audio', event: 'synthesized-audio',
vendor, vendor,

View File

@@ -45,6 +45,10 @@ class Task extends Emitter {
return this.name; return this.name;
} }
set disableTracing(val) {
this._disableTracing = val;
}
toJSON() { toJSON() {
return this.data; return this.data;
} }
@@ -177,15 +181,16 @@ class Task extends Emitter {
// If actionHook delay action is configured, and ws application have not responded yet any verb for actionHook // If actionHook delay action is configured, and ws application have not responded yet any verb for actionHook
// We have to transfer the task to call-session to await on next ws command verbs, and also run action Hook // We have to transfer the task to call-session to await on next ws command verbs, and also run action Hook
// delay actions // delay actions
if (this.hookDelayActionOpts) { //if (this.hookDelayActionOpts) {
this.emit('ActionHookDelayActionOptions', this.hookDelayActionOpts); // this.emit('ActionHookDelayActionOptions', this.hookDelayActionOpts);
} //}
} }
if (expectResponse && json && Array.isArray(json)) { if (expectResponse && json && Array.isArray(json)) {
const makeTask = require('./make_task'); const makeTask = require('./make_task');
const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata)); const tasks = normalizeJambones(this.logger, json).map((tdata) => makeTask(this.logger, tdata));
if (tasks && tasks.length > 0) { if (tasks && tasks.length > 0) {
this.callSession.replaceApplication(tasks); this.callSession.replaceApplication(tasks);
return true;
} }
} }
} catch (err) { } catch (err) {
@@ -193,6 +198,7 @@ class Task extends Emitter {
span.end(); span.end();
throw err; throw err;
} }
return false;
} }
} }

View File

@@ -0,0 +1,158 @@
const makeTask = require('../tasks/make_task');
const Emitter = require('events');
const { normalizeJambones } = require('@jambonz/verb-specifications');
const {TaskName} = require('../utils/constants');
/**
* ActionHookDelayProcessor
* @extends Emitter
*
* @param {Object} logger - logger instance
* @param {Object} opts - options
* @param {Object} cs - call session
* @param {Object} ep - endpoint
*
* @emits {Event} 'giveup' - when associated giveup timer expires
*
* Ref:https://www.jambonz.org/docs/supporting-articles/handling-action-hook-delays/
*/
class ActionHookDelayProcessor extends Emitter {
constructor(logger, opts, cs) {
super();
this.logger = logger;
this.cs = cs;
const enabled = this.init(opts);
if (enabled && (!this.actions || !Array.isArray(this.actions) || this.actions.length === 0)) {
throw new Error('ActionHookDelayProcessor: no actions specified');
}
else if (enabled && this.actions.some((a) => !a.verb || ![TaskName.Say, TaskName.Play].includes(a.verb))) {
throw new Error(`ActionHookDelayProcessor: invalid actions specified: ${JSON.stringify(this.actions)}`);
}
}
get properties() {
return {
actions: this.actions,
retries: this.retries,
noResponseTimeout: this.noResponseTimeout,
noResponseGiveUpTimeout: this.noResponseGiveUpTimeout
};
}
get ep() {
return this.cs.ep;
}
init(opts) {
this.logger.debug({opts}, 'ActionHookDelayProcessor#init');
this.actions = opts.actions;
this.retries = opts.retries || 0;
this.noResponseTimeout = opts.noResponseTimeout || 0;
this.noResponseGiveUpTimeout = opts.noResponseGiveUpTimeout;
// return false if these options actually disable the ahdp
return ('enable' in opts && opts.enable === true) ||
('enabled' in opts && opts.enabled === true) ||
(!('enable' in opts) && !('enabled' in opts));
}
start() {
this.logger.debug('ActionHookDelayProcessor#start');
if (this._noResponseTimer) {
this.logger.debug('ActionHookDelayProcessor#start: already started due to prior gather which is continuing');
return;
}
this._retryCount = 0;
const timeoutMs = this.noResponseTimeout === 0 ? 1 : this.noResponseTimeout * 1000;
this._noResponseTimer = setTimeout(this._onNoResponseTimer.bind(this), timeoutMs);
if (this.noResponseGiveUpTimeout > 0) {
const timeoutMs = this.noResponseGiveUpTimeout * 1000;
this._noResponseGiveUpTimer = setTimeout(this._onNoResponseGiveUpTimer.bind(this), timeoutMs);
}
}
async stop() {
this.logger.debug('ActionHookDelayProcessor#stop');
if (this._noResponseTimer) {
clearTimeout(this._noResponseTimer);
this._noResponseTimer = null;
}
if (this._noResponseGiveUpTimer) {
clearTimeout(this._noResponseGiveUpTimer);
this._noResponseGiveUpTimer = null;
}
if (this._taskInProgress) {
this.logger.debug(`ActionHookDelayProcessor#stop: killing task in progress: ${this._taskInProgress.name}`);
/** if we are doing a play, kill it immediately
* if we are doing a say, wait for it to finish
*/
if (TaskName.Say === this._taskInProgress.name) {
this._sayResolver = () => {
this.logger.debug('ActionHookDelayProcessor#stop: say is done, continue on..');
this._taskInProgress.kill(this.cs);
this._taskInProgress = null;
};
this.logger.debug('ActionHookDelayProcessor#stop returning promise');
return new Promise((resolve) => this._sayResolver = resolve);
}
else {
/* play */
this._taskInProgress.kill(this.cs);
this._taskInProgress = null;
}
}
this.logger.debug('ActionHookDelayProcessor#stop returning');
}
_onNoResponseTimer() {
this.logger.debug('ActionHookDelayProcessor#_onNoResponseTimer');
this._noResponseTimer = null;
/* get the next play or say action */
const verb = this.actions[this._retryCount % this.actions.length];
const t = normalizeJambones(this.logger, [verb]);
this.logger.debug({verb}, 'ActionHookDelayProcessor#_onNoResponseTimer: starting action');
try {
this._taskInProgress = makeTask(this.logger, t[0]);
this._taskInProgress.disableTracing = true;
this._taskInProgress.exec(this.cs, {ep: this.ep});
} catch (err) {
this.logger.info(err, 'ActionHookDelayProcessor#_onNoResponseTimer: error starting action');
this._taskInProgress = null;
return;
}
this.ep.once('playback-stop', (evt) => {
this._taskInProgress = null;
if (this._sayResolver) {
/* we were waiting for the play to finish before continuing to next task */
this.logger.debug({evt}, 'got playback-stop');
this._sayResolver();
this._sayResolver = null;
}
else {
/* possibly start the no response timer again */
if (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);
}
}
});
this._retryCount++;
}
_onNoResponseGiveUpTimer() {
this.logger.info('ActionHookDelayProcessor#_onNoResponseGiveUpTimer');
this.stop().catch((err) => {});
this.emit('giveup');
}
}
module.exports = ActionHookDelayProcessor;