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