ben.carrasco/jambonz-feature-server
1
0
Fork 0
mirror of https://github.com/jambonz/jambonz-feature-server.git synced 2025-12-21 00:58:34 +00:00
Code Issues Packages Projects Releases Wiki Activity

reduce verbosity of logging (#1145)

Browse Source
This commit is contained in:
Dave Horton
2025-04-09 15:36:58 -04:00
committed by GitHub
parent 77f0fc85a3
commit d310ba0ed1
4 changed files with 33 additions and 33 deletions
Download Patch File Download Diff File Expand all files Collapse all files

41
lib/session/call-session.js
View File

@@ -962,7 +962,7 @@ class CallSession extends Emitter {
(type === 'tts' && credential.use_for_tts) || (type === 'tts' && credential.use_for_tts) ||
(type === 'stt' && credential.use_for_stt) (type === 'stt' && credential.use_for_stt)
)) { )) {
this.logger.info( this.logger.debug(
`${type}: ${credential.vendor} ${credential.label ? `, label: ${credential.label}` : ''} `); `${type}: ${credential.vendor} ${credential.label ? `, label: ${credential.label}` : ''} `);
if ('google' === vendor) { if ('google' === vendor) {
if (type === 'tts' && !credential.tts_tested_ok || if (type === 'tts' && !credential.tts_tested_ok ||
@@ -1459,7 +1459,7 @@ class CallSession extends Emitter {
} }
if (tasks) { if (tasks) {
const t = normalizeJambones(this.logger, tasks).map((tdata) => makeTask(this.logger, tdata)); const t = normalizeJambones(this.logger, tasks).map((tdata) => makeTask(this.logger, tdata));
this.logger.info({tasks: listTaskNames(t)}, 'CallSession:_lccCallHook new task list'); this.logger.debug({tasks: listTaskNames(t)}, 'CallSession:_lccCallHook new task list');
this.replaceApplication(t); this.replaceApplication(t);
if (this.wakeupResolver) { if (this.wakeupResolver) {
//this.logger.debug({resolution}, 'CallSession:_onCommand - got commands, waking up..'); //this.logger.debug({resolution}, 'CallSession:_onCommand - got commands, waking up..');
@@ -1726,10 +1726,10 @@ Duration=${duration} `
this.currentTask.ep : this.currentTask.ep :
this.ep; this.ep;
const db = parseDecibels(opts); const db = parseDecibels(opts);
this.logger.info(`_lccBoostAudioSignal: boosting audio signal by ${db} dB`); this.logger.debug(`_lccBoostAudioSignal: boosting audio signal by ${db} dB`);
const args = [ep.uuid, 'setGain', db]; const args = [ep.uuid, 'setGain', db];
const response = await ep.api('uuid_dub', args); const response = await ep.api('uuid_dub', args);
this.logger.info({response}, '_lccBoostAudioSignal: response from freeswitch'); this.logger.debug({response}, '_lccBoostAudioSignal: response from freeswitch');
} }
async _lccMediaPath(desiredPath) { async _lccMediaPath(desiredPath) {
@@ -1782,7 +1782,6 @@ Duration=${duration} `
let res; let res;
try { try {
res = await this.ttsStreamingBuffer?.bufferTokens(tokens); res = await this.ttsStreamingBuffer?.bufferTokens(tokens);
this.logger.info({id, res}, 'CallSession:_lccTtsTokens - tts:tokens-result');
} catch (err) { } catch (err) {
this.logger.info(err, 'CallSession:_lccTtsTokens'); this.logger.info(err, 'CallSession:_lccTtsTokens');
} }
@@ -1917,7 +1916,7 @@ Duration=${duration} `
this.tasks = tasks; this.tasks = tasks;
this.taskIdx = 0; this.taskIdx = 0;
this.stackIdx++; this.stackIdx++;
this.logger.info({tasks: listTaskNames(tasks)}, this.logger.debug({tasks: listTaskNames(tasks)},
`CallSession:replaceApplication reset with ${tasks.length} new tasks, stack depth is ${this.stackIdx}`); `CallSession:replaceApplication reset with ${tasks.length} new tasks, stack depth is ${this.stackIdx}`);
if (this.currentTask) { if (this.currentTask) {
this.currentTask.kill(this, KillReason.Replaced); this.currentTask.kill(this, KillReason.Replaced);
@@ -1932,7 +1931,7 @@ Duration=${duration} `
kill(onBackgroundGatherBargein = false) { kill(onBackgroundGatherBargein = false) {
if (this.isConfirmCallSession) this.logger.debug('CallSession:kill (ConfirmSession)'); if (this.isConfirmCallSession) this.logger.debug('CallSession:kill (ConfirmSession)');
else this.logger.info('CallSession:kill'); else this.logger.debug('CallSession:kill');
this._endVerbHookSpan(); this._endVerbHookSpan();
if (this.currentTask) { if (this.currentTask) {
this.currentTask.kill(this); this.currentTask.kill(this);
@@ -1997,7 +1996,7 @@ Duration=${duration} `
task.synthesizer.label : task.synthesizer.label :
this.speechSynthesisLabel; this.speechSynthesisLabel;
this.logger.info({vendor, language, voice, label}, this.logger.debug({vendor, language, voice, label},
'CallSession:_preCacheAudio - precaching audio for future prompt'); 'CallSession:_preCacheAudio - precaching audio for future prompt');
task._synthesizeWithSpecificVendor(this, this.ep, {vendor, language, voice, label, preCache: true}) task._synthesizeWithSpecificVendor(this, this.ep, {vendor, language, voice, label, preCache: true})
.catch((err) => this.logger.error(err, 'CallSession:_preCacheAudio - error precaching audio')); .catch((err) => this.logger.error(err, 'CallSession:_preCacheAudio - error precaching audio'));
@@ -2067,7 +2066,7 @@ Duration=${duration} `
} }
async _onCommand({msgid, command, call_sid, queueCommand, tool_call_id, data}) { async _onCommand({msgid, command, call_sid, queueCommand, tool_call_id, data}) {
this.logger.info({msgid, command, queueCommand, data}, 'CallSession:_onCommand - received command'); this.logger.debug({msgid, command, queueCommand, data}, 'CallSession:_onCommand - received command');
let resolution; let resolution;
switch (command) { switch (command) {
case 'redirect': case 'redirect':
@@ -2076,18 +2075,18 @@ Duration=${duration} `
const t = normalizeJambones(this.logger, data) const t = normalizeJambones(this.logger, data)
.map((tdata) => makeTask(this.logger, tdata)); .map((tdata) => makeTask(this.logger, tdata));
if (!queueCommand) { if (!queueCommand) {
this.logger.info({tasks: listTaskNames(t)}, 'CallSession:_onCommand new task list'); this.logger.debug({tasks: listTaskNames(t)}, 'CallSession:_onCommand new task list');
this.replaceApplication(t); this.replaceApplication(t);
} }
else if (JAMBONES_INJECT_CONTENT) { else if (JAMBONES_INJECT_CONTENT) {
if (JAMBONES_EAGERLY_PRE_CACHE_AUDIO) this._preCacheAudio(t); if (JAMBONES_EAGERLY_PRE_CACHE_AUDIO) this._preCacheAudio(t);
this._injectTasks(t); this._injectTasks(t);
this.logger.info({tasks: listTaskNames(this.tasks)}, 'CallSession:_onCommand - updated task list'); this.logger.debug({tasks: listTaskNames(this.tasks)}, 'CallSession:_onCommand - updated task list');
} }
else { else {
if (JAMBONES_EAGERLY_PRE_CACHE_AUDIO) this._preCacheAudio(t); if (JAMBONES_EAGERLY_PRE_CACHE_AUDIO) this._preCacheAudio(t);
this.tasks.push(...t); this.tasks.push(...t);
this.logger.info({tasks: listTaskNames(this.tasks)}, 'CallSession:_onCommand - updated task list'); this.logger.debug({tasks: listTaskNames(this.tasks)}, 'CallSession:_onCommand - updated task list');
} }
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);
@@ -2607,7 +2606,7 @@ Duration=${duration} `
if (json && Array.isArray(json)) { if (json && Array.isArray(json)) {
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.logger.info('CallSession:handleRefer received REFER, get new tasks'); this.logger.debug('CallSession:handleRefer received REFER, get new tasks');
this.replaceApplication(tasks); this.replaceApplication(tasks);
if (this.wakeupResolver) { if (this.wakeupResolver) {
this.wakeupResolver({reason: 'CallSession: referHook new taks'}); this.wakeupResolver({reason: 'CallSession: referHook new taks'});
@@ -2654,14 +2653,14 @@ Duration=${duration} `
if (typeof this.queueEventHookRequestor === 'undefined') { if (typeof this.queueEventHookRequestor === 'undefined') {
const pp = this._pool.promise(); const pp = this._pool.promise();
try { try {
this.logger.info({accountSid: this.accountSid}, 'performQueueWebhook: looking up account'); this.logger.debug({accountSid: this.accountSid}, 'performQueueWebhook: looking up account');
const [r] = await pp.query(sqlRetrieveQueueEventHook, [this.accountSid]); const [r] = await pp.query(sqlRetrieveQueueEventHook, [this.accountSid]);
if (0 === r.length) { if (0 === r.length) {
this.logger.info({accountSid: this.accountSid}, 'performQueueWebhook: no webhook provisioned'); this.logger.info({accountSid: this.accountSid}, 'performQueueWebhook: no webhook provisioned');
this.queueEventHookRequestor = null; this.queueEventHookRequestor = null;
} }
else { else {
this.logger.info({accountSid: this.accountSid, webhook: r[0]}, 'performQueueWebhook: webhook found'); this.logger.debug({accountSid: this.accountSid, webhook: r[0]}, 'performQueueWebhook: webhook found');
this.queueEventHookRequestor = new HttpRequestor(this.logger, this.accountSid, this.queueEventHookRequestor = new HttpRequestor(this.logger, this.accountSid,
r[0], this.webhook_secret); r[0], this.webhook_secret);
this.queueEventHook = r[0]; this.queueEventHook = r[0];
@@ -2675,7 +2674,7 @@ Duration=${duration} `
/* send webhook */ /* send webhook */
const params = {...obj, ...this.callInfo.toJSON()}; const params = {...obj, ...this.callInfo.toJSON()};
this.logger.info({accountSid: this.accountSid, params}, 'performQueueWebhook: sending webhook'); this.logger.debug({accountSid: this.accountSid, params}, 'performQueueWebhook: sending webhook');
this.queueEventHookRequestor.request('queue:status', this.queueEventHook, params) this.queueEventHookRequestor.request('queue:status', this.queueEventHook, params)
.catch((err) => { .catch((err) => {
this.logger.info({err, accountSid: this.accountSid, obj}, 'Error sending queue notification event'); this.logger.info({err, accountSid: this.accountSid, obj}, 'Error sending queue notification event');
@@ -2810,7 +2809,7 @@ Duration=${duration} `
async handleReinviteAfterMediaReleased(req, res) { async handleReinviteAfterMediaReleased(req, res) {
assert(this.dlg && this.dlg.connected && !this.ep); assert(this.dlg && this.dlg.connected && !this.ep);
const sdp = await this.dlg.modify(req.body); const sdp = await this.dlg.modify(req.body);
this.logger.info({sdp}, 'CallSession:handleReinviteAfterMediaReleased - reinvite to A leg returned sdp'); this.logger.debug({sdp}, 'CallSession:handleReinviteAfterMediaReleased - reinvite to A leg returned sdp');
res.send(200, {body: sdp}); res.send(200, {body: sdp});
} }
@@ -2891,7 +2890,7 @@ Duration=${duration} `
// if final transcription is received but endpoint is already closed, // if final transcription is received but endpoint is already closed,
// freeswitch module will not be able to send the transcription // freeswitch module will not be able to send the transcription
this.logger.info('callSession:_configMsEndpoint -' + this.logger.debug('callSession:_configMsEndpoint -' +
' transcribe task, wait for some time before destroy'); ' transcribe task, wait for some time before destroy');
await sleepFor(JAMBONES_TRANSCRIBE_EP_DESTROY_DELAY_MS); await sleepFor(JAMBONES_TRANSCRIBE_EP_DESTROY_DELAY_MS);
} }
@@ -2945,7 +2944,7 @@ Duration=${duration} `
_awaitCommandsOrHangup() { _awaitCommandsOrHangup() {
assert(!this.wakeupResolver); assert(!this.wakeupResolver);
return new Promise((resolve, reject) => { return new Promise((resolve, reject) => {
this.logger.info('_awaitCommandsOrHangup - waiting...'); this.logger.debug('_awaitCommandsOrHangup - waiting...');
this.wakeupResolver = resolve; this.wakeupResolver = resolve;
if (this._actionHookDelayProcessor) { if (this._actionHookDelayProcessor) {
@@ -2965,7 +2964,7 @@ Duration=${duration} `
this.ep.play(this.fillerNoise.url); this.ep.play(this.fillerNoise.url);
this.ep.once('playback-start', (evt) => { this.ep.once('playback-start', (evt) => {
if (evt.file === this.fillerNoise.url && !this._isPlayingFillerNoise) { if (evt.file === this.fillerNoise.url && !this._isPlayingFillerNoise) {
this.logger.info('CallSession:_awaitCommandsOrHangup - filler noise started'); this.logger.debug('CallSession:_awaitCommandsOrHangup - filler noise started');
this.ep.api('uuid_break', this.ep.uuid) this.ep.api('uuid_break', this.ep.uuid)
.catch((err) => this.logger.info(err, 'Error killing filler noise')); .catch((err) => this.logger.info(err, 'Error killing filler noise'));
} }
@@ -2976,7 +2975,7 @@ Duration=${duration} `
_clearTasks(backgroundGather, evt) { _clearTasks(backgroundGather, evt) {
if (this.requestor instanceof WsRequestor && !backgroundGather.cleared) { if (this.requestor instanceof WsRequestor && !backgroundGather.cleared) {
this.logger.info({evt}, 'CallSession:_clearTasks on event from background gather'); this.logger.debug({evt}, 'CallSession:_clearTasks on event from background gather');
try { try {
backgroundGather.cleared = true; backgroundGather.cleared = true;
this.kill(true); this.kill(true);

2
lib/tasks/listen.js
View File

@@ -221,7 +221,7 @@ class TaskListen extends Task {
} }
} }
_onConnect(ep) { _onConnect(ep) {
this.logger.debug('TaskListen:_onConnect'); this.logger.info('TaskListen:_onConnect');
} }
_onConnectFailure(ep, evt) { _onConnectFailure(ep, evt) {
this.logger.info(evt, 'TaskListen:_onConnectFailure'); this.logger.info(evt, 'TaskListen:_onConnectFailure');

19
lib/tasks/llm/llms/ultravox_s2s.js
View File

@@ -85,10 +85,10 @@ class TaskLlmUltravox_S2S extends Task {
}); });
const data = await body.json(); const data = await body.json();
if (statusCode !== 201 || !data?.joinUrl) { if (statusCode !== 201 || !data?.joinUrl) {
this.logger.error({statusCode, data}, 'Ultravox Error registering call'); this.logger.info({statusCode, data}, 'Ultravox Error registering call');
throw new Error(`Ultravox Error registering call: ${data.message}`); throw new Error(`Ultravox Error registering call: ${data.message}`);
} }
this.logger.info({joinUrl: data.joinUrl}, 'Ultravox Call registered'); this.logger.debug({joinUrl: data.joinUrl}, 'Ultravox Call registered');
return data; return data;
} }
@@ -120,7 +120,7 @@ class TaskLlmUltravox_S2S extends Task {
...data ...data
}); });
} catch (err) { } catch (err) {
this.logger.error({err}, 'TaskLlmUltraVox_S2S:_startListening'); this.logger.info({err}, 'TaskLlmUltraVox_S2S:_startListening - Error sending createCall');
this.notifyTaskDone(); this.notifyTaskDone();
} }
} }
@@ -148,7 +148,7 @@ class TaskLlmUltravox_S2S extends Task {
} }
_onConnect(ep) { _onConnect(ep) {
this.logger.debug('TaskLlmUltravox_S2S:_onConnect'); this.logger.info('TaskLlmUltravox_S2S:_onConnect');
} }
_onConnectFailure(_ep, evt) { _onConnectFailure(_ep, evt) {
this.logger.info(evt, 'TaskLlmUltravox_S2S:_onConnectFailure'); this.logger.info(evt, 'TaskLlmUltravox_S2S:_onConnectFailure');
@@ -164,7 +164,7 @@ class TaskLlmUltravox_S2S extends Task {
async _onServerEvent(_ep, evt) { async _onServerEvent(_ep, evt) {
let endConversation = false; let endConversation = false;
const type = evt.type; const type = evt.type;
this.logger.info({evt}, 'TaskLlmUltravox_S2S:_onServerEvent'); this.logger.debug({evt}, 'TaskLlmUltravox_S2S:_onServerEvent');
/* server errors of some sort */ /* server errors of some sort */
if (type === 'error') { if (type === 'error') {
@@ -179,7 +179,7 @@ class TaskLlmUltravox_S2S extends Task {
else if (type === 'client_tool_invocation') { else if (type === 'client_tool_invocation') {
this.logger.debug({evt}, 'TaskLlmUltravox_S2S:_onServerEvent - function_call'); this.logger.debug({evt}, 'TaskLlmUltravox_S2S:_onServerEvent - function_call');
if (!this.toolHook) { if (!this.toolHook) {
this.logger.warn({evt}, 'TaskLlmUltravox_S2S:_onServerEvent - no toolHook defined!'); this.logger.info({evt}, 'TaskLlmUltravox_S2S:_onServerEvent - no toolHook defined!');
} }
else { else {
const {toolName: name, invocationId: call_id, parameters: args} = evt; const {toolName: name, invocationId: call_id, parameters: args} = evt;
@@ -221,13 +221,14 @@ class TaskLlmUltravox_S2S extends Task {
if (!data.type || ![ if (!data.type || ![
'input_text_message' 'input_text_message'
].includes(data.type)) { ].includes(data.type)) {
this.logger.info({data}, 'TaskLlmUltravox_S2S:processLlmUpdate - invalid mid-call request'); this.logger.info({data},
'TaskLlmUltravox_S2S:processLlmUpdate - invalid mid-call request, only input_text_message supported');
} }
else { else {
await this._api(ep, [ep.uuid, ClientEvent, JSON.stringify(data)]); await this._api(ep, [ep.uuid, ClientEvent, JSON.stringify(data)]);
} }
} catch (err) { } catch (err) {
this.logger.info({err}, 'TaskLlmUltravox_S2S:processLlmUpdate'); this.logger.info({err, data}, 'TaskLlmUltravox_S2S:processLlmUpdate - Error processing LLM update');
} }
} }
@@ -243,7 +244,7 @@ class TaskLlmUltravox_S2S extends Task {
await this._api(ep, [ep.uuid, ClientEvent, JSON.stringify(data)]); await this._api(ep, [ep.uuid, ClientEvent, JSON.stringify(data)]);
} }
} catch (err) { } catch (err) {
this.logger.info({err}, 'TaskLlmUltravox_S2S:processToolOutput'); this.logger.info({err, data}, 'TaskLlmUltravox_S2S:processToolOutput - Error processing tool output');
} }
} }

4
lib/tasks/tts-task.js
View File

@@ -137,7 +137,7 @@ class TtsTask extends Task {
throw new Error(`vendor ${vendor} is not supported for tts streaming yet`); throw new Error(`vendor ${vendor} is not supported for tts streaming yet`);
} }
} }
this.logger.info({vendor, credentials, obj}, 'setTtsStreamingChannelVars'); this.logger.debug({vendor, credentials, obj}, 'setTtsStreamingChannelVars');
await ep.set(obj); await ep.set(obj);
} }
@@ -231,7 +231,7 @@ class TtsTask extends Task {
//cs.currentTtsVendor = vendor; //cs.currentTtsVendor = vendor;
if (!preCache && !this._disableTracing) if (!preCache && !this._disableTracing)
this.logger.info({vendor, language, voice, model: this.model}, 'TaskSay:exec'); this.logger.debug({vendor, language, voice, model: this.model}, 'TaskSay:exec');
try { try {
if (!credentials) { if (!credentials) {
writeAlerts({ writeAlerts({