1use std::{
2 fmt, io,
3 time::{Duration, Instant},
4};
5
6use ic_host_artifacts::batch::{BatchLabelError, validate_labels};
7use ic_platform::pocket_ic::{CanisterLogRecord, CanisterStatusResult, PocketIc};
8use ic_platform::principal::ExternalPrincipal as Principal;
9
10use super::{
11 PocketIcCallFailure,
12 transport::{self, capture_call},
13};
14
15pub const DEFAULT_CANISTER_LOG_RECORD_LIMIT: usize = 32;
17
18pub const DEFAULT_CANISTER_LOG_BYTE_LIMIT: usize = 16 * 1024;
20
21#[derive(Clone, Copy, Debug, Eq, PartialEq)]
23pub struct CanisterLogRenderLimits {
24 pub record_limit: usize,
26 pub byte_limit: usize,
28}
29
30impl Default for CanisterLogRenderLimits {
31 fn default() -> Self {
32 Self {
33 record_limit: DEFAULT_CANISTER_LOG_RECORD_LIMIT,
34 byte_limit: DEFAULT_CANISTER_LOG_BYTE_LIMIT,
35 }
36 }
37}
38
39#[derive(Clone, Copy, Debug, Eq, PartialEq)]
41pub struct CanisterDiagnosticsRequest {
42 pub canister_id: Principal,
44 pub status_sender: Principal,
46 pub log_sender: Principal,
48 pub log_limits: CanisterLogRenderLimits,
50}
51
52#[derive(Clone, Debug, Eq, PartialEq)]
54pub struct LabeledCanisterDiagnosticsRequest {
55 pub label: String,
57 pub request: CanisterDiagnosticsRequest,
59}
60
61#[derive(Clone, Debug, Eq, PartialEq)]
63pub struct CanisterDiagnosticLogRecord {
64 index: u64,
65 timestamp_nanos: u64,
66 content: String,
67 original_content_bytes: usize,
68 omitted_content_bytes: usize,
69}
70
71impl CanisterDiagnosticLogRecord {
72 #[must_use]
74 pub const fn index(&self) -> u64 {
75 self.index
76 }
77
78 #[must_use]
80 pub const fn timestamp_nanos(&self) -> u64 {
81 self.timestamp_nanos
82 }
83
84 #[must_use]
86 pub fn content(&self) -> &str {
87 &self.content
88 }
89
90 #[must_use]
92 pub const fn original_content_bytes(&self) -> usize {
93 self.original_content_bytes
94 }
95
96 #[must_use]
98 pub const fn omitted_content_bytes(&self) -> usize {
99 self.omitted_content_bytes
100 }
101
102 #[must_use]
104 pub const fn was_truncated(&self) -> bool {
105 self.omitted_content_bytes != 0
106 }
107}
108
109#[derive(Clone, Debug, Eq, PartialEq)]
111pub struct CanisterDiagnosticLogs {
112 records: Vec<CanisterDiagnosticLogRecord>,
113 total_records: usize,
114 total_content_bytes: usize,
115 omitted_content_bytes: usize,
116}
117
118impl CanisterDiagnosticLogs {
119 #[must_use]
121 pub fn records(&self) -> &[CanisterDiagnosticLogRecord] {
122 &self.records
123 }
124
125 #[must_use]
127 pub const fn total_records(&self) -> usize {
128 self.total_records
129 }
130
131 #[must_use]
133 pub const fn total_content_bytes(&self) -> usize {
134 self.total_content_bytes
135 }
136
137 #[must_use]
139 pub const fn omitted_records(&self) -> usize {
140 self.total_records - self.records.len()
141 }
142
143 #[must_use]
145 pub const fn omitted_content_bytes(&self) -> usize {
146 self.omitted_content_bytes
147 }
148
149 #[must_use]
151 pub const fn was_truncated(&self) -> bool {
152 self.omitted_records() != 0 || self.omitted_content_bytes != 0
153 }
154}
155
156impl fmt::Display for CanisterDiagnosticLogs {
157 fn fmt(&self, formatter: &mut fmt::Formatter<'_>) -> fmt::Result {
158 if self.records.is_empty() {
159 if self.total_records == 0 {
160 formatter.write_str("<empty>")?;
161 } else {
162 formatter.write_str("<no retained records>")?;
163 }
164 } else {
165 for (position, record) in self.records.iter().enumerate() {
166 if position != 0 {
167 formatter.write_str(", ")?;
168 }
169 write!(
170 formatter,
171 "[{}@{}]={:?}",
172 record.index, record.timestamp_nanos, record.content
173 )?;
174 if record.was_truncated() {
175 write!(
176 formatter,
177 " (truncated {} bytes)",
178 record.omitted_content_bytes
179 )?;
180 }
181 }
182 }
183 if self.was_truncated() {
184 write!(
185 formatter,
186 "; truncated omitted_records={} omitted_content_bytes={}",
187 self.omitted_records(),
188 self.omitted_content_bytes
189 )?;
190 }
191 Ok(())
192 }
193}
194
195#[derive(Debug)]
197pub struct CanisterDiagnosticsReport {
198 pub request: CanisterDiagnosticsRequest,
200 pub status: Result<CanisterStatusResult, PocketIcCallFailure>,
202 pub logs: Result<CanisterDiagnosticLogs, PocketIcCallFailure>,
204}
205
206impl CanisterDiagnosticsReport {
207 #[must_use]
209 pub const fn is_success(&self) -> bool {
210 self.status.is_ok() && self.logs.is_ok()
211 }
212}
213
214#[derive(Debug)]
216pub struct CanisterDiagnosticsBatchEntry {
217 pub label: String,
219 pub report: CanisterDiagnosticsReport,
221 pub entry_elapsed: Duration,
223}
224
225impl CanisterDiagnosticsBatchEntry {
226 #[must_use]
228 pub const fn is_success(&self) -> bool {
229 self.report.is_success()
230 }
231}
232
233#[derive(Debug, Default)]
235pub struct CanisterDiagnosticsBatchReport {
236 pub entries: Vec<CanisterDiagnosticsBatchEntry>,
238 pub total: Duration,
240}
241
242impl CanisterDiagnosticsBatchReport {
243 pub fn failures(&self) -> impl Iterator<Item = &CanisterDiagnosticsBatchEntry> {
245 self.entries.iter().filter(|entry| !entry.is_success())
246 }
247
248 #[must_use]
250 pub fn is_success(&self) -> bool {
251 self.entries
252 .iter()
253 .all(CanisterDiagnosticsBatchEntry::is_success)
254 }
255}
256
257impl fmt::Display for CanisterDiagnosticsBatchReport {
258 fn fmt(&self, formatter: &mut fmt::Formatter<'_>) -> fmt::Result {
259 write!(
260 formatter,
261 "diagnostics={} total={:?}",
262 self.entries.len(),
263 self.total
264 )?;
265 for entry in &self.entries {
266 write!(
267 formatter,
268 "; label={:?} elapsed={:?} {}",
269 entry.label, entry.entry_elapsed, entry.report
270 )?;
271 }
272 Ok(())
273 }
274}
275
276impl fmt::Display for CanisterDiagnosticsReport {
277 fn fmt(&self, formatter: &mut fmt::Formatter<'_>) -> fmt::Result {
278 write!(
279 formatter,
280 "canister={} status_sender={} status=",
281 self.request.canister_id, self.request.status_sender
282 )?;
283 match &self.status {
284 Ok(status) => write!(
285 formatter,
286 "ok(state={:?} version={} controllers={} module_hash_bytes={} memory_bytes={} cycles={})",
287 status.status,
288 status.version,
289 status.settings.controllers.len(),
290 status.module_hash.as_ref().map_or(0, Vec::len),
291 status.memory_size,
292 status.cycles,
293 ),
294 Err(failure) => write!(formatter, "<{failure}>"),
295 }?;
296 write!(formatter, " log_sender={} logs=", self.request.log_sender)?;
297 match &self.logs {
298 Err(failure) => write!(formatter, "<{failure}>")?,
299 Ok(logs) => write!(formatter, "{logs}")?,
300 }
301 Ok(())
302 }
303}
304
305pub trait PocketIcDiagnosticsExt {
307 fn collect_canister_diagnostics(
312 &self,
313 request: CanisterDiagnosticsRequest,
314 ) -> CanisterDiagnosticsReport;
315
316 fn write_canister_diagnostics(
329 &self,
330 request: CanisterDiagnosticsRequest,
331 context: &str,
332 writer: &mut dyn io::Write,
333 ) -> io::Result<()> {
334 transport::capture_operation(|| {
335 let report = self.collect_canister_diagnostics(request);
336 writeln!(writer, "{context}: {report}")
337 })
338 .map_err(io::Error::other)?
339 }
340
341 fn collect_canister_diagnostics_batch(
351 &self,
352 requests: &[LabeledCanisterDiagnosticsRequest],
353 ) -> Result<CanisterDiagnosticsBatchReport, BatchLabelError> {
354 validate_labels(requests.iter().map(|request| request.label.as_str()))?;
355 let started = Instant::now();
356 let entries = requests
357 .iter()
358 .map(|labeled| {
359 let entry_started = Instant::now();
360 let request = labeled.request;
361 let report =
362 transport::capture_operation(|| self.collect_canister_diagnostics(request))
363 .unwrap_or_else(|source| CanisterDiagnosticsReport {
364 request,
365 status: Err(PocketIcCallFailure::Operation(source.clone())),
366 logs: Err(PocketIcCallFailure::Operation(source)),
367 });
368 CanisterDiagnosticsBatchEntry {
369 label: labeled.label.clone(),
370 report,
371 entry_elapsed: entry_started.elapsed(),
372 }
373 })
374 .collect();
375 Ok(CanisterDiagnosticsBatchReport {
376 entries,
377 total: started.elapsed(),
378 })
379 }
380}
381
382impl PocketIcDiagnosticsExt for PocketIc {
383 fn collect_canister_diagnostics(
384 &self,
385 request: CanisterDiagnosticsRequest,
386 ) -> CanisterDiagnosticsReport {
387 let status =
388 capture_call(|| self.canister_status(request.canister_id, Some(request.status_sender)));
389 let logs =
390 capture_call(|| self.fetch_canister_logs(request.canister_id, request.log_sender))
391 .map(|records| render_log_records(records, request.log_limits));
392
393 CanisterDiagnosticsReport {
394 request,
395 status,
396 logs,
397 }
398 }
399}
400
401fn render_log_records(
402 records: Vec<CanisterLogRecord>,
403 limits: CanisterLogRenderLimits,
404) -> CanisterDiagnosticLogs {
405 let total_records = records.len();
406 let mut total_content_bytes = 0usize;
407 let mut rendered = Vec::with_capacity(total_records.min(limits.record_limit));
408 let mut retained_bytes = 0usize;
409 let mut omitted_content_bytes = 0usize;
410
411 for record in records {
412 total_content_bytes = total_content_bytes.saturating_add(record.content.len());
413 let include = rendered.len() < limits.record_limit && retained_bytes < limits.byte_limit;
414 let retained = if include {
415 record
416 .content
417 .len()
418 .min(limits.byte_limit.saturating_sub(retained_bytes))
419 } else {
420 0
421 };
422 let omitted = record.content.len().saturating_sub(retained);
423 omitted_content_bytes = omitted_content_bytes.saturating_add(omitted);
424 if !include {
425 continue;
426 }
427
428 let content = String::from_utf8_lossy(&record.content[..retained]).into_owned();
429 retained_bytes = retained_bytes.saturating_add(retained);
430 rendered.push(CanisterDiagnosticLogRecord {
431 index: record.idx,
432 timestamp_nanos: record.timestamp_nanos,
433 content,
434 original_content_bytes: record.content.len(),
435 omitted_content_bytes: omitted,
436 });
437 }
438
439 CanisterDiagnosticLogs {
440 records: rendered,
441 total_records,
442 total_content_bytes,
443 omitted_content_bytes,
444 }
445}
446
447#[cfg(test)]
448mod tests {
449 use std::cell::Cell;
450
451 use ic_host_artifacts::batch::BatchLabelError;
452 use ic_platform::pocket_ic::CanisterLogRecord;
453 use ic_platform::principal::ExternalPrincipal as Principal;
454
455 use super::{
456 CanisterDiagnosticsReport, CanisterDiagnosticsRequest, CanisterLogRenderLimits,
457 LabeledCanisterDiagnosticsRequest, PocketIcCallFailure, PocketIcDiagnosticsExt,
458 capture_call, render_log_records,
459 };
460
461 #[test]
462 fn diagnostic_transport_classification_survives_context_and_io_wrapping() {
463 const REFUSED: &str = "HTTP failure: reqwest::Error { kind: Request, url: \"http://127.0.0.1:1234/instances/0/read/get_time\", source: ConnectError(\"tcp connect error\", Os { code: 111, kind: ConnectionRefused, message: \"Connection refused\" }) }";
464 const RESET: &str = "HTTP failure: reqwest::Error { kind: Request, url: \"http://127.0.0.1:49238/instances/0/read/get_time\", source: hyper_util::client::legacy::Error(SendRequest, hyper::Error(Io, Os { code: 54, kind: ConnectionReset, message: \"Connection reset by peer\" })) }";
465 for message in [REFUSED, RESET, "application worker channel closed"] {
466 let error = capture_call::<()>(|| panic!("{message}"))
467 .expect_err("diagnostic operation should capture the panic");
468 let expected = message != "application worker channel closed";
469 let PocketIcCallFailure::Operation(source) = &error else {
470 panic!("expected the original operation error");
471 };
472 assert_eq!(source.message(), message);
473 assert_eq!(source.is_transport(), expected);
474 let chained = std::error::Error::source(&error)
475 .and_then(|cause| cause.downcast_ref::<super::super::PocketIcOperationError>())
476 .expect("diagnostic error exposes its original typed cause");
477 assert_eq!(chained, source);
478 assert_eq!(
479 super::super::is_dead_pocket_ic_transport_error(&error),
480 expected,
481 );
482 let wrapped = std::io::Error::other(error);
483 assert_eq!(
484 super::super::is_dead_pocket_ic_transport_error(&wrapped),
485 expected,
486 );
487 }
488 }
489
490 struct PanickingThenReporting {
491 calls: Cell<usize>,
492 request: Cell<Option<CanisterDiagnosticsRequest>>,
493 }
494
495 impl PocketIcDiagnosticsExt for PanickingThenReporting {
496 fn collect_canister_diagnostics(
497 &self,
498 request: CanisterDiagnosticsRequest,
499 ) -> CanisterDiagnosticsReport {
500 let call = self.calls.get();
501 self.calls.set(call + 1);
502 self.request.set(Some(request));
503 assert_ne!(call, 0, "synthetic first-entry diagnostic panic");
504 CanisterDiagnosticsReport {
505 request,
506 status: Err(PocketIcCallFailure::Operation(
507 super::super::PocketIcOperationError::new("synthetic status failure"),
508 )),
509 logs: Err(PocketIcCallFailure::Operation(
510 super::super::PocketIcOperationError::new("synthetic log failure"),
511 )),
512 }
513 }
514 }
515
516 struct PanickingWriter;
517
518 impl std::io::Write for PanickingWriter {
519 fn write(&mut self, _: &[u8]) -> std::io::Result<usize> {
520 panic!("synthetic writer panic");
521 }
522 fn flush(&mut self) -> std::io::Result<()> {
523 Ok(())
524 }
525 }
526
527 #[test]
528 fn explicit_reporting_preserves_requests_and_contains_secondary_failures() {
529 let collector = PanickingThenReporting {
530 calls: Cell::new(0),
531 request: Cell::new(None),
532 };
533 let request = CanisterDiagnosticsRequest {
534 canister_id: Principal::from_slice(&[1]),
535 status_sender: Principal::from_slice(&[2]),
536 log_sender: Principal::from_slice(&[3]),
537 log_limits: CanisterLogRenderLimits::default(),
538 };
539 let mut output = Vec::new();
540 let error = collector
541 .write_canister_diagnostics(request, "install", &mut output)
542 .expect_err("collection panic becomes secondary error");
543 assert_eq!(output, [] as [u8; 0]);
544 assert_eq!(collector.calls.get(), 1);
545 assert_eq!(collector.request.get(), Some(request));
546 assert!(
547 error
548 .get_ref()
549 .unwrap()
550 .downcast_ref::<super::super::PocketIcOperationError>()
551 .unwrap()
552 .message()
553 .contains("synthetic first-entry diagnostic panic")
554 );
555
556 collector
557 .write_canister_diagnostics(request, "install", &mut output)
558 .unwrap();
559 let text = String::from_utf8(output).unwrap();
560 assert!(text.starts_with("install: "));
561 assert!(
562 text.contains("synthetic status failure") && text.contains("synthetic log failure")
563 );
564 assert_eq!(collector.calls.get(), 2);
565 assert_eq!(collector.request.get(), Some(request));
566
567 let mut full_writer = std::io::Cursor::new([0_u8; 0]);
568 let error = collector
569 .write_canister_diagnostics(request, "install", &mut full_writer)
570 .expect_err("ordinary writer failure is retained");
571 assert_eq!(error.kind(), std::io::ErrorKind::WriteZero);
572 let error = collector
573 .write_canister_diagnostics(request, "install", &mut PanickingWriter)
574 .expect_err("writer panic becomes secondary error");
575 assert!(
576 error
577 .get_ref()
578 .unwrap()
579 .downcast_ref::<super::super::PocketIcOperationError>()
580 .unwrap()
581 .message()
582 .contains("synthetic writer panic")
583 );
584 assert_eq!(
585 collector.calls.get(),
586 4,
587 "one explicit collection per call, with no retries"
588 );
589 }
590
591 #[test]
592 fn labeled_batch_retains_order_and_continues_after_entry_panic() {
593 let collector = PanickingThenReporting {
594 calls: Cell::new(0),
595 request: Cell::new(None),
596 };
597 let first = CanisterDiagnosticsRequest {
598 canister_id: Principal::from_slice(&[1]),
599 status_sender: Principal::from_slice(&[2]),
600 log_sender: Principal::from_slice(&[3]),
601 log_limits: CanisterLogRenderLimits::default(),
602 };
603 let second = CanisterDiagnosticsRequest {
604 canister_id: Principal::from_slice(&[4]),
605 status_sender: Principal::from_slice(&[5]),
606 log_sender: Principal::from_slice(&[6]),
607 log_limits: CanisterLogRenderLimits::default(),
608 };
609 let report = collector
610 .collect_canister_diagnostics_batch(&[
611 LabeledCanisterDiagnosticsRequest {
612 label: "root".into(),
613 request: first,
614 },
615 LabeledCanisterDiagnosticsRequest {
616 label: "worker".into(),
617 request: second,
618 },
619 ])
620 .expect("valid labeled diagnostics batch");
621
622 assert_eq!(collector.calls.get(), 2);
623 assert_eq!(report.entries.len(), 2);
624 assert_eq!(report.entries[0].label, "root");
625 assert_eq!(report.entries[0].report.request, first);
626 assert_eq!(report.entries[1].label, "worker");
627 assert_eq!(report.entries[1].report.request, second);
628 assert!(
629 report
630 .entries
631 .iter()
632 .all(|entry| entry.entry_elapsed <= report.total)
633 );
634 assert_eq!(report.failures().count(), 2);
635 assert!(!report.is_success());
636 let compact = report.to_string();
637 assert!(compact.contains("label=\"root\""));
638 assert!(compact.contains("label=\"worker\""));
639 assert!(compact.contains("synthetic first-entry diagnostic panic"));
640 }
641
642 #[test]
643 fn diagnostic_batch_rejects_invalid_labels_before_collection() {
644 let collector = PanickingThenReporting {
645 calls: Cell::new(0),
646 request: Cell::new(None),
647 };
648 let request = CanisterDiagnosticsRequest {
649 canister_id: Principal::from_slice(&[1]),
650 status_sender: Principal::from_slice(&[2]),
651 log_sender: Principal::from_slice(&[3]),
652 log_limits: CanisterLogRenderLimits::default(),
653 };
654 let empty = collector
655 .collect_canister_diagnostics_batch(&[LabeledCanisterDiagnosticsRequest {
656 label: String::new(),
657 request,
658 }])
659 .expect_err("empty label must reject diagnostics batch");
660 assert_eq!(empty, BatchLabelError::Empty { index: 0 });
661 assert_eq!(collector.calls.get(), 0);
662
663 let duplicate = collector
664 .collect_canister_diagnostics_batch(&[
665 LabeledCanisterDiagnosticsRequest {
666 label: "same".into(),
667 request,
668 },
669 LabeledCanisterDiagnosticsRequest {
670 label: "same".into(),
671 request,
672 },
673 ])
674 .expect_err("duplicate labels must reject diagnostics batch");
675 assert_eq!(
676 duplicate,
677 BatchLabelError::Duplicate {
678 label: "same".to_owned(),
679 first_index: 0,
680 duplicate_index: 1,
681 }
682 );
683 assert_eq!(collector.calls.get(), 0);
684 }
685
686 #[test]
687 fn log_rendering_is_bounded_lossy_utf8_and_reports_truncation() {
688 let logs = render_log_records(
689 vec![
690 CanisterLogRecord {
691 idx: 7,
692 timestamp_nanos: 11,
693 content: vec![b'f', 0x80, b'o'],
694 },
695 CanisterLogRecord {
696 idx: 8,
697 timestamp_nanos: 12,
698 content: b"bar".to_vec(),
699 },
700 ],
701 CanisterLogRenderLimits {
702 record_limit: 1,
703 byte_limit: 2,
704 },
705 );
706
707 assert_eq!(logs.total_records(), 2);
708 assert_eq!(logs.total_content_bytes(), 6);
709 assert_eq!(logs.omitted_records(), 1);
710 assert_eq!(logs.omitted_content_bytes(), 4);
711 assert!(logs.was_truncated());
712 assert_eq!(logs.records().len(), 1);
713 assert_eq!(logs.records()[0].content(), "f�");
714 assert_eq!(logs.records()[0].original_content_bytes(), 3);
715 assert_eq!(logs.records()[0].omitted_content_bytes(), 1);
716 assert!(logs.records()[0].was_truncated());
717 let rendered = logs.to_string();
718 assert!(rendered.contains("f�"));
719 assert!(rendered.contains("truncated omitted_records=1 omitted_content_bytes=4"));
720 }
721
722 #[test]
723 fn zero_log_bounds_retain_only_aggregate_truncation() {
724 for (record_limit, byte_limit) in [(0, 0), (0, 16), (16, 0)] {
725 let logs = render_log_records(
726 vec![CanisterLogRecord {
727 idx: 1,
728 timestamp_nanos: 2,
729 content: b"hello".to_vec(),
730 }],
731 CanisterLogRenderLimits {
732 record_limit,
733 byte_limit,
734 },
735 );
736
737 assert_eq!(logs.records(), []);
738 assert_eq!(logs.total_records(), 1);
739 assert_eq!(logs.total_content_bytes(), 5);
740 assert_eq!(logs.omitted_records(), 1);
741 assert_eq!(logs.omitted_content_bytes(), 5);
742 assert!(logs.was_truncated());
743 assert_eq!(
744 logs.to_string(),
745 "<no retained records>; truncated omitted_records=1 omitted_content_bytes=5"
746 );
747 }
748 }
749
750 #[test]
751 fn logs_within_bounds_preserve_empty_records_and_raw_byte_totals() {
752 let limits = CanisterLogRenderLimits {
753 record_limit: 3,
754 byte_limit: 3,
755 };
756 let empty = render_log_records(vec![], limits);
757 assert_eq!(empty.total_records(), 0);
758 assert_eq!(empty.total_content_bytes(), 0);
759 assert_eq!(empty.omitted_records(), 0);
760 assert_eq!(empty.omitted_content_bytes(), 0);
761 assert!(!empty.was_truncated());
762 assert_eq!(empty.to_string(), "<empty>");
763
764 let logs = render_log_records(
765 vec![
766 CanisterLogRecord {
767 idx: 1,
768 timestamp_nanos: 2,
769 content: vec![],
770 },
771 CanisterLogRecord {
772 idx: 3,
773 timestamp_nanos: 4,
774 content: vec![0x80, b'a'],
775 },
776 CanisterLogRecord {
777 idx: 5,
778 timestamp_nanos: 6,
779 content: vec![],
780 },
781 ],
782 limits,
783 );
784 assert_eq!(logs.total_records(), 3);
785 assert_eq!(logs.records().len(), 3);
786 assert_eq!(logs.total_content_bytes(), 2);
787 assert_eq!(logs.records()[0].content(), "");
788 assert_eq!(logs.records()[1].content(), "�a");
789 assert_eq!(logs.records()[2].content(), "");
790 assert_eq!(logs.omitted_records(), 0);
791 assert_eq!(logs.omitted_content_bytes(), 0);
792 assert!(!logs.was_truncated());
793 }
794}