max / synckit
- Co-Authored-By
- Claude Opus 5 (1M context) <noreply@anthropic.com>
- Claude-Session
- https://claude.ai/code/session_01MptwXZ8k65v19rFmdGAyki
1 file changed,
+108 insertions,
-0 deletions
| @@ -444,6 +444,114 @@ | |||
| 444 | 444 | ); | |
| 445 | 445 | } | |
| 446 | 446 | ||
| 447 | + | // ── The unknown-tag log line ── | |
| 448 | + | // | |
| 449 | + | // `from_wire` answers `Monthly` for "monthly", for "" and for any tag it does | |
| 450 | + | // not recognise, so nothing above can tell those three apart: the guard on | |
| 451 | + | // the `debug!` is invisible to a return-value assertion. The line is how an | |
| 452 | + | // operator learns the server has started sending an interval this client | |
| 453 | + | // does not know, and the guard is what keeps the two expected cases quiet | |
| 454 | + | // rather than logging on every ordinary monthly subscription. | |
| 455 | + | // | |
| 456 | + | // A recording subscriber is what makes it observable. `with_default` scopes | |
| 457 | + | // it to this thread, so nothing global is installed, and the subscriber is | |
| 458 | + | // twenty lines rather than a `tracing-subscriber` dev-dependency. | |
| 459 | + | ||
| 460 | + | /// Pull the `tag` field off an event, whichever way it was recorded. | |
| 461 | + | /// `tag = %other` arrives through `record_debug` as a `format_args`, so the | |
| 462 | + | /// `Debug` rendering is the raw string with no quotes around it. | |
| 463 | + | #[derive(Default)] | |
| 464 | + | struct TagVisitor(Option<String>); | |
| 465 | + | ||
| 466 | + | impl tracing::field::Visit for TagVisitor { | |
| 467 | + | fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) { | |
| 468 | + | if field.name() == "tag" { | |
| 469 | + | self.0 = Some(format!("{value:?}")); | |
| 470 | + | } | |
| 471 | + | } | |
| 472 | + | ||
| 473 | + | fn record_str(&mut self, field: &tracing::field::Field, value: &str) { | |
| 474 | + | if field.name() == "tag" { | |
| 475 | + | self.0 = Some(value.to_string()); | |
| 476 | + | } | |
| 477 | + | } | |
| 478 | + | } | |
| 479 | + | ||
| 480 | + | /// Records the `tag` of every event emitted while it is the thread default. | |
| 481 | + | struct TagRecorder(std::sync::Arc<std::sync::Mutex<Vec<Option<String>>>>); | |
| 482 | + | ||
| 483 | + | impl tracing::Subscriber for TagRecorder { | |
| 484 | + | fn register_callsite( | |
| 485 | + | &self, | |
| 486 | + | _: &'static tracing::Metadata<'static>, | |
| 487 | + | ) -> tracing::subscriber::Interest { | |
| 488 | + | // `sometimes`, not the default `always`/`never` verdict: interest is | |
| 489 | + | // cached per callsite for the life of the process, so a verdict | |
| 490 | + | // recorded here would outlive the guard below and decide the answer | |
| 491 | + | // for every later caller in this test binary. | |
| 492 | + | tracing::subscriber::Interest::sometimes() | |
| 493 | + | } | |
| 494 | + | ||
| 495 | + | fn enabled(&self, _: &tracing::Metadata<'_>) -> bool { | |
| 496 | + | true | |
| 497 | + | } | |
| 498 | + | ||
| 499 | + | fn new_span(&self, _: &tracing::span::Attributes<'_>) -> tracing::span::Id { | |
| 500 | + | tracing::span::Id::from_u64(1) | |
| 501 | + | } | |
| 502 | + | ||
| 503 | + | fn record(&self, _: &tracing::span::Id, _: &tracing::span::Record<'_>) {} | |
| 504 | + | ||
| 505 | + | fn record_follows_from(&self, _: &tracing::span::Id, _: &tracing::span::Id) {} | |
| 506 | + | ||
| 507 | + | fn event(&self, event: &tracing::Event<'_>) { | |
| 508 | + | let mut visitor = TagVisitor::default(); | |
| 509 | + | event.record(&mut visitor); | |
| 510 | + | self.0.lock().expect("the recorder mutex").push(visitor.0); | |
| 511 | + | } | |
| 512 | + | ||
| 513 | + | fn enter(&self, _: &tracing::span::Id) {} | |
| 514 | + | ||
| 515 | + | fn exit(&self, _: &tracing::span::Id) {} | |
| 516 | + | } | |
| 517 | + | ||
| 518 | + | /// The tags `from_wire` logged while parsing `wire`, in order. | |
| 519 | + | fn tags_logged_parsing(wire: &str) -> Vec<Option<String>> { | |
| 520 | + | let events = std::sync::Arc::new(std::sync::Mutex::new(Vec::new())); | |
| 521 | + | let recorder = TagRecorder(std::sync::Arc::clone(&events)); | |
| 522 | + | tracing::subscriber::with_default(recorder, || { | |
| 523 | + | let _ = BillingInterval::from_wire(wire); | |
| 524 | + | }); | |
| 525 | + | let events = events.lock().expect("the recorder mutex"); | |
| 526 | + | events.clone() | |
| 527 | + | } | |
| 528 | + | ||
| 529 | + | #[test] | |
| 530 | + | fn an_unrecognised_interval_tag_is_logged_and_the_expected_ones_are_not() { | |
| 531 | + | assert_eq!( | |
| 532 | + | tags_logged_parsing("weekly"), | |
| 533 | + | vec![Some("weekly".to_string())], | |
| 534 | + | "a tag this client does not know must say so, and say which one" | |
| 535 | + | ); | |
| 536 | + | // The two cases the guard exists to keep quiet. "monthly" is the ordinary | |
| 537 | + | // subscription and "" is an absent field; logging either would put a line | |
| 538 | + | // in the operator's log on every single parse. | |
| 539 | + | assert!( | |
| 540 | + | tags_logged_parsing("monthly").is_empty(), | |
| 541 | + | "the plain monthly tag is not unknown and must not be logged" | |
| 542 | + | ); | |
| 543 | + | assert!( | |
| 544 | + | tags_logged_parsing("").is_empty(), | |
| 545 | + | "an empty tag is an absent field, not an unrecognised interval" | |
| 546 | + | ); | |
| 547 | + | // Not part of the guard, but the branch it shares a match with: an | |
| 548 | + | // `annual` tag never reaches the fallback arm at all. | |
| 549 | + | assert!( | |
| 550 | + | tags_logged_parsing("annual").is_empty(), | |
| 551 | + | "annual is recognised and returns before the fallback arm" | |
| 552 | + | ); | |
| 553 | + | } | |
| 554 | + | ||
| 447 | 555 | #[test] | |
| 448 | 556 | fn cents_accessor_saturation_and_display() { | |
| 449 | 557 | assert_eq!(Cents(7).get(), 7); |