arrow_tiberius/write/
profile.rs

1//! Benchmark-only profiling support for the write path.
2
3use std::time::Duration;
4
5#[cfg(feature = "bench-profile")]
6mod enabled {
7    use std::{
8        cell::RefCell,
9        sync::atomic::{AtomicBool, Ordering},
10        time::Duration,
11    };
12
13    use tiberius::BulkLoadStats;
14
15    /// Accumulated timings for the direct raw writer path.
16    #[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
17    pub struct DirectWriteProfile {
18        /// Time spent measuring runtime batches before encoding.
19        pub measure_batch: Duration,
20        /// Time spent splitting measured batches into bounded row ranges.
21        pub row_range_split: Duration,
22        /// Time spent encoding/appending raw rows before Tiberius writes packets.
23        pub append_encode: Duration,
24        /// Total time spent in raw-row send calls, including append encoding.
25        pub send_total: Duration,
26        /// Number of rows accepted by the direct writer.
27        pub rows: u64,
28        /// Number of batches accepted by the direct writer.
29        pub batches: u64,
30        /// Number of raw row ranges sent.
31        pub row_ranges: u64,
32        /// Total encoded raw row bytes sent or appended.
33        pub encoded_bytes: u64,
34        /// Largest encoded row range in bytes.
35        pub max_row_range_bytes: u64,
36        /// Non-null SQL Server `nvarchar` payload bytes after UTF-16 encoding.
37        pub nvarchar_utf16_bytes: u64,
38        /// Non-null SQL Server `varbinary` payload bytes.
39        pub varbinary_bytes: u64,
40        /// Number of null cells observed by the profiled direct writer path.
41        pub null_cells: u64,
42        /// Number of bulk packet drain attempts inside Tiberius.
43        pub packet_write_calls: u64,
44        /// Number of full TDS bulk-load packets written before finalization.
45        pub packets_written: u64,
46        /// Total packet payload bytes written before finalization.
47        pub packet_payload_bytes: u64,
48        /// Largest full packet payload written before finalization.
49        pub max_packet_payload_bytes: u64,
50        /// Largest buffered bulk-load byte count before a packet drain attempt.
51        pub max_buffered_bytes_before_write: u64,
52        /// Buffered bulk-load tail left after the latest packet drain attempt.
53        pub buffered_bytes_after_last_write: u64,
54        /// Final `EndOfMessage` packet payload bytes written during finalization.
55        pub finalized_packet_payload_bytes: u64,
56        /// Time spent inside bulk-load packet drain attempts.
57        pub bulk_write_packets_elapsed: Duration,
58        /// Number of lower-level connection writes issued by bulk load.
59        pub bulk_write_to_wire_calls: u64,
60        /// Time spent awaiting lower-level connection writes from bulk load.
61        pub bulk_write_to_wire_elapsed: Duration,
62        /// Payload bytes passed to lower-level connection writes from bulk load.
63        pub bulk_write_to_wire_payload_bytes: u64,
64        /// Slowest lower-level connection write awaited by bulk load.
65        pub bulk_max_write_to_wire_elapsed: Duration,
66        /// Largest lower-level connection write payload from bulk load.
67        pub bulk_max_write_to_wire_payload_bytes: u64,
68        /// Number of explicit bulk-load flushes.
69        pub bulk_flush_calls: u64,
70        /// Time spent awaiting explicit bulk-load flushes.
71        pub bulk_flush_elapsed: Duration,
72        /// Slowest explicit bulk-load flush.
73        pub bulk_max_flush_elapsed: Duration,
74        /// Time spent finalizing the bulk-load request.
75        pub bulk_finalize_elapsed: Duration,
76        /// Time spent awaiting the final `EndOfMessage` packet write.
77        pub bulk_finalize_write_to_wire_elapsed: Duration,
78        /// Time spent awaiting the final explicit flush.
79        pub bulk_finalize_flush_elapsed: Duration,
80        /// Time spent waiting for the server result after final bulk flush.
81        pub bulk_finalize_result_elapsed: Duration,
82        /// Number of bulk-load packets passed through the framed connection sink.
83        pub bulk_connection_write_calls: u64,
84        /// Payload bytes passed through the framed connection sink.
85        pub bulk_connection_write_payload_bytes: u64,
86        /// Time spent waiting for the framed connection sink to accept packets.
87        pub bulk_connection_write_ready_elapsed: Duration,
88        /// Time spent encoding packets into the framed connection sink.
89        pub bulk_connection_write_encode_elapsed: Duration,
90        /// Time spent flushing packets through the framed connection sink.
91        pub bulk_connection_write_flush_elapsed: Duration,
92        /// Slowest framed connection sink readiness wait.
93        pub bulk_connection_write_max_ready_elapsed: Duration,
94        /// Slowest packet encode into the framed connection sink.
95        pub bulk_connection_write_max_encode_elapsed: Duration,
96        /// Slowest framed connection sink flush.
97        pub bulk_connection_write_max_flush_elapsed: Duration,
98        /// Largest payload passed through the framed connection sink.
99        pub bulk_connection_write_max_payload_bytes: u64,
100        /// Number of bulk-load packets written through the direct packet path.
101        pub bulk_direct_packet_write_calls: u64,
102        /// Payload bytes written through the direct packet path.
103        pub bulk_direct_packet_payload_bytes: u64,
104        /// Header bytes written through the direct packet path.
105        pub bulk_direct_packet_header_bytes: u64,
106        /// Largest packet payload written through the direct packet path.
107        pub bulk_direct_packet_max_payload_bytes: u64,
108        /// Number of final `EndOfMessage` direct packets.
109        pub bulk_direct_packet_final_calls: u64,
110        /// Payload bytes in final `EndOfMessage` direct packets.
111        pub bulk_direct_packet_final_payload_bytes: u64,
112        /// Header bytes in final `EndOfMessage` direct packets.
113        pub bulk_direct_packet_final_header_bytes: u64,
114        /// Direct packet writes observed on raw, non-TLS streams.
115        pub bulk_direct_packet_raw_stream_calls: u64,
116        /// Direct packet writes observed on TLS streams.
117        pub bulk_direct_packet_tls_stream_calls: u64,
118        /// Low-level write calls issued by the direct packet path.
119        pub bulk_direct_packet_low_level_write_calls: u64,
120        /// Low-level bytes written by the direct packet path.
121        pub bulk_direct_packet_low_level_write_bytes: u64,
122        /// Largest low-level write accepted by the direct packet path.
123        pub bulk_direct_packet_max_low_level_write_bytes: u64,
124        /// Time spent in low-level writes for the direct packet path.
125        pub bulk_direct_packet_write_elapsed: Duration,
126        /// Slowest low-level write in the direct packet path.
127        pub bulk_direct_packet_max_write_elapsed: Duration,
128        /// Low-level write calls used for direct packet headers.
129        pub bulk_direct_packet_header_write_calls: u64,
130        /// Header bytes accepted by low-level writes.
131        pub bulk_direct_packet_header_write_bytes: u64,
132        /// Largest header byte count accepted by one low-level write.
133        pub bulk_direct_packet_header_max_write_bytes: u64,
134        /// Time spent in low-level header writes.
135        pub bulk_direct_packet_header_write_elapsed: Duration,
136        /// Slowest low-level header write.
137        pub bulk_direct_packet_header_max_write_elapsed: Duration,
138        /// Low-level header writes that accepted fewer bytes than remained.
139        pub bulk_direct_packet_header_partial_writes: u64,
140        /// Low-level write calls used for direct packet payloads.
141        pub bulk_direct_packet_payload_write_calls: u64,
142        /// Payload bytes accepted by low-level writes.
143        pub bulk_direct_packet_payload_write_bytes: u64,
144        /// Largest payload byte count accepted by one low-level write.
145        pub bulk_direct_packet_payload_max_write_bytes: u64,
146        /// Time spent in low-level payload writes.
147        pub bulk_direct_packet_payload_write_elapsed: Duration,
148        /// Slowest low-level payload write.
149        pub bulk_direct_packet_payload_max_write_elapsed: Duration,
150        /// Low-level payload writes that accepted fewer bytes than remained.
151        pub bulk_direct_packet_payload_partial_writes: u64,
152        /// Number of low-level `poll_write` attempts.
153        pub bulk_direct_packet_poll_write_polls: u64,
154        /// Number of low-level `poll_write` attempts that returned `Pending`.
155        pub bulk_direct_packet_poll_write_pending_count: u64,
156        /// Time spent waiting after low-level `poll_write` returned `Pending`.
157        pub bulk_direct_packet_poll_write_pending_elapsed: Duration,
158        /// Slowest wait after low-level `poll_write` returned `Pending`.
159        pub bulk_direct_packet_poll_write_max_pending_elapsed: Duration,
160        /// Number of low-level `poll_write` attempts that returned ready.
161        pub bulk_direct_packet_poll_write_ready_count: u64,
162        /// Time spent in ready low-level `poll_write` attempts.
163        pub bulk_direct_packet_poll_write_ready_elapsed: Duration,
164        /// Slowest ready low-level `poll_write` attempt.
165        pub bulk_direct_packet_poll_write_max_ready_elapsed: Duration,
166        /// Explicit flush calls issued by the direct packet path.
167        pub bulk_direct_packet_flush_calls: u64,
168        /// Time spent flushing the direct packet path.
169        pub bulk_direct_packet_flush_elapsed: Duration,
170        /// Slowest flush in the direct packet path.
171        pub bulk_direct_packet_max_flush_elapsed: Duration,
172        /// Number of direct packet flush polls that returned `Pending`.
173        pub bulk_direct_packet_flush_pending_count: u64,
174        /// Time spent waiting after direct packet flush polls returned `Pending`.
175        pub bulk_direct_packet_flush_pending_elapsed: Duration,
176        /// Slowest wait after a direct packet flush poll returned `Pending`.
177        pub bulk_direct_packet_flush_max_pending_elapsed: Duration,
178    }
179
180    impl DirectWriteProfile {
181        /// Returns approximate send time outside the append/encode closure.
182        pub fn send_without_append_encode(&self) -> Duration {
183            self.send_total.saturating_sub(self.append_encode)
184        }
185    }
186
187    thread_local! {
188        static DIRECT_PROFILE: RefCell<Option<DirectWriteProfile>> = const { RefCell::new(None) };
189    }
190    static DIRECT_DATE_FAST_PATH_DISABLED: AtomicBool = AtomicBool::new(false);
191    static DIRECT_FIXED_WIDTH_FAST_PATH_DISABLED: AtomicBool = AtomicBool::new(false);
192
193    /// Scoped benchmark override that disables the direct date fast path.
194    #[derive(Debug)]
195    pub struct DirectDateFastPathOverride {
196        previous: bool,
197    }
198
199    /// Scoped benchmark override that disables the whole fixed-width fast path.
200    #[derive(Debug)]
201    pub struct DirectFixedWidthFastPathOverride {
202        previous: bool,
203    }
204
205    impl Drop for DirectDateFastPathOverride {
206        fn drop(&mut self) {
207            DIRECT_DATE_FAST_PATH_DISABLED.store(self.previous, Ordering::Relaxed);
208        }
209    }
210
211    impl Drop for DirectFixedWidthFastPathOverride {
212        fn drop(&mut self) {
213            DIRECT_FIXED_WIDTH_FAST_PATH_DISABLED.store(self.previous, Ordering::Relaxed);
214        }
215    }
216
217    /// Disables direct date fixed-width fast-path encoding for the current scope.
218    pub fn disable_direct_date_fast_path_for_scope() -> DirectDateFastPathOverride {
219        DirectDateFastPathOverride {
220            previous: DIRECT_DATE_FAST_PATH_DISABLED.swap(true, Ordering::Relaxed),
221        }
222    }
223
224    /// Disables direct fixed-width fast-path encoding for the current scope.
225    pub fn disable_direct_fixed_width_fast_path_for_scope() -> DirectFixedWidthFastPathOverride {
226        DirectFixedWidthFastPathOverride {
227            previous: DIRECT_FIXED_WIDTH_FAST_PATH_DISABLED.swap(true, Ordering::Relaxed),
228        }
229    }
230
231    pub(crate) fn direct_date_fast_path_disabled() -> bool {
232        DIRECT_DATE_FAST_PATH_DISABLED.load(Ordering::Relaxed)
233    }
234
235    pub(crate) fn direct_fixed_width_fast_path_disabled() -> bool {
236        DIRECT_FIXED_WIDTH_FAST_PATH_DISABLED.load(Ordering::Relaxed)
237    }
238
239    /// Starts direct writer profiling on the current thread.
240    ///
241    /// Existing data for the current thread is cleared.
242    pub fn start_direct_write_profile() {
243        DIRECT_PROFILE.with(|profile| {
244            *profile.borrow_mut() = Some(DirectWriteProfile::default());
245        });
246    }
247
248    /// Stops direct writer profiling on the current thread and returns the data.
249    pub fn finish_direct_write_profile() -> Option<DirectWriteProfile> {
250        DIRECT_PROFILE.with(|profile| profile.borrow_mut().take())
251    }
252
253    pub(crate) fn record_measure_batch(elapsed: Duration) {
254        with_profile(|profile| profile.measure_batch += elapsed);
255    }
256
257    pub(crate) fn record_row_range_split(elapsed: Duration) {
258        with_profile(|profile| profile.row_range_split += elapsed);
259    }
260
261    pub(crate) fn record_append_encode(elapsed: Duration) {
262        with_profile(|profile| profile.append_encode += elapsed);
263    }
264
265    pub(crate) fn record_send_total(elapsed: Duration) {
266        with_profile(|profile| profile.send_total += elapsed);
267    }
268
269    pub(crate) fn record_accepted_batch(rows: usize) {
270        with_profile(|profile| {
271            profile.rows = profile.rows.saturating_add(usize_to_u64_saturating(rows));
272            profile.batches = profile.batches.saturating_add(1);
273        });
274    }
275
276    pub(crate) fn record_row_range(encoded_bytes: usize) {
277        with_profile(|profile| {
278            let encoded_bytes = usize_to_u64_saturating(encoded_bytes);
279            profile.row_ranges = profile.row_ranges.saturating_add(1);
280            profile.encoded_bytes = profile.encoded_bytes.saturating_add(encoded_bytes);
281            profile.max_row_range_bytes = profile.max_row_range_bytes.max(encoded_bytes);
282        });
283    }
284
285    pub(crate) fn record_nvarchar_utf16_bytes(encoded_bytes: usize) {
286        with_profile(|profile| {
287            profile.nvarchar_utf16_bytes = profile
288                .nvarchar_utf16_bytes
289                .saturating_add(usize_to_u64_saturating(encoded_bytes));
290        });
291    }
292
293    pub(crate) fn record_varbinary_bytes(encoded_bytes: usize) {
294        with_profile(|profile| {
295            profile.varbinary_bytes = profile
296                .varbinary_bytes
297                .saturating_add(usize_to_u64_saturating(encoded_bytes));
298        });
299    }
300
301    pub(crate) fn record_null_cell() {
302        with_profile(|profile| {
303            profile.null_cells = profile.null_cells.saturating_add(1);
304        });
305    }
306
307    pub(crate) fn record_bulk_load_stats(stats: BulkLoadStats) {
308        let packet = stats.packet;
309        let timing = stats.write_timing;
310        let connection = timing.connection_write;
311        let direct = timing.direct_packet_write;
312
313        with_profile(|profile| {
314            profile.packet_write_calls = profile
315                .packet_write_calls
316                .saturating_add(packet.write_packets_calls);
317            profile.packets_written = profile
318                .packets_written
319                .saturating_add(packet.packets_written);
320            profile.packet_payload_bytes = profile
321                .packet_payload_bytes
322                .saturating_add(packet.packet_payload_bytes);
323            profile.max_packet_payload_bytes = profile
324                .max_packet_payload_bytes
325                .max(usize_to_u64_saturating(packet.max_packet_payload_bytes));
326            profile.max_buffered_bytes_before_write =
327                profile
328                    .max_buffered_bytes_before_write
329                    .max(usize_to_u64_saturating(
330                        packet.max_buffered_bytes_before_write,
331                    ));
332            profile.buffered_bytes_after_last_write =
333                usize_to_u64_saturating(packet.buffered_bytes_after_last_write);
334            profile.finalized_packet_payload_bytes = profile
335                .finalized_packet_payload_bytes
336                .saturating_add(usize_to_u64_saturating(
337                    packet.finalized_packet_payload_bytes,
338                ));
339            profile.bulk_write_packets_elapsed += timing.write_packets_elapsed;
340            profile.bulk_write_to_wire_calls = profile
341                .bulk_write_to_wire_calls
342                .saturating_add(timing.write_to_wire_calls);
343            profile.bulk_write_to_wire_elapsed += timing.write_to_wire_elapsed;
344            profile.bulk_write_to_wire_payload_bytes = profile
345                .bulk_write_to_wire_payload_bytes
346                .saturating_add(timing.write_to_wire_payload_bytes);
347            profile.bulk_max_write_to_wire_elapsed = profile
348                .bulk_max_write_to_wire_elapsed
349                .max(timing.max_write_to_wire_elapsed);
350            profile.bulk_max_write_to_wire_payload_bytes = profile
351                .bulk_max_write_to_wire_payload_bytes
352                .max(usize_to_u64_saturating(
353                    timing.max_write_to_wire_payload_bytes,
354                ));
355            profile.bulk_flush_calls = profile.bulk_flush_calls.saturating_add(timing.flush_calls);
356            profile.bulk_flush_elapsed += timing.flush_elapsed;
357            profile.bulk_max_flush_elapsed =
358                profile.bulk_max_flush_elapsed.max(timing.max_flush_elapsed);
359            profile.bulk_finalize_elapsed += timing.finalize_elapsed;
360            profile.bulk_finalize_write_to_wire_elapsed += timing.finalize_write_to_wire_elapsed;
361            profile.bulk_finalize_flush_elapsed += timing.finalize_flush_elapsed;
362            profile.bulk_finalize_result_elapsed += timing.finalize_result_elapsed;
363            profile.bulk_connection_write_calls = profile
364                .bulk_connection_write_calls
365                .saturating_add(connection.calls);
366            profile.bulk_connection_write_payload_bytes = profile
367                .bulk_connection_write_payload_bytes
368                .saturating_add(connection.payload_bytes);
369            profile.bulk_connection_write_ready_elapsed += connection.ready_elapsed;
370            profile.bulk_connection_write_encode_elapsed += connection.encode_elapsed;
371            profile.bulk_connection_write_flush_elapsed += connection.flush_elapsed;
372            profile.bulk_connection_write_max_ready_elapsed = profile
373                .bulk_connection_write_max_ready_elapsed
374                .max(connection.max_ready_elapsed);
375            profile.bulk_connection_write_max_encode_elapsed = profile
376                .bulk_connection_write_max_encode_elapsed
377                .max(connection.max_encode_elapsed);
378            profile.bulk_connection_write_max_flush_elapsed = profile
379                .bulk_connection_write_max_flush_elapsed
380                .max(connection.max_flush_elapsed);
381            profile.bulk_connection_write_max_payload_bytes = profile
382                .bulk_connection_write_max_payload_bytes
383                .max(usize_to_u64_saturating(connection.max_payload_bytes));
384            profile.bulk_direct_packet_write_calls = profile
385                .bulk_direct_packet_write_calls
386                .saturating_add(direct.calls);
387            profile.bulk_direct_packet_payload_bytes = profile
388                .bulk_direct_packet_payload_bytes
389                .saturating_add(direct.payload_bytes);
390            profile.bulk_direct_packet_header_bytes = profile
391                .bulk_direct_packet_header_bytes
392                .saturating_add(direct.header_bytes);
393            profile.bulk_direct_packet_max_payload_bytes = profile
394                .bulk_direct_packet_max_payload_bytes
395                .max(usize_to_u64_saturating(direct.max_payload_bytes));
396            profile.bulk_direct_packet_final_calls = profile
397                .bulk_direct_packet_final_calls
398                .saturating_add(direct.final_calls);
399            profile.bulk_direct_packet_final_payload_bytes = profile
400                .bulk_direct_packet_final_payload_bytes
401                .saturating_add(direct.final_payload_bytes);
402            profile.bulk_direct_packet_final_header_bytes = profile
403                .bulk_direct_packet_final_header_bytes
404                .saturating_add(direct.final_header_bytes);
405            profile.bulk_direct_packet_raw_stream_calls = profile
406                .bulk_direct_packet_raw_stream_calls
407                .saturating_add(direct.raw_stream_calls);
408            profile.bulk_direct_packet_tls_stream_calls = profile
409                .bulk_direct_packet_tls_stream_calls
410                .saturating_add(direct.tls_stream_calls);
411            profile.bulk_direct_packet_low_level_write_calls = profile
412                .bulk_direct_packet_low_level_write_calls
413                .saturating_add(direct.write_calls);
414            profile.bulk_direct_packet_low_level_write_bytes = profile
415                .bulk_direct_packet_low_level_write_bytes
416                .saturating_add(direct.write_bytes);
417            profile.bulk_direct_packet_max_low_level_write_bytes = profile
418                .bulk_direct_packet_max_low_level_write_bytes
419                .max(usize_to_u64_saturating(direct.max_write_bytes));
420            profile.bulk_direct_packet_write_elapsed += direct.write_elapsed;
421            profile.bulk_direct_packet_max_write_elapsed = profile
422                .bulk_direct_packet_max_write_elapsed
423                .max(direct.max_write_elapsed);
424            profile.bulk_direct_packet_header_write_calls = profile
425                .bulk_direct_packet_header_write_calls
426                .saturating_add(direct.header_write_calls);
427            profile.bulk_direct_packet_header_write_bytes = profile
428                .bulk_direct_packet_header_write_bytes
429                .saturating_add(direct.header_write_bytes);
430            profile.bulk_direct_packet_header_max_write_bytes = profile
431                .bulk_direct_packet_header_max_write_bytes
432                .max(usize_to_u64_saturating(direct.header_max_write_bytes));
433            profile.bulk_direct_packet_header_write_elapsed += direct.header_write_elapsed;
434            profile.bulk_direct_packet_header_max_write_elapsed = profile
435                .bulk_direct_packet_header_max_write_elapsed
436                .max(direct.header_max_write_elapsed);
437            profile.bulk_direct_packet_header_partial_writes = profile
438                .bulk_direct_packet_header_partial_writes
439                .saturating_add(direct.header_partial_writes);
440            profile.bulk_direct_packet_payload_write_calls = profile
441                .bulk_direct_packet_payload_write_calls
442                .saturating_add(direct.payload_write_calls);
443            profile.bulk_direct_packet_payload_write_bytes = profile
444                .bulk_direct_packet_payload_write_bytes
445                .saturating_add(direct.payload_write_bytes);
446            profile.bulk_direct_packet_payload_max_write_bytes = profile
447                .bulk_direct_packet_payload_max_write_bytes
448                .max(usize_to_u64_saturating(direct.payload_max_write_bytes));
449            profile.bulk_direct_packet_payload_write_elapsed += direct.payload_write_elapsed;
450            profile.bulk_direct_packet_payload_max_write_elapsed = profile
451                .bulk_direct_packet_payload_max_write_elapsed
452                .max(direct.payload_max_write_elapsed);
453            profile.bulk_direct_packet_payload_partial_writes = profile
454                .bulk_direct_packet_payload_partial_writes
455                .saturating_add(direct.payload_partial_writes);
456            profile.bulk_direct_packet_poll_write_polls = profile
457                .bulk_direct_packet_poll_write_polls
458                .saturating_add(direct.poll_write_polls);
459            profile.bulk_direct_packet_poll_write_pending_count = profile
460                .bulk_direct_packet_poll_write_pending_count
461                .saturating_add(direct.poll_write_pending_count);
462            profile.bulk_direct_packet_poll_write_pending_elapsed +=
463                direct.poll_write_pending_elapsed;
464            profile.bulk_direct_packet_poll_write_max_pending_elapsed = profile
465                .bulk_direct_packet_poll_write_max_pending_elapsed
466                .max(direct.poll_write_max_pending_elapsed);
467            profile.bulk_direct_packet_poll_write_ready_count = profile
468                .bulk_direct_packet_poll_write_ready_count
469                .saturating_add(direct.poll_write_ready_count);
470            profile.bulk_direct_packet_poll_write_ready_elapsed += direct.poll_write_ready_elapsed;
471            profile.bulk_direct_packet_poll_write_max_ready_elapsed = profile
472                .bulk_direct_packet_poll_write_max_ready_elapsed
473                .max(direct.poll_write_max_ready_elapsed);
474            profile.bulk_direct_packet_flush_calls = profile
475                .bulk_direct_packet_flush_calls
476                .saturating_add(direct.flush_calls);
477            profile.bulk_direct_packet_flush_elapsed += direct.flush_elapsed;
478            profile.bulk_direct_packet_max_flush_elapsed = profile
479                .bulk_direct_packet_max_flush_elapsed
480                .max(direct.max_flush_elapsed);
481            profile.bulk_direct_packet_flush_pending_count = profile
482                .bulk_direct_packet_flush_pending_count
483                .saturating_add(direct.flush_pending_count);
484            profile.bulk_direct_packet_flush_pending_elapsed += direct.flush_pending_elapsed;
485            profile.bulk_direct_packet_flush_max_pending_elapsed = profile
486                .bulk_direct_packet_flush_max_pending_elapsed
487                .max(direct.flush_max_pending_elapsed);
488        });
489    }
490
491    fn with_profile(update: impl FnOnce(&mut DirectWriteProfile)) {
492        DIRECT_PROFILE.with(|profile| {
493            if let Some(profile) = profile.borrow_mut().as_mut() {
494                update(profile);
495            }
496        });
497    }
498
499    fn usize_to_u64_saturating(value: usize) -> u64 {
500        u64::try_from(value).unwrap_or(u64::MAX)
501    }
502}
503
504#[cfg(not(feature = "bench-profile"))]
505mod disabled {
506    use std::time::Duration;
507
508    pub(crate) fn record_measure_batch(_elapsed: Duration) {}
509
510    pub(crate) fn record_row_range_split(_elapsed: Duration) {}
511
512    pub(crate) fn record_append_encode(_elapsed: Duration) {}
513
514    pub(crate) fn record_send_total(_elapsed: Duration) {}
515
516    pub(crate) fn record_accepted_batch(_rows: usize) {}
517
518    pub(crate) fn record_row_range(_encoded_bytes: usize) {}
519
520    pub(crate) fn record_nvarchar_utf16_bytes(_encoded_bytes: usize) {}
521
522    pub(crate) fn record_varbinary_bytes(_encoded_bytes: usize) {}
523
524    pub(crate) fn record_null_cell() {}
525
526    pub(crate) fn direct_date_fast_path_disabled() -> bool {
527        false
528    }
529
530    pub(crate) fn direct_fixed_width_fast_path_disabled() -> bool {
531        false
532    }
533}
534
535#[cfg(not(feature = "bench-profile"))]
536pub(crate) use disabled::*;
537#[cfg(feature = "bench-profile")]
538pub use enabled::{
539    DirectDateFastPathOverride, DirectFixedWidthFastPathOverride, DirectWriteProfile,
540    disable_direct_date_fast_path_for_scope, disable_direct_fixed_width_fast_path_for_scope,
541    finish_direct_write_profile, start_direct_write_profile,
542};
543#[cfg(feature = "bench-profile")]
544pub(crate) use enabled::{
545    direct_date_fast_path_disabled, direct_fixed_width_fast_path_disabled, record_accepted_batch,
546    record_append_encode, record_bulk_load_stats, record_measure_batch, record_null_cell,
547    record_nvarchar_utf16_bytes, record_row_range, record_row_range_split, record_send_total,
548    record_varbinary_bytes,
549};
550
551pub(crate) fn record_elapsed<T>(start: std::time::Instant, record: fn(Duration), value: T) -> T {
552    record(start.elapsed());
553    value
554}
555
556#[cfg(all(test, feature = "bench-profile"))]
557mod tests {
558    use std::time::Duration;
559
560    #[test]
561    fn direct_profile_accumulates_and_resets_current_thread_data() {
562        super::start_direct_write_profile();
563        super::record_measure_batch(Duration::from_millis(2));
564        super::record_row_range_split(Duration::from_millis(3));
565        super::record_append_encode(Duration::from_millis(5));
566        super::record_send_total(Duration::from_millis(13));
567        super::record_accepted_batch(7);
568        super::record_row_range(11);
569        super::record_nvarchar_utf16_bytes(17);
570        super::record_varbinary_bytes(19);
571        super::record_null_cell();
572        super::record_bulk_load_stats(tiberius::BulkLoadStats {
573            packet: tiberius::BulkLoadPacketStats {
574                write_packets_calls: 23,
575                packets_written: 29,
576                packet_payload_bytes: 31,
577                max_packet_payload_bytes: 37,
578                max_buffered_bytes_before_write: 41,
579                buffered_bytes_after_last_write: 43,
580                finalized_packet_payload_bytes: 47,
581            },
582            write_timing: tiberius::BulkLoadWriteTimingStats {
583                write_packets_elapsed: Duration::from_millis(53),
584                write_to_wire_calls: 59,
585                write_to_wire_elapsed: Duration::from_millis(61),
586                write_to_wire_payload_bytes: 67,
587                max_write_to_wire_elapsed: Duration::from_millis(71),
588                max_write_to_wire_payload_bytes: 73,
589                flush_calls: 79,
590                flush_elapsed: Duration::from_millis(83),
591                max_flush_elapsed: Duration::from_millis(89),
592                finalize_elapsed: Duration::from_millis(97),
593                finalize_write_to_wire_elapsed: Duration::from_millis(101),
594                finalize_flush_elapsed: Duration::from_millis(103),
595                finalize_result_elapsed: Duration::from_millis(107),
596                connection_write: tiberius::BulkLoadConnectionWriteStats {
597                    calls: 109,
598                    payload_bytes: 113,
599                    ready_elapsed: Duration::from_millis(127),
600                    encode_elapsed: Duration::from_millis(131),
601                    flush_elapsed: Duration::from_millis(137),
602                    max_ready_elapsed: Duration::from_millis(139),
603                    max_encode_elapsed: Duration::from_millis(149),
604                    max_flush_elapsed: Duration::from_millis(151),
605                    max_payload_bytes: 157,
606                },
607                direct_packet_write: tiberius::BulkLoadDirectPacketWriteStats {
608                    calls: 163,
609                    payload_bytes: 167,
610                    header_bytes: 173,
611                    max_payload_bytes: 179,
612                    final_calls: 181,
613                    final_payload_bytes: 191,
614                    final_header_bytes: 193,
615                    raw_stream_calls: 197,
616                    tls_stream_calls: 199,
617                    write_calls: 179,
618                    write_bytes: 181,
619                    max_write_bytes: 191,
620                    write_elapsed: Duration::from_millis(193),
621                    max_write_elapsed: Duration::from_millis(197),
622                    header_write_calls: 211,
623                    header_write_bytes: 223,
624                    header_max_write_bytes: 227,
625                    header_write_elapsed: Duration::from_millis(229),
626                    header_max_write_elapsed: Duration::from_millis(233),
627                    header_partial_writes: 239,
628                    payload_write_calls: 241,
629                    payload_write_bytes: 251,
630                    payload_max_write_bytes: 257,
631                    payload_write_elapsed: Duration::from_millis(263),
632                    payload_max_write_elapsed: Duration::from_millis(269),
633                    payload_partial_writes: 271,
634                    poll_write_polls: 277,
635                    poll_write_pending_count: 281,
636                    poll_write_pending_elapsed: Duration::from_millis(283),
637                    poll_write_max_pending_elapsed: Duration::from_millis(293),
638                    poll_write_ready_count: 307,
639                    poll_write_ready_elapsed: Duration::from_millis(311),
640                    poll_write_max_ready_elapsed: Duration::from_millis(313),
641                    flush_calls: 199,
642                    flush_elapsed: Duration::from_millis(211),
643                    max_flush_elapsed: Duration::from_millis(223),
644                    flush_pending_count: 317,
645                    flush_pending_elapsed: Duration::from_millis(331),
646                    flush_max_pending_elapsed: Duration::from_millis(337),
647                },
648            },
649        });
650
651        let profile = super::finish_direct_write_profile().unwrap();
652
653        assert_eq!(profile.measure_batch, Duration::from_millis(2));
654        assert_eq!(profile.row_range_split, Duration::from_millis(3));
655        assert_eq!(profile.append_encode, Duration::from_millis(5));
656        assert_eq!(profile.send_total, Duration::from_millis(13));
657        assert_eq!(
658            profile.send_without_append_encode(),
659            Duration::from_millis(8)
660        );
661        assert_eq!(profile.rows, 7);
662        assert_eq!(profile.batches, 1);
663        assert_eq!(profile.row_ranges, 1);
664        assert_eq!(profile.encoded_bytes, 11);
665        assert_eq!(profile.max_row_range_bytes, 11);
666        assert_eq!(profile.nvarchar_utf16_bytes, 17);
667        assert_eq!(profile.varbinary_bytes, 19);
668        assert_eq!(profile.null_cells, 1);
669        assert_eq!(profile.packet_write_calls, 23);
670        assert_eq!(profile.packets_written, 29);
671        assert_eq!(profile.packet_payload_bytes, 31);
672        assert_eq!(profile.max_packet_payload_bytes, 37);
673        assert_eq!(profile.max_buffered_bytes_before_write, 41);
674        assert_eq!(profile.buffered_bytes_after_last_write, 43);
675        assert_eq!(profile.finalized_packet_payload_bytes, 47);
676        assert_eq!(
677            profile.bulk_write_packets_elapsed,
678            Duration::from_millis(53)
679        );
680        assert_eq!(profile.bulk_write_to_wire_calls, 59);
681        assert_eq!(
682            profile.bulk_write_to_wire_elapsed,
683            Duration::from_millis(61)
684        );
685        assert_eq!(profile.bulk_write_to_wire_payload_bytes, 67);
686        assert_eq!(
687            profile.bulk_max_write_to_wire_elapsed,
688            Duration::from_millis(71)
689        );
690        assert_eq!(profile.bulk_max_write_to_wire_payload_bytes, 73);
691        assert_eq!(profile.bulk_flush_calls, 79);
692        assert_eq!(profile.bulk_flush_elapsed, Duration::from_millis(83));
693        assert_eq!(profile.bulk_max_flush_elapsed, Duration::from_millis(89));
694        assert_eq!(profile.bulk_finalize_elapsed, Duration::from_millis(97));
695        assert_eq!(
696            profile.bulk_finalize_write_to_wire_elapsed,
697            Duration::from_millis(101)
698        );
699        assert_eq!(
700            profile.bulk_finalize_flush_elapsed,
701            Duration::from_millis(103)
702        );
703        assert_eq!(
704            profile.bulk_finalize_result_elapsed,
705            Duration::from_millis(107)
706        );
707        assert_eq!(profile.bulk_connection_write_calls, 109);
708        assert_eq!(profile.bulk_connection_write_payload_bytes, 113);
709        assert_eq!(
710            profile.bulk_connection_write_ready_elapsed,
711            Duration::from_millis(127)
712        );
713        assert_eq!(
714            profile.bulk_connection_write_encode_elapsed,
715            Duration::from_millis(131)
716        );
717        assert_eq!(
718            profile.bulk_connection_write_flush_elapsed,
719            Duration::from_millis(137)
720        );
721        assert_eq!(
722            profile.bulk_connection_write_max_ready_elapsed,
723            Duration::from_millis(139)
724        );
725        assert_eq!(
726            profile.bulk_connection_write_max_encode_elapsed,
727            Duration::from_millis(149)
728        );
729        assert_eq!(
730            profile.bulk_connection_write_max_flush_elapsed,
731            Duration::from_millis(151)
732        );
733        assert_eq!(profile.bulk_connection_write_max_payload_bytes, 157);
734        assert_eq!(profile.bulk_direct_packet_write_calls, 163);
735        assert_eq!(profile.bulk_direct_packet_payload_bytes, 167);
736        assert_eq!(profile.bulk_direct_packet_header_bytes, 173);
737        assert_eq!(profile.bulk_direct_packet_max_payload_bytes, 179);
738        assert_eq!(profile.bulk_direct_packet_final_calls, 181);
739        assert_eq!(profile.bulk_direct_packet_final_payload_bytes, 191);
740        assert_eq!(profile.bulk_direct_packet_final_header_bytes, 193);
741        assert_eq!(profile.bulk_direct_packet_raw_stream_calls, 197);
742        assert_eq!(profile.bulk_direct_packet_tls_stream_calls, 199);
743        assert_eq!(profile.bulk_direct_packet_low_level_write_calls, 179);
744        assert_eq!(profile.bulk_direct_packet_low_level_write_bytes, 181);
745        assert_eq!(profile.bulk_direct_packet_max_low_level_write_bytes, 191);
746        assert_eq!(
747            profile.bulk_direct_packet_write_elapsed,
748            Duration::from_millis(193)
749        );
750        assert_eq!(
751            profile.bulk_direct_packet_max_write_elapsed,
752            Duration::from_millis(197)
753        );
754        assert_eq!(profile.bulk_direct_packet_header_write_calls, 211);
755        assert_eq!(profile.bulk_direct_packet_header_write_bytes, 223);
756        assert_eq!(profile.bulk_direct_packet_header_max_write_bytes, 227);
757        assert_eq!(
758            profile.bulk_direct_packet_header_write_elapsed,
759            Duration::from_millis(229)
760        );
761        assert_eq!(
762            profile.bulk_direct_packet_header_max_write_elapsed,
763            Duration::from_millis(233)
764        );
765        assert_eq!(profile.bulk_direct_packet_header_partial_writes, 239);
766        assert_eq!(profile.bulk_direct_packet_payload_write_calls, 241);
767        assert_eq!(profile.bulk_direct_packet_payload_write_bytes, 251);
768        assert_eq!(profile.bulk_direct_packet_payload_max_write_bytes, 257);
769        assert_eq!(
770            profile.bulk_direct_packet_payload_write_elapsed,
771            Duration::from_millis(263)
772        );
773        assert_eq!(
774            profile.bulk_direct_packet_payload_max_write_elapsed,
775            Duration::from_millis(269)
776        );
777        assert_eq!(profile.bulk_direct_packet_payload_partial_writes, 271);
778        assert_eq!(profile.bulk_direct_packet_poll_write_polls, 277);
779        assert_eq!(profile.bulk_direct_packet_poll_write_pending_count, 281);
780        assert_eq!(
781            profile.bulk_direct_packet_poll_write_pending_elapsed,
782            Duration::from_millis(283)
783        );
784        assert_eq!(
785            profile.bulk_direct_packet_poll_write_max_pending_elapsed,
786            Duration::from_millis(293)
787        );
788        assert_eq!(profile.bulk_direct_packet_poll_write_ready_count, 307);
789        assert_eq!(
790            profile.bulk_direct_packet_poll_write_ready_elapsed,
791            Duration::from_millis(311)
792        );
793        assert_eq!(
794            profile.bulk_direct_packet_poll_write_max_ready_elapsed,
795            Duration::from_millis(313)
796        );
797        assert_eq!(profile.bulk_direct_packet_flush_calls, 199);
798        assert_eq!(
799            profile.bulk_direct_packet_flush_elapsed,
800            Duration::from_millis(211)
801        );
802        assert_eq!(
803            profile.bulk_direct_packet_max_flush_elapsed,
804            Duration::from_millis(223)
805        );
806        assert_eq!(profile.bulk_direct_packet_flush_pending_count, 317);
807        assert_eq!(
808            profile.bulk_direct_packet_flush_pending_elapsed,
809            Duration::from_millis(331)
810        );
811        assert_eq!(
812            profile.bulk_direct_packet_flush_max_pending_elapsed,
813            Duration::from_millis(337)
814        );
815        assert!(super::finish_direct_write_profile().is_none());
816    }
817}
arrow_tiberius/write/profile.rs

arrow_tiberius/write/
profile.rs
