Skip to content

Commit afcd4e5

Browse files
jhereticjheretic
committed
fix: Redact additonal fields from debugging and move some tracing logs to instrumentation.
1 parent b486bf3 commit afcd4e5

2 files changed

Lines changed: 93 additions & 181 deletions

File tree

‎crates/bitpart/src/csml/interpret.rs‎

Lines changed: 62 additions & 179 deletions
Original file line numberDiff line numberDiff line change
@@ -30,7 +30,7 @@ use serde_json::{Value, map::Map};
3030
use std::collections::HashMap;
3131
use std::sync::mpsc as std_mpsc;
3232
use tokio::sync::mpsc as tokio_mpsc;
33-
use tracing::{debug, error, info, trace, warn};
33+
use tracing::{debug, error, info, instrument, trace, warn};
3434

3535
use super::data::{ConversationData, SwitchBot};
3636
use super::utils::{
@@ -46,6 +46,16 @@ enum InterpreterReturn {
4646
SwitchBot(SwitchBot),
4747
}
4848

49+
#[instrument(
50+
name = "csml.step",
51+
skip_all,
52+
fields(
53+
bot_id = %data.client.bot_id,
54+
user_id = %data.client.user_id,
55+
channel_id = %data.client.channel_id,
56+
flow = %data.context.flow,
57+
),
58+
)]
4959
pub async fn step(
5060
data: &mut ConversationData,
5161
event: Event,
@@ -59,15 +69,8 @@ pub async fn step(
5969
let (sender, mut receiver) = tokio_mpsc::channel::<MSG>(32);
6070
let context = data.context.clone();
6171
let mut switch_bot = None;
62-
info!(
63-
flow = data.context.flow.to_string(),
64-
"interpreter: start interpretations of bot {:?}", bot.id
65-
);
72+
info!("interpreter: start interpretations of bot {:?}", bot.id);
6673
debug!(
67-
bot_id = data.client.bot_id.to_string(),
68-
user_id = data.client.user_id.to_string(),
69-
channel_id = data.client.channel_id.to_string(),
70-
flow = data.context.flow.to_string(),
7174
"interpreter: start interpretations of bot {:?}, with ",
7275
bot.id
7376
);
@@ -107,30 +110,16 @@ pub async fn step(
107110
}
108111
},
109112
MSG::Message(msg) => {
110-
info!(flow = data.context.flow.to_string(), "sending message");
111-
debug!(
112-
bot_id = data.client.bot_id.to_string(),
113-
user_id = data.client.user_id.to_string(),
114-
channel_id = data.client.channel_id.to_string(),
115-
flow = data.context.flow.to_string(),
116-
"sending message {:?}",
117-
msg
118-
);
113+
info!("sending message");
114+
debug!("sending message {:?}", msg);
119115

120116
debug!("CONTEXT {:?}", data.context);
121117
send_msg_to_callback_url(data, vec![msg.clone()], interaction_order, false);
122118
data.messages.push(msg);
123119
}
124120
MSG::Shout(msg) => {
125-
info!(flow = data.context.flow.to_string(), "sending message");
126-
debug!(
127-
bot_id = data.client.bot_id.to_string(),
128-
user_id = data.client.user_id.to_string(),
129-
channel_id = data.client.channel_id.to_string(),
130-
flow = data.context.flow.to_string(),
131-
"shouting message {:?}",
132-
msg
133-
);
121+
info!("sending message");
122+
debug!("shouting message {:?}", msg);
134123

135124
debug!("CONTEXT {:?}", data.context);
136125

@@ -156,15 +145,8 @@ pub async fn step(
156145
}
157146
}
158147
MSG::Whisper(msg) => {
159-
info!(flow = data.context.flow.to_string(), "sending message");
160-
debug!(
161-
bot_id = data.client.bot_id.to_string(),
162-
user_id = data.client.user_id.to_string(),
163-
channel_id = data.client.channel_id.to_string(),
164-
flow = data.context.flow.to_string(),
165-
"whispering message {:?}",
166-
msg
167-
);
148+
info!("sending message");
149+
debug!("whispering message {:?}", msg);
168150

169151
debug!("CONTEXT {:?}", data.context);
170152

@@ -192,14 +174,8 @@ pub async fn step(
192174
}
193175
}
194176
MSG::Delete => {
195-
info!(flow = data.context.flow.to_string(), "sending message");
196-
debug!(
197-
bot_id = data.client.bot_id.to_string(),
198-
user_id = data.client.user_id.to_string(),
199-
channel_id = data.client.channel_id.to_string(),
200-
flow = data.context.flow.to_string(),
201-
"deleting client",
202-
);
177+
info!("sending message");
178+
debug!("deleting client");
203179

204180
debug!("CONTEXT {:?}", data.context);
205181

@@ -212,47 +188,15 @@ pub async fn step(
212188
message,
213189
log_lvl,
214190
} => {
191+
// Note: `flow` here is the CSML script's own flow identifier,
192+
// logged as `csml_flow` to disambiguate from the span's `flow`
193+
// field which comes from `data.context.flow`.
215194
match log_lvl {
216-
LogLvl::Error => error!(
217-
bot_id = data.client.bot_id.to_string(),
218-
user_id = data.client.user_id.to_string(),
219-
channel_id = data.client.channel_id.to_string(),
220-
flow,
221-
line,
222-
message
223-
),
224-
LogLvl::Warn => warn!(
225-
bot_id = data.client.bot_id.to_string(),
226-
user_id = data.client.user_id.to_string(),
227-
channel_id = data.client.channel_id.to_string(),
228-
flow,
229-
line,
230-
message
231-
),
232-
LogLvl::Info => info!(
233-
bot_id = data.client.bot_id.to_string(),
234-
user_id = data.client.user_id.to_string(),
235-
channel_id = data.client.channel_id.to_string(),
236-
flow,
237-
line,
238-
message
239-
),
240-
LogLvl::Debug => debug!(
241-
bot_id = data.client.bot_id.to_string(),
242-
user_id = data.client.user_id.to_string(),
243-
channel_id = data.client.channel_id.to_string(),
244-
flow,
245-
line,
246-
message
247-
),
248-
LogLvl::Trace => trace!(
249-
bot_id = data.client.bot_id.to_string(),
250-
user_id = data.client.user_id.to_string(),
251-
channel_id = data.client.channel_id.to_string(),
252-
flow,
253-
line,
254-
message
255-
),
195+
LogLvl::Error => error!(csml_flow = flow, line, message),
196+
LogLvl::Warn => warn!(csml_flow = flow, line, message),
197+
LogLvl::Info => info!(csml_flow = flow, line, message),
198+
LogLvl::Debug => debug!(csml_flow = flow, line, message),
199+
LogLvl::Trace => trace!(csml_flow = flow, line, message),
256200
};
257201
}
258202
MSG::Hold(Hold {
@@ -271,15 +215,8 @@ pub async fn step(
271215
"previous": previous,
272216
"secure": secure
273217
});
274-
info!(flow = data.context.flow.to_string(), "hold bot");
275-
debug!(
276-
bot_id = data.client.bot_id.to_string(),
277-
user_id = data.client.user_id.to_string(),
278-
channel_id = data.client.channel_id.to_string(),
279-
flow = data.context.flow.to_string(),
280-
"hold bot, state_hold {:?}",
281-
state_hold
282-
);
218+
info!("hold bot");
219+
debug!("hold bot, state_hold {:?}", state_hold);
283220

284221
db::state::set(
285222
&data.client,
@@ -344,14 +281,7 @@ pub async fn step(
344281

345282
MSG::Error(err_msg) => {
346283
conversation_end = true;
347-
error!(
348-
bot_id = data.client.bot_id.to_string(),
349-
user_id = data.client.user_id.to_string(),
350-
channel_id = data.client.channel_id.to_string(),
351-
flow = data.context.flow.to_string(),
352-
"interpreter error: {:?}",
353-
err_msg
354-
);
284+
error!("interpreter error: {:?}", err_msg);
355285

356286
send_msg_to_callback_url(data, vec![err_msg.clone()], interaction_order, true);
357287
data.messages.push(err_msg);
@@ -384,6 +314,17 @@ pub async fn step(
384314
))
385315
}
386316

317+
#[instrument(
318+
name = "csml.manage_switch_bot",
319+
skip_all,
320+
fields(
321+
bot_id = %data.client.bot_id,
322+
user_id = %data.client.user_id,
323+
channel_id = %data.client.channel_id,
324+
flow = %data.context.flow,
325+
target_bot = %target_bot,
326+
),
327+
)]
387328
async fn manage_switch_bot(
388329
data: &mut ConversationData,
389330
interaction_order: &mut i32,
@@ -427,61 +368,26 @@ async fn manage_switch_bot(
427368
true,
428369
);
429370

430-
error!(
431-
flow = data.context.flow.to_string(),
432-
message = error_message
433-
);
371+
error!(message = error_message);
434372
return Ok(InterpreterReturn::End);
435373
}
436374
};
437375

438376
let (flow, step) = match (flow, step) {
439377
(Some(flow), Some(step)) => {
440-
info!(
441-
bot_id = data.client.bot_id.to_string(),
442-
user_id = data.client.user_id.to_string(),
443-
channel_id = data.client.channel_id.to_string(),
444-
flow = data.context.flow.to_string(),
445-
"goto step: {:?}",
446-
data.context.step.get_step()
447-
);
448-
378+
info!("goto step: {:?}", data.context.step.get_step());
449379
(Some(flow), step)
450380
}
451381
(Some(flow), None) => {
452-
info!(
453-
bot_id = data.client.bot_id.to_string(),
454-
user_id = data.client.user_id.to_string(),
455-
channel_id = data.client.channel_id.to_string(),
456-
flow = data.context.flow.to_string(),
457-
"goto step: {:?}",
458-
data.context.step.get_step()
459-
);
460-
382+
info!("goto step: {:?}", data.context.step.get_step());
461383
(Some(flow), ContextStepInfo::Normal("start".to_owned()))
462384
}
463385
(None, Some(step)) => {
464-
info!(
465-
bot_id = data.client.bot_id.to_string(),
466-
user_id = data.client.user_id.to_string(),
467-
channel_id = data.client.channel_id.to_string(),
468-
flow = data.context.flow.to_string(),
469-
"goto step: {:?}",
470-
data.context.step.get_step()
471-
);
472-
386+
info!("goto step: {:?}", data.context.step.get_step());
473387
(None, step)
474388
}
475389
(None, None) => {
476-
info!(
477-
bot_id = data.client.bot_id.to_string(),
478-
user_id = data.client.user_id.to_string(),
479-
channel_id = data.client.channel_id.to_string(),
480-
flow = data.context.flow.to_string(),
481-
"goto step: {:?}",
482-
data.context.step.get_step()
483-
);
484-
390+
info!("goto step: {:?}", data.context.step.get_step());
485391
(None, ContextStepInfo::Normal("start".to_owned()))
486392
}
487393
};
@@ -492,7 +398,7 @@ async fn manage_switch_bot(
492398
// send message switch bot
493399
send_msg_to_callback_url(data, vec![message], *interaction_order, true);
494400

495-
info!(flow = data.context.flow.to_string(), "switch bot");
401+
info!("switch bot");
496402

497403
db::conversation::set_status_by_id(&data.conversation_id, "CLOSED", db).await?;
498404

@@ -525,6 +431,16 @@ async fn manage_switch_bot(
525431
}
526432

527433
#[allow(clippy::too_many_arguments)]
434+
#[instrument(
435+
name = "csml.manage_internal_goto",
436+
skip_all,
437+
fields(
438+
bot_id = %data.client.bot_id,
439+
user_id = %data.client.user_id,
440+
channel_id = %data.client.channel_id,
441+
flow = %data.context.flow,
442+
),
443+
)]
528444
async fn manage_internal_goto<'a>(
529445
data: &mut ConversationData,
530446
conversation_end: &mut bool,
@@ -538,57 +454,24 @@ async fn manage_internal_goto<'a>(
538454
) -> Result<InterpreterReturn> {
539455
match (flow, step) {
540456
(Some(flow), Some(step)) => {
541-
debug!(
542-
bot_id = data.client.bot_id.to_string(),
543-
user_id = data.client.user_id.to_string(),
544-
channel_id = data.client.channel_id.to_string(),
545-
flow = data.context.flow.to_string(),
546-
"goto step: {:?}",
547-
data.context.step.get_step()
548-
);
549-
457+
debug!("goto step: {:?}", data.context.step.get_step());
550458
update_current_context(data, memories)?;
551459
goto_flow(data, interaction_order, current_flow, bot, flow, step, db).await?
552460
}
553461
(Some(flow), None) => {
554-
debug!(
555-
bot_id = data.client.bot_id.to_string(),
556-
user_id = data.client.user_id.to_string(),
557-
channel_id = data.client.channel_id.to_string(),
558-
flow = data.context.flow.to_string(),
559-
"goto step: {:?}",
560-
data.context.step.get_step()
561-
);
562-
462+
debug!("goto step: {:?}", data.context.step.get_step());
563463
update_current_context(data, memories)?;
564464
let step = ContextStepInfo::Normal("start".to_owned());
565-
566465
goto_flow(data, interaction_order, current_flow, bot, flow, step, db).await?
567466
}
568467
(None, Some(step)) => {
569-
debug!(
570-
bot_id = data.client.bot_id.to_string(),
571-
user_id = data.client.user_id.to_string(),
572-
channel_id = data.client.channel_id.to_string(),
573-
flow = data.context.flow.to_string(),
574-
"goto step: {:?}",
575-
data.context.step.get_step()
576-
);
577-
468+
debug!("goto step: {:?}", data.context.step.get_step());
578469
if goto_step(data, conversation_end, interaction_order, step, db).await? {
579470
return Ok(InterpreterReturn::End);
580471
}
581472
}
582473
(None, None) => {
583-
debug!(
584-
bot_id = data.client.bot_id.to_string(),
585-
user_id = data.client.user_id.to_string(),
586-
channel_id = data.client.channel_id.to_string(),
587-
flow = data.context.flow.to_string(),
588-
"goto end: {:?}",
589-
data.context.step.get_step()
590-
);
591-
474+
debug!("goto end: {:?}", data.context.step.get_step());
592475
let step = ContextStepInfo::Normal("end".to_owned());
593476
if goto_step(data, conversation_end, interaction_order, step, db).await? {
594477
return Ok(InterpreterReturn::End);

0 commit comments

Comments
 (0)