1use std::fmt;
17use std::str::FromStr;
18use std::sync::Arc;
19use std::time::Duration;
20
21use delta_kernel_derive::internal_api;
22use strum::{AsRefStr, Display as StrumDisplay, EnumString, IntoStaticStr};
23use tracing::field::{Field, Visit};
24use tracing::span::Attributes;
25use tracing::warn;
26use uuid::Uuid;
27
28use crate::log_segment::LogSegment;
29
30#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash)]
39pub struct MetricId(pub(crate) Uuid);
40
41impl MetricId {
42 #[allow(clippy::new_without_default)]
44 pub fn new() -> Self {
45 Self(Uuid::new_v4())
46 }
47
48 pub(crate) fn nil() -> Self {
51 Self(Uuid::nil())
52 }
53
54 pub fn as_bytes(&self) -> [u8; 16] {
57 *self.0.as_bytes()
58 }
59
60 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
63 #[derive(Default)]
64 struct V(Uuid);
65 impl Visit for V {
66 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
67 if field.name() == "operation_id" {
68 let s = format!("{value:?}");
69 match Uuid::from_str(&s) {
70 Ok(u) => self.0 = u,
71 Err(e) => warn!("Invalid uuid '{s}' on span: {e}. Using default."),
72 }
73 }
74 }
75 }
76 let mut v = V::default();
77 attrs.record(&mut v);
78 Self(v.0)
79 }
80}
81
82impl fmt::Display for MetricId {
83 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
84 self.0.fmt(f)
85 }
86}
87
88#[derive(Debug, Clone)]
94pub enum MetricEvent {
95 LogSegmentLoadSuccess(LogSegmentLoadSuccess),
96 LogSegmentLoadFailure(LogSegmentLoadFailure),
97 ProtocolMetadataLoadSuccess(ProtocolMetadataLoadSuccess),
98 ProtocolMetadataLoadFailure(ProtocolMetadataLoadFailure),
99 SnapshotBuildSuccess(SnapshotBuildSuccess),
100 SnapshotBuildFailure(SnapshotBuildFailure),
101 TransactionCommitSuccess(TransactionCommitSuccess),
102 TransactionCommitFailure(TransactionCommitFailure),
103 DomainMetadataLoadSuccess(DomainMetadataLoadSuccess),
104 DomainMetadataLoadFailure,
105 SetTransactionLoadSuccess(SetTransactionLoadSuccess),
106 SetTransactionLoadFailure,
107 CrcReadSuccess(CrcReadSuccess),
108 CrcReadFailure,
109 JsonReadCompleted(JsonReadCompleted),
110 ParquetReadCompleted(ParquetReadCompleted),
111 ScanMetadataCompleted(ScanMetadataCompleted),
112 StorageListCompleted(StorageListCompleted),
113 StorageReadCompleted(StorageReadCompleted),
114 StorageCopyCompleted(StorageCopyCompleted),
115}
116
117impl MetricEvent {
118 pub(crate) fn set_duration_if_applicable(&mut self, d: Duration) {
120 match self {
121 Self::SnapshotBuildSuccess(e) => e.set_duration(d),
123 Self::TransactionCommitSuccess(e) => e.set_duration(d),
124 Self::DomainMetadataLoadSuccess(e) => e.set_duration(d),
125 Self::SetTransactionLoadSuccess(e) => e.set_duration(d),
126 Self::CrcReadSuccess(e) => e.set_duration(d),
127
128 Self::LogSegmentLoadSuccess(_)
131 | Self::ProtocolMetadataLoadSuccess(_)
132 | Self::ScanMetadataCompleted(_)
133 | Self::StorageListCompleted(_)
134 | Self::StorageReadCompleted(_)
135 | Self::StorageCopyCompleted(_) => {}
136
137 Self::LogSegmentLoadFailure(_)
139 | Self::ProtocolMetadataLoadFailure(_)
140 | Self::SnapshotBuildFailure(_)
141 | Self::TransactionCommitFailure(_)
142 | Self::DomainMetadataLoadFailure
143 | Self::SetTransactionLoadFailure
144 | Self::CrcReadFailure => {}
145
146 Self::JsonReadCompleted(_) | Self::ParquetReadCompleted(_) => {}
148 }
149 }
150
151 pub(crate) fn record_u64(&mut self, name: &str, value: u64) -> Result<(), &'static str> {
152 match self {
153 Self::SnapshotBuildSuccess(e) => e.record_u64(name, value),
155 Self::TransactionCommitSuccess(e) => e.record_u64(name, value),
156 Self::DomainMetadataLoadSuccess(e) => e.record_u64(name, value),
157 Self::CrcReadSuccess(e) => e.record_u64(name, value),
158
159 Self::LogSegmentLoadSuccess(_) => Err(LogSegmentLoadSuccess::SPAN_NAME),
160 Self::ProtocolMetadataLoadSuccess(_) => Err(ProtocolMetadataLoadSuccess::SPAN_NAME),
161 Self::SetTransactionLoadSuccess(_) => Err(SetTransactionLoadSuccess::SPAN_NAME),
162 Self::ScanMetadataCompleted(_) => Err(ScanMetadataCompleted::SPAN_NAME),
163 Self::JsonReadCompleted(_) => Err(JsonReadCompleted::SPAN_NAME),
164 Self::ParquetReadCompleted(_) => Err(ParquetReadCompleted::SPAN_NAME),
165 Self::StorageListCompleted(_)
166 | Self::StorageReadCompleted(_)
167 | Self::StorageCopyCompleted(_) => Err(STORAGE_SPAN),
168
169 Self::LogSegmentLoadFailure(_) => Err(LogSegmentLoadSuccess::SPAN_NAME),
171 Self::ProtocolMetadataLoadFailure(_) => Err(ProtocolMetadataLoadSuccess::SPAN_NAME),
172 Self::SnapshotBuildFailure(_) => Err(SnapshotBuildSuccess::SPAN_NAME),
173 Self::TransactionCommitFailure(_) => Err(TransactionCommitSuccess::SPAN_NAME),
174 Self::DomainMetadataLoadFailure => Err(DomainMetadataLoadSuccess::SPAN_NAME),
175 Self::SetTransactionLoadFailure => Err(SetTransactionLoadSuccess::SPAN_NAME),
176 Self::CrcReadFailure => Err(CrcReadSuccess::SPAN_NAME),
177 }
178 }
179
180 pub(crate) fn record_bool(&mut self, name: &str, value: bool) -> Result<(), &'static str> {
181 match self {
182 Self::TransactionCommitSuccess(e) => e.record_bool(name, value),
184 Self::DomainMetadataLoadSuccess(e) => e.record_bool(name, value),
185 Self::SetTransactionLoadSuccess(e) => e.record_bool(name, value),
186
187 Self::LogSegmentLoadSuccess(_) => Err(LogSegmentLoadSuccess::SPAN_NAME),
189 Self::ProtocolMetadataLoadSuccess(_) => Err(ProtocolMetadataLoadSuccess::SPAN_NAME),
190 Self::SnapshotBuildSuccess(_) => Err(SnapshotBuildSuccess::SPAN_NAME),
191 Self::CrcReadSuccess(_) => Err(CrcReadSuccess::SPAN_NAME),
192 Self::ScanMetadataCompleted(_) => Err(ScanMetadataCompleted::SPAN_NAME),
193 Self::JsonReadCompleted(_) => Err(JsonReadCompleted::SPAN_NAME),
194 Self::ParquetReadCompleted(_) => Err(ParquetReadCompleted::SPAN_NAME),
195 Self::StorageListCompleted(_)
196 | Self::StorageReadCompleted(_)
197 | Self::StorageCopyCompleted(_) => Err(STORAGE_SPAN),
198
199 Self::LogSegmentLoadFailure(_) => Err(LogSegmentLoadSuccess::SPAN_NAME),
201 Self::ProtocolMetadataLoadFailure(_) => Err(ProtocolMetadataLoadSuccess::SPAN_NAME),
202 Self::SnapshotBuildFailure(_) => Err(SnapshotBuildSuccess::SPAN_NAME),
203 Self::TransactionCommitFailure(_) => Err(TransactionCommitSuccess::SPAN_NAME),
204 Self::DomainMetadataLoadFailure => Err(DomainMetadataLoadSuccess::SPAN_NAME),
205 Self::SetTransactionLoadFailure => Err(SetTransactionLoadSuccess::SPAN_NAME),
206 Self::CrcReadFailure => Err(CrcReadSuccess::SPAN_NAME),
207 }
208 }
209
210 pub(crate) fn record_str(&mut self, name: &str, value: &str) -> Result<(), &'static str> {
211 if name == "failure_reason" {
212 if let Self::TransactionCommitSuccess(e) = self {
213 let operation_id = e.operation_id;
214 let table_type = e.table_type;
215 let correlation_id = e.correlation_id.take();
216 *self = Self::TransactionCommitFailure(TransactionCommitFailure {
217 operation_id,
218 table_type,
219 correlation_id,
220 reason: value.parse().unwrap_or_else(|e| {
221 warn!("Invalid failure_reason '{value}' on span: {e}. Using Error.");
222 CommitFailureReason::Error
223 }),
224 });
225 }
226 return Ok(());
227 }
228 match self {
231 Self::TransactionCommitSuccess(e) => e.record_str(name, value),
232 _ => Ok(()),
233 }
234 }
235
236 pub(crate) fn into_failure(self) -> Self {
238 match self {
239 Self::LogSegmentLoadSuccess(e) => Self::LogSegmentLoadFailure(LogSegmentLoadFailure {
240 operation_id: e.operation_id,
241 table_type: e.table_type,
242 correlation_id: e.correlation_id,
243 load_type: e.load_type,
244 }),
245 Self::ProtocolMetadataLoadSuccess(e) => {
246 Self::ProtocolMetadataLoadFailure(ProtocolMetadataLoadFailure {
247 operation_id: e.operation_id,
248 table_type: e.table_type,
249 correlation_id: e.correlation_id,
250 load_type: e.load_type,
251 })
252 }
253 Self::SnapshotBuildSuccess(e) => Self::SnapshotBuildFailure(SnapshotBuildFailure {
254 operation_id: e.operation_id,
255 table_type: e.table_type,
256 correlation_id: e.correlation_id,
257 load_type: e.load_type,
258 }),
259 Self::TransactionCommitSuccess(e) => {
260 Self::TransactionCommitFailure(TransactionCommitFailure {
261 operation_id: e.operation_id,
262 table_type: e.table_type,
263 correlation_id: e.correlation_id,
264 reason: CommitFailureReason::Error,
265 })
266 }
267 Self::DomainMetadataLoadSuccess(_) => Self::DomainMetadataLoadFailure,
268 Self::SetTransactionLoadSuccess(_) => Self::SetTransactionLoadFailure,
269 Self::CrcReadSuccess(_) => Self::CrcReadFailure,
270 e @ (Self::LogSegmentLoadFailure(_)
274 | Self::ProtocolMetadataLoadFailure(_)
275 | Self::SnapshotBuildFailure(_)
276 | Self::TransactionCommitFailure(_)
277 | Self::DomainMetadataLoadFailure
278 | Self::SetTransactionLoadFailure
279 | Self::CrcReadFailure
280 | Self::JsonReadCompleted(_)
281 | Self::ParquetReadCompleted(_)
282 | Self::ScanMetadataCompleted(_)
283 | Self::StorageListCompleted(_)
284 | Self::StorageReadCompleted(_)
285 | Self::StorageCopyCompleted(_)) => e,
286 }
287 }
288}
289
290impl fmt::Display for MetricEvent {
291 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
292 match self {
293 Self::LogSegmentLoadSuccess(e) => e.fmt(f),
294 Self::LogSegmentLoadFailure(e) => e.fmt(f),
295 Self::ProtocolMetadataLoadSuccess(e) => e.fmt(f),
296 Self::ProtocolMetadataLoadFailure(e) => e.fmt(f),
297 Self::SnapshotBuildSuccess(e) => e.fmt(f),
298 Self::SnapshotBuildFailure(e) => e.fmt(f),
299 Self::TransactionCommitSuccess(e) => e.fmt(f),
300 Self::TransactionCommitFailure(e) => e.fmt(f),
301 Self::DomainMetadataLoadSuccess(e) => e.fmt(f),
302 Self::DomainMetadataLoadFailure => f.write_str("DomainMetadataLoadFailure"),
303 Self::SetTransactionLoadSuccess(e) => e.fmt(f),
304 Self::SetTransactionLoadFailure => f.write_str("SetTransactionLoadFailure"),
305 Self::CrcReadSuccess(e) => e.fmt(f),
306 Self::CrcReadFailure => f.write_str("CrcReadFailure"),
307 Self::JsonReadCompleted(e) => e.fmt(f),
308 Self::ParquetReadCompleted(e) => e.fmt(f),
309 Self::ScanMetadataCompleted(e) => e.fmt(f),
310 Self::StorageListCompleted(e) => e.fmt(f),
311 Self::StorageReadCompleted(e) => e.fmt(f),
312 Self::StorageCopyCompleted(e) => e.fmt(f),
313 }
314 }
315}
316
317pub(crate) const LOG_SEGMENT_LOADED_SPAN: &str = "segment.for_snapshot";
325
326#[derive(
329 Debug, Clone, Copy, PartialEq, Eq, Default, EnumString, StrumDisplay, AsRefStr, IntoStaticStr,
330)]
331#[strum(serialize_all = "snake_case")]
332#[non_exhaustive]
333pub enum LogSegmentLoadType {
334 Full,
337 Incremental,
340 #[default]
343 Unknown,
344}
345
346impl LogSegmentLoadType {
347 fn parse_or_unknown(s: &str) -> Self {
348 if s.is_empty() {
349 return Self::Unknown;
350 }
351 Self::from_str(s).unwrap_or_else(|e| {
352 warn!("Invalid load_type '{s}': {e}. Using Unknown.");
353 Self::Unknown
354 })
355 }
356}
357
358#[derive(Debug, Clone)]
362pub struct LogSegmentLoadSuccess {
363 pub operation_id: MetricId,
364 pub correlation_id: Option<Arc<str>>,
367 pub table_type: TableType,
368 pub load_type: LogSegmentLoadType,
369 pub num_commit_files: u64,
370 pub num_checkpoint_files: u64,
371 pub num_compaction_files: u64,
372 pub crc_versions_behind: Option<u64>,
375 pub duration: Duration,
376}
377
378impl LogSegmentLoadSuccess {
379 pub(crate) const SPAN_NAME: &'static str = LOG_SEGMENT_LOADED_SPAN;
380
381 const CRC_VERSIONS_BEHIND_FIELD: &'static str = "crc_versions_behind";
383
384 fn encode_crc_versions_behind(v: Option<u64>) -> i64 {
385 v.map_or(-1, |n| n as i64)
386 }
387
388 fn decode_crc_versions_behind(v: i64) -> Option<u64> {
389 u64::try_from(v).ok()
390 }
391
392 fn empty() -> Self {
394 Self {
395 operation_id: MetricId::nil(),
396 correlation_id: None,
397 table_type: TableType::from_catalog_managed(false),
398 load_type: LogSegmentLoadType::default(),
399 num_commit_files: 0,
400 num_checkpoint_files: 0,
401 num_compaction_files: 0,
402 crc_versions_behind: None,
403 duration: Duration::ZERO,
404 }
405 }
406
407 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
408 let mut event = Self::empty();
409 attrs.record(&mut event);
410 event
411 }
412}
413
414impl Visit for LogSegmentLoadSuccess {
415 fn record_bool(&mut self, field: &Field, value: bool) {
416 if field.name() == IS_CATALOG_MANAGED_FIELD {
417 self.table_type = TableType::from_catalog_managed(value);
418 }
419 }
420
421 fn record_str(&mut self, field: &Field, value: &str) {
422 match field.name() {
423 CORRELATION_ID_FIELD if !value.is_empty() => self.correlation_id = Some(value.into()),
424 "load_type" => self.load_type = LogSegmentLoadType::parse_or_unknown(value),
425 _ => {}
426 }
427 }
428
429 fn record_u64(&mut self, field: &Field, value: u64) {
430 match field.name() {
431 "duration_ns" => self.duration = Duration::from_nanos(value),
432 "num_commit_files" => self.num_commit_files = value,
433 "num_checkpoint_files" => self.num_checkpoint_files = value,
434 "num_compaction_files" => self.num_compaction_files = value,
435 _ => {}
436 }
437 }
438
439 fn record_i64(&mut self, field: &Field, value: i64) {
440 if field.name() == Self::CRC_VERSIONS_BEHIND_FIELD {
441 self.crc_versions_behind = Self::decode_crc_versions_behind(value);
442 }
443 }
444
445 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
446 if let Some(id) = record_operation_id(field, value, Self::SPAN_NAME) {
447 self.operation_id = id;
448 }
449 }
450}
451
452impl fmt::Display for LogSegmentLoadSuccess {
453 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
454 let Self {
455 operation_id,
456 table_type,
457 correlation_id,
458 load_type,
459 duration,
460 num_commit_files,
461 num_checkpoint_files,
462 num_compaction_files,
463 crc_versions_behind,
464 } = self;
465 write!(
466 f,
467 "LogSegmentLoadSuccess(id={operation_id}, table_type={table_type}, \
468 correlation_id={correlation_id:?}, load_type={load_type}, \
469 duration={duration:?}, commits={num_commit_files}, \
470 checkpoints={num_checkpoint_files}, compactions={num_compaction_files}, \
471 crc_versions_behind={crc_versions_behind:?})"
472 )
473 }
474}
475
476#[derive(Debug, Clone)]
478pub struct LogSegmentLoadFailure {
479 pub operation_id: MetricId,
480 pub correlation_id: Option<Arc<str>>,
483 pub table_type: TableType,
484 pub load_type: LogSegmentLoadType,
485}
486
487impl fmt::Display for LogSegmentLoadFailure {
488 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
489 write!(
490 f,
491 "LogSegmentLoadFailure(id={}, table_type={}, correlation_id={:?}, load_type={})",
492 self.operation_id, self.table_type, self.correlation_id, self.load_type
493 )
494 }
495}
496
497pub(crate) const PROTOCOL_METADATA_LOADED_SPAN: &str = "segment.read_metadata";
502
503#[derive(Debug, Clone, Copy, PartialEq, Eq, EnumString, StrumDisplay, AsRefStr, IntoStaticStr)]
505#[strum(serialize_all = "snake_case")]
506#[non_exhaustive]
507pub enum ProtocolMetadataSource {
508 CrcAtTarget,
510 CrcAdvancedByReplay,
512 CrcSeededPmOnlyReplay,
515 FullReplay,
518 Unknown,
521}
522
523impl ProtocolMetadataSource {
524 fn parse_or_unknown(s: &str) -> Self {
525 if s.is_empty() {
526 return Self::Unknown;
527 }
528 Self::from_str(s).unwrap_or_else(|e| {
529 warn!("Invalid pm_source '{s}': {e}. Using Unknown.");
530 Self::Unknown
531 })
532 }
533}
534
535#[derive(Debug, Clone)]
539pub struct ProtocolMetadataLoadSuccess {
540 pub operation_id: MetricId,
541 pub correlation_id: Option<Arc<str>>,
544 pub table_type: TableType,
545 pub load_type: LogSegmentLoadType,
546 pub source: ProtocolMetadataSource,
547 pub duration: Duration,
548}
549
550impl ProtocolMetadataLoadSuccess {
551 pub(crate) const SPAN_NAME: &'static str = PROTOCOL_METADATA_LOADED_SPAN;
552
553 fn empty() -> Self {
556 Self {
557 operation_id: MetricId::nil(),
558 correlation_id: None,
559 table_type: TableType::from_catalog_managed(false),
560 load_type: LogSegmentLoadType::default(),
561 source: ProtocolMetadataSource::Unknown,
562 duration: Duration::ZERO,
563 }
564 }
565
566 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
567 let mut event = Self::empty();
568 attrs.record(&mut event);
569 event
570 }
571}
572
573impl Visit for ProtocolMetadataLoadSuccess {
574 fn record_bool(&mut self, field: &Field, value: bool) {
575 if field.name() == IS_CATALOG_MANAGED_FIELD {
576 self.table_type = TableType::from_catalog_managed(value);
577 }
578 }
579
580 fn record_str(&mut self, field: &Field, value: &str) {
581 match field.name() {
582 CORRELATION_ID_FIELD if !value.is_empty() => self.correlation_id = Some(value.into()),
583 "load_type" => self.load_type = LogSegmentLoadType::parse_or_unknown(value),
584 "pm_source" => self.source = ProtocolMetadataSource::parse_or_unknown(value),
585 _ => {}
586 }
587 }
588
589 fn record_u64(&mut self, field: &Field, value: u64) {
590 if field.name() == "duration_ns" {
591 self.duration = Duration::from_nanos(value);
592 }
593 }
594
595 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
596 if let Some(id) = record_operation_id(field, value, Self::SPAN_NAME) {
597 self.operation_id = id;
598 }
599 }
600}
601
602impl fmt::Display for ProtocolMetadataLoadSuccess {
603 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
604 let Self {
605 operation_id,
606 table_type,
607 correlation_id,
608 load_type,
609 source,
610 duration,
611 } = self;
612 write!(
613 f,
614 "ProtocolMetadataLoadSuccess(id={operation_id}, table_type={table_type}, \
615 correlation_id={correlation_id:?}, load_type={load_type}, source={source}, \
616 duration={duration:?})"
617 )
618 }
619}
620
621#[derive(Debug, Clone)]
623pub struct ProtocolMetadataLoadFailure {
624 pub operation_id: MetricId,
625 pub correlation_id: Option<Arc<str>>,
628 pub table_type: TableType,
629 pub load_type: LogSegmentLoadType,
630}
631
632impl fmt::Display for ProtocolMetadataLoadFailure {
633 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
634 write!(
635 f,
636 "ProtocolMetadataLoadFailure(id={}, table_type={}, correlation_id={:?}, \
637 load_type={})",
638 self.operation_id, self.table_type, self.correlation_id, self.load_type
639 )
640 }
641}
642
643pub(crate) const SNAPSHOT_COMPLETED_SPAN: &str = "snap.build";
648
649#[derive(Debug, Clone)]
651pub struct SnapshotBuildSuccess {
652 pub operation_id: MetricId,
654 pub correlation_id: Option<Arc<str>>,
657 pub table_type: TableType,
658 pub load_type: LogSegmentLoadType,
659
660 pub version: u64,
662
663 pub duration: Duration,
665}
666
667impl SnapshotBuildSuccess {
668 pub(crate) const SPAN_NAME: &'static str = SNAPSHOT_COMPLETED_SPAN;
669
670 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
671 Self {
672 operation_id: MetricId::from_attrs(attrs),
673 table_type: TableType::from_catalog_managed(read_is_catalog_managed(attrs)),
674 correlation_id: correlation_id_from_attrs(attrs),
675 load_type: load_type_from_attrs(attrs),
676 version: 0,
677 duration: Duration::default(),
678 }
679 }
680
681 pub(crate) fn record_u64(&mut self, name: &str, value: u64) -> Result<(), &'static str> {
682 match name {
683 "version" => self.version = value,
684 _ => return Err(Self::SPAN_NAME),
685 }
686 Ok(())
687 }
688
689 pub(crate) fn set_duration(&mut self, d: Duration) {
690 self.duration = d;
691 }
692}
693
694impl fmt::Display for SnapshotBuildSuccess {
695 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
696 let Self {
697 operation_id,
698 table_type,
699 correlation_id,
700 load_type,
701 version,
702 duration,
703 } = self;
704 write!(
705 f,
706 "SnapshotBuildSuccess(id={operation_id}, table_type={table_type}, \
707 correlation_id={correlation_id:?}, load_type={load_type}, version={version}, \
708 duration={duration:?})"
709 )
710 }
711}
712
713#[derive(Debug, Clone)]
719pub struct SnapshotBuildFailure {
720 pub operation_id: MetricId,
721 pub correlation_id: Option<Arc<str>>,
724 pub table_type: TableType,
725 pub load_type: LogSegmentLoadType,
726}
727
728impl fmt::Display for SnapshotBuildFailure {
729 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
730 write!(
731 f,
732 "SnapshotBuildFailure(id={}, table_type={}, correlation_id={:?}, load_type={})",
733 self.operation_id, self.table_type, self.correlation_id, self.load_type
734 )
735 }
736}
737
738pub(crate) const TRANSACTION_COMMIT_SPAN: &str = "txn.commit";
743
744#[derive(Debug, Clone)]
746pub struct TransactionCommitSuccess {
747 pub operation_id: MetricId,
749 pub correlation_id: Option<Arc<str>>,
752 pub table_type: TableType,
753 pub commit_version: u64,
754
755 pub num_add_files: u64,
757 pub num_remove_files: u64,
758 pub num_dv_updates: u64,
759 pub add_files_bytes: u64,
760 pub remove_files_bytes: u64,
761 pub is_blind_append: bool,
762 pub data_change: bool,
763 pub operation: Option<String>,
764 pub prepare_duration: Duration,
766 pub committer_duration: Duration,
768
769 pub total_duration: Duration,
771}
772
773impl TransactionCommitSuccess {
774 pub(crate) const SPAN_NAME: &'static str = TRANSACTION_COMMIT_SPAN;
775
776 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
777 let mut v = TransactionCommitAttrs::default();
778 attrs.record(&mut v);
779 Self {
780 operation_id: MetricId::from_attrs(attrs),
781 table_type: TableType::from_catalog_managed(read_is_catalog_managed(attrs)),
782 correlation_id: correlation_id_from_attrs(attrs),
783 commit_version: v.commit_version,
784 num_add_files: 0,
785 num_remove_files: 0,
786 num_dv_updates: 0,
787 add_files_bytes: 0,
788 remove_files_bytes: 0,
789 is_blind_append: false,
790 data_change: false,
791 operation: None,
792 prepare_duration: Duration::default(),
793 committer_duration: Duration::default(),
794 total_duration: Duration::default(),
795 }
796 }
797
798 pub(crate) fn record_u64(&mut self, name: &str, value: u64) -> Result<(), &'static str> {
799 match name {
800 "num_add_files" => self.num_add_files = value,
801 "num_remove_files" => self.num_remove_files = value,
802 "num_dv_updates" => self.num_dv_updates = value,
803 "add_files_bytes" => self.add_files_bytes = value,
804 "remove_files_bytes" => self.remove_files_bytes = value,
805 "prepare_duration_ns" => self.prepare_duration = Duration::from_nanos(value),
806 "committer_duration_ns" => self.committer_duration = Duration::from_nanos(value),
807 _ => return Err(Self::SPAN_NAME),
808 }
809 Ok(())
810 }
811
812 pub(crate) fn record_bool(&mut self, name: &str, value: bool) -> Result<(), &'static str> {
813 match name {
814 "is_blind_append" => self.is_blind_append = value,
815 "data_change" => self.data_change = value,
816 _ => return Err(Self::SPAN_NAME),
817 }
818 Ok(())
819 }
820
821 pub(crate) fn record_str(&mut self, name: &str, value: &str) -> Result<(), &'static str> {
822 match name {
823 "operation" => self.operation = Some(value.to_string()),
824 _ => return Err(Self::SPAN_NAME),
825 }
826 Ok(())
827 }
828
829 pub(crate) fn set_duration(&mut self, d: Duration) {
830 self.total_duration = d;
831 }
832}
833
834impl fmt::Display for TransactionCommitSuccess {
835 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
836 let Self {
837 operation_id,
838 table_type,
839 correlation_id,
840 commit_version,
841 num_add_files,
842 num_remove_files,
843 num_dv_updates,
844 add_files_bytes,
845 remove_files_bytes,
846 is_blind_append,
847 data_change,
848 operation,
849 prepare_duration,
850 committer_duration,
851 total_duration,
852 } = self;
853 write!(
854 f,
855 "TransactionCommitSuccess(id={operation_id}, table_type={table_type}, \
856 correlation_id={correlation_id:?}, version={commit_version}, \
857 total_duration={total_duration:?}, prepare={prepare_duration:?}, committer={committer_duration:?}, \
858 add_files={num_add_files}, remove_files={num_remove_files}, dv_updates={num_dv_updates}, \
859 add_bytes={add_files_bytes}, remove_bytes={remove_files_bytes}, \
860 is_blind_append={is_blind_append}, data_change={data_change}, operation={operation:?})"
861 )
862 }
863}
864
865#[derive(Debug, Clone, Copy, PartialEq, Eq, EnumString, StrumDisplay, AsRefStr, IntoStaticStr)]
870#[strum(serialize_all = "snake_case")]
871pub enum CommitFailureReason {
872 Conflict,
874 RetryableIo,
876 Error,
878}
879
880#[derive(Debug, Clone)]
883pub struct TransactionCommitFailure {
884 pub operation_id: MetricId,
885 pub correlation_id: Option<Arc<str>>,
888 pub table_type: TableType,
889 pub reason: CommitFailureReason,
890}
891
892impl fmt::Display for TransactionCommitFailure {
893 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
894 let Self {
895 operation_id,
896 table_type,
897 correlation_id,
898 reason,
899 } = self;
900 write!(
901 f,
902 "TransactionCommitFailure(id={operation_id}, table_type={table_type}, \
903 correlation_id={correlation_id:?}, reason={reason})"
904 )
905 }
906}
907
908#[derive(Default)]
909struct TransactionCommitAttrs {
910 commit_version: u64,
911}
912
913impl Visit for TransactionCommitAttrs {
914 fn record_u64(&mut self, field: &Field, value: u64) {
915 if field.name() == "commit_version" {
916 self.commit_version = value;
917 }
918 }
919
920 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
921}
922
923pub(crate) const DOMAIN_METADATA_LOADED_SPAN: &str = "snap.get_domain_metadata";
928
929#[derive(Debug, Clone)]
933pub struct DomainMetadataLoadSuccess {
934 pub from_cache: bool,
936 pub num_domains_returned: u64,
937
938 pub duration: Duration,
940}
941
942impl DomainMetadataLoadSuccess {
943 pub(crate) const SPAN_NAME: &'static str = DOMAIN_METADATA_LOADED_SPAN;
944
945 pub(crate) fn from_attrs(_attrs: &Attributes<'_>) -> Self {
946 Self {
947 from_cache: false,
948 num_domains_returned: 0,
949 duration: Duration::default(),
950 }
951 }
952
953 pub(crate) fn record_u64(&mut self, name: &str, value: u64) -> Result<(), &'static str> {
954 match name {
955 "num_domains_returned" => self.num_domains_returned = value,
956 _ => return Err(Self::SPAN_NAME),
957 }
958 Ok(())
959 }
960
961 pub(crate) fn record_bool(&mut self, name: &str, value: bool) -> Result<(), &'static str> {
962 match name {
963 "from_cache" => self.from_cache = value,
964 _ => return Err(Self::SPAN_NAME),
965 }
966 Ok(())
967 }
968
969 pub(crate) fn set_duration(&mut self, d: Duration) {
970 self.duration = d;
971 }
972}
973
974impl fmt::Display for DomainMetadataLoadSuccess {
975 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
976 let Self {
977 from_cache,
978 num_domains_returned,
979 duration,
980 } = self;
981 write!(
982 f,
983 "DomainMetadataLoadSuccess(duration={duration:?}, from_cache={from_cache}, \
984 num_domains_returned={num_domains_returned})"
985 )
986 }
987}
988
989pub(crate) const SET_TRANSACTION_LOADED_SPAN: &str = "snap.get_app_id_version";
994
995#[derive(Debug, Clone)]
999pub struct SetTransactionLoadSuccess {
1000 pub from_cache: bool,
1002 pub found: bool,
1003
1004 pub duration: Duration,
1006}
1007
1008impl SetTransactionLoadSuccess {
1009 pub(crate) const SPAN_NAME: &'static str = SET_TRANSACTION_LOADED_SPAN;
1010
1011 pub(crate) fn from_attrs(_attrs: &Attributes<'_>) -> Self {
1012 Self {
1013 from_cache: false,
1014 found: false,
1015 duration: Duration::default(),
1016 }
1017 }
1018
1019 pub(crate) fn record_bool(&mut self, name: &str, value: bool) -> Result<(), &'static str> {
1020 match name {
1021 "from_cache" => self.from_cache = value,
1022 "found" => self.found = value,
1023 _ => return Err(Self::SPAN_NAME),
1024 }
1025 Ok(())
1026 }
1027
1028 pub(crate) fn set_duration(&mut self, d: Duration) {
1029 self.duration = d;
1030 }
1031}
1032
1033impl fmt::Display for SetTransactionLoadSuccess {
1034 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1035 let Self {
1036 from_cache,
1037 found,
1038 duration,
1039 } = self;
1040 write!(
1041 f,
1042 "SetTransactionLoadSuccess(duration={duration:?}, from_cache={from_cache}, found={found})"
1043 )
1044 }
1045}
1046
1047pub(crate) const CRC_READ_COMPLETED_SPAN: &str = "crc_read_completed";
1052
1053#[derive(Debug, Clone)]
1055pub struct CrcReadSuccess {
1056 pub bytes_read: u64,
1058
1059 pub duration: Duration,
1061}
1062
1063impl CrcReadSuccess {
1064 pub(crate) const SPAN_NAME: &'static str = CRC_READ_COMPLETED_SPAN;
1065
1066 pub(crate) fn from_attrs(_attrs: &Attributes<'_>) -> Self {
1067 Self {
1068 bytes_read: 0,
1069 duration: Duration::default(),
1070 }
1071 }
1072
1073 pub(crate) fn record_u64(&mut self, name: &str, value: u64) -> Result<(), &'static str> {
1074 match name {
1075 "bytes_read" => self.bytes_read = value,
1076 _ => return Err(Self::SPAN_NAME),
1077 }
1078 Ok(())
1079 }
1080
1081 pub(crate) fn set_duration(&mut self, d: Duration) {
1082 self.duration = d;
1083 }
1084}
1085
1086impl fmt::Display for CrcReadSuccess {
1087 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1088 let Self {
1089 duration,
1090 bytes_read,
1091 } = self;
1092 write!(
1093 f,
1094 "CrcReadSuccess(duration={duration:?}, bytes={bytes_read})"
1095 )
1096 }
1097}
1098
1099#[derive(Debug, Clone)]
1107pub struct JsonReadCompleted {
1108 pub num_files: u64,
1110 pub bytes_read: u64,
1111}
1112
1113impl JsonReadCompleted {
1114 pub(crate) const SPAN_NAME: &'static str = "json_read_completed";
1115
1116 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
1117 let mut v = FileReadAttrs::default();
1118 attrs.record(&mut v);
1119 Self {
1120 num_files: v.num_files,
1121 bytes_read: v.bytes_read,
1122 }
1123 }
1124}
1125
1126impl fmt::Display for JsonReadCompleted {
1127 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1128 let Self {
1129 num_files,
1130 bytes_read,
1131 } = self;
1132 write!(
1133 f,
1134 "JsonReadCompleted(files={num_files}, bytes={bytes_read})"
1135 )
1136 }
1137}
1138
1139#[derive(Debug, Clone)]
1147pub struct ParquetReadCompleted {
1148 pub num_files: u64,
1150 pub bytes_read: u64,
1151}
1152
1153impl ParquetReadCompleted {
1154 pub(crate) const SPAN_NAME: &'static str = "parquet_read_completed";
1155
1156 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
1157 let mut v = FileReadAttrs::default();
1158 attrs.record(&mut v);
1159 Self {
1160 num_files: v.num_files,
1161 bytes_read: v.bytes_read,
1162 }
1163 }
1164}
1165
1166impl fmt::Display for ParquetReadCompleted {
1167 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1168 let Self {
1169 num_files,
1170 bytes_read,
1171 } = self;
1172 write!(
1173 f,
1174 "ParquetReadCompleted(files={num_files}, bytes={bytes_read})"
1175 )
1176 }
1177}
1178
1179#[derive(Default)]
1181struct FileReadAttrs {
1182 num_files: u64,
1183 bytes_read: u64,
1184}
1185
1186impl Visit for FileReadAttrs {
1187 fn record_u64(&mut self, field: &Field, value: u64) {
1188 match field.name() {
1189 "num_files" => self.num_files = value,
1190 "bytes_read" => self.bytes_read = value,
1191 _ => {}
1192 }
1193 }
1194 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
1195}
1196
1197#[derive(Debug, Clone, Copy, PartialEq, Eq, EnumString, StrumDisplay, AsRefStr, IntoStaticStr)]
1206pub enum ScanType {
1207 #[strum(serialize = "sequential")]
1209 SequentialPhase,
1210 #[strum(serialize = "parallel")]
1212 ParallelPhase,
1213 #[strum(serialize = "full")]
1215 Full,
1216}
1217
1218impl ScanType {
1219 fn parse_lenient(s: &str) -> Self {
1220 Self::from_str(s).unwrap_or_else(|e| {
1221 warn!("Invalid scan_type '{s}' on span: {e}. Using Full.");
1222 Self::Full
1223 })
1224 }
1225}
1226
1227pub(crate) const IS_CATALOG_MANAGED_FIELD: &str = "is_catalog_managed";
1235
1236#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, serde::Serialize, serde::Deserialize)]
1238pub enum TableType {
1239 #[default]
1241 PathBased,
1242 CatalogManaged,
1244}
1245
1246impl TableType {
1247 #[internal_api]
1248 pub(crate) fn from_catalog_managed(is_catalog_managed: bool) -> Self {
1249 if is_catalog_managed {
1250 Self::CatalogManaged
1251 } else {
1252 Self::PathBased
1253 }
1254 }
1255
1256 pub(crate) fn is_catalog_managed(self) -> bool {
1257 self == Self::CatalogManaged
1258 }
1259}
1260
1261impl fmt::Display for TableType {
1262 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1263 f.write_str(match self {
1264 Self::PathBased => "path_based",
1265 Self::CatalogManaged => "catalog_managed",
1266 })
1267 }
1268}
1269
1270#[derive(Debug, Clone)]
1272pub struct SnapshotLoadMetricContext {
1273 pub(crate) operation_id: MetricId,
1274 pub(crate) correlation_id: Option<Arc<str>>,
1275 pub(crate) is_catalog_managed: bool,
1276 pub(crate) load_type: LogSegmentLoadType,
1277}
1278
1279#[cfg(test)]
1280impl SnapshotLoadMetricContext {
1281 pub(crate) fn for_test() -> Self {
1284 Self {
1285 operation_id: MetricId::nil(),
1286 correlation_id: None,
1287 is_catalog_managed: false,
1288 load_type: LogSegmentLoadType::default(),
1289 }
1290 }
1291}
1292
1293pub(crate) fn record_operation_id(
1297 field: &Field,
1298 value: &dyn fmt::Debug,
1299 span_name: &str,
1300) -> Option<MetricId> {
1301 (field.name() == "operation_id").then(|| {
1302 let s = format!("{value:?}");
1303 Uuid::from_str(&s).map(MetricId).unwrap_or_else(|e| {
1304 warn!("Invalid uuid '{s}' on {span_name}: {e}. Using nil.");
1305 MetricId::nil()
1306 })
1307 })
1308}
1309
1310pub(crate) fn read_is_catalog_managed(attrs: &Attributes<'_>) -> bool {
1311 #[derive(Default)]
1312 struct V(bool);
1313 impl Visit for V {
1314 fn record_bool(&mut self, field: &Field, value: bool) {
1315 if field.name() == IS_CATALOG_MANAGED_FIELD {
1316 self.0 = value;
1317 }
1318 }
1319 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
1320 }
1321 let mut v = V::default();
1322 attrs.record(&mut v);
1323 v.0
1324}
1325
1326pub(crate) const CORRELATION_ID_FIELD: &str = "correlation_id";
1329
1330pub(crate) fn correlation_id_from_attrs(attrs: &Attributes<'_>) -> Option<Arc<str>> {
1333 #[derive(Default)]
1334 struct CorrelationIdVisitor(Option<Arc<str>>);
1335 impl Visit for CorrelationIdVisitor {
1336 fn record_str(&mut self, field: &Field, value: &str) {
1337 if field.name() == CORRELATION_ID_FIELD && !value.is_empty() {
1338 self.0 = Some(value.into());
1339 }
1340 }
1341 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
1342 }
1343 let mut v = CorrelationIdVisitor::default();
1344 attrs.record(&mut v);
1345 v.0
1346}
1347
1348pub(crate) fn load_type_from_attrs(attrs: &Attributes<'_>) -> LogSegmentLoadType {
1349 #[derive(Default)]
1350 struct V(LogSegmentLoadType);
1351 impl Visit for V {
1352 fn record_str(&mut self, field: &Field, value: &str) {
1353 if field.name() == "load_type" {
1354 self.0 = LogSegmentLoadType::parse_or_unknown(value);
1355 }
1356 }
1357 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
1358 }
1359 let mut v = V::default();
1360 attrs.record(&mut v);
1361 v.0
1362}
1363
1364#[derive(Debug, Clone)]
1367pub struct ScanMetadataCompleted {
1368 pub operation_id: MetricId,
1371 pub correlation_id: Option<Arc<str>>,
1374 pub table_type: TableType,
1376 pub scan_type: ScanType,
1378 pub duration: Duration,
1380 pub num_add_files_seen: u64,
1385 pub num_active_add_files: u64,
1387 pub active_add_files_bytes: u64,
1389 pub num_remove_files_seen: u64,
1391 pub num_non_file_actions: u64,
1393 pub num_predicate_filtered: u64,
1395 pub peak_hash_set_size: usize,
1397 pub dedup_visitor_time: Duration,
1399 pub predicate_eval_time: Duration,
1401}
1402
1403impl ScanMetadataCompleted {
1404 pub(crate) const SPAN_NAME: &'static str = "scan.metadata_completed";
1405
1406 pub(crate) fn from_attrs(attrs: &Attributes<'_>) -> Self {
1407 let mut v = ScanMetadataCompletedAttrs::default();
1408 attrs.record(&mut v);
1409 Self {
1410 operation_id: MetricId(v.operation_id),
1411 table_type: TableType::from_catalog_managed(v.is_catalog_managed),
1412 correlation_id: v.correlation_id,
1413 scan_type: ScanType::parse_lenient(&v.scan_type),
1414 duration: Duration::from_nanos(v.duration_ns),
1415 num_add_files_seen: v.num_add_files_seen,
1416 num_active_add_files: v.num_active_add_files,
1417 active_add_files_bytes: v.active_add_files_bytes,
1418 num_remove_files_seen: v.num_remove_files_seen,
1419 num_non_file_actions: v.num_non_file_actions,
1420 num_predicate_filtered: v.num_predicate_filtered,
1421 peak_hash_set_size: v.peak_hash_set_size as usize,
1422 dedup_visitor_time: Duration::from_nanos(v.dedup_visitor_time_ns),
1423 predicate_eval_time: Duration::from_nanos(v.predicate_eval_time_ns),
1424 }
1425 }
1426}
1427
1428impl fmt::Display for ScanMetadataCompleted {
1429 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1430 let Self {
1431 operation_id,
1432 table_type,
1433 correlation_id,
1434 scan_type,
1435 duration,
1436 num_add_files_seen,
1437 num_active_add_files,
1438 active_add_files_bytes,
1439 num_remove_files_seen,
1440 num_non_file_actions,
1441 num_predicate_filtered,
1442 peak_hash_set_size,
1443 dedup_visitor_time,
1444 predicate_eval_time,
1445 } = self;
1446 write!(
1447 f,
1448 "ScanMetadataCompleted(id={operation_id}, table_type={table_type}, \
1449 correlation_id={correlation_id:?}, scan_type={scan_type}, duration={duration:?}, \
1450 add_files_seen={num_add_files_seen}, active_add_files={num_active_add_files}, \
1451 active_add_files_bytes={active_add_files_bytes}, \
1452 remove_files_seen={num_remove_files_seen}, non_file_actions={num_non_file_actions}, \
1453 predicate_filtered={num_predicate_filtered}, peak_hash_set_size={peak_hash_set_size}, \
1454 dedup_visitor_time={dedup_visitor_time:?}, predicate_eval_time={predicate_eval_time:?})"
1455 )
1456 }
1457}
1458
1459#[derive(Default)]
1460struct ScanMetadataCompletedAttrs {
1461 operation_id: Uuid,
1462 is_catalog_managed: bool,
1463 correlation_id: Option<Arc<str>>,
1464 scan_type: String,
1465 duration_ns: u64,
1466 num_add_files_seen: u64,
1467 num_active_add_files: u64,
1468 active_add_files_bytes: u64,
1469 num_remove_files_seen: u64,
1470 num_non_file_actions: u64,
1471 num_predicate_filtered: u64,
1472 peak_hash_set_size: u64,
1473 dedup_visitor_time_ns: u64,
1474 predicate_eval_time_ns: u64,
1475}
1476
1477impl Visit for ScanMetadataCompletedAttrs {
1478 fn record_bool(&mut self, field: &Field, value: bool) {
1479 if field.name() == IS_CATALOG_MANAGED_FIELD {
1480 self.is_catalog_managed = value;
1481 }
1482 }
1483
1484 fn record_str(&mut self, field: &Field, value: &str) {
1485 if field.name() == CORRELATION_ID_FIELD && !value.is_empty() {
1486 self.correlation_id = Some(value.into());
1487 }
1488 }
1489
1490 fn record_u64(&mut self, field: &Field, value: u64) {
1491 match field.name() {
1492 "duration_ns" => self.duration_ns = value,
1493 "num_add_files_seen" => self.num_add_files_seen = value,
1494 "num_active_add_files" => self.num_active_add_files = value,
1495 "active_add_files_bytes" => self.active_add_files_bytes = value,
1496 "num_remove_files_seen" => self.num_remove_files_seen = value,
1497 "num_non_file_actions" => self.num_non_file_actions = value,
1498 "num_predicate_filtered" => self.num_predicate_filtered = value,
1499 "peak_hash_set_size" => self.peak_hash_set_size = value,
1500 "dedup_visitor_time_ns" => self.dedup_visitor_time_ns = value,
1501 "predicate_eval_time_ns" => self.predicate_eval_time_ns = value,
1502 _ => {}
1503 }
1504 }
1505
1506 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
1507 if let Some(id) = record_operation_id(field, value, ScanMetadataCompleted::SPAN_NAME) {
1508 self.operation_id = id.0;
1509 } else if field.name() == "scan_type" {
1510 self.scan_type = format!("{value:?}");
1511 }
1512 }
1513}
1514
1515pub(crate) const STORAGE_SPAN: &str = "storage";
1524
1525pub(crate) fn storage_metric_from_attrs(attrs: &Attributes<'_>) -> Option<MetricEvent> {
1528 let mut v = StorageAttrs::default();
1529 attrs.record(&mut v);
1530 let duration = Duration::from_nanos(v.duration_ns);
1531 match v.kind {
1532 StorageKind::List => Some(MetricEvent::StorageListCompleted(StorageListCompleted {
1533 duration,
1534 num_files: v.num_files,
1535 })),
1536 StorageKind::Read => Some(MetricEvent::StorageReadCompleted(StorageReadCompleted {
1537 duration,
1538 num_files: v.num_files,
1539 bytes_read: v.bytes_read,
1540 })),
1541 StorageKind::Copy => Some(MetricEvent::StorageCopyCompleted(StorageCopyCompleted {
1542 duration,
1543 })),
1544 StorageKind::Unknown => None,
1545 }
1546}
1547
1548#[derive(Default)]
1549enum StorageKind {
1550 #[default]
1551 Unknown,
1552 List,
1553 Read,
1554 Copy,
1555}
1556
1557#[derive(Default)]
1558struct StorageAttrs {
1559 kind: StorageKind,
1560 num_files: u64,
1561 bytes_read: u64,
1562 duration_ns: u64,
1563}
1564
1565impl Visit for StorageAttrs {
1566 fn record_str(&mut self, field: &Field, value: &str) {
1567 if field.name() == "name" {
1568 self.kind = match value {
1569 StorageListCompleted::NAME => StorageKind::List,
1570 StorageReadCompleted::NAME => StorageKind::Read,
1571 StorageCopyCompleted::NAME => StorageKind::Copy,
1572 _ => {
1573 warn!("Storage span with unknown name: {value}");
1574 StorageKind::Unknown
1575 }
1576 };
1577 }
1578 }
1579
1580 fn record_u64(&mut self, field: &Field, value: u64) {
1581 match field.name() {
1582 "num_files" => self.num_files = value,
1583 "bytes_read" => self.bytes_read = value,
1584 "duration_ns" => self.duration_ns = value,
1585 _ => {}
1586 }
1587 }
1588
1589 fn record_debug(&mut self, _field: &Field, _value: &dyn fmt::Debug) {}
1590}
1591
1592#[derive(Debug, Clone)]
1598pub struct StorageListCompleted {
1599 pub duration: Duration,
1601 pub num_files: u64,
1602}
1603
1604impl StorageListCompleted {
1605 pub(crate) const NAME: &'static str = "list_completed";
1606}
1607
1608impl fmt::Display for StorageListCompleted {
1609 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1610 let Self {
1611 duration,
1612 num_files,
1613 } = self;
1614 write!(
1615 f,
1616 "StorageListCompleted(duration={duration:?}, files={num_files})"
1617 )
1618 }
1619}
1620
1621#[derive(Debug, Clone)]
1627pub struct StorageReadCompleted {
1628 pub duration: Duration,
1630 pub num_files: u64,
1631 pub bytes_read: u64,
1632}
1633
1634impl StorageReadCompleted {
1635 pub(crate) const NAME: &'static str = "read_completed";
1636}
1637
1638impl fmt::Display for StorageReadCompleted {
1639 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1640 let Self {
1641 duration,
1642 num_files,
1643 bytes_read,
1644 } = self;
1645 write!(
1646 f,
1647 "StorageReadCompleted(duration={duration:?}, files={num_files}, bytes={bytes_read})"
1648 )
1649 }
1650}
1651
1652#[derive(Debug, Clone)]
1658pub struct StorageCopyCompleted {
1659 pub duration: Duration,
1661}
1662
1663impl StorageCopyCompleted {
1664 pub(crate) const NAME: &'static str = "copy_completed";
1665}
1666
1667impl fmt::Display for StorageCopyCompleted {
1668 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1669 let Self { duration } = self;
1670 write!(f, "StorageCopyCompleted(duration={duration:?})")
1671 }
1672}
1673
1674pub fn emit_json_read_completed(num_files: u64, bytes_read: u64) {
1687 let _span = tracing::span!(
1688 tracing::Level::INFO,
1689 JsonReadCompleted::SPAN_NAME,
1690 report = tracing::field::Empty,
1691 num_files,
1692 bytes_read,
1693 );
1694}
1695
1696pub fn emit_parquet_read_completed(num_files: u64, bytes_read: u64) {
1701 let _span = tracing::span!(
1702 tracing::Level::INFO,
1703 ParquetReadCompleted::SPAN_NAME,
1704 report = tracing::field::Empty,
1705 num_files,
1706 bytes_read,
1707 );
1708}
1709
1710pub(crate) fn emit_scan_metadata_completed(e: &ScanMetadataCompleted) {
1713 let _span = tracing::span!(
1714 tracing::Level::INFO,
1715 ScanMetadataCompleted::SPAN_NAME,
1716 report = tracing::field::Empty,
1717 operation_id = %e.operation_id,
1718 is_catalog_managed = e.table_type.is_catalog_managed(),
1719 correlation_id = e.correlation_id.as_deref().unwrap_or(""),
1720 scan_type = %e.scan_type,
1721 duration_ns = e.duration.as_nanos() as u64,
1722 num_add_files_seen = e.num_add_files_seen,
1723 num_active_add_files = e.num_active_add_files,
1724 active_add_files_bytes = e.active_add_files_bytes,
1725 num_remove_files_seen = e.num_remove_files_seen,
1726 num_non_file_actions = e.num_non_file_actions,
1727 num_predicate_filtered = e.num_predicate_filtered,
1728 peak_hash_set_size = e.peak_hash_set_size as u64,
1729 dedup_visitor_time_ns = e.dedup_visitor_time.as_nanos() as u64,
1730 predicate_eval_time_ns = e.predicate_eval_time.as_nanos() as u64,
1731 );
1732}
1733
1734pub(crate) fn emit_log_segment_load(
1738 ctx: &SnapshotLoadMetricContext,
1739 segment: &LogSegment,
1740 duration: Duration,
1741) {
1742 tracing::span!(
1743 tracing::Level::INFO,
1744 LogSegmentLoadSuccess::SPAN_NAME,
1745 report = tracing::field::Empty,
1746 operation_id = %ctx.operation_id,
1747 is_catalog_managed = ctx.is_catalog_managed,
1748 correlation_id = ctx.correlation_id.as_deref().unwrap_or(""),
1749 load_type = ctx.load_type.as_ref(),
1750 num_commit_files = segment.listed.ascending_commit_files.len() as u64,
1751 num_checkpoint_files = segment.listed.checkpoint_parts.len() as u64,
1752 num_compaction_files = segment.listed.ascending_compaction_files.len() as u64,
1753 crc_versions_behind =
1754 LogSegmentLoadSuccess::encode_crc_versions_behind(segment.crc_versions_behind()),
1755 duration_ns = duration.as_nanos() as u64,
1756 );
1757}
1758
1759pub(crate) fn emit_log_segment_load_failure(ctx: &SnapshotLoadMetricContext) {
1761 let span = tracing::span!(
1762 tracing::Level::INFO,
1763 LogSegmentLoadSuccess::SPAN_NAME,
1764 report = tracing::field::Empty,
1765 operation_id = %ctx.operation_id,
1766 is_catalog_managed = ctx.is_catalog_managed,
1767 correlation_id = ctx.correlation_id.as_deref().unwrap_or(""),
1768 load_type = ctx.load_type.as_ref(),
1769 );
1770 let _enter = span.enter();
1771 tracing::info!(error = tracing::field::debug("log segment load failed"));
1772}
1773
1774pub(crate) fn emit_protocol_metadata_load(
1777 ctx: &SnapshotLoadMetricContext,
1778 source: ProtocolMetadataSource,
1779 duration: Duration,
1780) {
1781 let _span = tracing::span!(
1782 tracing::Level::INFO,
1783 ProtocolMetadataLoadSuccess::SPAN_NAME,
1784 report = tracing::field::Empty,
1785 operation_id = %ctx.operation_id,
1786 is_catalog_managed = ctx.is_catalog_managed,
1787 correlation_id = ctx.correlation_id.as_deref().unwrap_or(""),
1788 load_type = ctx.load_type.as_ref(),
1789 pm_source = source.as_ref(),
1790 duration_ns = duration.as_nanos() as u64,
1791 );
1792}
1793
1794pub(crate) fn emit_protocol_metadata_load_failure(ctx: &SnapshotLoadMetricContext) {
1797 let span = tracing::span!(
1798 tracing::Level::INFO,
1799 ProtocolMetadataLoadSuccess::SPAN_NAME,
1800 report = tracing::field::Empty,
1801 operation_id = %ctx.operation_id,
1802 is_catalog_managed = ctx.is_catalog_managed,
1803 correlation_id = ctx.correlation_id.as_deref().unwrap_or(""),
1804 load_type = ctx.load_type.as_ref(),
1805 );
1806 let _enter = span.enter();
1807 tracing::info!(error = tracing::field::debug("protocol/metadata load failed"));
1808}
1809
1810#[cfg(test)]
1811mod tests {
1812 use rstest::rstest;
1813
1814 use super::*;
1815
1816 fn commit_success(operation_id: MetricId) -> TransactionCommitSuccess {
1817 TransactionCommitSuccess {
1818 operation_id,
1819 table_type: TableType::PathBased,
1820 correlation_id: None,
1821 commit_version: 1,
1822 num_add_files: 0,
1823 num_remove_files: 0,
1824 num_dv_updates: 0,
1825 add_files_bytes: 0,
1826 remove_files_bytes: 0,
1827 is_blind_append: false,
1828 data_change: false,
1829 operation: None,
1830 prepare_duration: Duration::default(),
1831 committer_duration: Duration::default(),
1832 total_duration: Duration::default(),
1833 }
1834 }
1835
1836 #[rstest]
1837 #[case::conflict("conflict", CommitFailureReason::Conflict)]
1838 #[case::retryable_io("retryable_io", CommitFailureReason::RetryableIo)]
1839 #[case::error("error", CommitFailureReason::Error)]
1840 #[case::unknown_defaults_to_error("totally_unknown", CommitFailureReason::Error)]
1841 fn record_str_failure_reason_flips_to_expected_reason(
1842 #[case] value: &str,
1843 #[case] expected: CommitFailureReason,
1844 ) {
1845 let id = MetricId::new();
1846 let mut event = MetricEvent::TransactionCommitSuccess(commit_success(id));
1847 event.record_str("failure_reason", value).unwrap();
1848 let MetricEvent::TransactionCommitFailure(failure) = event else {
1849 panic!("expected TransactionCommitFailure");
1850 };
1851 assert_eq!(failure.operation_id, id);
1852 assert_eq!(failure.reason, expected);
1853 }
1854
1855 #[test]
1856 fn record_str_operation_sets_field_without_flipping() {
1857 let mut event = MetricEvent::TransactionCommitSuccess(commit_success(MetricId::new()));
1858 event.record_str("operation", "WRITE").unwrap();
1859 let MetricEvent::TransactionCommitSuccess(success) = event else {
1860 panic!("expected TransactionCommitSuccess");
1861 };
1862 assert_eq!(success.operation.as_deref(), Some("WRITE"));
1863 }
1864
1865 #[test]
1866 fn record_u64_num_dv_updates_sets_field() {
1867 let mut event = MetricEvent::TransactionCommitSuccess(commit_success(MetricId::new()));
1868 event.record_u64("num_dv_updates", 7).unwrap();
1869 let MetricEvent::TransactionCommitSuccess(success) = event else {
1870 panic!("expected TransactionCommitSuccess");
1871 };
1872 assert_eq!(success.num_dv_updates, 7);
1873 }
1874
1875 #[rstest]
1876 #[case::conflict(CommitFailureReason::Conflict, "conflict")]
1877 #[case::retryable_io(CommitFailureReason::RetryableIo, "retryable_io")]
1878 #[case::error(CommitFailureReason::Error, "error")]
1879 fn commit_failure_reason_serializes_to_wire_name_and_parses_back(
1880 #[case] reason: CommitFailureReason,
1881 #[case] wire: &str,
1882 ) {
1883 let serialized: &'static str = reason.into();
1884 assert_eq!(serialized, wire);
1885 assert_eq!(CommitFailureReason::from_str(wire).unwrap(), reason);
1886 }
1887
1888 #[rstest]
1889 #[case::sequential(ScanType::SequentialPhase, "sequential")]
1890 #[case::parallel(ScanType::ParallelPhase, "parallel")]
1891 #[case::full(ScanType::Full, "full")]
1892 fn scan_type_serializes_to_wire_name_and_parses_back(
1893 #[case] scan_type: ScanType,
1894 #[case] wire: &str,
1895 ) {
1896 let serialized: &'static str = scan_type.into();
1897 assert_eq!(serialized, wire);
1898 assert_eq!(ScanType::from_str(wire).unwrap(), scan_type);
1899 }
1900
1901 #[rstest]
1902 #[case::known("parallel", ScanType::ParallelPhase)]
1903 #[case::unknown_defaults_to_full("totally_unknown", ScanType::Full)]
1904 fn scan_type_parse_lenient_maps_unknown_to_full(
1905 #[case] value: &str,
1906 #[case] expected: ScanType,
1907 ) {
1908 assert_eq!(ScanType::parse_lenient(value), expected);
1909 }
1910
1911 #[rstest]
1912 #[case::full(LogSegmentLoadType::Full, "full")]
1913 #[case::incremental(LogSegmentLoadType::Incremental, "incremental")]
1914 #[case::unknown(LogSegmentLoadType::Unknown, "unknown")]
1915 fn log_segment_load_type_serializes_to_wire_name_and_parses_back(
1916 #[case] load_type: LogSegmentLoadType,
1917 #[case] wire: &str,
1918 ) {
1919 let serialized: &'static str = load_type.into();
1920 assert_eq!(serialized, wire);
1921 assert_eq!(LogSegmentLoadType::from_str(wire).unwrap(), load_type);
1922 }
1923
1924 #[rstest]
1925 #[case::known("incremental", LogSegmentLoadType::Incremental)]
1926 #[case::empty_maps_to_unknown("", LogSegmentLoadType::Unknown)]
1927 #[case::unrecognized_maps_to_unknown("totally_unknown", LogSegmentLoadType::Unknown)]
1928 fn log_segment_load_type_parse_or_unknown(
1929 #[case] value: &str,
1930 #[case] expected: LogSegmentLoadType,
1931 ) {
1932 assert_eq!(LogSegmentLoadType::parse_or_unknown(value), expected);
1933 }
1934
1935 #[rstest]
1936 #[case::none(None)]
1937 #[case::zero(Some(0))]
1938 #[case::some(Some(7))]
1939 fn crc_versions_behind_sentinel_round_trips(#[case] v: Option<u64>) {
1940 let encoded = LogSegmentLoadSuccess::encode_crc_versions_behind(v);
1941 assert_eq!(
1942 LogSegmentLoadSuccess::decode_crc_versions_behind(encoded),
1943 v
1944 );
1945 }
1946
1947 #[rstest]
1948 #[case::crc_at_target(ProtocolMetadataSource::CrcAtTarget, "crc_at_target")]
1949 #[case::crc_advanced(ProtocolMetadataSource::CrcAdvancedByReplay, "crc_advanced_by_replay")]
1950 #[case::crc_seeded(
1951 ProtocolMetadataSource::CrcSeededPmOnlyReplay,
1952 "crc_seeded_pm_only_replay"
1953 )]
1954 #[case::full_replay(ProtocolMetadataSource::FullReplay, "full_replay")]
1955 #[case::unknown(ProtocolMetadataSource::Unknown, "unknown")]
1956 fn protocol_metadata_source_serializes_to_wire_name_and_parses_back(
1957 #[case] source: ProtocolMetadataSource,
1958 #[case] wire: &str,
1959 ) {
1960 let serialized: &'static str = source.into();
1961 assert_eq!(serialized, wire);
1962 assert_eq!(ProtocolMetadataSource::from_str(wire).unwrap(), source);
1963 }
1964
1965 #[rstest]
1966 #[case::known("crc_at_target", ProtocolMetadataSource::CrcAtTarget)]
1967 #[case::empty_maps_to_unknown("", ProtocolMetadataSource::Unknown)]
1968 #[case::unrecognized_maps_to_unknown("totally_unknown", ProtocolMetadataSource::Unknown)]
1969 fn protocol_metadata_source_parse_or_unknown(
1970 #[case] value: &str,
1971 #[case] expected: ProtocolMetadataSource,
1972 ) {
1973 assert_eq!(ProtocolMetadataSource::parse_or_unknown(value), expected);
1974 }
1975
1976 #[test]
1977 fn into_failure_maps_commit_success_to_error_reason() {
1978 let id = MetricId::new();
1979 let failure = MetricEvent::TransactionCommitSuccess(commit_success(id)).into_failure();
1980 let MetricEvent::TransactionCommitFailure(failure) = failure else {
1981 panic!("expected TransactionCommitFailure");
1982 };
1983 assert_eq!(failure.operation_id, id);
1984 assert_eq!(failure.reason, CommitFailureReason::Error);
1985 }
1986
1987 #[test]
1988 fn record_str_failure_reason_flip_preserves_correlation_id() {
1989 let mut success = commit_success(MetricId::new());
1990 success.correlation_id = Some("commit-req-1".into());
1991 let mut event = MetricEvent::TransactionCommitSuccess(success);
1992 event.record_str("failure_reason", "conflict").unwrap();
1993 let MetricEvent::TransactionCommitFailure(failure) = event else {
1994 panic!("expected TransactionCommitFailure");
1995 };
1996 assert_eq!(failure.correlation_id.as_deref(), Some("commit-req-1"));
1997 }
1998
1999 #[test]
2000 fn into_failure_preserves_correlation_id() {
2001 let mut success = commit_success(MetricId::new());
2002 success.correlation_id = Some("commit-req-2".into());
2003 let MetricEvent::TransactionCommitFailure(failure) =
2004 MetricEvent::TransactionCommitSuccess(success).into_failure()
2005 else {
2006 panic!("expected TransactionCommitFailure");
2007 };
2008 assert_eq!(failure.correlation_id.as_deref(), Some("commit-req-2"));
2009
2010 let snapshot = SnapshotBuildSuccess {
2011 operation_id: MetricId::new(),
2012 table_type: TableType::PathBased,
2013 correlation_id: Some("snap-req-3".into()),
2014 load_type: LogSegmentLoadType::Incremental,
2015 version: 0,
2016 duration: Duration::default(),
2017 };
2018 let MetricEvent::SnapshotBuildFailure(failure) =
2019 MetricEvent::SnapshotBuildSuccess(snapshot).into_failure()
2020 else {
2021 panic!("expected SnapshotBuildFailure");
2022 };
2023 assert_eq!(failure.correlation_id.as_deref(), Some("snap-req-3"));
2024 assert_eq!(failure.load_type, LogSegmentLoadType::Incremental);
2025 }
2026}