1use std::collections::HashMap;
10use std::future::Future;
11use std::sync::Arc;
12use std::sync::LazyLock;
13use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH};
14
15use parking_lot::Mutex;
16
17mod qot_push;
18mod response;
19
20use qot_push::QotPushCounter;
21use response::response_ret_type_is_success;
22
23#[derive(Debug, Clone, PartialEq)]
24pub struct ReqReplyStatisticsSnapshot {
25 pub proto_id: u32,
26 pub count: u32,
27 pub total_cost_avg_ms: f32,
28 pub open_d_cost_avg_ms: f32,
29 pub net_delay_avg_ms: f32,
30 pub is_local_reply: bool,
31}
32
33#[derive(Debug, Clone, PartialEq)]
34pub struct QotPushStatisticsSnapshot {
35 pub qot_push_type: i32,
36 pub item_list: Vec<DelayStatisticsItemSnapshot>,
37 pub delay_avg_ms: f32,
38 pub count: i32,
39}
40
41#[derive(Debug, Clone, PartialEq)]
42pub struct PlaceOrderStatisticsSnapshot {
43 pub order_id: String,
44 pub total_cost_ms: f32,
45 pub open_d_cost_ms: f32,
46 pub net_delay_ms: f32,
47 pub update_cost_ms: f32,
48}
49
50#[derive(Debug, Clone, PartialEq)]
51pub struct DelayStatisticsItemSnapshot {
52 pub begin: i32,
53 pub end: i32,
54 pub count: i32,
55 pub proportion: f32,
56 pub cumulative_ratio: f32,
57}
58
59pub const QOT_PUSH_TYPE_PRICE: i32 = 1;
60pub const QOT_PUSH_TYPE_TICKER: i32 = 2;
61pub const QOT_PUSH_TYPE_ORDER_BOOK: i32 = 3;
62pub const QOT_PUSH_TYPE_BROKER: i32 = 4;
63
64const QOT_PUSH_STAGE_SR2SS: i32 = 1;
65const QOT_PUSH_STAGE_SS2CR: i32 = 2;
66const QOT_PUSH_STAGE_CR2CS: i32 = 3;
67const QOT_PUSH_STAGE_SS2CS: i32 = 4;
68const QOT_PUSH_STAGE_SR2CS: i32 = 5;
69
70#[derive(Default)]
71struct ReqReplyCounter {
72 count: u32,
73 total_cost_avg_ms: f64,
74 open_d_cost_avg_ms: f64,
75 net_delay_avg_ms: f64,
76 is_local_reply: bool,
77}
78
79impl ReqReplyCounter {
80 fn add(&mut self, total: Duration, open_d: Duration, net_delay: Duration, local_reply: bool) {
81 let count = self.count as f64;
82 self.total_cost_avg_ms =
83 ((self.total_cost_avg_ms * count) + duration_ms(total)) / (count + 1.0);
84 self.open_d_cost_avg_ms =
85 ((self.open_d_cost_avg_ms * count) + duration_ms(open_d)) / (count + 1.0);
86 self.net_delay_avg_ms =
87 ((self.net_delay_avg_ms * count) + duration_ms(net_delay)) / (count + 1.0);
88 self.count += 1;
89 if local_reply {
90 self.is_local_reply = true;
91 }
92 }
93
94 fn snapshot(&self, proto_id: u32) -> ReqReplyStatisticsSnapshot {
95 ReqReplyStatisticsSnapshot {
96 proto_id,
97 count: self.count,
98 total_cost_avg_ms: self.total_cost_avg_ms as f32,
99 open_d_cost_avg_ms: self.open_d_cost_avg_ms as f32,
100 net_delay_avg_ms: self.net_delay_avg_ms as f32,
101 is_local_reply: self.is_local_reply,
102 }
103 }
104}
105
106#[derive(Default)]
107struct DelayStatisticsStore {
108 req_reply_counts: Mutex<HashMap<u32, ReqReplyCounter>>,
109 qot_push_counts: Mutex<HashMap<i32, QotPushCounter>>,
110 place_order_req_details: Mutex<Vec<PlaceOrderReqDetail>>,
111 place_order_push_once: Mutex<Vec<PlaceOrderPushOnce>>,
112 time_adjustment: Mutex<TimeAdjustment>,
113}
114
115impl DelayStatisticsStore {
116 fn set_time_adjustment(&self, s2c_time_diff_us: i64, net_delay_us: i64) {
117 *self.time_adjustment.lock() = TimeAdjustment {
118 s2c_time_diff_us,
119 net_delay_us,
120 };
121 }
122
123 fn time_adjustment(&self) -> TimeAdjustment {
124 *self.time_adjustment.lock()
125 }
126
127 fn record_req_reply(&self, ctx: &ApiRequestDelayContext) {
128 let total_cost = ctx.begin.elapsed();
129 let api_end_at = SystemTime::now();
130 let backend_spans = ctx.backend_spans.lock();
131 let is_local_reply = backend_spans.is_empty();
132 let backend_cost = backend_union_duration(&backend_spans);
133 let open_d_cost = total_cost.saturating_sub(backend_cost);
134
135 self.req_reply_counts
136 .lock()
137 .entry(ctx.proto_id)
138 .or_default()
139 .add(total_cost, open_d_cost, Duration::ZERO, is_local_reply);
140
141 self.record_place_order_req_detail(ctx, &backend_spans, api_end_at);
142 }
143
144 fn snapshot_req_reply(&self) -> Vec<ReqReplyStatisticsSnapshot> {
145 let mut items: Vec<_> = self
146 .req_reply_counts
147 .lock()
148 .iter()
149 .map(|(&proto_id, counter)| counter.snapshot(proto_id))
150 .collect();
151 items.sort_by_key(|item| item.proto_id);
152 items
153 }
154
155 fn record_qot_push_count(
156 &self,
157 qot_push_type: i32,
158 server_recv_from_exchange_time_ms: Option<i64>,
159 server_send_to_client_time_ms: Option<i64>,
160 f3c_recv_at: SystemTime,
161 api_response_at: SystemTime,
162 ) {
163 let Some(f3c_recv_us) = system_time_us(f3c_recv_at) else {
164 return;
165 };
166 let Some(api_response_us) = system_time_us(api_response_at) else {
167 return;
168 };
169
170 let TimeAdjustment {
171 s2c_time_diff_us,
172 net_delay_us,
173 } = *self.time_adjustment.lock();
174
175 let mut server_recv_us = server_recv_from_exchange_time_ms.unwrap_or(0) * 1000;
176 let mut server_send_us = server_send_to_client_time_ms.unwrap_or(0) * 1000;
177 if server_recv_us != 0 {
178 server_recv_us -= s2c_time_diff_us;
179 }
180 if server_send_us != 0 {
181 server_send_us -= s2c_time_diff_us;
182 }
183
184 let mut f3c_recv_us = f3c_recv_us;
189 let mut api_response_us = api_response_us;
190 if server_send_us > f3c_recv_us {
191 let open_d_cost_us = api_response_us.saturating_sub(f3c_recv_us);
192 f3c_recv_us = server_send_us + net_delay_us;
193 api_response_us = f3c_recv_us + open_d_cost_us;
194 }
195
196 let mut counts = self.qot_push_counts.lock();
197 let counter = counts.entry(qot_push_type).or_default();
198 counter.add(QOT_PUSH_STAGE_SR2SS, server_recv_us, server_send_us);
199 counter.add(QOT_PUSH_STAGE_SS2CR, server_send_us, f3c_recv_us);
200 counter.add(QOT_PUSH_STAGE_CR2CS, f3c_recv_us, api_response_us);
201 counter.add(QOT_PUSH_STAGE_SS2CS, server_send_us, api_response_us);
202 counter.add(QOT_PUSH_STAGE_SR2CS, server_recv_us, api_response_us);
203 counter.total_count = counter.total_count.saturating_add(1);
204 }
205
206 fn snapshot_qot_push(
207 &self,
208 qot_push_stage: i32,
209 segment_list: &[i32],
210 ) -> Vec<QotPushStatisticsSnapshot> {
211 if qot_push_stage == 0 || segment_list.len() < 2 {
212 return Vec::new();
213 }
214
215 let counts = self.qot_push_counts.lock();
216 let mut items = Vec::new();
217 for qot_push_type in [
218 QOT_PUSH_TYPE_PRICE,
219 QOT_PUSH_TYPE_TICKER,
220 QOT_PUSH_TYPE_ORDER_BOOK,
221 QOT_PUSH_TYPE_BROKER,
222 ] {
223 let Some(counter) = counts.get(&qot_push_type) else {
224 continue;
225 };
226 let Some(stage) = counter.stages.get(&qot_push_stage) else {
227 continue;
228 };
229 if stage.total == 0 {
230 continue;
231 }
232
233 let mut cumulative_count = 0i32;
234 let total = stage.total as f32;
235 let item_list = segment_list
236 .windows(2)
237 .map(|window| {
238 let begin = window[0];
239 let end = window[1];
240 let count = stage.range_count(begin, end) as i32;
241 cumulative_count += count;
242 DelayStatisticsItemSnapshot {
243 begin,
244 end,
245 count,
246 proportion: count as f32 / total * 100.0,
247 cumulative_ratio: cumulative_count as f32 / total * 100.0,
248 }
249 })
250 .collect();
251
252 items.push(QotPushStatisticsSnapshot {
253 qot_push_type,
254 item_list,
255 delay_avg_ms: stage.cost_avg_ms,
256 count: stage.total as i32,
257 });
258 }
259 items
260 }
261
262 fn record_place_order_req_detail(
263 &self,
264 ctx: &ApiRequestDelayContext,
265 backend_spans: &[BackendSpan],
266 api_end_at: SystemTime,
267 ) {
268 if ctx.proto_id != crate::proto_id::TRD_PLACE_ORDER {
269 return;
270 }
271 let Some(user_data) = ctx.place_order_user_data.lock().clone() else {
272 return;
273 };
274 let Some(api_begin_us) = system_time_us(ctx.begin_at) else {
275 return;
276 };
277 let Some(api_end_us) = system_time_us(api_end_at) else {
278 return;
279 };
280 if api_end_us < api_begin_us {
281 return;
282 }
283 let first_span = backend_spans.first();
284 let first_backend_begin_us = first_span.and_then(|span| system_time_us(span.begin_at));
285 let first_backend_end_us = first_span.and_then(|span| system_time_us(span.end_at));
286
287 self.place_order_req_details
288 .lock()
289 .push(PlaceOrderReqDetail {
290 order_id: user_data.order_id,
291 trd_env: user_data.trd_env,
292 _market: user_data.market,
293 api_begin_us,
294 api_end_us,
295 first_backend_begin_us,
296 first_backend_end_us,
297 net_delay_us: ctx.time_adjustment.net_delay_us,
298 });
299 }
300
301 fn set_place_order_user_data(&self, user_data: PlaceOrderUserData) {
302 let _ = CURRENT_API_REQUEST.try_with(|ctx| {
303 *ctx.place_order_user_data.lock() = Some(user_data);
304 });
305 }
306
307 fn record_place_order_update_push(
308 &self,
309 order_id: String,
310 trd_env: i32,
311 market: i32,
312 order_status: i32,
313 api_response_at: SystemTime,
314 ) {
315 let Some(api_response_us) = system_time_us(api_response_at) else {
316 return;
317 };
318 self.place_order_push_once.lock().push(PlaceOrderPushOnce {
319 order_id,
320 _trd_env: trd_env,
321 _market: market,
322 order_status,
323 api_response_us,
324 });
325 }
326
327 fn snapshot_place_order(&self) -> Vec<PlaceOrderStatisticsSnapshot> {
328 let mut earliest_push_by_order: HashMap<String, i64> = HashMap::new();
329 for push in self.place_order_push_once.lock().iter() {
330 if !place_order_update_status_counts(push.order_status) {
331 continue;
332 }
333 earliest_push_by_order
334 .entry(push.order_id.clone())
335 .and_modify(|existing| *existing = (*existing).min(push.api_response_us))
336 .or_insert(push.api_response_us);
337 }
338
339 self.place_order_req_details
340 .lock()
341 .iter()
342 .filter(|detail| detail.trd_env != 0)
343 .filter_map(|detail| {
344 let total_cost_us = detail.api_end_us.checked_sub(detail.api_begin_us)?;
345 let open_d_cost_us =
346 match (detail.first_backend_begin_us, detail.first_backend_end_us) {
347 (Some(begin), Some(end)) => begin
348 .saturating_sub(detail.api_begin_us)
349 .saturating_add(detail.api_end_us.saturating_sub(end)),
350 _ => 0,
351 };
352 let update_cost_us = earliest_push_by_order
353 .get(&detail.order_id)
354 .map(|push_us| push_us.saturating_sub(detail.api_end_us))
355 .unwrap_or(0);
356
357 Some(PlaceOrderStatisticsSnapshot {
358 order_id: detail.order_id.clone(),
359 total_cost_ms: us_to_ms(total_cost_us),
360 open_d_cost_ms: us_to_ms(open_d_cost_us),
361 net_delay_ms: us_to_ms(detail.net_delay_us.max(0)),
362 update_cost_ms: us_to_ms(update_cost_us),
363 })
364 })
365 .collect()
366 }
367}
368
369#[derive(Debug, Clone, Copy, Default)]
370struct TimeAdjustment {
371 s2c_time_diff_us: i64,
372 net_delay_us: i64,
373}
374
375#[derive(Debug, Clone)]
376struct PlaceOrderUserData {
377 order_id: String,
378 trd_env: i32,
379 market: i32,
380}
381
382#[derive(Debug, Clone)]
383struct PlaceOrderReqDetail {
384 order_id: String,
385 trd_env: i32,
386 _market: i32,
387 api_begin_us: i64,
388 api_end_us: i64,
389 first_backend_begin_us: Option<i64>,
390 first_backend_end_us: Option<i64>,
391 net_delay_us: i64,
392}
393
394#[derive(Debug, Clone)]
395struct PlaceOrderPushOnce {
396 order_id: String,
397 _trd_env: i32,
398 _market: i32,
399 order_status: i32,
400 api_response_us: i64,
401}
402
403#[derive(Debug)]
404struct ApiRequestDelayContext {
405 proto_id: u32,
406 begin: Instant,
407 begin_at: SystemTime,
408 backend_spans: Mutex<Vec<BackendSpan>>,
409 place_order_user_data: Mutex<Option<PlaceOrderUserData>>,
410 time_adjustment: TimeAdjustment,
411}
412
413impl ApiRequestDelayContext {
414 fn new(proto_id: u32) -> Self {
415 Self {
416 proto_id,
417 begin: Instant::now(),
418 begin_at: SystemTime::now(),
419 backend_spans: Mutex::new(Vec::new()),
420 place_order_user_data: Mutex::new(None),
421 time_adjustment: DELAY_STATS.time_adjustment(),
422 }
423 }
424
425 fn record_backend_span(
426 &self,
427 begin: Instant,
428 end: Instant,
429 begin_at: SystemTime,
430 end_at: SystemTime,
431 ) {
432 if end >= begin {
433 self.backend_spans.lock().push(BackendSpan {
434 begin,
435 end,
436 begin_at,
437 end_at,
438 });
439 }
440 }
441}
442
443#[derive(Debug, Clone, Copy)]
444struct BackendSpan {
445 begin: Instant,
446 end: Instant,
447 begin_at: SystemTime,
448 end_at: SystemTime,
449}
450
451static DELAY_STATS: LazyLock<DelayStatisticsStore> = LazyLock::new(DelayStatisticsStore::default);
452
453tokio::task_local! {
454 static CURRENT_API_REQUEST: Arc<ApiRequestDelayContext>;
455}
456
457pub async fn with_api_request<F, Fut>(
463 _conn_id: u64,
464 _serial_no: u32,
465 proto_id: u32,
466 future: F,
467) -> Option<Vec<u8>>
468where
469 F: FnOnce() -> Fut,
470 Fut: Future<Output = Option<Vec<u8>>>,
471{
472 let ctx = Arc::new(ApiRequestDelayContext::new(proto_id));
473 let response = CURRENT_API_REQUEST.scope(ctx.clone(), future()).await;
474
475 if response
476 .as_deref()
477 .is_some_and(response_ret_type_is_success)
478 {
479 DELAY_STATS.record_req_reply(&ctx);
480 }
481
482 response
483}
484
485pub async fn trace_backend_request<Fut, T>(_cmd_id: u16, future: Fut) -> T
489where
490 Fut: Future<Output = T>,
491{
492 let begin = Instant::now();
493 let begin_at = SystemTime::now();
494 let output = future.await;
495 let end_at = SystemTime::now();
496 let end = Instant::now();
497
498 let _ =
499 CURRENT_API_REQUEST.try_with(|ctx| ctx.record_backend_span(begin, end, begin_at, end_at));
500 output
501}
502
503pub fn snapshot_req_reply_statistics() -> Vec<ReqReplyStatisticsSnapshot> {
504 DELAY_STATS.snapshot_req_reply()
505}
506
507pub fn record_qot_push_count(
508 qot_push_type: i32,
509 server_recv_from_exchange_time_ms: Option<i64>,
510 server_send_to_client_time_ms: Option<i64>,
511 f3c_recv_at: SystemTime,
512 api_response_at: SystemTime,
513) {
514 DELAY_STATS.record_qot_push_count(
515 qot_push_type,
516 server_recv_from_exchange_time_ms,
517 server_send_to_client_time_ms,
518 f3c_recv_at,
519 api_response_at,
520 );
521}
522
523pub fn record_place_order_request(order_id: &str, trd_env: i32, market: i32) {
529 let order_id = order_id.trim();
530 if order_id.is_empty() {
531 return;
532 }
533 DELAY_STATS.set_place_order_user_data(PlaceOrderUserData {
534 order_id: order_id.to_string(),
535 trd_env,
536 market,
537 });
538}
539
540pub fn record_place_order_update_push(
547 order_id: &str,
548 trd_env: i32,
549 market: i32,
550 order_status: i32,
551 api_response_at: SystemTime,
552) {
553 let order_id = order_id.trim();
554 if order_id.is_empty() {
555 return;
556 }
557 DELAY_STATS.record_place_order_update_push(
558 order_id.to_string(),
559 trd_env,
560 market,
561 order_status,
562 api_response_at,
563 );
564}
565
566pub fn set_time_adjustment(s2c_time_diff_us: i64, net_delay_us: i64) {
576 DELAY_STATS.set_time_adjustment(s2c_time_diff_us, net_delay_us);
577}
578
579pub fn snapshot_qot_push_statistics(
580 qot_push_stage: i32,
581 segment_list: &[i32],
582) -> Vec<QotPushStatisticsSnapshot> {
583 DELAY_STATS.snapshot_qot_push(qot_push_stage, segment_list)
584}
585
586pub fn snapshot_place_order_statistics() -> Vec<PlaceOrderStatisticsSnapshot> {
587 DELAY_STATS.snapshot_place_order()
588}
589
590fn backend_union_duration(spans: &[BackendSpan]) -> Duration {
591 if spans.is_empty() {
592 return Duration::ZERO;
593 }
594
595 let mut spans = spans.to_vec();
596 spans.sort_by_key(|span| span.begin);
597
598 let mut total = Duration::ZERO;
599 let mut cur_begin = spans[0].begin;
600 let mut cur_end = spans[0].end;
601
602 for span in spans.into_iter().skip(1) {
603 if span.begin <= cur_end {
604 if span.end > cur_end {
605 cur_end = span.end;
606 }
607 } else {
608 total += cur_end.duration_since(cur_begin);
609 cur_begin = span.begin;
610 cur_end = span.end;
611 }
612 }
613
614 total + cur_end.duration_since(cur_begin)
615}
616
617fn duration_ms(duration: Duration) -> f64 {
618 duration.as_secs_f64() * 1000.0
619}
620
621fn us_to_ms(us: i64) -> f32 {
622 us as f32 / 1000.0
623}
624
625fn system_time_us(time: SystemTime) -> Option<i64> {
626 let duration = time.duration_since(UNIX_EPOCH).ok()?;
627 i64::try_from(duration.as_micros()).ok()
628}
629
630fn place_order_update_status_counts(order_status: i32) -> bool {
631 matches!(order_status, 5 | 11 | 14 | 10)
635}
636
637#[cfg(test)]
638mod tests;