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 if rendered.len() == limits.record_limit || retained_bytes == limits.byte_limit {
414 omitted_content_bytes = omitted_content_bytes.saturating_add(record.content.len());
415 continue;
416 }
417
418 let available = limits.byte_limit.saturating_sub(retained_bytes);
419 let retained = record.content.len().min(available);
420 let omitted = record.content.len().saturating_sub(retained);
421 let content = String::from_utf8_lossy(&record.content[..retained]).into_owned();
422 retained_bytes = retained_bytes.saturating_add(retained);
423 omitted_content_bytes = omitted_content_bytes.saturating_add(omitted);
424 rendered.push(CanisterDiagnosticLogRecord {
425 index: record.idx,
426 timestamp_nanos: record.timestamp_nanos,
427 content,
428 original_content_bytes: record.content.len(),
429 omitted_content_bytes: omitted,
430 });
431 }
432
433 CanisterDiagnosticLogs {
434 records: rendered,
435 total_records,
436 total_content_bytes,
437 omitted_content_bytes,
438 }
439}
440
441#[cfg(test)]
442mod tests {
443 use std::cell::Cell;
444
445 use ic_host_artifacts::batch::BatchLabelError;
446 use ic_platform::pocket_ic::CanisterLogRecord;
447 use ic_platform::principal::ExternalPrincipal as Principal;
448
449 use super::{
450 CanisterDiagnosticsReport, CanisterDiagnosticsRequest, CanisterLogRenderLimits,
451 LabeledCanisterDiagnosticsRequest, PocketIcCallFailure, PocketIcDiagnosticsExt,
452 capture_call, render_log_records,
453 };
454
455 #[test]
456 fn diagnostic_transport_classification_survives_context_and_io_wrapping() {
457 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\" }) }";
458 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\" })) }";
459 for message in [REFUSED, RESET, "application worker channel closed"] {
460 let error = capture_call::<()>(|| panic!("{message}"))
461 .expect_err("diagnostic operation should capture the panic");
462 let expected = message != "application worker channel closed";
463 let PocketIcCallFailure::Operation(source) = &error else {
464 panic!("expected the original operation error");
465 };
466 assert_eq!(source.message(), message);
467 assert_eq!(source.is_transport(), expected);
468 let chained = std::error::Error::source(&error)
469 .and_then(|cause| cause.downcast_ref::<super::super::PocketIcOperationError>())
470 .expect("diagnostic error exposes its original typed cause");
471 assert_eq!(chained, source);
472 assert_eq!(
473 super::super::is_dead_pocket_ic_transport_error(&error),
474 expected,
475 );
476 let wrapped = std::io::Error::other(error);
477 assert_eq!(
478 super::super::is_dead_pocket_ic_transport_error(&wrapped),
479 expected,
480 );
481 }
482 }
483
484 struct PanickingThenReporting {
485 calls: Cell<usize>,
486 request: Cell<Option<CanisterDiagnosticsRequest>>,
487 }
488
489 impl PocketIcDiagnosticsExt for PanickingThenReporting {
490 fn collect_canister_diagnostics(
491 &self,
492 request: CanisterDiagnosticsRequest,
493 ) -> CanisterDiagnosticsReport {
494 let call = self.calls.get();
495 self.calls.set(call + 1);
496 self.request.set(Some(request));
497 assert_ne!(call, 0, "synthetic first-entry diagnostic panic");
498 CanisterDiagnosticsReport {
499 request,
500 status: Err(PocketIcCallFailure::Operation(
501 super::super::PocketIcOperationError::new("synthetic status failure"),
502 )),
503 logs: Err(PocketIcCallFailure::Operation(
504 super::super::PocketIcOperationError::new("synthetic log failure"),
505 )),
506 }
507 }
508 }
509
510 struct PanickingWriter;
511
512 impl std::io::Write for PanickingWriter {
513 fn write(&mut self, _: &[u8]) -> std::io::Result<usize> {
514 panic!("synthetic writer panic");
515 }
516 fn flush(&mut self) -> std::io::Result<()> {
517 Ok(())
518 }
519 }
520
521 #[test]
522 fn explicit_reporting_preserves_requests_and_contains_secondary_failures() {
523 let collector = PanickingThenReporting {
524 calls: Cell::new(0),
525 request: Cell::new(None),
526 };
527 let request = CanisterDiagnosticsRequest {
528 canister_id: Principal::from_slice(&[1]),
529 status_sender: Principal::from_slice(&[2]),
530 log_sender: Principal::from_slice(&[3]),
531 log_limits: CanisterLogRenderLimits::default(),
532 };
533 let mut output = Vec::new();
534 let error = collector
535 .write_canister_diagnostics(request, "install", &mut output)
536 .expect_err("collection panic becomes secondary error");
537 assert_eq!(output, [] as [u8; 0]);
538 assert_eq!(collector.calls.get(), 1);
539 assert_eq!(collector.request.get(), Some(request));
540 assert!(
541 error
542 .get_ref()
543 .unwrap()
544 .downcast_ref::<super::super::PocketIcOperationError>()
545 .unwrap()
546 .message()
547 .contains("synthetic first-entry diagnostic panic")
548 );
549
550 collector
551 .write_canister_diagnostics(request, "install", &mut output)
552 .unwrap();
553 let text = String::from_utf8(output).unwrap();
554 assert!(text.starts_with("install: "));
555 assert!(
556 text.contains("synthetic status failure") && text.contains("synthetic log failure")
557 );
558 assert_eq!(collector.calls.get(), 2);
559 assert_eq!(collector.request.get(), Some(request));
560
561 let mut full_writer = std::io::Cursor::new([0_u8; 0]);
562 let error = collector
563 .write_canister_diagnostics(request, "install", &mut full_writer)
564 .expect_err("ordinary writer failure is retained");
565 assert_eq!(error.kind(), std::io::ErrorKind::WriteZero);
566 let error = collector
567 .write_canister_diagnostics(request, "install", &mut PanickingWriter)
568 .expect_err("writer panic becomes secondary error");
569 assert!(
570 error
571 .get_ref()
572 .unwrap()
573 .downcast_ref::<super::super::PocketIcOperationError>()
574 .unwrap()
575 .message()
576 .contains("synthetic writer panic")
577 );
578 assert_eq!(
579 collector.calls.get(),
580 4,
581 "one explicit collection per call, with no retries"
582 );
583 }
584
585 #[test]
586 fn labeled_batch_retains_order_and_continues_after_entry_panic() {
587 let collector = PanickingThenReporting {
588 calls: Cell::new(0),
589 request: Cell::new(None),
590 };
591 let first = CanisterDiagnosticsRequest {
592 canister_id: Principal::from_slice(&[1]),
593 status_sender: Principal::from_slice(&[2]),
594 log_sender: Principal::from_slice(&[3]),
595 log_limits: CanisterLogRenderLimits::default(),
596 };
597 let second = CanisterDiagnosticsRequest {
598 canister_id: Principal::from_slice(&[4]),
599 status_sender: Principal::from_slice(&[5]),
600 log_sender: Principal::from_slice(&[6]),
601 log_limits: CanisterLogRenderLimits::default(),
602 };
603 let report = collector
604 .collect_canister_diagnostics_batch(&[
605 LabeledCanisterDiagnosticsRequest {
606 label: "root".into(),
607 request: first,
608 },
609 LabeledCanisterDiagnosticsRequest {
610 label: "worker".into(),
611 request: second,
612 },
613 ])
614 .expect("valid labeled diagnostics batch");
615
616 assert_eq!(collector.calls.get(), 2);
617 assert_eq!(report.entries.len(), 2);
618 assert_eq!(report.entries[0].label, "root");
619 assert_eq!(report.entries[0].report.request, first);
620 assert_eq!(report.entries[1].label, "worker");
621 assert_eq!(report.entries[1].report.request, second);
622 assert!(
623 report
624 .entries
625 .iter()
626 .all(|entry| entry.entry_elapsed <= report.total)
627 );
628 assert_eq!(report.failures().count(), 2);
629 assert!(!report.is_success());
630 let compact = report.to_string();
631 assert!(compact.contains("label=\"root\""));
632 assert!(compact.contains("label=\"worker\""));
633 assert!(compact.contains("synthetic first-entry diagnostic panic"));
634 }
635
636 #[test]
637 fn diagnostic_batch_rejects_invalid_labels_before_collection() {
638 let collector = PanickingThenReporting {
639 calls: Cell::new(0),
640 request: Cell::new(None),
641 };
642 let request = CanisterDiagnosticsRequest {
643 canister_id: Principal::from_slice(&[1]),
644 status_sender: Principal::from_slice(&[2]),
645 log_sender: Principal::from_slice(&[3]),
646 log_limits: CanisterLogRenderLimits::default(),
647 };
648 let empty = collector
649 .collect_canister_diagnostics_batch(&[LabeledCanisterDiagnosticsRequest {
650 label: String::new(),
651 request,
652 }])
653 .expect_err("empty label must reject diagnostics batch");
654 assert_eq!(empty, BatchLabelError::Empty { index: 0 });
655 assert_eq!(collector.calls.get(), 0);
656
657 let duplicate = collector
658 .collect_canister_diagnostics_batch(&[
659 LabeledCanisterDiagnosticsRequest {
660 label: "same".into(),
661 request,
662 },
663 LabeledCanisterDiagnosticsRequest {
664 label: "same".into(),
665 request,
666 },
667 ])
668 .expect_err("duplicate labels must reject diagnostics batch");
669 assert_eq!(
670 duplicate,
671 BatchLabelError::Duplicate {
672 label: "same".to_owned(),
673 first_index: 0,
674 duplicate_index: 1,
675 }
676 );
677 assert_eq!(collector.calls.get(), 0);
678 }
679
680 #[test]
681 fn log_rendering_is_bounded_lossy_utf8_and_reports_truncation() {
682 let logs = render_log_records(
683 vec![
684 CanisterLogRecord {
685 idx: 7,
686 timestamp_nanos: 11,
687 content: vec![b'f', 0x80, b'o'],
688 },
689 CanisterLogRecord {
690 idx: 8,
691 timestamp_nanos: 12,
692 content: b"bar".to_vec(),
693 },
694 ],
695 CanisterLogRenderLimits {
696 record_limit: 1,
697 byte_limit: 2,
698 },
699 );
700
701 assert_eq!(logs.total_records(), 2);
702 assert_eq!(logs.total_content_bytes(), 6);
703 assert_eq!(logs.omitted_records(), 1);
704 assert_eq!(logs.omitted_content_bytes(), 4);
705 assert!(logs.was_truncated());
706 assert_eq!(logs.records().len(), 1);
707 assert_eq!(logs.records()[0].content(), "f�");
708 assert_eq!(logs.records()[0].original_content_bytes(), 3);
709 assert_eq!(logs.records()[0].omitted_content_bytes(), 1);
710 assert!(logs.records()[0].was_truncated());
711 let rendered = logs.to_string();
712 assert!(rendered.contains("f�"));
713 assert!(rendered.contains("truncated omitted_records=1 omitted_content_bytes=4"));
714 }
715
716 #[test]
717 fn zero_log_bounds_retain_only_aggregate_truncation() {
718 for (record_limit, byte_limit) in [(0, 0), (0, 16), (16, 0)] {
719 let logs = render_log_records(
720 vec![CanisterLogRecord {
721 idx: 1,
722 timestamp_nanos: 2,
723 content: b"hello".to_vec(),
724 }],
725 CanisterLogRenderLimits {
726 record_limit,
727 byte_limit,
728 },
729 );
730
731 assert_eq!(logs.records(), []);
732 assert_eq!(logs.total_records(), 1);
733 assert_eq!(logs.total_content_bytes(), 5);
734 assert_eq!(logs.omitted_records(), 1);
735 assert_eq!(logs.omitted_content_bytes(), 5);
736 assert!(logs.was_truncated());
737 assert_eq!(
738 logs.to_string(),
739 "<no retained records>; truncated omitted_records=1 omitted_content_bytes=5"
740 );
741 }
742 }
743
744 #[test]
745 fn logs_within_bounds_preserve_empty_records_and_raw_byte_totals() {
746 let limits = CanisterLogRenderLimits {
747 record_limit: 3,
748 byte_limit: 3,
749 };
750 let empty = render_log_records(vec![], limits);
751 assert_eq!(empty.total_records(), 0);
752 assert_eq!(empty.total_content_bytes(), 0);
753 assert_eq!(empty.omitted_records(), 0);
754 assert_eq!(empty.omitted_content_bytes(), 0);
755 assert!(!empty.was_truncated());
756 assert_eq!(empty.to_string(), "<empty>");
757
758 let logs = render_log_records(
759 vec![
760 CanisterLogRecord {
761 idx: 1,
762 timestamp_nanos: 2,
763 content: vec![],
764 },
765 CanisterLogRecord {
766 idx: 3,
767 timestamp_nanos: 4,
768 content: vec![0x80, b'a'],
769 },
770 CanisterLogRecord {
771 idx: 5,
772 timestamp_nanos: 6,
773 content: vec![],
774 },
775 ],
776 limits,
777 );
778 assert_eq!(logs.total_records(), 3);
779 assert_eq!(logs.records().len(), 3);
780 assert_eq!(logs.total_content_bytes(), 2);
781 assert_eq!(logs.records()[0].content(), "");
782 assert_eq!(logs.records()[1].content(), "�a");
783 assert_eq!(logs.records()[2].content(), "");
784 assert_eq!(logs.omitted_records(), 0);
785 assert_eq!(logs.omitted_content_bytes(), 0);
786 assert!(!logs.was_truncated());
787 }
788}