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

arrow_tiberius/write/
profile.rs
