1use core::{
16 fmt::{self, Debug, Display},
17 result,
18};
19use std::{
20 io,
21 marker::PhantomData,
22 num::{NonZero, NonZeroU32},
23 ops::AddAssign,
24 pin::Pin,
25 sync::{Arc, LazyLock, Mutex, PoisonError},
26 time::{Duration, SystemTime},
27};
28
29use bytes::Bytes;
30use governor::{DefaultDirectRateLimiter, InsufficientCapacity, Jitter, Quota, RateLimiter};
31use human_units::{
32 FormatDuration,
33 iec::{Byte, Prefix},
34};
35use nisshi_client::{Client, ConnectionManager};
36use nisshi_sans_io::{
37 ByteSize as _, ErrorCode, ProduceRequest,
38 produce_request::{PartitionProduceData, TopicProduceData},
39 record::{Record, deflated, inflated},
40};
41use nonzero_ext::nonzero;
42use opentelemetry::{
43 InstrumentationScope, KeyValue, global,
44 metrics::{Counter, Meter},
45};
46use opentelemetry_otlp::ExporterBuildError;
47use opentelemetry_sdk::{
48 error::{OTelSdkError, OTelSdkResult},
49 metrics::{
50 SdkMeterProvider, Temporality,
51 data::{AggregatedMetrics, Histogram, Metric, MetricData, ResourceMetrics},
52 exporter::PushMetricExporter,
53 },
54};
55use opentelemetry_semantic_conventions::SCHEMA_URL;
56use tokio::{
57 signal::unix::{SignalKind, signal},
58 task::JoinSet,
59 time::sleep,
60};
61use tokio_util::sync::CancellationToken;
62use tracing::{debug, instrument};
63use url::Url;
64
65pub type Result<T, E = Error> = result::Result<T, E>;
66
67pub(crate) static METER: LazyLock<Meter> = LazyLock::new(|| {
68 global::meter_with_scope(
69 InstrumentationScope::builder(env!("CARGO_PKG_NAME"))
70 .with_version(env!("CARGO_PKG_VERSION"))
71 .with_schema_url(SCHEMA_URL)
72 .build(),
73 )
74});
75
76#[derive(thiserror::Error, Debug)]
77pub enum Error {
78 Api(ErrorCode),
79 Client(#[from] nisshi_client::Error),
80 ExporterBuild(#[from] ExporterBuildError),
81 InsufficientCapacity(#[from] InsufficientCapacity),
82 Io(Arc<io::Error>),
83 OtelSdk(#[from] OTelSdkError),
84 Random(#[from] getrandom::Error),
85 Poison,
86 Protocol(#[from] nisshi_sans_io::Error),
87 UnknownHost(String),
88 Url(#[from] url::ParseError),
89}
90
91impl<T> From<PoisonError<T>> for Error {
92 fn from(_value: PoisonError<T>) -> Self {
93 Self::Poison
94 }
95}
96
97impl From<io::Error> for Error {
98 fn from(value: io::Error) -> Self {
99 Self::Io(Arc::new(value))
100 }
101}
102
103impl Display for Error {
104 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
105 write!(f, "{self:?}")
106 }
107}
108
109#[derive(Copy, Clone, Debug, Eq, Hash, Ord, PartialEq, PartialOrd)]
110pub enum CancelKind {
111 Interrupt,
112 Terminate,
113 Timeout,
114}
115
116#[derive(Clone, Debug, Eq, Hash, Ord, PartialEq, PartialOrd)]
117pub struct Perf {
118 broker: Url,
119 topic: String,
120 partition: i32,
121 batch_size: u32,
122 record_size: usize,
123 per_second: Option<u32>,
124 throughput: Option<u32>,
125 producers: u32,
126 duration: Option<Duration>,
127}
128
129#[derive(Clone, Debug)]
130pub struct Builder<B, T> {
131 broker: B,
132 topic: T,
133 partition: i32,
134 batch_size: u32,
135 record_size: usize,
136 per_second: Option<u32>,
137 throughput: Option<u32>,
138 producers: u32,
139 duration: Option<Duration>,
140}
141
142impl Default for Builder<PhantomData<Url>, PhantomData<String>> {
143 fn default() -> Self {
144 Self {
145 broker: Default::default(),
146 topic: Default::default(),
147 partition: Default::default(),
148 batch_size: 1,
149 record_size: 1024,
150 per_second: None,
151 throughput: None,
152 producers: 1,
153 duration: None,
154 }
155 }
156}
157
158impl<B, T> Builder<B, T> {
159 pub fn broker(self, broker: impl Into<Url>) -> Builder<Url, T> {
160 Builder {
161 broker: broker.into(),
162 topic: self.topic,
163 partition: self.partition,
164 batch_size: self.batch_size,
165 record_size: self.record_size,
166 per_second: self.per_second,
167 throughput: self.throughput,
168 producers: self.producers,
169 duration: self.duration,
170 }
171 }
172
173 pub fn topic(self, topic: impl Into<String>) -> Builder<B, String> {
174 Builder {
175 broker: self.broker,
176 topic: topic.into(),
177 partition: self.partition,
178 batch_size: self.batch_size,
179 record_size: self.record_size,
180 per_second: self.per_second,
181 throughput: self.throughput,
182 producers: self.producers,
183 duration: self.duration,
184 }
185 }
186
187 pub fn partition(self, partition: i32) -> Builder<B, T> {
188 Self { partition, ..self }
189 }
190
191 pub fn batch_size(self, batch_size: u32) -> Self {
192 Self { batch_size, ..self }
193 }
194
195 pub fn record_size(self, record_size: usize) -> Self {
196 Self {
197 record_size,
198 ..self
199 }
200 }
201
202 pub fn per_second(self, per_second: Option<u32>) -> Self {
203 Self { per_second, ..self }
204 }
205
206 pub fn throughput(self, throughput: Option<u32>) -> Self {
207 Self { throughput, ..self }
208 }
209
210 pub fn producers(self, producers: u32) -> Self {
211 Self { producers, ..self }
212 }
213
214 pub fn duration(self, duration: Option<Duration>) -> Self {
215 Self { duration, ..self }
216 }
217}
218
219impl Builder<Url, String> {
220 pub fn build(self) -> Perf {
221 Perf {
222 broker: self.broker,
223 topic: self.topic,
224 partition: self.partition,
225 batch_size: self.batch_size,
226 record_size: self.record_size,
227 per_second: self.per_second,
228 throughput: self.throughput,
229 producers: self.producers,
230 duration: self.duration,
231 }
232 }
233}
234
235static RATE_LIMIT_DURATION: LazyLock<opentelemetry::metrics::Histogram<u64>> =
236 LazyLock::new(|| {
237 METER
238 .u64_histogram("rate_limit_duration")
239 .with_unit("ms")
240 .with_description("Rate limit latencies in milliseconds")
241 .build()
242 });
243
244static PRODUCE_RECORD_COUNT: LazyLock<Counter<u64>> = LazyLock::new(|| {
245 METER
246 .u64_counter("produce_record_count")
247 .with_description("Produced record count")
248 .build()
249});
250
251static PRODUCE_API_DURATION: LazyLock<opentelemetry::metrics::Histogram<u64>> =
252 LazyLock::new(|| {
253 METER
254 .u64_histogram("produce_duration")
255 .with_unit("ms")
256 .with_description("Produce API latencies in milliseconds")
257 .build()
258 });
259
260impl Perf {
261 pub fn builder() -> Builder<PhantomData<Url>, PhantomData<String>> {
262 Builder::default()
263 }
264
265 pub async fn main(self) -> Result<ErrorCode> {
266 let token = CancellationToken::new();
267
268 let meter_provider = {
269 let exporter = MetricExporter::new(token.clone());
270 let meter_provider = SdkMeterProvider::builder()
271 .with_periodic_exporter(exporter)
272 .build();
273 global::set_meter_provider(meter_provider.clone());
274
275 meter_provider
276 };
277
278 let mut interrupt_signal = signal(SignalKind::interrupt()).unwrap();
279 debug!(?interrupt_signal);
280
281 let mut terminate_signal = signal(SignalKind::terminate()).unwrap();
282 debug!(?terminate_signal);
283
284 let rate_limiter = self
285 .per_second
286 .or(self.throughput)
287 .inspect(|limit| debug!(?limit))
288 .and_then(NonZeroU32::new)
289 .map(Quota::per_second)
290 .map(RateLimiter::direct)
291 .map(Arc::new)
292 .inspect(|rate_limiter| debug!(?rate_limiter));
293
294 let record_data = {
295 let mut data = vec![0u8; self.record_size];
296 getrandom::fill(&mut data)?;
297 Bytes::from(data)
298 };
299
300 let batch_size = NonZeroU32::new(self.batch_size)
301 .inspect(|batch_size| debug!(batch_size = batch_size.get()))
302 .unwrap_or(nonzero!(10u32));
303
304 let mut set = JoinSet::new();
305
306 let client = ConnectionManager::builder(self.broker)
307 .client_id(Some(env!("CARGO_PKG_NAME").into()))
308 .build()
309 .await
310 .inspect(|pool| debug!(?pool))
311 .map(Client::new)?;
312
313 for id in 0..self.producers {
314 let producer = Producer {
315 id,
316 rate_limiter: rate_limiter.clone(),
317 topic: self.topic.clone(),
318 partition: self.partition,
319 record_data: record_data.clone(),
320 token: token.clone(),
321 client: client.clone(),
322 batch_size,
323 throughput: self.throughput,
324 };
325
326 _ = set.spawn(async move {
327 loop {
328 match producer.rate_limited().await {
329 Ok(false) | Err(_) => break,
330 _ => continue,
331 }
332 }
333 });
334 }
335
336 let join_all = async {
337 while !set.is_empty() {
338 debug!(len = set.len());
339 _ = set.join_next().await;
340 }
341 };
342
343 let duration = self
344 .duration
345 .map(sleep)
346 .map(Box::pin)
347 .map(|pinned| pinned as Pin<Box<dyn Future<Output = ()>>>)
348 .unwrap_or(Box::pin(std::future::pending()) as Pin<Box<dyn Future<Output = ()>>>);
349
350 let cancellation = tokio::select! {
351
352 timeout = duration => {
353 debug!(?timeout);
354 token.cancel();
355 Some(CancelKind::Timeout)
356 }
357
358 completed = join_all => {
359 debug!(?completed);
360 None
361 }
362
363 interrupt = interrupt_signal.recv() => {
364 debug!(?interrupt);
365 Some(CancelKind::Interrupt)
366 }
367
368 terminate = terminate_signal.recv() => {
369 debug!(?terminate);
370 Some(CancelKind::Terminate)
371 }
372
373 };
374
375 debug!(?cancellation);
376
377 meter_provider
378 .shutdown()
379 .inspect(|shutdown| debug!(?shutdown))?;
380
381 if let Some(CancelKind::Timeout) = cancellation {
382 sleep(Duration::from_secs(5)).await;
383 }
384
385 debug!(abort = set.len());
386 set.abort_all();
387
388 while !set.is_empty() {
389 _ = set.join_next().await;
390 }
391
392 Ok(ErrorCode::None)
393 }
394}
395
396#[derive(Clone, Debug)]
397struct Producer {
398 id: u32,
399 rate_limiter: Option<Arc<DefaultDirectRateLimiter>>,
400 topic: String,
401 partition: i32,
402 record_data: Bytes,
403 token: CancellationToken,
404 client: Client,
405 batch_size: NonZero<u32>,
406 throughput: Option<u32>,
407}
408
409impl Producer {
410 #[instrument(skip_all, fields(record_data_len = self.record_data.len()))]
411 fn frame(&self) -> Result<deflated::Frame> {
412 let mut batch = inflated::Batch::builder();
413 let offset_deltas = 0..(self.batch_size.get() as i32);
414
415 for offset_delta in offset_deltas {
416 batch = batch.record(
417 Record::builder()
418 .value(Some(self.record_data.clone()))
419 .offset_delta(offset_delta),
420 )
421 }
422
423 batch
424 .last_offset_delta(self.batch_size.get() as i32)
425 .build()
426 .map(|batch| inflated::Frame {
427 batches: vec![batch],
428 })
429 .and_then(deflated::Frame::try_from)
430 .map_err(Into::into)
431 }
432
433 #[instrument(skip_all)]
434 async fn produce(&self, frame: deflated::Frame) -> Result<()> {
435 let req = ProduceRequest::default().topic_data(Some(
436 [TopicProduceData::default()
437 .name(self.topic.clone())
438 .partition_data(Some(
439 [PartitionProduceData::default()
440 .index(self.partition)
441 .records(Some(frame))]
442 .into(),
443 ))]
444 .into(),
445 ));
446
447 let response = self.client.call(req).await?;
448
449 assert!(
450 response
451 .responses
452 .unwrap_or_default()
453 .into_iter()
454 .all(|topic| {
455 topic
456 .partition_responses
457 .unwrap_or_default()
458 .iter()
459 .all(|partition| partition.error_code == i16::from(ErrorCode::None))
460 })
461 );
462
463 Ok(())
464 }
465
466 #[instrument(skip_all, fields(id = self.id))]
467 async fn rate_limited(&self) -> Result<bool> {
468 let attributes = [KeyValue::new("producer", self.id.to_string())];
469
470 let frame = self.frame()?;
471
472 if let Some(ref rate_limiter) = self.rate_limiter {
473 let rate_limit_start = SystemTime::now();
474
475 let cells = self
476 .throughput
477 .and(
478 frame
479 .size_in_bytes()
480 .ok()
481 .and_then(|bytes| NonZeroU32::new(bytes as u32)),
482 )
483 .unwrap_or(self.batch_size);
484
485 tokio::select! {
486 cancelled = self.token.cancelled() => {
487 debug!(?cancelled);
488 return Ok(false)
489 },
490
491 Ok(_) = rate_limiter.until_n_ready_with_jitter(cells, Jitter::up_to(Duration::from_millis(10))) => {
492 RATE_LIMIT_DURATION.record(
493 rate_limit_start
494 .elapsed()
495 .inspect(|duration|debug!(rate_limit_duration_ms = duration.as_millis()))
496 .map_or(0, |duration| duration.as_millis() as u64),
497 &attributes)
498
499 },
500 }
501 }
502
503 let produce_start = SystemTime::now();
504
505 tokio::select! {
506 cancelled = self.token.cancelled() => {
507 debug!(?cancelled);
508 return Ok(false)
509 },
510
511 Ok(_) = self.produce(frame) => {
512 PRODUCE_RECORD_COUNT.add(self.batch_size.get() as u64, &attributes);
513 PRODUCE_API_DURATION.record(produce_start.elapsed().inspect(|duration|debug!(produce_duration_ms = duration.as_millis())).map_or(0, |duration| duration.as_millis() as u64), &attributes);
514 },
515 }
516
517 Ok(!self.token.is_cancelled())
518 }
519}
520
521#[derive(Clone, Copy, Debug, Eq, Hash, Ord, PartialEq, PartialOrd)]
522struct Observation {
523 taken_at: SystemTime,
524 bytes_sent: u64,
525 record_count: u64,
526}
527
528impl AddAssign for Observation {
529 fn add_assign(&mut self, rhs: Self) {
530 self.taken_at = self.taken_at.max(rhs.taken_at);
531 self.bytes_sent += rhs.bytes_sent;
532 self.record_count += rhs.record_count;
533 }
534}
535
536impl Default for Observation {
537 fn default() -> Self {
538 Self {
539 taken_at: SystemTime::now(),
540 bytes_sent: Default::default(),
541 record_count: Default::default(),
542 }
543 }
544}
545
546#[derive(Clone, Copy, Debug, PartialEq, PartialOrd)]
547struct Info {
548 started_at: SystemTime,
549 previous: Option<ObservationLatency>,
550 current: ObservationLatency,
551}
552
553impl Info {
554 fn new(started_at: SystemTime) -> Self {
555 Self {
556 started_at,
557 current: Default::default(),
558 previous: Default::default(),
559 }
560 }
561
562 fn with_previous(self, previous: Option<ObservationLatency>) -> Self {
563 Self { previous, ..self }
564 }
565
566 fn elapsed(&self) -> Duration {
567 self.current
568 .observation
569 .taken_at
570 .duration_since(
571 self.previous
572 .map_or(self.started_at, |previous| previous.observation.taken_at),
573 )
574 .expect("duration")
575 }
576
577 fn bytes_sent(&self) -> u64 {
578 self.current.observation.bytes_sent
579 - self
580 .previous
581 .map(|previous| previous.observation.bytes_sent)
582 .unwrap_or_default()
583 }
584
585 fn records_sent(&self) -> u64 {
586 self.current.observation.record_count
587 - self
588 .previous
589 .map(|previous| previous.observation.record_count)
590 .unwrap_or_default()
591 }
592
593 fn records_sent_per_second(&self) -> f64 {
594 self.records_sent() as f64 / self.elapsed().as_secs() as f64
595 }
596
597 fn bandwidth(&self) -> Byte {
598 self.bytes_sent()
599 .checked_div(self.elapsed().as_secs())
600 .map(|throughput| Byte::with_iec_prefix(throughput, Prefix::None))
601 .expect("throughput")
602 }
603}
604
605impl Display for Info {
606 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
607 write!(
608 f,
609 "elapsed: {}, {} records sent, {:.1} records/s, ({}/s), latency: {} min, {:.1}ms avg, {} max",
610 self.elapsed().format_duration(),
611 self.records_sent(),
612 self.records_sent_per_second(),
613 self.bandwidth().format_iec(),
614 self.current
615 .latency
616 .min
617 .map(|min| min.format_duration())
618 .expect("minimum"),
619 self.current.latency.mean.expect("mean"),
620 self.current
621 .latency
622 .max
623 .map(|max| max.format_duration())
624 .expect("max")
625 )
626 }
627}
628
629#[derive(Clone, Copy, Debug, Default, PartialEq, PartialOrd)]
630struct Latency {
631 min: Option<Duration>,
632 max: Option<Duration>,
633 mean: Option<f64>,
634}
635
636impl From<&Histogram<u64>> for Latency {
637 fn from(histogram: &Histogram<u64>) -> Self {
638 let min = histogram
639 .data_points()
640 .filter_map(|dp| dp.min())
641 .min()
642 .map(Duration::from_millis);
643
644 let max = histogram
645 .data_points()
646 .filter_map(|dp| dp.max())
647 .max()
648 .map(Duration::from_millis);
649
650 let sum = histogram.data_points().map(|dp| dp.sum()).sum::<u64>() as f64;
651 let count = histogram.data_points().map(|dp| dp.count()).sum::<u64>() as f64;
652
653 let mean = Some(sum / count);
654
655 Self { min, max, mean }
656 }
657}
658
659#[derive(Clone, Copy, Debug, Default, PartialEq, PartialOrd)]
660struct ObservationLatency {
661 observation: Observation,
662 latency: Latency,
663}
664
665#[derive(Debug)]
666struct MetricExporter {
667 started_at: SystemTime,
668 temporality: Temporality,
669 previous: Mutex<Option<ObservationLatency>>,
670 cancellation: CancellationToken,
671}
672
673impl MetricExporter {
674 fn new(cancellation: CancellationToken) -> Self {
675 let started_at = SystemTime::now();
676 Self {
677 started_at,
678 temporality: Default::default(),
679 previous: Default::default(),
680 cancellation,
681 }
682 }
683
684 #[instrument(skip_all, fields(scope = scope.name(), metric = metric.name()))]
685 fn info(&self, scope: &InstrumentationScope, metric: &Metric, info: &mut Info) {
686 match (scope.name(), metric.name(), metric.data()) {
687 ("nisshi-client", "tcp_bytes_sent", AggregatedMetrics::U64(MetricData::Sum(sum))) => {
688 for (point, data) in sum.data_points().enumerate() {
689 debug!(point, value = ?data.value());
690 }
691
692 info.current.observation.bytes_sent =
693 sum.data_points().map(|sum| sum.value()).sum::<u64>();
694 }
695
696 (
697 "nisshi-perf",
698 "produce_record_count",
699 AggregatedMetrics::U64(MetricData::Sum(sum)),
700 ) => {
701 for (point, data) in sum.data_points().enumerate() {
702 debug!(point, value = ?data.value());
703 }
704
705 info.current.observation.record_count =
706 sum.data_points().map(|sum| sum.value()).sum::<u64>();
707 }
708
709 (
710 "nisshi-perf",
711 "produce_duration",
712 AggregatedMetrics::U64(MetricData::Histogram(histogram)),
713 ) => {
714 info.current.latency = Latency::from(histogram);
715 }
716
717 _ => (),
718 }
719 }
720}
721
722impl PushMetricExporter for MetricExporter {
723 async fn export(&self, metrics: &ResourceMetrics) -> OTelSdkResult {
724 let cancelled = self.cancellation.is_cancelled();
725
726 if cancelled {
727 if let Some(previous) = *self.previous.lock().expect("previous") {
728 let mut info = Info::new(self.started_at);
729 info.current = previous;
730
731 println!("{}", info);
732 }
733 } else {
734 let mut previous = self.previous.lock().expect("previous");
735
736 let mut info = Info::new(self.started_at).with_previous(previous.take());
737
738 for scope in metrics.scope_metrics() {
739 debug!(scope = scope.scope().name());
740
741 for metric in scope.metrics() {
742 debug!(scope = scope.scope().name(), metric = metric.name());
743
744 self.info(scope.scope(), metric, &mut info);
745 }
746 }
747
748 println!("{info}");
749
750 _ = previous.replace(info.current);
751 }
752
753 Ok(())
754 }
755
756 fn force_flush(&self) -> OTelSdkResult {
757 Ok(())
758 }
759
760 #[instrument]
761 fn shutdown_with_timeout(&self, timeout: Duration) -> OTelSdkResult {
762 Ok(())
763 }
764
765 fn temporality(&self) -> Temporality {
766 self.temporality
767 }
768}
769
770#[cfg(test)]
771mod tests {
772 use super::*;
773
774 #[test]
775 fn add_assign_observation() {
776 let now = SystemTime::now();
777 let delta = Duration::from_secs(5);
778
779 let previous = Observation {
780 taken_at: now.checked_sub(delta).expect("previous"),
781 bytes_sent: 32_123,
782 record_count: 12_321,
783 };
784
785 let mut current = Observation {
786 taken_at: now,
787 bytes_sent: 43_234,
788 record_count: 54_345,
789 };
790
791 current += previous;
792
793 assert_eq!(now, current.taken_at);
794 assert_eq!(75_357, current.bytes_sent);
795 assert_eq!(66_666, current.record_count);
796 }
797
798 #[test]
799 fn middle_observation() {
800 let now = SystemTime::now();
801 let elapsed = Duration::from_secs(4);
802
803 let previous = {
804 let observation = Observation {
805 taken_at: now.checked_sub(elapsed).expect("previous"),
806 bytes_sent: 43_234,
807 record_count: 212,
808 };
809
810 ObservationLatency {
811 observation,
812 latency: Default::default(),
813 }
814 };
815
816 let mut info = Info::new(now).with_previous(Some(previous));
817
818 info.current = {
819 let observation = Observation {
820 taken_at: now,
821 bytes_sent: 65_456,
822 record_count: 656,
823 };
824
825 ObservationLatency {
826 observation,
827 latency: Default::default(),
828 }
829 };
830
831 assert_eq!(elapsed, info.elapsed());
832 assert_eq!(5_555, info.bandwidth().0);
833 assert_eq!(111f64, info.records_sent_per_second());
834 }
835
836 #[test]
837 fn last_or_first_observation() {
838 let now = SystemTime::now();
839 let elapsed = Duration::from_secs(4);
840
841 let mut info = Info::new(now.checked_sub(elapsed).expect("elapsed"));
842
843 info.current = {
844 let observation = Observation {
845 taken_at: now,
846 bytes_sent: 65_456,
847 record_count: 656,
848 };
849
850 ObservationLatency {
851 observation,
852 latency: Default::default(),
853 }
854 };
855
856 assert_eq!(elapsed, info.elapsed());
857 assert_eq!(16_364, info.bandwidth().0);
858 assert_eq!(164f64, info.records_sent_per_second());
859 }
860}