1use crate::attached::AttachedLines;
2use crate::decode::truncate_at_char_boundary;
3use crate::level::LogLevel;
4use crate::line::{
5 is_date_at, is_log_header_at, is_uuid_at, parse_line, LineKind, UUID_PREFIX_LEN,
6};
7use crate::message::{classify_message, MessageKind, SdpDirection};
8use std::collections::VecDeque;
9
10#[derive(Debug, Clone, PartialEq, Eq)]
15#[non_exhaustive]
16pub enum Block {
17 ChannelData {
20 fields: Vec<(String, String)>,
21 variables: Vec<(String, String)>,
22 },
23 Sdp {
25 direction: SdpDirection,
26 body: Vec<String>,
27 },
28 CodecNegotiation {
30 comparisons: Vec<(String, String)>,
31 selected: Vec<String>,
32 },
33}
34
35#[derive(Debug, Clone, Copy, PartialEq, Eq)]
39pub enum UnclassifiedTracking {
40 CountOnly,
42 TrackLines,
44 CaptureData,
46}
47
48#[derive(Debug, Clone, PartialEq, Eq)]
50#[non_exhaustive]
51pub enum UnclassifiedReason {
52 OrphanContinuation,
54 UnknownMessageFormat,
56 TruncatedField,
58}
59
60#[derive(Debug, Clone, PartialEq, Eq)]
62pub struct UnclassifiedLine {
63 pub line_number: u64,
64 pub reason: UnclassifiedReason,
65 pub data: Option<String>,
67}
68
69#[derive(Debug, Clone, Default)]
71pub struct ParseStats {
72 pub lines_processed: u64,
73 pub lines_unclassified: u64,
74 pub lines_in_entries: u64,
76 pub lines_empty_orphan: u64,
78 pub lines_split: u64,
81 pub unclassified_lines: Vec<UnclassifiedLine>,
83}
84
85impl ParseStats {
86 pub fn unaccounted_lines(&self) -> u64 {
93 let expected = self.lines_in_entries + self.lines_empty_orphan;
94 let actual = self.lines_processed + self.lines_split;
95 actual.saturating_sub(expected)
96 }
97}
98
99#[derive(Debug)]
105pub struct LogEntry {
106 pub uuid: String,
108 pub timestamp: String,
110 pub level: Option<LogLevel>,
112 pub idle_pct: Option<String>,
114 pub source: Option<String>,
116 pub message: String,
118 pub kind: LineKind,
120 pub message_kind: MessageKind,
122 pub block: Option<Block>,
124 pub attached: AttachedLines,
126 pub line_number: u64,
128 pub warnings: Vec<String>,
130}
131
132fn parse_field_line(msg: &str) -> Option<(String, String)> {
133 let colon = msg.find(": ")?;
134 let name = &msg[..colon];
135 if name.contains(' ') || name.is_empty() {
136 return None;
137 }
138 let value_part = &msg[colon + 2..];
139 let value = if let Some(inner) = value_part.strip_prefix('[') {
140 inner.strip_suffix(']').unwrap_or(inner)
141 } else {
142 value_part
143 };
144 Some((name.to_string(), value.to_string()))
145}
146
147enum StreamState {
148 Idle,
149 InChannelData {
150 fields: Vec<(String, String)>,
151 variables: Vec<(String, String)>,
152 open_var_name: Option<String>,
153 open_var_value: Option<String>,
154 },
155 InSdp {
156 direction: SdpDirection,
157 body: Vec<String>,
158 },
159 InCodecNegotiation {
160 comparisons: Vec<(String, String)>,
161 selected: Vec<String>,
162 },
163}
164
165impl StreamState {
166 fn take_idle(&mut self) -> StreamState {
167 std::mem::replace(self, StreamState::Idle)
168 }
169}
170
171pub struct LogStream<I> {
181 lines: I,
182 last_uuid: String,
183 last_timestamp: String,
184 pending: Option<LogEntry>,
185 state: StreamState,
186 stats: ParseStats,
187 tracking: UnclassifiedTracking,
188 line_number: u64,
189 split_pending: VecDeque<String>,
190 deferred_warning: Option<String>,
191}
192
193impl<I: Iterator<Item = String>> LogStream<I> {
194 pub fn new(lines: I) -> Self {
196 LogStream {
197 lines,
198 last_uuid: String::new(),
199 last_timestamp: String::new(),
200 pending: None,
201 state: StreamState::Idle,
202 stats: ParseStats::default(),
203 tracking: UnclassifiedTracking::CountOnly,
204 line_number: 0,
205 split_pending: VecDeque::new(),
206 deferred_warning: None,
207 }
208 }
209
210 pub fn unclassified_tracking(mut self, level: UnclassifiedTracking) -> Self {
212 self.tracking = level;
213 self
214 }
215
216 pub fn stats(&self) -> &ParseStats {
218 &self.stats
219 }
220
221 pub fn drain_unclassified(&mut self) -> Vec<UnclassifiedLine> {
225 std::mem::take(&mut self.stats.unclassified_lines)
226 }
227
228 fn record_unclassified(&mut self, reason: UnclassifiedReason, data: Option<&str>) {
229 self.stats.lines_unclassified += 1;
230 match self.tracking {
231 UnclassifiedTracking::CountOnly => {}
232 UnclassifiedTracking::TrackLines => {
233 self.stats.unclassified_lines.push(UnclassifiedLine {
234 line_number: self.line_number,
235 reason,
236 data: None,
237 });
238 }
239 UnclassifiedTracking::CaptureData => {
240 self.stats.unclassified_lines.push(UnclassifiedLine {
241 line_number: self.line_number,
242 reason,
243 data: data.map(|s| s.to_string()),
244 });
245 }
246 }
247 }
248
249 fn finalize_block(&mut self) -> (Option<Block>, Vec<String>) {
250 let mut warnings = Vec::new();
251 match self.state.take_idle() {
252 StreamState::Idle => (None, warnings),
253 StreamState::InChannelData {
254 fields,
255 mut variables,
256 open_var_name,
257 open_var_value,
258 } => {
259 if let (Some(ref name), Some(value)) = (&open_var_name, open_var_value) {
260 warnings.push(format!("unclosed multi-line variable: {name}"));
261 variables.push((name.clone(), value));
262 }
263 (Some(Block::ChannelData { fields, variables }), warnings)
264 }
265 StreamState::InSdp { direction, body } => {
266 (Some(Block::Sdp { direction, body }), warnings)
267 }
268 StreamState::InCodecNegotiation {
269 comparisons,
270 selected,
271 } => (
272 Some(Block::CodecNegotiation {
273 comparisons,
274 selected,
275 }),
276 warnings,
277 ),
278 }
279 }
280
281 fn finalize_pending(&mut self) -> Option<LogEntry> {
282 let (block, warnings) = self.finalize_block();
283 if let Some(ref mut p) = self.pending {
284 p.block = block;
285 p.warnings.extend(warnings);
286 self.stats.lines_in_entries += 1 + p.attached.len() as u64;
287 }
288 self.pending.take()
289 }
290
291 fn start_block_for_message(&mut self, message_kind: &MessageKind) {
292 self.state = match message_kind {
293 MessageKind::ChannelData => StreamState::InChannelData {
294 fields: Vec::new(),
295 variables: Vec::new(),
296 open_var_name: None,
297 open_var_value: None,
298 },
299 MessageKind::SdpMarker { direction } => StreamState::InSdp {
300 direction: direction.clone(),
301 body: Vec::new(),
302 },
303 MessageKind::CodecNegotiation => StreamState::InCodecNegotiation {
304 comparisons: Vec::new(),
305 selected: Vec::new(),
306 },
307 _ => StreamState::Idle,
308 };
309 }
310
311 fn accumulate_codec_entry(&mut self, msg: &str) {
312 let mut warning = None;
313 if let StreamState::InCodecNegotiation {
314 comparisons,
315 selected,
316 } = &mut self.state
317 {
318 let rest = msg.strip_prefix("Audio Codec Compare ").unwrap_or(msg);
319 if rest.contains("is saved as a match") {
320 let codec = rest.find(']').map(|end| &rest[1..end]).unwrap_or(rest);
321 selected.push(codec.to_string());
322 } else if let Some(slash) = rest.find("]/[") {
323 let offered = &rest[1..slash];
324 let local = &rest[slash + 3..rest.len().saturating_sub(1)];
325 comparisons.push((offered.to_string(), local.to_string()));
326 } else {
327 warning = Some(format!(
328 "unrecognized codec negotiation line: {}",
329 truncate_at_char_boundary(msg, 80)
330 ));
331 }
332 }
333 if let (Some(w), Some(ref mut pending)) = (warning, &mut self.pending) {
334 pending.warnings.push(w);
335 }
336 }
337
338 fn accumulate_continuation(&mut self, msg: &str, line: &str) {
339 let msg_kind = classify_message(msg);
340 let mut warning = None;
341 match &mut self.state {
342 StreamState::InChannelData {
343 fields,
344 variables,
345 open_var_name,
346 open_var_value,
347 } => {
348 if let Some(ref mut val) = open_var_value {
349 val.push('\n');
350 val.push_str(msg);
351 if msg.ends_with(']') {
352 let trimmed = val.trim_end_matches(']').to_string();
353 let name = open_var_name.take().unwrap();
354 *open_var_value = None;
355 variables.push((name, trimmed));
356 }
357 } else {
358 match &msg_kind {
359 MessageKind::ChannelField { name, value } => {
360 fields.push((name.clone(), value.clone()));
361 }
362 MessageKind::Variable { name, value } => {
363 if !msg.ends_with(']') && msg.contains(": [") {
364 *open_var_name = Some(name.clone());
365 *open_var_value = Some(value.clone());
366 } else {
367 variables.push((name.clone(), value.clone()));
368 }
369 }
370 _ => {
371 if let Some((name, value)) = parse_field_line(msg) {
372 fields.push((name, value));
373 } else {
374 warning = Some(format!(
375 "unparseable CHANNEL_DATA line: {}",
376 truncate_at_char_boundary(msg, 80)
377 ));
378 }
379 }
380 }
381 }
382 }
383 StreamState::InSdp { body, .. } => {
384 body.push(msg.to_string());
385 }
386 StreamState::InCodecNegotiation { .. } => {
387 warning = Some(format!(
388 "unexpected codec negotiation continuation: {}",
389 truncate_at_char_boundary(msg, 80)
390 ));
391 }
392 StreamState::Idle => {}
393 }
394 if let Some(ref mut pending) = self.pending {
395 if let Some(w) = warning {
396 pending.warnings.push(w);
397 }
398 pending.attached.push(line);
399 }
400 }
401
402 fn new_entry(
403 &mut self,
404 uuid: String,
405 timestamp: String,
406 message: String,
407 kind: LineKind,
408 message_kind: MessageKind,
409 ) -> LogEntry {
410 let mut warnings = Vec::new();
411 if let Some(w) = self.deferred_warning.take() {
412 warnings.push(w);
413 }
414 LogEntry {
415 uuid,
416 timestamp,
417 message,
418 kind,
419 message_kind,
420 level: None,
421 idle_pct: None,
422 source: None,
423 block: None,
424 attached: AttachedLines::new(),
425 line_number: self.line_number,
426 warnings,
427 }
428 }
429}
430
431const MOD_LOGFILE_BUF_SIZE: usize = 2048;
435
436const MAX_LINE_PAYLOAD: usize = MOD_LOGFILE_BUF_SIZE - UUID_PREFIX_LEN - 1;
439
440const COLLISION_SCAN_SLACK: usize = 64;
446
447impl<I: Iterator<Item = String>> LogStream<I> {
448 fn detect_collision(&mut self, line: String) -> String {
466 if line.len() > MAX_LINE_PAYLOAD {
467 let warning = format!(
468 "line exceeds mod_logfile 2048-byte buffer ({} bytes), data may be truncated",
469 line.len() + 38,
470 );
471 if let Some(ref mut pending) = self.pending {
472 pending.warnings.push(warning);
473 } else {
474 self.deferred_warning = Some(warning);
475 }
476 }
477
478 let bytes = line.as_bytes();
480 let min_scan = if is_uuid_at(bytes, 0) {
481 if bytes.len() > UUID_PREFIX_LEN && bytes[UUID_PREFIX_LEN].is_ascii_digit() {
482 64 } else {
484 UUID_PREFIX_LEN }
486 } else if is_date_at(bytes, 0) {
487 27 } else {
489 0
490 };
491
492 let end = bytes.len().saturating_sub(28);
493 let oversize = bytes.len() > MAX_LINE_PAYLOAD;
494
495 let mut splits: Vec<usize> = Vec::new();
515 let mut chunk_start = 0usize;
516 let mut offset = min_scan;
517 while offset <= end {
518 if is_log_header_at(bytes, offset) {
519 let split_at = if offset >= chunk_start + UUID_PREFIX_LEN
520 && is_uuid_at(bytes, offset - UUID_PREFIX_LEN)
521 {
522 offset - UUID_PREFIX_LEN
523 } else {
524 offset
525 };
526 if split_at > chunk_start {
527 splits.push(split_at);
528 chunk_start = split_at;
529 offset += 27;
530 } else {
531 offset = (offset + 27).max(offset + 1);
536 }
537 continue;
538 }
539 if oversize {
540 let boundary = chunk_start + MAX_LINE_PAYLOAD;
541 if offset + COLLISION_SCAN_SLACK >= boundary
542 && offset <= boundary + COLLISION_SCAN_SLACK
543 && is_uuid_at(bytes, offset)
544 {
545 splits.push(offset);
546 chunk_start = offset;
547 offset += UUID_PREFIX_LEN;
548 continue;
549 }
550 }
551 offset += 1;
552 }
553
554 if splits.is_empty() {
555 return line;
556 }
557
558 let mut tail = line;
561 let mut chunks: Vec<String> = Vec::with_capacity(splits.len());
562 for &at in splits.iter().rev() {
563 chunks.push(tail.split_off(at));
564 }
565 chunks.reverse();
566 self.split_pending.extend(chunks);
567 tail
568 }
569}
570
571impl<I: Iterator<Item = String>> Iterator for LogStream<I> {
572 type Item = LogEntry;
573
574 fn next(&mut self) -> Option<LogEntry> {
575 loop {
576 let line = if let Some(split) = self.split_pending.pop_front() {
577 self.stats.lines_split += 1;
578 split
582 } else {
583 let Some(line) = self.lines.next() else {
584 return self.finalize_pending();
585 };
586
587 if line.starts_with('\x00') {
588 let yielded = self.finalize_pending();
589 self.last_uuid.clear();
590 self.last_timestamp.clear();
591 if yielded.is_some() {
592 return yielded;
593 }
594 continue;
595 }
596
597 self.line_number += 1;
598 self.stats.lines_processed += 1;
599 self.detect_collision(line)
600 };
601
602 let parsed = parse_line(&line);
603
604 match parsed.kind {
605 LineKind::Full | LineKind::System | LineKind::Truncated => {
606 let uuid = parsed.uuid.unwrap_or("").to_string();
607 let message_kind = classify_message(parsed.message);
608
609 if message_kind == MessageKind::CodecNegotiation {
611 if let (Some(ref pending), StreamState::InCodecNegotiation { .. }) =
612 (&self.pending, &self.state)
613 {
614 if uuid == pending.uuid {
615 self.accumulate_codec_entry(parsed.message);
616 if let Some(ref mut p) = self.pending {
617 p.attached.push(&line);
618 }
619 continue;
620 }
621 }
622 }
623
624 let yielded = self.finalize_pending();
625
626 let timestamp = parsed
627 .timestamp
628 .map(|t| t.to_string())
629 .unwrap_or_else(|| self.last_timestamp.clone());
630
631 if !uuid.is_empty() {
632 self.last_uuid = uuid.clone();
633 }
634 if parsed.timestamp.is_some() {
635 self.last_timestamp = timestamp.clone();
636 }
637
638 self.start_block_for_message(&message_kind);
639 if message_kind == MessageKind::CodecNegotiation {
640 self.accumulate_codec_entry(parsed.message);
641 }
642
643 let mut entry = self.new_entry(
644 uuid,
645 timestamp,
646 parsed.message.to_string(),
647 parsed.kind,
648 message_kind,
649 );
650 entry.level = parsed.level;
651 entry.idle_pct = parsed.idle_pct.map(|s| s.to_string());
652 entry.source = parsed.source.map(|s| s.to_string());
653 self.pending = Some(entry);
654
655 if yielded.is_some() {
656 return yielded;
657 }
658 }
659
660 LineKind::UuidContinuation => {
661 let uuid = parsed.uuid.unwrap_or("").to_string();
662 let is_primary = parsed.message.starts_with("EXECUTE ");
663
664 if let Some(ref pending) = self.pending {
665 if !is_primary && uuid == pending.uuid {
666 self.accumulate_continuation(parsed.message, &line);
667 } else {
668 let yielded = self.finalize_pending();
669 let message_kind = classify_message(parsed.message);
670
671 if !uuid.is_empty() {
672 self.last_uuid = uuid.clone();
673 }
674
675 self.start_block_for_message(&message_kind);
676 self.pending = Some(self.new_entry(
677 uuid,
678 self.last_timestamp.clone(),
679 parsed.message.to_string(),
680 parsed.kind,
681 message_kind,
682 ));
683
684 return yielded;
685 }
686 } else {
687 let message_kind = classify_message(parsed.message);
688
689 if !uuid.is_empty() {
690 self.last_uuid = uuid.clone();
691 }
692
693 self.start_block_for_message(&message_kind);
694 self.pending = Some(self.new_entry(
695 uuid,
696 self.last_timestamp.clone(),
697 parsed.message.to_string(),
698 parsed.kind,
699 message_kind,
700 ));
701 }
702 }
703
704 LineKind::BareContinuation => {
705 if self.pending.is_some() {
706 self.accumulate_continuation(parsed.message, &line);
707 } else {
708 self.record_unclassified(
709 UnclassifiedReason::OrphanContinuation,
710 Some(&line),
711 );
712 let message_kind = classify_message(parsed.message);
713 self.pending = Some(self.new_entry(
714 self.last_uuid.clone(),
715 self.last_timestamp.clone(),
716 parsed.message.to_string(),
717 parsed.kind,
718 message_kind,
719 ));
720 }
721 }
722
723 LineKind::Empty => {
724 if let Some(ref mut pending) = self.pending {
725 pending.attached.push(&line);
726 } else {
727 self.stats.lines_empty_orphan += 1;
728 }
729 }
730 }
731 }
732 }
733}
734
735#[cfg(test)]
736mod tests {
737 use super::*;
738
739 const UUID1: &str = "a1b2c3d4-e5f6-7890-abcd-ef1234567890";
740 const UUID2: &str = "b2c3d4e5-f6a7-8901-bcde-f12345678901";
741
742 fn full_line(uuid: &str, ts: &str, msg: &str) -> String {
743 format!("{uuid} {ts} 95.97% [DEBUG] sofia.c:100 {msg}")
744 }
745
746 const TS1: &str = "2025-01-15 10:30:45.123456";
747 const TS2: &str = "2025-01-15 10:30:46.234567";
748
749 #[test]
752 fn inherits_uuid_for_bare_continuation() {
753 let lines = vec![
754 full_line(UUID1, TS1, "CHANNEL_DATA:"),
755 "variable_foo: [bar]".to_string(),
756 "variable_baz: [qux]".to_string(),
757 ];
758 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
759 assert_eq!(entries.len(), 1);
760 assert_eq!(entries[0].uuid, UUID1);
761 assert_eq!(entries[0].attached.len(), 2);
762 assert_eq!(entries[0].attached.get(0), Some("variable_foo: [bar]"));
763 assert_eq!(entries[0].attached.get(1), Some("variable_baz: [qux]"));
764 }
765
766 #[test]
767 fn inherits_timestamp_for_uuid_continuation() {
768 let lines = vec![
769 full_line(UUID1, TS1, "First"),
770 format!("{UUID2} Channel-State: [CS_EXECUTE]"),
771 ];
772 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
773 assert_eq!(entries.len(), 2);
774 assert_eq!(entries[0].timestamp, TS1);
775 assert_eq!(entries[1].uuid, UUID2);
776 assert_eq!(entries[1].timestamp, TS1);
777 }
778
779 #[test]
780 fn new_full_line_yields_previous() {
781 let lines = vec![
782 full_line(UUID1, TS1, "First"),
783 full_line(UUID2, TS2, "Second"),
784 ];
785 let mut stream = LogStream::new(lines.into_iter());
786 let first = stream.next().unwrap();
787 assert_eq!(first.uuid, UUID1);
788 assert_eq!(first.message, "First");
789 let second = stream.next().unwrap();
790 assert_eq!(second.uuid, UUID2);
791 assert_eq!(second.message, "Second");
792 assert!(stream.next().is_none());
793 }
794
795 #[test]
796 fn channel_data_collected_as_attached() {
797 let lines = vec![
798 full_line(UUID1, TS1, "CHANNEL_DATA:"),
799 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
800 format!("{UUID1} Unique-ID: [{UUID1}]"),
801 "variable_sip_call_id: [test123@192.0.2.1]".to_string(),
802 ];
803 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
804 assert_eq!(entries.len(), 1);
805 assert_eq!(entries[0].message, "CHANNEL_DATA:");
806 assert_eq!(entries[0].attached.len(), 3);
807 }
808
809 #[test]
810 fn sdp_body_collected_as_attached() {
811 let lines = vec![
812 full_line(UUID1, TS1, "Local SDP:"),
813 "v=0".to_string(),
814 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
815 "s=-".to_string(),
816 "c=IN IP4 192.0.2.1".to_string(),
817 "m=audio 10000 RTP/AVP 0".to_string(),
818 ];
819 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
820 assert_eq!(entries.len(), 1);
821 assert_eq!(entries[0].attached.len(), 5);
822 }
823
824 #[test]
825 fn truncated_starts_new_entry() {
826 let lines = vec![
827 full_line(UUID1, TS1, "First"),
828 format!(
829 "varia{UUID2} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 set(x=y)"
830 ),
831 ];
832 let mut stream = LogStream::new(lines.into_iter());
833 let first = stream.next().unwrap();
834 assert_eq!(first.uuid, UUID1);
835 assert_eq!(first.message, "First");
836 let second = stream.next().unwrap();
837 assert_eq!(second.uuid, UUID2);
838 assert_eq!(second.kind, LineKind::Truncated);
839 }
840
841 #[test]
842 fn empty_lines_in_attached() {
843 let lines = vec![
844 full_line(UUID1, TS1, "First"),
845 String::new(),
846 "continuation".to_string(),
847 ];
848 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
849 assert_eq!(entries.len(), 1);
850 assert_eq!(entries[0].attached.len(), 2);
851 assert_eq!(entries[0].attached.get(0), Some(""));
852 assert_eq!(entries[0].attached.get(1), Some("continuation"));
853 }
854
855 #[test]
856 fn system_line_no_uuid() {
857 let lines = vec![format!(
858 "{TS1} 95.97% [INFO] mod_event_socket.c:1772 Event Socket command"
859 )];
860 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
861 assert_eq!(entries.len(), 1);
862 assert_eq!(entries[0].uuid, "");
863 assert_eq!(entries[0].kind, LineKind::System);
864 }
865
866 #[test]
867 fn final_entry_on_exhaustion() {
868 let lines = vec![full_line(UUID1, TS1, "Only entry")];
869 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
870 assert_eq!(entries.len(), 1);
871 assert_eq!(entries[0].message, "Only entry");
872 }
873
874 #[test]
875 fn consecutive_full_lines() {
876 let lines = vec![
877 full_line(UUID1, TS1, "First"),
878 full_line(UUID1, TS2, "Second"),
879 full_line(UUID2, TS1, "Third"),
880 ];
881 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
882 assert_eq!(entries.len(), 3);
883 for entry in &entries {
884 assert!(entry.attached.is_empty());
885 }
886 }
887
888 #[test]
889 fn execute_after_channel_data_same_uuid() {
890 let lines = vec![
891 full_line(UUID1, TS1, "CHANNEL_DATA:"),
892 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
893 format!("{UUID1} variable_sip_call_id: [test@192.0.2.1]"),
894 "variable_foo: [bar]".to_string(),
895 String::new(),
896 String::new(),
897 format!("{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 export(originate_timeout=3600)"),
898 full_line(UUID1, TS2, "EXPORT (export_vars) [originate_timeout]=[3600]"),
899 ];
900 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
901 assert_eq!(entries.len(), 3);
902 assert_eq!(entries[0].message, "CHANNEL_DATA:");
903 assert_eq!(entries[0].attached.len(), 5);
904 assert_eq!(entries[1].message, "EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 export(originate_timeout=3600)");
905 assert_eq!(entries[1].kind, LineKind::UuidContinuation);
906 assert_eq!(
907 entries[2].message,
908 "EXPORT (export_vars) [originate_timeout]=[3600]"
909 );
910 }
911
912 #[test]
913 fn execute_between_full_lines_same_uuid() {
914 let lines = vec![
915 full_line(UUID1, TS1, "CoreSession::setVariable(X-C911P-City, ST GEORGES)"),
916 format!("{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 db(insert/ng_{UUID1}/city/ST GEORGES)"),
917 full_line(UUID1, TS2, "CoreSession::setVariable(X-C911P-Region, SGS)"),
918 ];
919 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
920 assert_eq!(entries.len(), 3);
921 assert_eq!(
922 entries[0].message,
923 "CoreSession::setVariable(X-C911P-City, ST GEORGES)"
924 );
925 assert!(entries[0].attached.is_empty());
926 assert!(entries[1].message.starts_with("EXECUTE "));
927 assert_eq!(entries[1].kind, LineKind::UuidContinuation);
928 assert_eq!(
929 entries[2].message,
930 "CoreSession::setVariable(X-C911P-Region, SGS)"
931 );
932 }
933
934 #[test]
935 fn multiple_execute_between_full_lines() {
936 let lines = vec![
937 full_line(UUID1, TS1, "CoreSession::setVariable(ngcs_call_id, urn:emergency:uid:callid:test)"),
938 format!("{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 db(insert/ng_{UUID1}/call_id/urn:emergency:uid:callid:test)"),
939 format!("{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 db(insert/callid_codecs/urn:emergency:uid:callid:test/PCMU@8000h)"),
940 full_line(UUID1, TS2, "CoreSession::setVariable(ngcs_short_call_id, test)"),
941 ];
942 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
943 assert_eq!(entries.len(), 4);
944 assert!(entries[0].attached.is_empty());
945 assert!(entries[1].message.contains("call_id"));
946 assert!(entries[2].message.contains("callid_codecs"));
947 assert_eq!(
948 entries[3].message,
949 "CoreSession::setVariable(ngcs_short_call_id, test)"
950 );
951 }
952
953 #[test]
954 fn uuid_continuation_different_uuid_yields() {
955 let lines = vec![
956 full_line(UUID1, TS1, "First"),
957 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
958 format!("{UUID2} Dialplan: sofia/internal/+15550001234@192.0.2.1 parsing [public]"),
959 ];
960 let mut stream = LogStream::new(lines.into_iter());
961 let first = stream.next().unwrap();
962 assert_eq!(first.uuid, UUID1);
963 assert_eq!(first.attached.len(), 1);
964 let second = stream.next().unwrap();
965 assert_eq!(second.uuid, UUID2);
966 assert_eq!(
967 second.message,
968 "Dialplan: sofia/internal/+15550001234@192.0.2.1 parsing [public]"
969 );
970 }
971
972 #[test]
975 fn channel_data_block_fields_and_variables() {
976 let lines = vec![
977 full_line(UUID1, TS1, "CHANNEL_DATA:"),
978 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
979 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
980 format!("{UUID1} Unique-ID: [{UUID1}]"),
981 "variable_sip_call_id: [test123@192.0.2.1]".to_string(),
982 "variable_direction: [inbound]".to_string(),
983 ];
984 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
985 assert_eq!(entries.len(), 1);
986 assert_eq!(entries[0].message_kind, MessageKind::ChannelData);
987 let block = entries[0].block.as_ref().expect("should have block");
988 match block {
989 Block::ChannelData { fields, variables } => {
990 assert_eq!(fields.len(), 3);
991 assert_eq!(
992 fields[0],
993 (
994 "Channel-Name".to_string(),
995 "sofia/internal/+15550001234@192.0.2.1".to_string()
996 )
997 );
998 assert_eq!(
999 fields[1],
1000 ("Channel-State".to_string(), "CS_EXECUTE".to_string())
1001 );
1002 assert_eq!(fields[2], ("Unique-ID".to_string(), UUID1.to_string()));
1003 assert_eq!(variables.len(), 2);
1004 assert_eq!(
1005 variables[0],
1006 (
1007 "variable_sip_call_id".to_string(),
1008 "test123@192.0.2.1".to_string()
1009 )
1010 );
1011 assert_eq!(
1012 variables[1],
1013 ("variable_direction".to_string(), "inbound".to_string())
1014 );
1015 }
1016 other => panic!("expected ChannelData block, got {other:?}"),
1017 }
1018 }
1019
1020 #[test]
1021 fn channel_data_multiline_variable_reassembly() {
1022 let lines = vec![
1023 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1024 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
1025 "variable_switch_r_sdp: [v=0".to_string(),
1026 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
1027 "s=-".to_string(),
1028 "c=IN IP4 192.0.2.1".to_string(),
1029 "m=audio 47758 RTP/AVP 0 101".to_string(),
1030 "a=rtpmap:0 PCMU/8000".to_string(),
1031 "]".to_string(),
1032 "variable_direction: [inbound]".to_string(),
1033 ];
1034 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1035 assert_eq!(entries.len(), 1);
1036 let block = entries[0].block.as_ref().expect("should have block");
1037 match block {
1038 Block::ChannelData { fields, variables } => {
1039 assert_eq!(fields.len(), 1);
1040 assert_eq!(variables.len(), 2);
1041 assert_eq!(variables[0].0, "variable_switch_r_sdp");
1042 assert!(variables[0].1.starts_with("v=0\n"));
1043 assert!(variables[0].1.contains("m=audio 47758 RTP/AVP 0 101"));
1044 assert!(!variables[0].1.ends_with(']'));
1045 assert_eq!(
1046 variables[1],
1047 ("variable_direction".to_string(), "inbound".to_string())
1048 );
1049 }
1050 other => panic!("expected ChannelData block, got {other:?}"),
1051 }
1052 assert_eq!(entries[0].attached.len(), 9);
1053 }
1054
1055 #[test]
1056 fn sdp_block_detection() {
1057 let lines = vec![
1058 full_line(UUID1, TS1, "Local SDP:"),
1059 "v=0".to_string(),
1060 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
1061 "s=-".to_string(),
1062 "c=IN IP4 192.0.2.1".to_string(),
1063 "m=audio 10000 RTP/AVP 0".to_string(),
1064 "a=rtpmap:0 PCMU/8000".to_string(),
1065 ];
1066 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1067 assert_eq!(entries.len(), 1);
1068 match &entries[0].message_kind {
1069 MessageKind::SdpMarker { direction } => assert_eq!(*direction, SdpDirection::Local),
1070 other => panic!("expected SdpMarker, got {other:?}"),
1071 }
1072 let block = entries[0].block.as_ref().expect("should have block");
1073 match block {
1074 Block::Sdp { direction, body } => {
1075 assert_eq!(*direction, SdpDirection::Local);
1076 assert_eq!(body.len(), 6);
1077 assert_eq!(body[0], "v=0");
1078 assert_eq!(body[5], "a=rtpmap:0 PCMU/8000");
1079 }
1080 other => panic!("expected Sdp block, got {other:?}"),
1081 }
1082 }
1083
1084 #[test]
1085 fn sdp_block_terminated_by_primary_line() {
1086 let lines = vec![
1087 full_line(UUID1, TS1, "Remote SDP:"),
1088 "v=0".to_string(),
1089 "m=audio 10000 RTP/AVP 0".to_string(),
1090 full_line(UUID1, TS2, "Next event"),
1091 ];
1092 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1093 assert_eq!(entries.len(), 2);
1094 let block = entries[0].block.as_ref().expect("should have block");
1095 match block {
1096 Block::Sdp { direction, body } => {
1097 assert_eq!(*direction, SdpDirection::Remote);
1098 assert_eq!(body.len(), 2);
1099 }
1100 other => panic!("expected Sdp block, got {other:?}"),
1101 }
1102 assert!(entries[1].block.is_none());
1103 }
1104
1105 #[test]
1106 fn sdp_from_uuid_continuation() {
1107 let lines = vec![
1108 format!("{UUID1} Local SDP:"),
1109 format!("{UUID1} v=0"),
1110 format!("{UUID1} o=FreeSWITCH 1234 5678 IN IP4 192.0.2.1"),
1111 format!("{UUID1} s=FreeSWITCH"),
1112 format!("{UUID1} c=IN IP4 192.0.2.1"),
1113 ];
1114 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1115 assert_eq!(entries.len(), 1);
1116 let block = entries[0].block.as_ref().expect("should have block");
1117 match block {
1118 Block::Sdp { direction, body } => {
1119 assert_eq!(*direction, SdpDirection::Local);
1120 assert_eq!(body.len(), 4);
1121 assert_eq!(body[0], "v=0");
1122 }
1123 other => panic!("expected Sdp block, got {other:?}"),
1124 }
1125 }
1126
1127 #[test]
1128 fn channel_data_interrupted_by_different_uuid() {
1129 let lines = vec![
1130 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1131 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
1132 format!("{UUID2} Dialplan: sofia/internal/+15559999999@192.0.2.1 parsing [public]"),
1133 ];
1134 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1135 assert_eq!(entries.len(), 2);
1136 let block = entries[0].block.as_ref().expect("should have block");
1137 match block {
1138 Block::ChannelData { fields, .. } => {
1139 assert_eq!(fields.len(), 1);
1140 }
1141 other => panic!("expected ChannelData, got {other:?}"),
1142 }
1143 }
1144
1145 #[test]
1146 fn no_block_for_non_block_message() {
1147 let lines = vec![full_line(UUID1, TS1, "some random freeswitch log message")];
1148 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1149 assert_eq!(entries.len(), 1);
1150 assert!(entries[0].block.is_none());
1151 assert_eq!(entries[0].message_kind, MessageKind::General);
1152 }
1153
1154 #[test]
1155 fn message_kind_on_execute() {
1156 let lines = vec![
1157 full_line(UUID1, TS1, "First"),
1158 format!("{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 set(foo=bar)"),
1159 ];
1160 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1161 assert_eq!(entries.len(), 2);
1162 match &entries[1].message_kind {
1163 MessageKind::Execute {
1164 application,
1165 arguments,
1166 ..
1167 } => {
1168 assert_eq!(application, "set");
1169 assert_eq!(arguments, "foo=bar");
1170 }
1171 other => panic!("expected Execute, got {other:?}"),
1172 }
1173 }
1174
1175 #[test]
1178 fn stats_lines_processed() {
1179 let lines = vec![
1180 full_line(UUID1, TS1, "First"),
1181 full_line(UUID1, TS2, "Second"),
1182 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
1183 ];
1184 let mut stream = LogStream::new(lines.into_iter());
1185 let _: Vec<_> = stream.by_ref().collect();
1186 assert_eq!(stream.stats().lines_processed, 3);
1187 }
1188
1189 #[test]
1190 fn stats_unclassified_orphan() {
1191 let lines = vec![
1192 "variable_foo: [bar]".to_string(),
1193 full_line(UUID1, TS1, "After orphan"),
1194 ];
1195 let mut stream = LogStream::new(lines.into_iter())
1196 .unclassified_tracking(UnclassifiedTracking::TrackLines);
1197 let _: Vec<_> = stream.by_ref().collect();
1198 assert_eq!(stream.stats().lines_unclassified, 1);
1199 assert_eq!(stream.stats().unclassified_lines.len(), 1);
1200 assert_eq!(
1201 stream.stats().unclassified_lines[0].reason,
1202 UnclassifiedReason::OrphanContinuation,
1203 );
1204 }
1205
1206 #[test]
1207 fn stats_capture_data() {
1208 let lines = vec!["orphan line".to_string(), full_line(UUID1, TS1, "After")];
1209 let mut stream = LogStream::new(lines.into_iter())
1210 .unclassified_tracking(UnclassifiedTracking::CaptureData);
1211 let _: Vec<_> = stream.by_ref().collect();
1212 assert_eq!(stream.stats().unclassified_lines.len(), 1);
1213 assert_eq!(
1214 stream.stats().unclassified_lines[0].data.as_deref(),
1215 Some("orphan line"),
1216 );
1217 }
1218
1219 #[test]
1220 fn stats_count_only_no_allocation() {
1221 let lines = vec!["orphan line".to_string(), full_line(UUID1, TS1, "After")];
1222 let mut stream = LogStream::new(lines.into_iter());
1223 let _: Vec<_> = stream.by_ref().collect();
1224 assert_eq!(stream.stats().lines_unclassified, 1);
1225 assert!(stream.stats().unclassified_lines.is_empty());
1226 }
1227
1228 #[test]
1229 fn line_number_tracking() {
1230 let lines = vec![
1231 full_line(UUID1, TS1, "First"),
1232 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
1233 full_line(UUID2, TS2, "Third"),
1234 ];
1235 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1236 assert_eq!(entries[0].line_number, 1);
1237 assert_eq!(entries[1].line_number, 3);
1238 }
1239
1240 #[test]
1241 fn drain_unclassified() {
1242 let lines = vec![
1243 "orphan1".to_string(),
1244 "orphan2".to_string(),
1245 full_line(UUID1, TS1, "After"),
1246 ];
1247 let mut stream = LogStream::new(lines.into_iter())
1248 .unclassified_tracking(UnclassifiedTracking::TrackLines);
1249 let _: Vec<_> = stream.by_ref().collect();
1250 let drained = stream.drain_unclassified();
1251 assert_eq!(drained.len(), 1);
1252 assert!(stream.stats().unclassified_lines.is_empty());
1253 assert_eq!(stream.stats().lines_unclassified, 1);
1254 }
1255
1256 #[test]
1264 fn continuation_lines_at_file_boundary_must_not_inherit_previous_timestamp() {
1265 use crate::TrackedChain;
1266
1267 let uuid_a = "aaaaaaaa-1111-2222-3333-444444444444";
1268 let uuid_b = "bbbbbbbb-1111-2222-3333-444444444444";
1269 let ts_old = "2025-01-15 23:58:03.000000";
1270 let ts_new = "2025-01-16 08:37:12.000000";
1271
1272 let seg1: Vec<String> = vec![format!(
1273 "{uuid_a} {ts_old} 95.00% [DEBUG] test.c:1 Last line in rotated file"
1274 )];
1275
1276 let seg2: Vec<String> = vec![
1279 format!("{uuid_b} CHANNEL_DATA:"),
1280 format!("{uuid_b} Channel-State: [CS_EXECUTE]"),
1281 format!("{uuid_b} {ts_new} 95.00% [DEBUG] test.c:1 First timestamped line in new file"),
1282 ];
1283
1284 let segments: Vec<(String, Box<dyn Iterator<Item = String>>)> = vec![
1285 ("rotated.log".to_string(), Box::new(seg1.into_iter())),
1286 ("freeswitch.log".to_string(), Box::new(seg2.into_iter())),
1287 ];
1288
1289 let (chain, _) = TrackedChain::new(segments);
1290 let entries: Vec<_> = LogStream::new(chain).collect();
1291
1292 let b_entry = entries
1293 .iter()
1294 .find(|e| e.uuid == uuid_b)
1295 .expect("should find entry for uuid_b");
1296
1297 assert_ne!(
1301 b_entry.timestamp, ts_old,
1302 "continuation lines in a new file segment inherited timestamp \
1303 '{ts_old}' from the previous segment — timestamps must not bleed \
1304 across file boundaries"
1305 );
1306 }
1307
1308 fn assert_accounting(stream: &LogStream<impl Iterator<Item = String>>) {
1311 let stats = stream.stats();
1312 assert_eq!(
1313 stats.unaccounted_lines(),
1314 0,
1315 "line accounting invariant violated: \
1316 processed={} + split={} != in_entries={} + empty_orphan={}",
1317 stats.lines_processed,
1318 stats.lines_split,
1319 stats.lines_in_entries,
1320 stats.lines_empty_orphan,
1321 );
1322 }
1323
1324 #[test]
1325 fn accounting_full_lines() {
1326 let lines = vec![
1327 full_line(UUID1, TS1, "First"),
1328 full_line(UUID2, TS2, "Second"),
1329 ];
1330 let mut stream = LogStream::new(lines.into_iter());
1331 let entries: Vec<_> = stream.by_ref().collect();
1332 assert_eq!(entries.len(), 2);
1333 assert_eq!(stream.stats().lines_in_entries, 2);
1334 assert_accounting(&stream);
1335 }
1336
1337 #[test]
1338 fn accounting_with_attached() {
1339 let lines = vec![
1340 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1341 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
1342 "variable_foo: [bar]".to_string(),
1343 full_line(UUID2, TS2, "Next"),
1344 ];
1345 let mut stream = LogStream::new(lines.into_iter());
1346 let entries: Vec<_> = stream.by_ref().collect();
1347 assert_eq!(entries.len(), 2);
1348 assert_eq!(stream.stats().lines_in_entries, 4);
1351 assert_accounting(&stream);
1352 }
1353
1354 #[test]
1355 fn accounting_system_line() {
1356 let lines = vec![format!(
1357 "{TS1} 95.97% [NOTICE] mod_logfile.c:217 New log started."
1358 )];
1359 let mut stream = LogStream::new(lines.into_iter());
1360 let _: Vec<_> = stream.by_ref().collect();
1361 assert_eq!(stream.stats().lines_in_entries, 1);
1362 assert_accounting(&stream);
1363 }
1364
1365 #[test]
1366 fn accounting_empty_orphan() {
1367 let lines = vec![
1368 String::new(),
1369 " ".to_string(),
1370 full_line(UUID1, TS1, "After"),
1371 ];
1372 let mut stream = LogStream::new(lines.into_iter());
1373 let entries: Vec<_> = stream.by_ref().collect();
1374 assert_eq!(entries.len(), 1);
1375 assert_eq!(stream.stats().lines_empty_orphan, 2);
1376 assert_accounting(&stream);
1377 }
1378
1379 #[test]
1380 fn accounting_empty_attached() {
1381 let lines = vec![
1382 full_line(UUID1, TS1, "First"),
1383 String::new(),
1384 "continuation".to_string(),
1385 ];
1386 let mut stream = LogStream::new(lines.into_iter());
1387 let entries: Vec<_> = stream.by_ref().collect();
1388 assert_eq!(entries.len(), 1);
1389 assert_eq!(entries[0].attached.len(), 2);
1390 assert_eq!(stream.stats().lines_empty_orphan, 0);
1391 assert_eq!(stream.stats().lines_in_entries, 3);
1392 assert_accounting(&stream);
1393 }
1394
1395 #[test]
1396 fn accounting_orphan_continuation() {
1397 let lines = vec!["orphan line".to_string(), full_line(UUID1, TS1, "After")];
1398 let mut stream = LogStream::new(lines.into_iter());
1399 let _: Vec<_> = stream.by_ref().collect();
1400 assert_accounting(&stream);
1401 }
1402
1403 #[test]
1404 fn accounting_codec_merging() {
1405 let lines = vec![
1406 full_line(
1407 UUID1,
1408 TS1,
1409 "Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]",
1410 ),
1411 full_line(
1412 UUID1,
1413 TS1,
1414 "Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a match",
1415 ),
1416 full_line(UUID2, TS2, "Next"),
1417 ];
1418 let mut stream = LogStream::new(lines.into_iter());
1419 let _: Vec<_> = stream.by_ref().collect();
1420 assert_accounting(&stream);
1421 }
1422
1423 #[test]
1424 fn accounting_truncated_line() {
1425 let lines = vec![
1426 full_line(UUID1, TS1, "First"),
1427 format!(
1428 "varia{UUID2} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 set(x=y)"
1429 ),
1430 ];
1431 let mut stream = LogStream::new(lines.into_iter());
1432 let _: Vec<_> = stream.by_ref().collect();
1433 assert_accounting(&stream);
1434 }
1435
1436 #[test]
1437 fn accounting_long_line_collision_split() {
1438 let long_value = "x".repeat(MAX_LINE_PAYLOAD + 10);
1441 let line = format!(
1442 "variable_sip_multipart: [{long_value}]{UUID2} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 set(foo=bar)"
1443 );
1444 let lines = vec![full_line(UUID1, TS1, "CHANNEL_DATA:"), line];
1445 let mut stream = LogStream::new(lines.into_iter());
1446 let entries: Vec<_> = stream.by_ref().collect();
1447
1448 assert_eq!(entries[0].message, "CHANNEL_DATA:");
1450
1451 let split_entry = entries.iter().find(|e| e.uuid == UUID2);
1453 assert!(
1454 split_entry.is_some(),
1455 "collision UUID should produce a separate entry"
1456 );
1457
1458 assert_eq!(stream.stats().lines_split, 1);
1459 assert_accounting(&stream);
1460 }
1461
1462 #[test]
1463 fn no_split_on_short_lines() {
1464 let line = format!("variable_call_uuid: [{UUID2}]");
1467 let lines = vec![full_line(UUID1, TS1, "CHANNEL_DATA:"), line];
1468 let mut stream = LogStream::new(lines.into_iter());
1469 let entries: Vec<_> = stream.by_ref().collect();
1470 assert_eq!(entries.len(), 1);
1471 assert_eq!(stream.stats().lines_split, 0);
1472 assert_accounting(&stream);
1473 }
1474
1475 #[test]
1476 fn timestamp_collision_splits_system_lines() {
1477 let line = format!(
1478 "{TS1} 98.03% [INFO] mod_event_socket.c:1752 Event Socket Command from ::1:42864: api sofia jsonstatus{TS2} 97.93% [INFO] mod_event_socket.c:1752 Event Socket Command from ::1:42898: api fsctl pause_check"
1479 );
1480 let mut stream = LogStream::new(std::iter::once(line));
1481 let entries: Vec<_> = stream.by_ref().collect();
1482 assert_eq!(entries.len(), 2);
1483 assert_eq!(
1484 entries[0].message,
1485 "Event Socket Command from ::1:42864: api sofia jsonstatus"
1486 );
1487 assert_eq!(
1488 entries[1].message,
1489 "Event Socket Command from ::1:42898: api fsctl pause_check"
1490 );
1491 assert_eq!(stream.stats().lines_split, 1);
1492 assert_accounting(&stream);
1493 }
1494
1495 #[test]
1496 fn timestamp_collision_splits_three_entries() {
1497 let ts3 = "2025-01-15 10:30:47.345678";
1498 let line = format!(
1499 "{TS1} 95.00% [INFO] mod.c:1 first{TS2} 96.00% [INFO] mod.c:1 second{ts3} 97.00% [INFO] mod.c:1 third"
1500 );
1501 let mut stream = LogStream::new(std::iter::once(line));
1502 let entries: Vec<_> = stream.by_ref().collect();
1503 assert_eq!(entries.len(), 3);
1504 assert_eq!(entries[0].message, "first");
1505 assert_eq!(entries[1].message, "second");
1506 assert_eq!(entries[2].message, "third");
1507 assert_eq!(stream.stats().lines_split, 2);
1508 assert_accounting(&stream);
1509 }
1510
1511 #[test]
1512 fn timestamp_collision_oversize_write_contention() {
1513 let entry = |n: usize| {
1519 format!(
1520 "{TS1} 98.77% [INFO] mod_event_socket.c:1754 Event Socket Command from ::1:42864: api db select/ngcs_sip_call_id/entry-{n:04}"
1521 )
1522 };
1523 let count: u64 = 20;
1524 let line: String = (0..count).map(|n| entry(n as usize)).collect();
1525 assert!(
1526 line.len() > super::MAX_LINE_PAYLOAD,
1527 "test fixture should exceed MAX_LINE_PAYLOAD, got {}",
1528 line.len()
1529 );
1530
1531 let mut stream = LogStream::new(std::iter::once(line));
1532 let entries: Vec<_> = stream.by_ref().collect();
1533 assert_eq!(entries.len() as u64, count);
1534 for (i, e) in entries.iter().enumerate() {
1535 assert_eq!(
1536 e.message,
1537 format!(
1538 "Event Socket Command from ::1:42864: api db select/ngcs_sip_call_id/entry-{i:04}"
1539 )
1540 );
1541 }
1542 assert_eq!(stream.stats().lines_split, count - 1);
1543 assert_accounting(&stream);
1544 }
1545
1546 #[test]
1547 fn timestamp_collision_with_uuid_prefix() {
1548 let line = format!(
1550 "{TS1} 95.00% [INFO] mod.c:1 first{UUID1} {TS2} 96.00% [DEBUG] sofia.c:100 second"
1551 );
1552 let mut stream = LogStream::new(std::iter::once(line));
1553 let entries: Vec<_> = stream.by_ref().collect();
1554 assert_eq!(entries.len(), 2);
1555 assert_eq!(entries[0].message, "first");
1556 assert_eq!(entries[1].uuid, UUID1);
1557 assert_eq!(entries[1].message, "second");
1558 assert_eq!(stream.stats().lines_split, 1);
1559 assert_accounting(&stream);
1560 }
1561
1562 #[test]
1566 fn timestamp_collision_no_idle_pct_system() {
1567 let line = format!(
1568 "{TS1} [WARNING] sofia_presence.c:4546 Session does not exist, aborting REFER.{TS2} [WARNING] sofia_presence.c:4546 Session does not exist, aborting REFER."
1569 );
1570 let mut stream = LogStream::new(std::iter::once(line));
1571 let entries: Vec<_> = stream.by_ref().collect();
1572 assert_eq!(entries.len(), 2);
1573 assert_eq!(
1574 entries[0].message,
1575 "Session does not exist, aborting REFER."
1576 );
1577 assert_eq!(
1578 entries[1].message,
1579 "Session does not exist, aborting REFER."
1580 );
1581 assert_eq!(stream.stats().lines_split, 1);
1582 assert_accounting(&stream);
1583 }
1584
1585 #[test]
1586 fn timestamp_collision_no_idle_pct_uuid_suffix() {
1587 let line = format!(
1590 "{TS1} [WARNING] sofia_presence.c:4546 Session does not exist, aborting REFER.{UUID1} {TS2} [NOTICE] sofia.c:1114 Hangup sofia/internal/sos@192.0.2.10:5080 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]"
1591 );
1592 let mut stream = LogStream::new(std::iter::once(line));
1593 let entries: Vec<_> = stream.by_ref().collect();
1594 assert_eq!(entries.len(), 2);
1595 assert_eq!(entries[0].uuid, "");
1596 assert_eq!(
1597 entries[0].message,
1598 "Session does not exist, aborting REFER."
1599 );
1600 assert_eq!(entries[1].uuid, UUID1);
1601 assert_eq!(entries[1].level, Some(LogLevel::Notice));
1602 assert_eq!(
1603 entries[1].message,
1604 "Hangup sofia/internal/sos@192.0.2.10:5080 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]"
1605 );
1606 assert_eq!(stream.stats().lines_split, 1);
1607 assert_accounting(&stream);
1608 }
1609
1610 #[test]
1611 fn timestamp_collision_no_idle_pct_run_on() {
1612 let count: u64 = 15;
1614 let line: String = (0..count)
1615 .map(|n| {
1616 format!(
1617 "2024-04-02 10:31:{:02}.945614 [WARNING] sofia_presence.c:4546 Session does not exist, aborting REFER.",
1618 n + 10
1619 )
1620 })
1621 .collect();
1622 let mut stream = LogStream::new(std::iter::once(line));
1623 let entries: Vec<_> = stream.by_ref().collect();
1624 assert_eq!(entries.len() as u64, count);
1625 for e in &entries {
1626 assert_eq!(e.message, "Session does not exist, aborting REFER.");
1627 }
1628 assert_eq!(stream.stats().lines_split, count - 1);
1629 assert_accounting(&stream);
1630 }
1631
1632 #[test]
1633 fn channel_data_multiline_variable_spans_many_lines() {
1634 let lines = vec![
1635 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1636 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
1637 "variable_switch_r_sdp: [v=0".to_string(),
1638 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
1639 "s=-".to_string(),
1640 "c=IN IP4 192.0.2.1".to_string(),
1641 "t=0 0".to_string(),
1642 "m=audio 47758 RTP/AVP 0 8 101".to_string(),
1643 "a=rtpmap:0 PCMU/8000".to_string(),
1644 "a=rtpmap:8 PCMA/8000".to_string(),
1645 "a=rtpmap:101 telephone-event/8000".to_string(),
1646 "a=fmtp:101 0-16".to_string(),
1647 "]".to_string(),
1648 "variable_direction: [inbound]".to_string(),
1649 ];
1650 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1651 assert_eq!(entries.len(), 1);
1652 let block = entries[0].block.as_ref().expect("should have block");
1653 match block {
1654 Block::ChannelData { fields, variables } => {
1655 assert_eq!(fields.len(), 1);
1656 assert_eq!(variables.len(), 2);
1657 assert_eq!(variables[0].0, "variable_switch_r_sdp");
1658 let sdp = &variables[0].1;
1659 assert!(sdp.starts_with("v=0\n"));
1660 assert!(sdp.contains("a=fmtp:101 0-16"));
1661 assert!(!sdp.ends_with(']'));
1662 assert_eq!(variables[1].0, "variable_direction");
1663 }
1664 other => panic!("expected ChannelData block, got {other:?}"),
1665 }
1666 }
1667
1668 #[test]
1669 fn sdp_from_verto_update_media() {
1670 let lines = vec![
1671 full_line(UUID1, TS1, "updateMedia: Local SDP"),
1672 "v=0".to_string(),
1673 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
1674 "m=audio 10000 RTP/AVP 0".to_string(),
1675 ];
1676 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1677 assert_eq!(entries.len(), 1);
1678 match &entries[0].message_kind {
1679 MessageKind::SdpMarker { direction } => assert_eq!(*direction, SdpDirection::Local),
1680 other => panic!("expected SdpMarker, got {other:?}"),
1681 }
1682 let block = entries[0].block.as_ref().expect("should have block");
1683 match block {
1684 Block::Sdp { direction, body } => {
1685 assert_eq!(*direction, SdpDirection::Local);
1686 assert_eq!(body.len(), 3);
1687 }
1688 other => panic!("expected Sdp block, got {other:?}"),
1689 }
1690 }
1691
1692 #[test]
1693 fn duplicate_sdp_marker() {
1694 let lines = vec![
1695 full_line(UUID1, TS1, "Duplicate SDP"),
1696 "v=0".to_string(),
1697 "m=audio 10000 RTP/AVP 0".to_string(),
1698 ];
1699 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1700 assert_eq!(entries.len(), 1);
1701 match &entries[0].message_kind {
1702 MessageKind::SdpMarker { direction } => assert_eq!(*direction, SdpDirection::Unknown),
1703 other => panic!("expected SdpMarker, got {other:?}"),
1704 }
1705 assert!(entries[0].block.is_some());
1706 }
1707
1708 #[test]
1709 fn warning_on_unclosed_multiline_variable() {
1710 let lines = vec![
1711 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1712 "variable_switch_r_sdp: [v=0".to_string(),
1713 "o=- 1234 5678 IN IP4 192.0.2.1".to_string(),
1714 full_line(UUID2, TS2, "Next entry"),
1715 ];
1716 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1717 assert_eq!(entries.len(), 2);
1718 assert!(
1719 entries[0]
1720 .warnings
1721 .iter()
1722 .any(|w| w.contains("unclosed multi-line variable")),
1723 "expected unclosed variable warning, got: {:?}",
1724 entries[0].warnings
1725 );
1726 }
1727
1728 #[test]
1729 fn warning_on_unparseable_channel_data_line() {
1730 let lines = vec![
1731 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1732 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
1733 format!("{UUID1} this is not a valid field line"),
1734 ];
1735 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1736 assert_eq!(entries.len(), 1);
1737 assert!(
1738 entries[0]
1739 .warnings
1740 .iter()
1741 .any(|w| w.contains("unparseable CHANNEL_DATA")),
1742 "expected unparseable warning, got: {:?}",
1743 entries[0].warnings
1744 );
1745 }
1746
1747 #[test]
1748 fn warning_on_unexpected_codec_continuation() {
1749 let lines = vec![
1750 full_line(
1751 UUID1,
1752 TS1,
1753 "Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]",
1754 ),
1755 format!("{UUID1} some unexpected continuation line"),
1756 ];
1757 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1758 assert_eq!(entries.len(), 1);
1759 assert!(
1760 entries[0]
1761 .warnings
1762 .iter()
1763 .any(|w| w.contains("unexpected codec negotiation")),
1764 "expected codec warning, got: {:?}",
1765 entries[0].warnings
1766 );
1767 }
1768
1769 #[test]
1770 fn system_line_uuid_continuation_not_absorbed() {
1771 let lines = vec![
1774 format!("{TS1} 95.97% [INFO] mod_event_socket.c:1772 Event Socket command"),
1775 format!("{UUID1} Channel-State: [CS_EXECUTE]"),
1776 ];
1777 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1778 assert_eq!(
1779 entries.len(),
1780 2,
1781 "UUID continuation should not be absorbed by system entry"
1782 );
1783 assert_eq!(entries[0].uuid, "");
1784 assert_eq!(entries[1].uuid, UUID1);
1785 }
1786
1787 #[test]
1788 fn truncated_collision_in_channel_data_variable() {
1789 let padding = "x".repeat(2000);
1795 let collision_line = format!(
1796 "{UUID1} variable_long_xml: [{padding}{UUID1} EXECUTE [depth=0] sofia/internal/+15550001234@192.0.2.1 export(foo=bar)"
1797 );
1798 assert!(
1799 collision_line.len() > super::MAX_LINE_PAYLOAD,
1800 "test line must exceed buffer limit, got {}",
1801 collision_line.len()
1802 );
1803
1804 let lines = vec![
1805 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1806 format!("{UUID1} Channel-Name: [sofia/internal/+15550001234@192.0.2.1]"),
1807 format!("{UUID1} variable_direction: [inbound]"),
1808 collision_line,
1809 full_line(UUID1, TS2, "Next log entry"),
1810 ];
1811
1812 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
1813
1814 assert_eq!(entries[0].message, "CHANNEL_DATA:");
1816 let block = entries[0].block.as_ref().expect("should have block");
1817 match block {
1818 Block::ChannelData { fields, variables } => {
1819 assert_eq!(fields.len(), 1, "should have Channel-Name field");
1820 assert_eq!(fields[0].0, "Channel-Name");
1821 assert_eq!(
1822 variables.len(),
1823 2,
1824 "should have direction + unclosed long_xml"
1825 );
1826 assert_eq!(variables[0].0, "variable_direction");
1827 assert_eq!(variables[0].1, "inbound");
1828 assert_eq!(variables[1].0, "variable_long_xml");
1829 }
1830 other => panic!("expected ChannelData block, got {other:?}"),
1831 }
1832 assert!(
1833 entries[0]
1834 .warnings
1835 .iter()
1836 .any(|w| w.contains("line exceeds mod_logfile 2048-byte buffer")),
1837 "expected buffer overflow warning, got: {:?}",
1838 entries[0].warnings
1839 );
1840 assert!(
1841 entries[0]
1842 .warnings
1843 .iter()
1844 .any(|w| w.contains("unclosed multi-line variable")),
1845 "expected unclosed variable warning, got: {:?}",
1846 entries[0].warnings
1847 );
1848
1849 assert_eq!(entries[1].uuid, UUID1);
1851 assert!(
1852 entries[1].message.starts_with("EXECUTE "),
1853 "split entry should be EXECUTE, got: {}",
1854 entries[1].message
1855 );
1856
1857 assert_eq!(entries.len(), 3);
1859 assert_eq!(entries[2].message, "Next log entry");
1860 }
1861
1862 #[test]
1863 fn channel_data_uuid_drops_mid_block() {
1864 let lines = vec![
1869 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1870 format!("{UUID1} variable_max_forwards: [69]"),
1871 format!("{UUID1} variable_presence_id: [1251@[2001:db8::10]]"),
1872 format!("{UUID1} variable_sip_h_X-Custom-ID: [c4da84eb-88a7-40b2-b90d-e5bc2a0f634e]"),
1873 "variable_sip_h_X-Call-Info: [<urn:test:callid:20260316>;purpose=emergency-CallId]"
1875 .to_string(),
1876 "variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c]".to_string(),
1877 "variable_remote_media_ip: [2001:db8::10]".to_string(),
1878 "variable_remote_media_port: [9952]".to_string(),
1879 "variable_rtp_use_codec_name: [opus]".to_string(),
1880 full_line(UUID1, TS2, "Next entry"),
1881 ];
1882
1883 let mut stream = LogStream::new(lines.into_iter());
1884 let entries: Vec<_> = stream.by_ref().collect();
1885
1886 assert_eq!(entries.len(), 2);
1887 assert_eq!(entries[0].message, "CHANNEL_DATA:");
1888 let block = entries[0].block.as_ref().expect("should have block");
1889 match block {
1890 Block::ChannelData { fields, variables } => {
1891 assert_eq!(fields.len(), 0);
1892 assert_eq!(variables.len(), 8);
1893 assert_eq!(variables[0].0, "variable_max_forwards");
1895 assert_eq!(variables[0].1, "69");
1896 assert_eq!(variables[1].0, "variable_presence_id");
1897 assert_eq!(variables[1].1, "1251@[2001:db8::10]");
1898 assert_eq!(variables[2].0, "variable_sip_h_X-Custom-ID");
1899 assert_eq!(variables[3].0, "variable_sip_h_X-Call-Info");
1901 assert!(variables[3].1.contains("emergency-CallId"));
1902 assert_eq!(variables[4].0, "variable_ep_codec_string");
1903 assert_eq!(variables[7].0, "variable_rtp_use_codec_name");
1904 assert_eq!(variables[7].1, "opus");
1905 }
1906 other => panic!("expected ChannelData block, got {other:?}"),
1907 }
1908 assert_eq!(entries[0].attached.len(), 8);
1909 assert_eq!(entries[1].message, "Next entry");
1910 assert_accounting(&stream);
1911 }
1912
1913 #[test]
1914 fn channel_data_uuid_drops_with_multiline_variable() {
1915 let lines = vec![
1920 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1921 format!("{UUID1} variable_max_forwards: [69]"),
1922 format!("{UUID1} variable_sip_h_X-Custom-ID: [c4da84eb-88a7-40b2-b90d-e5bc2a0f634e]"),
1923 "variable_switch_r_sdp: [v=0\r".to_string(),
1925 "o=FreeSWITCH 1773663549 1773663550 IN IP6 2001:db8::10\r".to_string(),
1926 "s=FreeSWITCH\r".to_string(),
1927 "c=IN IP6 2001:db8::10\r".to_string(),
1928 "t=0 0\r".to_string(),
1929 "m=audio 9952 RTP/AVP 102 101 13\r".to_string(),
1930 "a=rtpmap:102 opus/48000/2\r".to_string(),
1931 "a=ptime:20\r".to_string(),
1932 "]".to_string(),
1933 "variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c]".to_string(),
1934 "variable_direction: [inbound]".to_string(),
1935 full_line(UUID1, TS2, "Next entry"),
1936 ];
1937
1938 let mut stream = LogStream::new(lines.into_iter());
1939 let entries: Vec<_> = stream.by_ref().collect();
1940
1941 assert_eq!(entries.len(), 2);
1942 let block = entries[0].block.as_ref().expect("should have block");
1943 match block {
1944 Block::ChannelData { fields, variables } => {
1945 assert_eq!(fields.len(), 0);
1946 assert_eq!(variables.len(), 5);
1947 assert_eq!(variables[0].0, "variable_max_forwards");
1948 assert_eq!(variables[1].0, "variable_sip_h_X-Custom-ID");
1949 assert_eq!(variables[2].0, "variable_switch_r_sdp");
1951 let sdp = &variables[2].1;
1952 assert!(
1953 sdp.starts_with("v=0\r\n"),
1954 "SDP should start with v=0\\r\\n, got: {sdp:?}"
1955 );
1956 assert!(sdp.contains("m=audio 9952 RTP/AVP 102 101 13\r"));
1957 assert!(sdp.contains("a=ptime:20\r"));
1958 assert!(!sdp.ends_with(']'), "closing bracket should be stripped");
1959 assert_eq!(variables[3].0, "variable_ep_codec_string");
1961 assert_eq!(variables[4].0, "variable_direction");
1962 assert_eq!(variables[4].1, "inbound");
1963 }
1964 other => panic!("expected ChannelData block, got {other:?}"),
1965 }
1966 assert_eq!(entries[0].attached.len(), 13);
1968 assert_accounting(&stream);
1969 }
1970
1971 #[test]
1972 fn channel_data_bare_variable_collision_with_execute() {
1973 let collision = format!(
1980 "variable_call_uuid: {UUID1} EXECUTE [depth=0] \
1981 sofia/internal-v6/1251@[2001:db8::10] export(nolocal:test_var=value)"
1982 );
1983
1984 let lines = vec![
1985 full_line(UUID1, TS1, "CHANNEL_DATA:"),
1986 format!("{UUID1} variable_max_forwards: [69]"),
1987 "variable_DP_MATCH: [ARRAY::create_conference|:create_conference]".to_string(),
1989 collision,
1990 full_line(
1992 UUID1,
1993 TS2,
1994 "EXPORT (export_vars) (REMOTE ONLY) [test_var]=[value]",
1995 ),
1996 ];
1997
1998 let mut stream = LogStream::new(lines.into_iter());
1999 let entries: Vec<_> = stream.by_ref().collect();
2000
2001 assert_eq!(entries.len(), 3);
2003 let block = entries[0].block.as_ref().expect("should have block");
2004 match block {
2005 Block::ChannelData { fields, variables } => {
2006 assert_eq!(fields.len(), 0);
2007 assert_eq!(variables.len(), 2);
2008 assert_eq!(variables[0].0, "variable_max_forwards");
2009 assert_eq!(variables[1].0, "variable_DP_MATCH");
2010 }
2011 other => panic!("expected ChannelData block, got {other:?}"),
2012 }
2013
2014 assert_eq!(entries[1].uuid, UUID1);
2016 assert_eq!(entries[1].kind, LineKind::Truncated);
2017 assert!(
2018 entries[1].message.starts_with("EXECUTE "),
2019 "truncated line should yield EXECUTE, got: {}",
2020 entries[1].message
2021 );
2022
2023 assert_eq!(entries[2].message_kind.label(), "variable");
2025 assert_accounting(&stream);
2026 }
2027
2028 #[test]
2031 fn multibyte_at_warning_truncation_unrecognized_codec() {
2032 let msg = format!(
2034 "Audio Codec Compare {}é tail beyond eighty bytes",
2035 "x".repeat(59)
2036 );
2037 assert!(!msg.is_char_boundary(80));
2038 let lines = vec![
2039 full_line(
2040 UUID1,
2041 TS1,
2042 "Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]",
2043 ),
2044 full_line(UUID1, TS1, &msg),
2045 ];
2046 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
2047 assert_eq!(entries.len(), 1);
2048 assert!(
2049 entries[0]
2050 .warnings
2051 .iter()
2052 .any(|w| w.contains("unrecognized codec negotiation")),
2053 "expected codec warning, got: {:?}",
2054 entries[0].warnings
2055 );
2056 }
2057
2058 #[test]
2059 fn multibyte_at_warning_truncation_channel_data() {
2060 let bare = format!(
2061 "{}é tail beyond eighty bytes with no field separator",
2062 "x".repeat(79)
2063 );
2064 assert!(!bare.is_char_boundary(80));
2065 let lines = vec![full_line(UUID1, TS1, "CHANNEL_DATA:"), bare];
2066 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
2067 assert_eq!(entries.len(), 1);
2068 assert!(
2069 entries[0]
2070 .warnings
2071 .iter()
2072 .any(|w| w.contains("unparseable CHANNEL_DATA")),
2073 "expected unparseable warning, got: {:?}",
2074 entries[0].warnings
2075 );
2076 }
2077
2078 #[test]
2079 fn multibyte_at_warning_truncation_codec_continuation() {
2080 let cont = format!("{}é tail beyond eighty bytes", "x".repeat(79));
2081 assert!(!cont.is_char_boundary(80));
2082 let lines = vec![
2083 full_line(
2084 UUID1,
2085 TS1,
2086 "Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]",
2087 ),
2088 format!("{UUID1} {cont}"),
2089 ];
2090 let entries: Vec<_> = LogStream::new(lines.into_iter()).collect();
2091 assert_eq!(entries.len(), 1);
2092 assert!(
2093 entries[0]
2094 .warnings
2095 .iter()
2096 .any(|w| w.contains("unexpected codec negotiation")),
2097 "expected codec continuation warning, got: {:?}",
2098 entries[0].warnings
2099 );
2100 }
2101
2102 #[test]
2103 fn system_line_with_embedded_uuid_gets_entry_uuid() {
2104 let lines = vec![
2107 format!(
2108 "{TS1} 95.97% [DEBUG] switch_cpp.cpp:1466 {UUID1} DAA-LOG WaveManager originate"
2109 ),
2110 format!(
2111 "{TS1} 95.97% [WARNING] switch_cpp.cpp:1466 {UUID1} DAA-LOG Failed to create session"
2112 ),
2113 full_line(UUID1, TS2, "State Change CS_EXECUTE -> CS_HIBERNATE"),
2114 ];
2115
2116 let mut stream = LogStream::new(lines.into_iter());
2117 let entries: Vec<_> = stream.by_ref().collect();
2118
2119 assert_eq!(entries.len(), 3);
2120 assert_eq!(entries[0].uuid, UUID1);
2122 assert_eq!(entries[0].kind, LineKind::System);
2123 assert_eq!(entries[0].message, "DAA-LOG WaveManager originate");
2124
2125 assert_eq!(entries[1].uuid, UUID1);
2126 assert_eq!(entries[1].kind, LineKind::System);
2127 assert_eq!(entries[1].message, "DAA-LOG Failed to create session");
2128
2129 assert_eq!(entries[2].uuid, UUID1);
2131 assert_eq!(entries[2].kind, LineKind::Full);
2132 assert_accounting(&stream);
2133 }
2134}