1use crate::WalGenerationIdentity;
38use fsqlite_types::sync_primitives::{Duration, Instant};
39use serde::{Deserialize, Serialize};
40use std::collections::VecDeque;
41use std::sync::{
42 LazyLock,
43 atomic::{AtomicBool, AtomicU64, Ordering},
44};
45
46use fsqlite_error::{FrankenError, Result};
47use fsqlite_types::cx::Cx;
48use fsqlite_vfs::{SyncKind, VfsFile};
49use tracing::{debug, info, trace};
50
51use crate::wal::{WalAppendFrameRef, WalFile};
52
53fn env_flag_enabled(value: &str) -> bool {
54 let value = value.trim();
55 value == "1"
56 || value.eq_ignore_ascii_case("true")
57 || value.eq_ignore_ascii_case("yes")
58 || value.eq_ignore_ascii_case("on")
59}
60
61#[must_use]
63pub fn detailed_consolidation_metrics_enabled() -> bool {
64 static ENABLED: LazyLock<bool> = LazyLock::new(|| {
65 std::env::var("FSQLITE_WAL_DETAILED_COMMIT_METRICS")
66 .is_ok_and(|value| env_flag_enabled(&value))
67 || std::env::var("FSQLITE_BENCH_PROFILE_INSERT")
68 .is_ok_and(|value| env_flag_enabled(&value))
69 });
70 *ENABLED
71}
72
73static COMMIT_PHASE_TIMING_ENABLED: AtomicBool = AtomicBool::new(false);
74
75pub fn set_commit_phase_timing_enabled(enabled: bool) -> bool {
81 COMMIT_PHASE_TIMING_ENABLED.swap(enabled, Ordering::Relaxed)
82}
83
84#[must_use]
86pub fn commit_phase_timing_forced_enabled() -> bool {
87 COMMIT_PHASE_TIMING_ENABLED.load(Ordering::Relaxed)
88}
89
90#[must_use]
92pub fn commit_phase_timing_enabled() -> bool {
93 detailed_consolidation_metrics_enabled() || commit_phase_timing_forced_enabled()
94}
95
96#[derive(Debug, Clone, Copy)]
102pub struct GroupCommitConfig {
103 pub max_group_size: usize,
107
108 pub max_group_delay: Duration,
112
113 pub max_group_delay_ceiling: Duration,
118}
119
120impl Default for GroupCommitConfig {
121 fn default() -> Self {
122 Self {
123 max_group_size: 64,
124 max_group_delay: Duration::from_millis(1),
125 max_group_delay_ceiling: Duration::from_millis(10),
126 }
127 }
128}
129
130impl GroupCommitConfig {
131 #[must_use]
133 pub fn validated(mut self) -> Self {
134 if self.max_group_size == 0 {
135 self.max_group_size = 1;
136 }
137 if self.max_group_delay > self.max_group_delay_ceiling {
138 self.max_group_delay = self.max_group_delay_ceiling;
139 }
140 self
141 }
142}
143
144#[derive(Debug, Clone)]
150pub struct FrameSubmission {
151 pub page_number: u32,
153 pub page_data: Vec<u8>,
155 pub db_size_if_commit: u32,
157}
158
159#[derive(Debug, Clone)]
161pub struct TransactionFrameBatch {
162 pub frames: Vec<FrameSubmission>,
164 pub conflict_pages: Vec<u32>,
172 pub conflict_snapshot: Option<TransactionConflictSnapshot>,
177 pub conflict_page_baselines: Vec<TransactionConflictPageBaseline>,
187 pub context: TransactionFrameBatchContext,
189}
190
191#[derive(Debug, Clone, Copy, PartialEq, Eq)]
193pub struct TransactionConflictSnapshot {
194 pub generation: WalGenerationIdentity,
195 pub last_commit_frame: Option<usize>,
196 pub commit_count: u64,
197}
198
199#[derive(Debug, Clone, Copy, PartialEq, Eq)]
201pub struct TransactionConflictPageBaseline {
202 pub page_number: u32,
204 pub page_hash: [u8; 32],
206}
207
208#[derive(Debug, Clone, Copy, PartialEq, Eq, Default)]
210pub struct TransactionFrameBatchContext {
211 pub batch_id: u64,
213 pub lane_id: u16,
215 pub staged_frame_count: u32,
217 pub staging_elapsed_ns: u64,
219}
220
221impl TransactionFrameBatch {
222 #[must_use]
224 pub fn new(frames: Vec<FrameSubmission>) -> Self {
225 Self {
226 frames,
227 conflict_pages: Vec::new(),
228 conflict_snapshot: None,
229 conflict_page_baselines: Vec::new(),
230 context: TransactionFrameBatchContext::default(),
231 }
232 }
233
234 #[must_use]
236 pub fn with_conflict_snapshot(
237 mut self,
238 conflict_pages: Vec<u32>,
239 conflict_snapshot: Option<TransactionConflictSnapshot>,
240 ) -> Self {
241 self.conflict_pages = conflict_pages;
242 self.conflict_snapshot = conflict_snapshot;
243 self
244 }
245
246 #[must_use]
248 pub fn with_conflict_page_baselines(
249 mut self,
250 conflict_page_baselines: Vec<TransactionConflictPageBaseline>,
251 ) -> Self {
252 self.conflict_page_baselines = conflict_page_baselines;
253 self
254 }
255
256 #[must_use]
258 pub fn with_context(mut self, context: TransactionFrameBatchContext) -> Self {
259 self.context = context;
260 self
261 }
262
263 #[must_use]
265 pub fn frame_count(&self) -> usize {
266 self.frames.len()
267 }
268
269 #[must_use]
271 pub fn has_commit_frame(&self) -> bool {
272 self.frames.last().is_some_and(|f| f.db_size_if_commit > 0)
273 }
274}
275
276#[derive(Debug, Clone, Copy, PartialEq, Eq)]
282pub enum ConsolidationPhase {
283 Filling,
285 Flushing,
287 Complete,
289}
290
291#[derive(Debug, Clone, Copy, PartialEq, Eq)]
293pub enum SubmitOutcome {
294 Flusher,
296 Waiter,
298}
299
300#[derive(Debug, Clone, Copy, PartialEq, Eq)]
302pub struct SubmitReceipt {
303 pub outcome: SubmitOutcome,
305 pub target_epoch: u64,
307}
308
309const PHASE_HISTOGRAM_CAPACITY: usize = 4096;
320
321pub struct PhaseHistogram {
322 samples: Box<[AtomicU64]>,
324 write_idx: AtomicU64,
326 max_us: AtomicU64,
328 count: AtomicU64,
330 sum_us: AtomicU64,
332 recent_tail_us: AtomicU64,
334}
335
336impl PhaseHistogram {
337 #[must_use]
338 pub fn new() -> Self {
339 let samples: Vec<AtomicU64> = std::iter::repeat_with(|| AtomicU64::new(0))
340 .take(PHASE_HISTOGRAM_CAPACITY)
341 .collect();
342 Self {
343 samples: samples.into_boxed_slice(),
344 write_idx: AtomicU64::new(0),
345 max_us: AtomicU64::new(0),
346 count: AtomicU64::new(0),
347 sum_us: AtomicU64::new(0),
348 recent_tail_us: AtomicU64::new(0),
349 }
350 }
351
352 pub fn record(&self, value_us: u64) {
354 let idx =
355 self.write_idx.fetch_add(1, Ordering::Relaxed) as usize % PHASE_HISTOGRAM_CAPACITY;
356 self.samples[idx].store(value_us, Ordering::Relaxed);
357 self.count.fetch_add(1, Ordering::Relaxed);
358 self.sum_us.fetch_add(value_us, Ordering::Relaxed);
359 let mut prev = self.max_us.load(Ordering::Relaxed);
361 while value_us > prev {
362 match self.max_us.compare_exchange_weak(
363 prev,
364 value_us,
365 Ordering::Relaxed,
366 Ordering::Relaxed,
367 ) {
368 Ok(_) => break,
369 Err(actual) => prev = actual,
370 }
371 }
372
373 let mut prev_tail = self.recent_tail_us.load(Ordering::Relaxed);
378 loop {
379 let decayed = prev_tail.saturating_mul(15) / 16;
380 let next_tail = value_us.max(decayed);
381 match self.recent_tail_us.compare_exchange_weak(
382 prev_tail,
383 next_tail,
384 Ordering::Relaxed,
385 Ordering::Relaxed,
386 ) {
387 Ok(_) => break,
388 Err(actual) => prev_tail = actual,
389 }
390 }
391 }
392
393 #[must_use]
395 pub fn recent_tail_us(&self) -> u64 {
396 self.recent_tail_us.load(Ordering::Relaxed)
397 }
398
399 #[must_use]
401 pub fn percentiles(&self) -> PhasePercentiles {
402 let total_count = self.count.load(Ordering::Relaxed);
403 let max = self.max_us.load(Ordering::Relaxed);
404 let sum = self.sum_us.load(Ordering::Relaxed);
405
406 if total_count == 0 {
407 return PhasePercentiles {
408 p50: 0,
409 p95: 0,
410 p99: 0,
411 max: 0,
412 count: 0,
413 mean_us: 0,
414 };
415 }
416
417 let n = total_count.min(PHASE_HISTOGRAM_CAPACITY as u64) as usize;
419 let mut buf = Vec::with_capacity(n);
420 for i in 0..n {
421 buf.push(self.samples[i].load(Ordering::Relaxed));
422 }
423 buf.sort_unstable();
424
425 let p = |pct: usize| -> u64 {
426 if buf.is_empty() {
427 return 0;
428 }
429 let idx = (pct * buf.len()) / 100;
430 buf[idx.min(buf.len() - 1)]
431 };
432
433 PhasePercentiles {
434 p50: p(50),
435 p95: p(95),
436 p99: p(99),
437 max,
438 count: total_count,
439 mean_us: sum / total_count,
440 }
441 }
442
443 pub fn reset(&self) {
445 for s in &self.samples {
446 s.store(0, Ordering::Relaxed);
447 }
448 self.write_idx.store(0, Ordering::Relaxed);
449 self.max_us.store(0, Ordering::Relaxed);
450 self.count.store(0, Ordering::Relaxed);
451 self.sum_us.store(0, Ordering::Relaxed);
452 self.recent_tail_us.store(0, Ordering::Relaxed);
453 }
454}
455
456impl Default for PhaseHistogram {
457 fn default() -> Self {
458 Self::new()
459 }
460}
461
462#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
464pub struct PhasePercentiles {
465 pub p50: u64,
466 pub p95: u64,
467 pub p99: u64,
468 pub max: u64,
469 pub count: u64,
470 pub mean_us: u64,
471}
472
473pub struct WakeReasonCounters {
479 pub notify: AtomicU64,
482 pub timeout: AtomicU64,
484 pub flusher_takeover: AtomicU64,
486 pub failed_epoch: AtomicU64,
488 pub busy_retry: AtomicU64,
490}
491
492impl WakeReasonCounters {
493 const fn new() -> Self {
494 Self {
495 notify: AtomicU64::new(0),
496 timeout: AtomicU64::new(0),
497 flusher_takeover: AtomicU64::new(0),
498 failed_epoch: AtomicU64::new(0),
499 busy_retry: AtomicU64::new(0),
500 }
501 }
502
503 #[must_use]
505 pub fn snapshot(&self) -> WakeReasonSnapshot {
506 WakeReasonSnapshot {
507 notify: self.notify.load(Ordering::Relaxed),
508 timeout: self.timeout.load(Ordering::Relaxed),
509 flusher_takeover: self.flusher_takeover.load(Ordering::Relaxed),
510 failed_epoch: self.failed_epoch.load(Ordering::Relaxed),
511 busy_retry: self.busy_retry.load(Ordering::Relaxed),
512 }
513 }
514
515 pub fn reset(&self) {
517 self.notify.store(0, Ordering::Relaxed);
518 self.timeout.store(0, Ordering::Relaxed);
519 self.flusher_takeover.store(0, Ordering::Relaxed);
520 self.failed_epoch.store(0, Ordering::Relaxed);
521 self.busy_retry.store(0, Ordering::Relaxed);
522 }
523}
524
525#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
527pub struct WakeReasonSnapshot {
528 pub notify: u64,
529 pub timeout: u64,
530 pub flusher_takeover: u64,
531 pub failed_epoch: u64,
532 pub busy_retry: u64,
533}
534
535impl WakeReasonSnapshot {
536 #[must_use]
538 pub fn total(&self) -> u64 {
539 self.notify + self.timeout + self.flusher_takeover + self.failed_epoch + self.busy_retry
540 }
541}
542
543pub struct ConsolidationMetrics {
549 pub groups_flushed: AtomicU64,
551 pub frames_consolidated: AtomicU64,
553 pub transactions_batched: AtomicU64,
555 pub fsyncs_total: AtomicU64,
557 pub flush_duration_us_total: AtomicU64,
559 pub wait_duration_us_total: AtomicU64,
561 pub max_group_size_observed: AtomicU64,
563 pub busy_retries: AtomicU64,
565
566 pub prepare_us_total: AtomicU64,
569 pub batch_build_us_total: AtomicU64,
571 pub conflict_snapshot_us_total: AtomicU64,
573 pub lane_prepare_us_total: AtomicU64,
575 pub consolidator_lock_wait_us_total: AtomicU64,
577 pub consolidator_flushing_wait_us_total: AtomicU64,
579 pub flusher_arrival_wait_us_total: AtomicU64,
581 pub inner_lock_wait_us_total: AtomicU64,
583 pub exclusive_lock_us_total: AtomicU64,
585 pub wal_append_us_total: AtomicU64,
587 pub flush_frame_prep_us_total: AtomicU64,
589 pub append_conflict_check_us_total: AtomicU64,
591 pub append_frames_us_total: AtomicU64,
593 pub wal_sync_us_total: AtomicU64,
595 pub waiter_epoch_wait_us_total: AtomicU64,
597 pub flusher_commits: AtomicU64,
599 pub waiter_commits: AtomicU64,
601 pub commit_phase_a_us_total: AtomicU64,
604 pub commit_phase_b_us_total: AtomicU64,
606 pub commit_phase_c1_us_total: AtomicU64,
608 pub commit_phase_c2_us_total: AtomicU64,
610 pub commit_phase_count: AtomicU64,
612
613 pub hist_consolidator_lock_wait: PhaseHistogram,
616 pub hist_arrival_wait: PhaseHistogram,
618 pub hist_wal_backend_lock_wait: PhaseHistogram,
620 pub hist_wal_append: PhaseHistogram,
622 pub hist_exclusive_lock: PhaseHistogram,
624 pub hist_waiter_epoch_wait: PhaseHistogram,
626 pub hist_phase_b: PhaseHistogram,
628 pub hist_wal_sync: PhaseHistogram,
630 pub hist_full_commit: PhaseHistogram,
632
633 pub wake_reasons: WakeReasonCounters,
636}
637
638impl ConsolidationMetrics {
639 #[must_use]
641 pub fn new() -> Self {
642 Self {
643 groups_flushed: AtomicU64::new(0),
644 frames_consolidated: AtomicU64::new(0),
645 transactions_batched: AtomicU64::new(0),
646 fsyncs_total: AtomicU64::new(0),
647 flush_duration_us_total: AtomicU64::new(0),
648 wait_duration_us_total: AtomicU64::new(0),
649 max_group_size_observed: AtomicU64::new(0),
650 busy_retries: AtomicU64::new(0),
651 prepare_us_total: AtomicU64::new(0),
653 batch_build_us_total: AtomicU64::new(0),
654 conflict_snapshot_us_total: AtomicU64::new(0),
655 lane_prepare_us_total: AtomicU64::new(0),
656 consolidator_lock_wait_us_total: AtomicU64::new(0),
657 consolidator_flushing_wait_us_total: AtomicU64::new(0),
658 flusher_arrival_wait_us_total: AtomicU64::new(0),
659 inner_lock_wait_us_total: AtomicU64::new(0),
660 exclusive_lock_us_total: AtomicU64::new(0),
661 wal_append_us_total: AtomicU64::new(0),
662 flush_frame_prep_us_total: AtomicU64::new(0),
663 append_conflict_check_us_total: AtomicU64::new(0),
664 append_frames_us_total: AtomicU64::new(0),
665 wal_sync_us_total: AtomicU64::new(0),
666 waiter_epoch_wait_us_total: AtomicU64::new(0),
667 flusher_commits: AtomicU64::new(0),
668 waiter_commits: AtomicU64::new(0),
669 commit_phase_a_us_total: AtomicU64::new(0),
670 commit_phase_b_us_total: AtomicU64::new(0),
671 commit_phase_c1_us_total: AtomicU64::new(0),
672 commit_phase_c2_us_total: AtomicU64::new(0),
673 commit_phase_count: AtomicU64::new(0),
674 hist_consolidator_lock_wait: PhaseHistogram::new(),
676 hist_arrival_wait: PhaseHistogram::new(),
677 hist_wal_backend_lock_wait: PhaseHistogram::new(),
678 hist_wal_append: PhaseHistogram::new(),
679 hist_exclusive_lock: PhaseHistogram::new(),
680 hist_waiter_epoch_wait: PhaseHistogram::new(),
681 hist_phase_b: PhaseHistogram::new(),
682 hist_wal_sync: PhaseHistogram::new(),
683 hist_full_commit: PhaseHistogram::new(),
684 wake_reasons: WakeReasonCounters::new(),
685 }
686 }
687
688 pub fn record_flush(&self, frames: u64, transactions: u64, duration_us: u64) {
690 self.groups_flushed.fetch_add(1, Ordering::Relaxed);
691 self.frames_consolidated
692 .fetch_add(frames, Ordering::Relaxed);
693 self.transactions_batched
694 .fetch_add(transactions, Ordering::Relaxed);
695 self.fsyncs_total.fetch_add(1, Ordering::Relaxed);
696 self.flush_duration_us_total
697 .fetch_add(duration_us, Ordering::Relaxed);
698 self.max_group_size_observed
700 .fetch_max(frames, Ordering::Relaxed);
701 }
702
703 pub fn record_wait(&self, duration_us: u64) {
705 self.wait_duration_us_total
706 .fetch_add(duration_us, Ordering::Relaxed);
707 }
708
709 pub fn record_busy_retry(&self) {
711 self.busy_retries.fetch_add(1, Ordering::Relaxed);
712 }
713
714 pub fn record_prepare_breakdown(
716 &self,
717 batch_build_us: u64,
718 conflict_snapshot_us: u64,
719 lane_prepare_us: u64,
720 ) {
721 self.batch_build_us_total
722 .fetch_add(batch_build_us, Ordering::Relaxed);
723 self.conflict_snapshot_us_total
724 .fetch_add(conflict_snapshot_us, Ordering::Relaxed);
725 self.lane_prepare_us_total
726 .fetch_add(lane_prepare_us, Ordering::Relaxed);
727 }
728
729 pub fn record_flush_breakdown(
731 &self,
732 flush_frame_prep_us: u64,
733 append_conflict_check_us: u64,
734 append_frames_us: u64,
735 ) {
736 self.flush_frame_prep_us_total
737 .fetch_add(flush_frame_prep_us, Ordering::Relaxed);
738 self.append_conflict_check_us_total
739 .fetch_add(append_conflict_check_us, Ordering::Relaxed);
740 self.append_frames_us_total
741 .fetch_add(append_frames_us, Ordering::Relaxed);
742 }
743
744 #[allow(clippy::too_many_arguments)]
746 pub fn record_phase_timing(
747 &self,
748 prepare_us: u64,
749 consolidator_lock_wait_us: u64,
750 consolidator_flushing_wait_us: u64,
751 is_flusher: bool,
752 flusher_arrival_wait_us: u64,
753 inner_lock_wait_us: u64,
754 exclusive_lock_us: u64,
755 wal_append_us: u64,
756 wal_sync_us: u64,
757 waiter_epoch_wait_us: u64,
758 ) {
759 self.prepare_us_total
760 .fetch_add(prepare_us, Ordering::Relaxed);
761 self.consolidator_lock_wait_us_total
762 .fetch_add(consolidator_lock_wait_us, Ordering::Relaxed);
763 self.consolidator_flushing_wait_us_total
764 .fetch_add(consolidator_flushing_wait_us, Ordering::Relaxed);
765
766 self.hist_consolidator_lock_wait
768 .record(consolidator_lock_wait_us);
769
770 if is_flusher {
771 self.flusher_arrival_wait_us_total
772 .fetch_add(flusher_arrival_wait_us, Ordering::Relaxed);
773 self.inner_lock_wait_us_total
774 .fetch_add(inner_lock_wait_us, Ordering::Relaxed);
775 self.exclusive_lock_us_total
776 .fetch_add(exclusive_lock_us, Ordering::Relaxed);
777 self.wal_append_us_total
778 .fetch_add(wal_append_us, Ordering::Relaxed);
779 self.wal_sync_us_total
780 .fetch_add(wal_sync_us, Ordering::Relaxed);
781 self.flusher_commits.fetch_add(1, Ordering::Relaxed);
782
783 self.hist_arrival_wait.record(flusher_arrival_wait_us);
785 self.hist_wal_backend_lock_wait.record(inner_lock_wait_us);
786 self.hist_wal_append.record(wal_append_us);
787 self.hist_exclusive_lock.record(exclusive_lock_us);
788 self.hist_wal_sync.record(wal_sync_us);
789 } else {
790 self.waiter_epoch_wait_us_total
791 .fetch_add(waiter_epoch_wait_us, Ordering::Relaxed);
792 self.waiter_commits.fetch_add(1, Ordering::Relaxed);
793
794 self.hist_waiter_epoch_wait.record(waiter_epoch_wait_us);
796 }
797
798 let phase_b_total = consolidator_lock_wait_us
800 + consolidator_flushing_wait_us
801 + if is_flusher {
802 flusher_arrival_wait_us
803 + inner_lock_wait_us
804 + exclusive_lock_us
805 + wal_append_us
806 + wal_sync_us
807 } else {
808 waiter_epoch_wait_us
809 };
810 self.hist_phase_b.record(phase_b_total);
811 }
812
813 pub fn record_commit_phases(
815 &self,
816 phase_a_us: u64,
817 phase_b_us: u64,
818 phase_c1_us: u64,
819 phase_c2_us: u64,
820 ) {
821 self.commit_phase_a_us_total
822 .fetch_add(phase_a_us, Ordering::Relaxed);
823 self.commit_phase_b_us_total
824 .fetch_add(phase_b_us, Ordering::Relaxed);
825 self.commit_phase_c1_us_total
826 .fetch_add(phase_c1_us, Ordering::Relaxed);
827 self.commit_phase_c2_us_total
828 .fetch_add(phase_c2_us, Ordering::Relaxed);
829 self.commit_phase_count.fetch_add(1, Ordering::Relaxed);
830
831 self.hist_full_commit
833 .record(phase_a_us + phase_b_us + phase_c1_us + phase_c2_us);
834 }
835
836 #[must_use]
838 pub fn snapshot(&self) -> ConsolidationMetricsSnapshot {
839 ConsolidationMetricsSnapshot {
840 groups_flushed: self.groups_flushed.load(Ordering::Relaxed),
841 frames_consolidated: self.frames_consolidated.load(Ordering::Relaxed),
842 transactions_batched: self.transactions_batched.load(Ordering::Relaxed),
843 fsyncs_total: self.fsyncs_total.load(Ordering::Relaxed),
844 flush_duration_us_total: self.flush_duration_us_total.load(Ordering::Relaxed),
845 wait_duration_us_total: self.wait_duration_us_total.load(Ordering::Relaxed),
846 max_group_size_observed: self.max_group_size_observed.load(Ordering::Relaxed),
847 busy_retries: self.busy_retries.load(Ordering::Relaxed),
848 prepare_us_total: self.prepare_us_total.load(Ordering::Relaxed),
850 batch_build_us_total: self.batch_build_us_total.load(Ordering::Relaxed),
851 conflict_snapshot_us_total: self.conflict_snapshot_us_total.load(Ordering::Relaxed),
852 lane_prepare_us_total: self.lane_prepare_us_total.load(Ordering::Relaxed),
853 consolidator_lock_wait_us_total: self
854 .consolidator_lock_wait_us_total
855 .load(Ordering::Relaxed),
856 consolidator_flushing_wait_us_total: self
857 .consolidator_flushing_wait_us_total
858 .load(Ordering::Relaxed),
859 flusher_arrival_wait_us_total: self
860 .flusher_arrival_wait_us_total
861 .load(Ordering::Relaxed),
862 inner_lock_wait_us_total: self.inner_lock_wait_us_total.load(Ordering::Relaxed),
863 exclusive_lock_us_total: self.exclusive_lock_us_total.load(Ordering::Relaxed),
864 wal_append_us_total: self.wal_append_us_total.load(Ordering::Relaxed),
865 flush_frame_prep_us_total: self.flush_frame_prep_us_total.load(Ordering::Relaxed),
866 append_conflict_check_us_total: self
867 .append_conflict_check_us_total
868 .load(Ordering::Relaxed),
869 append_frames_us_total: self.append_frames_us_total.load(Ordering::Relaxed),
870 wal_sync_us_total: self.wal_sync_us_total.load(Ordering::Relaxed),
871 waiter_epoch_wait_us_total: self.waiter_epoch_wait_us_total.load(Ordering::Relaxed),
872 flusher_commits: self.flusher_commits.load(Ordering::Relaxed),
873 waiter_commits: self.waiter_commits.load(Ordering::Relaxed),
874 commit_phase_a_us_total: self.commit_phase_a_us_total.load(Ordering::Relaxed),
875 commit_phase_b_us_total: self.commit_phase_b_us_total.load(Ordering::Relaxed),
876 commit_phase_c1_us_total: self.commit_phase_c1_us_total.load(Ordering::Relaxed),
877 commit_phase_c2_us_total: self.commit_phase_c2_us_total.load(Ordering::Relaxed),
878 commit_phase_count: self.commit_phase_count.load(Ordering::Relaxed),
879 hist_consolidator_lock_wait: self.hist_consolidator_lock_wait.percentiles(),
881 hist_arrival_wait: self.hist_arrival_wait.percentiles(),
882 hist_wal_backend_lock_wait: self.hist_wal_backend_lock_wait.percentiles(),
883 hist_wal_append: self.hist_wal_append.percentiles(),
884 hist_exclusive_lock: self.hist_exclusive_lock.percentiles(),
885 hist_waiter_epoch_wait: self.hist_waiter_epoch_wait.percentiles(),
886 hist_phase_b: self.hist_phase_b.percentiles(),
887 hist_wal_sync: self.hist_wal_sync.percentiles(),
888 hist_full_commit: self.hist_full_commit.percentiles(),
889 wake_reasons: self.wake_reasons.snapshot(),
890 }
891 }
892
893 pub fn reset(&self) {
895 self.groups_flushed.store(0, Ordering::Relaxed);
896 self.frames_consolidated.store(0, Ordering::Relaxed);
897 self.transactions_batched.store(0, Ordering::Relaxed);
898 self.fsyncs_total.store(0, Ordering::Relaxed);
899 self.flush_duration_us_total.store(0, Ordering::Relaxed);
900 self.wait_duration_us_total.store(0, Ordering::Relaxed);
901 self.max_group_size_observed.store(0, Ordering::Relaxed);
902 self.busy_retries.store(0, Ordering::Relaxed);
903 self.prepare_us_total.store(0, Ordering::Relaxed);
905 self.batch_build_us_total.store(0, Ordering::Relaxed);
906 self.conflict_snapshot_us_total.store(0, Ordering::Relaxed);
907 self.lane_prepare_us_total.store(0, Ordering::Relaxed);
908 self.consolidator_lock_wait_us_total
909 .store(0, Ordering::Relaxed);
910 self.consolidator_flushing_wait_us_total
911 .store(0, Ordering::Relaxed);
912 self.flusher_arrival_wait_us_total
913 .store(0, Ordering::Relaxed);
914 self.inner_lock_wait_us_total.store(0, Ordering::Relaxed);
915 self.exclusive_lock_us_total.store(0, Ordering::Relaxed);
916 self.wal_append_us_total.store(0, Ordering::Relaxed);
917 self.flush_frame_prep_us_total.store(0, Ordering::Relaxed);
918 self.append_conflict_check_us_total
919 .store(0, Ordering::Relaxed);
920 self.append_frames_us_total.store(0, Ordering::Relaxed);
921 self.wal_sync_us_total.store(0, Ordering::Relaxed);
922 self.waiter_epoch_wait_us_total.store(0, Ordering::Relaxed);
923 self.flusher_commits.store(0, Ordering::Relaxed);
924 self.waiter_commits.store(0, Ordering::Relaxed);
925 self.commit_phase_a_us_total.store(0, Ordering::Relaxed);
926 self.commit_phase_b_us_total.store(0, Ordering::Relaxed);
927 self.commit_phase_c1_us_total.store(0, Ordering::Relaxed);
928 self.commit_phase_c2_us_total.store(0, Ordering::Relaxed);
929 self.commit_phase_count.store(0, Ordering::Relaxed);
930 self.hist_consolidator_lock_wait.reset();
932 self.hist_arrival_wait.reset();
933 self.hist_wal_backend_lock_wait.reset();
934 self.hist_wal_append.reset();
935 self.hist_exclusive_lock.reset();
936 self.hist_waiter_epoch_wait.reset();
937 self.hist_phase_b.reset();
938 self.hist_wal_sync.reset();
939 self.hist_full_commit.reset();
940 self.wake_reasons.reset();
941 }
942}
943
944impl Default for ConsolidationMetrics {
945 fn default() -> Self {
946 Self::new()
947 }
948}
949
950#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
952pub struct ConsolidationMetricsSnapshot {
953 pub groups_flushed: u64,
954 pub frames_consolidated: u64,
955 pub transactions_batched: u64,
956 pub fsyncs_total: u64,
957 pub flush_duration_us_total: u64,
958 pub wait_duration_us_total: u64,
959 pub max_group_size_observed: u64,
960 pub busy_retries: u64,
961 pub prepare_us_total: u64,
963 pub batch_build_us_total: u64,
964 pub conflict_snapshot_us_total: u64,
965 pub lane_prepare_us_total: u64,
966 pub consolidator_lock_wait_us_total: u64,
967 pub consolidator_flushing_wait_us_total: u64,
968 pub flusher_arrival_wait_us_total: u64,
969 pub inner_lock_wait_us_total: u64,
970 pub exclusive_lock_us_total: u64,
971 pub wal_append_us_total: u64,
972 pub flush_frame_prep_us_total: u64,
973 pub append_conflict_check_us_total: u64,
974 pub append_frames_us_total: u64,
975 pub wal_sync_us_total: u64,
976 pub waiter_epoch_wait_us_total: u64,
977 pub flusher_commits: u64,
978 pub waiter_commits: u64,
979 pub commit_phase_a_us_total: u64,
981 pub commit_phase_b_us_total: u64,
982 pub commit_phase_c1_us_total: u64,
983 pub commit_phase_c2_us_total: u64,
984 pub commit_phase_count: u64,
985 pub hist_consolidator_lock_wait: PhasePercentiles,
987 pub hist_arrival_wait: PhasePercentiles,
988 pub hist_wal_backend_lock_wait: PhasePercentiles,
989 pub hist_wal_append: PhasePercentiles,
990 pub hist_exclusive_lock: PhasePercentiles,
991 pub hist_waiter_epoch_wait: PhasePercentiles,
992 pub hist_phase_b: PhasePercentiles,
993 pub hist_wal_sync: PhasePercentiles,
994 pub hist_full_commit: PhasePercentiles,
995 pub wake_reasons: WakeReasonSnapshot,
997}
998
999impl ConsolidationMetricsSnapshot {
1000 #[must_use]
1002 pub fn avg_group_size(&self) -> u64 {
1003 self.frames_consolidated
1004 .checked_div(self.groups_flushed)
1005 .unwrap_or(0)
1006 }
1007
1008 #[must_use]
1010 pub fn avg_transactions_per_group(&self) -> u64 {
1011 self.transactions_batched
1012 .checked_div(self.groups_flushed)
1013 .unwrap_or(0)
1014 }
1015
1016 #[must_use]
1018 pub fn avg_flush_duration_us(&self) -> u64 {
1019 self.flush_duration_us_total
1020 .checked_div(self.groups_flushed)
1021 .unwrap_or(0)
1022 }
1023
1024 #[must_use]
1029 pub fn fsync_reduction_ratio(&self) -> u64 {
1030 self.transactions_batched
1031 .checked_div(self.fsyncs_total)
1032 .unwrap_or(0)
1033 }
1034
1035 #[must_use]
1037 pub fn total_commits(&self) -> u64 {
1038 self.flusher_commits.saturating_add(self.waiter_commits)
1039 }
1040
1041 #[must_use]
1043 pub fn avg_prepare_us(&self) -> u64 {
1044 self.prepare_us_total
1045 .checked_div(self.total_commits())
1046 .unwrap_or(0)
1047 }
1048
1049 #[must_use]
1051 pub fn avg_consolidator_lock_wait_us(&self) -> u64 {
1052 self.consolidator_lock_wait_us_total
1053 .checked_div(self.total_commits())
1054 .unwrap_or(0)
1055 }
1056
1057 #[must_use]
1059 pub fn avg_wal_io_us(&self) -> u64 {
1060 self.wal_append_us_total
1061 .saturating_add(self.wal_sync_us_total)
1062 .checked_div(self.flusher_commits)
1063 .unwrap_or(0)
1064 }
1065
1066 #[must_use]
1068 pub fn avg_waiter_wait_us(&self) -> u64 {
1069 self.waiter_epoch_wait_us_total
1070 .checked_div(self.waiter_commits)
1071 .unwrap_or(0)
1072 }
1073
1074 #[must_use]
1080 pub fn flusher_lock_wait_us_total(&self) -> u64 {
1081 self.inner_lock_wait_us_total
1082 .saturating_add(self.exclusive_lock_us_total)
1083 .saturating_add(self.consolidator_flushing_wait_us_total)
1084 }
1085
1086 #[must_use]
1089 pub fn wal_service_us_total(&self) -> u64 {
1090 self.wal_append_us_total
1091 .saturating_add(self.wal_sync_us_total)
1092 }
1093
1094 #[must_use]
1098 #[allow(clippy::cast_precision_loss)]
1099 pub fn flusher_lock_wait_fraction(&self) -> f64 {
1100 let lock = self.flusher_lock_wait_us_total();
1101 let service = self.wal_service_us_total();
1102 let total = lock.saturating_add(service);
1103 if total == 0 {
1104 return 0.0;
1105 }
1106 lock as f64 / total as f64
1107 }
1108
1109 #[must_use]
1111 pub fn is_lock_topology_limited(&self) -> bool {
1112 self.flusher_lock_wait_us_total() > self.wal_service_us_total()
1113 }
1114
1115 #[must_use]
1117 pub fn phase_timing_report(&self) -> String {
1118 let total = self.total_commits();
1119 if total == 0 {
1120 return "no commits".to_string();
1121 }
1122
1123 let avg_prepare = self.avg_prepare_us();
1125 let avg_consol_lock = self.avg_consolidator_lock_wait_us();
1126 let avg_flushing_wait = self
1127 .consolidator_flushing_wait_us_total
1128 .checked_div(total)
1129 .unwrap_or(0);
1130
1131 let avg_arrival_wait = self
1133 .flusher_arrival_wait_us_total
1134 .checked_div(self.flusher_commits)
1135 .unwrap_or(0);
1136 let avg_inner_lock = self
1137 .inner_lock_wait_us_total
1138 .checked_div(self.flusher_commits)
1139 .unwrap_or(0);
1140 let avg_excl_lock = self
1141 .exclusive_lock_us_total
1142 .checked_div(self.flusher_commits)
1143 .unwrap_or(0);
1144 let avg_append = self
1145 .wal_append_us_total
1146 .checked_div(self.flusher_commits)
1147 .unwrap_or(0);
1148 let avg_sync = self
1149 .wal_sync_us_total
1150 .checked_div(self.flusher_commits)
1151 .unwrap_or(0);
1152
1153 let avg_epoch_wait = self.avg_waiter_wait_us();
1155
1156 format!(
1157 "commits: {} (flusher={}, waiter={})\n\
1158 per-commit avg:\n\
1159 ├─ prepare: {}µs\n\
1160 ├─ consolidator_lock_wait: {}µs\n\
1161 ├─ flushing_wait: {}µs\n\
1162 flusher path ({} commits):\n\
1163 ├─ arrival_wait: {}µs\n\
1164 ├─ inner_lock_wait: {}µs\n\
1165 ├─ exclusive_lock: {}µs\n\
1166 ├─ wal_append: {}µs\n\
1167 └─ wal_sync: {}µs (total WAL I/O: {}µs)\n\
1168 waiter path ({} commits):\n\
1169 └─ epoch_wait: {}µs\n\
1170 full commit path ({} commits):\n\
1171 ├─ phase_A (prepare+inner.lock): {}µs\n\
1172 ├─ phase_B (group_commit): {}µs\n\
1173 ├─ phase_C1 (post-commit+inner.lock): {}µs\n\
1174 └─ phase_C2 (publish): {}µs",
1175 total,
1176 self.flusher_commits,
1177 self.waiter_commits,
1178 avg_prepare,
1179 avg_consol_lock,
1180 avg_flushing_wait,
1181 self.flusher_commits,
1182 avg_arrival_wait,
1183 avg_inner_lock,
1184 avg_excl_lock,
1185 avg_append,
1186 avg_sync,
1187 avg_append + avg_sync,
1188 self.waiter_commits,
1189 avg_epoch_wait,
1190 self.commit_phase_count,
1191 self.commit_phase_a_us_total
1192 .checked_div(self.commit_phase_count)
1193 .unwrap_or(0),
1194 self.commit_phase_b_us_total
1195 .checked_div(self.commit_phase_count)
1196 .unwrap_or(0),
1197 self.commit_phase_c1_us_total
1198 .checked_div(self.commit_phase_count)
1199 .unwrap_or(0),
1200 self.commit_phase_c2_us_total
1201 .checked_div(self.commit_phase_count)
1202 .unwrap_or(0),
1203 )
1204 }
1205}
1206
1207impl std::fmt::Display for ConsolidationMetricsSnapshot {
1208 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
1209 write!(
1210 f,
1211 "groups={} frames={} txns={} fsyncs={} avg_group={} \
1212 avg_flush_us={} max_group={} busy_retries={} reduction={}x",
1213 self.groups_flushed,
1214 self.frames_consolidated,
1215 self.transactions_batched,
1216 self.fsyncs_total,
1217 self.avg_group_size(),
1218 self.avg_flush_duration_us(),
1219 self.max_group_size_observed,
1220 self.busy_retries,
1221 self.fsync_reduction_ratio(),
1222 )
1223 }
1224}
1225
1226pub static GLOBAL_CONSOLIDATION_METRICS: LazyLock<ConsolidationMetrics> =
1228 LazyLock::new(ConsolidationMetrics::new);
1229
1230#[cfg(test)]
1231pub(crate) static GLOBAL_CONSOLIDATION_METRICS_TEST_LOCK: LazyLock<std::sync::Mutex<()>> =
1232 LazyLock::new(|| std::sync::Mutex::new(()));
1233
1234#[derive(Debug)]
1245pub struct GroupCommitConsolidator {
1246 phase: ConsolidationPhase,
1248 pending_batches: VecDeque<TransactionFrameBatch>,
1250 pending_frame_count: usize,
1252 config: GroupCommitConfig,
1254 filling_started: Option<Instant>,
1256 epoch: u64,
1258 completed_epoch: u64,
1260 next_epoch_batches: VecDeque<TransactionFrameBatch>,
1264 next_epoch_frame_count: usize,
1266 promoted_epoch_flusher_vacant: bool,
1269}
1270
1271impl GroupCommitConsolidator {
1272 #[must_use]
1274 pub fn new(config: GroupCommitConfig) -> Self {
1275 let config = config.validated();
1276 Self {
1277 phase: ConsolidationPhase::Filling,
1278 pending_batches: VecDeque::new(),
1279 pending_frame_count: 0,
1280 config,
1281 filling_started: None,
1282 epoch: 0,
1283 completed_epoch: 0,
1284 next_epoch_batches: VecDeque::new(),
1285 next_epoch_frame_count: 0,
1286 promoted_epoch_flusher_vacant: false,
1287 }
1288 }
1289
1290 #[must_use]
1292 pub const fn phase(&self) -> ConsolidationPhase {
1293 self.phase
1294 }
1295
1296 #[must_use]
1298 pub const fn epoch(&self) -> u64 {
1299 self.epoch
1300 }
1301
1302 #[must_use]
1304 pub const fn max_group_delay(&self) -> Duration {
1305 self.config.max_group_delay
1306 }
1307
1308 #[must_use]
1310 pub const fn pending_frame_count(&self) -> usize {
1311 self.pending_frame_count
1312 }
1313
1314 #[must_use]
1316 pub fn pending_batch_count(&self) -> usize {
1317 self.pending_batches.len()
1318 }
1319
1320 pub fn submit_batch(&mut self, batch: TransactionFrameBatch) -> Result<SubmitReceipt> {
1329 if self.phase == ConsolidationPhase::Flushing {
1334 self.next_epoch_frame_count += batch.frame_count();
1335 self.next_epoch_batches.push_back(batch);
1336
1337 trace!(
1338 target: "fsqlite_wal::group_commit",
1339 epoch = self.epoch,
1340 next_epoch_frames = self.next_epoch_frame_count,
1341 next_epoch_batches = self.next_epoch_batches.len(),
1342 "batch pipelined for next epoch (submitted during FLUSHING)"
1343 );
1344
1345 return Ok(SubmitReceipt {
1348 outcome: SubmitOutcome::Waiter,
1349 target_epoch: self.epoch.saturating_add(1),
1350 });
1351 }
1352
1353 if self.phase == ConsolidationPhase::Complete {
1355 self.transition_to_filling();
1356 }
1357
1358 let is_first = self.pending_batches.is_empty();
1359
1360 if is_first {
1361 self.filling_started = Some(Instant::now());
1362 self.promoted_epoch_flusher_vacant = false;
1363 }
1364
1365 self.pending_frame_count += batch.frame_count();
1366 self.pending_batches.push_back(batch);
1367
1368 let outcome = if is_first {
1369 SubmitOutcome::Flusher
1370 } else {
1371 SubmitOutcome::Waiter
1372 };
1373
1374 trace!(
1375 target: "fsqlite_wal::group_commit",
1376 epoch = self.epoch,
1377 pending_frames = self.pending_frame_count,
1378 pending_batches = self.pending_batches.len(),
1379 outcome = ?outcome,
1380 "batch submitted"
1381 );
1382
1383 Ok(SubmitReceipt {
1384 outcome,
1385 target_epoch: self.epoch.saturating_add(1),
1386 })
1387 }
1388
1389 #[must_use]
1395 pub fn should_flush_now(&self) -> bool {
1396 if self.pending_frame_count >= self.config.max_group_size {
1397 return true;
1398 }
1399 if let Some(started) = self.filling_started
1400 && started.elapsed() >= self.config.max_group_delay
1401 {
1402 return true;
1403 }
1404 false
1405 }
1406
1407 #[must_use]
1409 pub fn time_until_flush(&self) -> Duration {
1410 if self.pending_frame_count >= self.config.max_group_size {
1411 return Duration::ZERO;
1412 }
1413 self.filling_started
1414 .map_or(self.config.max_group_delay, |started| {
1415 self.config
1416 .max_group_delay
1417 .saturating_sub(started.elapsed())
1418 })
1419 }
1420
1421 #[must_use]
1423 pub fn fill_age(&self) -> Duration {
1424 self.filling_started
1425 .map_or(Duration::ZERO, |started| started.elapsed())
1426 }
1427
1428 pub fn begin_flush(&mut self) -> Result<Vec<TransactionFrameBatch>> {
1437 if self.phase != ConsolidationPhase::Filling {
1438 return Err(FrankenError::Internal(format!(
1439 "begin_flush called in {:?} phase, expected Filling",
1440 self.phase
1441 )));
1442 }
1443
1444 self.phase = ConsolidationPhase::Flushing;
1445 self.promoted_epoch_flusher_vacant = false;
1446 self.epoch += 1;
1447
1448 let batches: Vec<_> = self.pending_batches.drain(..).collect();
1449 let frame_count = self.pending_frame_count;
1450 self.pending_frame_count = 0;
1451
1452 debug!(
1453 target: "fsqlite_wal::group_commit",
1454 epoch = self.epoch,
1455 batches = batches.len(),
1456 frames = frame_count,
1457 "begin_flush: FILLING → FLUSHING"
1458 );
1459
1460 Ok(batches)
1461 }
1462
1463 pub fn complete_flush(&mut self) -> Result<bool> {
1473 if self.phase != ConsolidationPhase::Flushing {
1474 return Err(FrankenError::Internal(format!(
1475 "complete_flush called in {:?} phase, expected Flushing",
1476 self.phase
1477 )));
1478 }
1479
1480 self.completed_epoch = self.epoch;
1481 self.filling_started = None;
1482
1483 if self.next_epoch_batches.is_empty() {
1489 self.phase = ConsolidationPhase::Complete;
1490 self.promoted_epoch_flusher_vacant = false;
1491 debug!(
1492 target: "fsqlite_wal::group_commit",
1493 epoch = self.epoch,
1494 "complete_flush: FLUSHING → COMPLETE"
1495 );
1496 Ok(false)
1497 } else {
1498 let promoted_count = self.next_epoch_batches.len();
1499 let promoted_frames = self.next_epoch_frame_count;
1500 self.pending_batches = std::mem::take(&mut self.next_epoch_batches);
1501 self.pending_frame_count = self.next_epoch_frame_count;
1502 self.next_epoch_frame_count = 0;
1503 self.phase = ConsolidationPhase::Filling;
1504 self.filling_started = Some(Instant::now());
1505 self.promoted_epoch_flusher_vacant = true;
1506
1507 debug!(
1508 target: "fsqlite_wal::group_commit",
1509 epoch = self.epoch,
1510 promoted_batches = promoted_count,
1511 promoted_frames = promoted_frames,
1512 "complete_flush: FLUSHING → FILLING (epoch pipelining)"
1513 );
1514 Ok(true) }
1516 }
1517
1518 #[must_use]
1520 pub fn has_pipelined_batches(&self) -> bool {
1521 !self.next_epoch_batches.is_empty()
1522 }
1523
1524 #[must_use]
1527 pub const fn has_flusher_vacancy(&self) -> bool {
1528 self.promoted_epoch_flusher_vacant
1529 }
1530
1531 #[must_use]
1536 pub fn claim_flusher_vacancy(&mut self) -> bool {
1537 if self.phase == ConsolidationPhase::Filling
1538 && self.promoted_epoch_flusher_vacant
1539 && !self.pending_batches.is_empty()
1540 {
1541 self.promoted_epoch_flusher_vacant = false;
1542 return true;
1543 }
1544 false
1545 }
1546
1547 pub fn abort_filling(&mut self, expected_epoch: u64) -> Result<u64> {
1559 if self.phase != ConsolidationPhase::Filling || self.pending_batches.is_empty() {
1560 return Err(FrankenError::Internal(format!(
1561 "abort_filling called in {:?} phase with {} pending batches",
1562 self.phase,
1563 self.pending_batches.len()
1564 )));
1565 }
1566
1567 let failed_epoch = self
1568 .epoch
1569 .checked_add(1)
1570 .ok_or(FrankenError::DatabaseFull)?;
1571 if failed_epoch != expected_epoch {
1572 return Err(FrankenError::Internal(format!(
1573 "abort_filling expected epoch {expected_epoch}, but active filling epoch targets {failed_epoch}"
1574 )));
1575 }
1576 self.epoch = failed_epoch;
1577 self.pending_batches.clear();
1578 self.pending_frame_count = 0;
1579 self.filling_started = None;
1580 self.phase = ConsolidationPhase::Complete;
1581 self.promoted_epoch_flusher_vacant = false;
1582
1583 debug!(
1584 target: "fsqlite_wal::group_commit",
1585 epoch = failed_epoch,
1586 "abort_filling: FILLING → COMPLETE"
1587 );
1588 Ok(failed_epoch)
1589 }
1590
1591 pub fn abort_flush(&mut self) -> Result<()> {
1600 if self.phase != ConsolidationPhase::Flushing {
1601 return Err(FrankenError::Internal(format!(
1602 "abort_flush called in {:?} phase, expected Flushing",
1603 self.phase
1604 )));
1605 }
1606
1607 if self.next_epoch_batches.is_empty() {
1611 self.phase = ConsolidationPhase::Complete;
1612 self.filling_started = None;
1613 self.promoted_epoch_flusher_vacant = false;
1614 } else {
1615 self.pending_batches = std::mem::take(&mut self.next_epoch_batches);
1616 self.pending_frame_count = self.next_epoch_frame_count;
1617 self.next_epoch_frame_count = 0;
1618 self.phase = ConsolidationPhase::Filling;
1619 self.filling_started = Some(Instant::now());
1620 self.promoted_epoch_flusher_vacant = true;
1621 }
1623
1624 debug!(
1625 target: "fsqlite_wal::group_commit",
1626 epoch = self.epoch,
1627 "abort_flush: FLUSHING → {:?}",
1628 self.phase
1629 );
1630
1631 Ok(())
1632 }
1633
1634 fn transition_to_filling(&mut self) {
1636 self.phase = ConsolidationPhase::Filling;
1637 self.filling_started = None;
1638 self.promoted_epoch_flusher_vacant = false;
1639 trace!(
1640 target: "fsqlite_wal::group_commit",
1641 epoch = self.epoch,
1642 "COMPLETE → FILLING"
1643 );
1644 }
1645
1646 #[must_use]
1648 pub const fn completed_epoch(&self) -> u64 {
1649 self.completed_epoch
1650 }
1651}
1652
1653pub async fn write_consolidated_frames<F: VfsFile>(
1668 cx: &Cx,
1669 wal: &mut WalFile<F>,
1670 batches: &[TransactionFrameBatch],
1671) -> Result<usize> {
1672 let frame_size = wal.frame_size();
1673 let total_frames: usize = batches.iter().map(TransactionFrameBatch::frame_count).sum();
1674 if total_frames == 0 {
1675 return Ok(0);
1676 }
1677
1678 let total_bytes = total_frames
1679 .checked_mul(frame_size)
1680 .ok_or_else(|| FrankenError::Internal("frame batch size overflow".to_owned()))?;
1681 let frame_refs = batches.iter().flat_map(|batch| {
1682 batch.frames.iter().map(|frame| WalAppendFrameRef {
1683 page_number: frame.page_number,
1684 page_data: &frame.page_data,
1685 db_size_if_commit: frame.db_size_if_commit,
1686 })
1687 });
1688
1689 let span = tracing::info_span!(
1690 target: "fsqlite_wal::group_commit",
1691 "consolidated_write",
1692 total_frames,
1693 total_bytes,
1694 batches = batches.len(),
1695 );
1696 let _guard = span.enter();
1697
1698 wal.append_frame_iter(cx, total_frames, frame_refs).await?;
1699 wal.durable_sync(cx, SyncKind::FullDurable)?;
1700 let bytes_written = u64::try_from(total_bytes).unwrap_or(u64::MAX);
1701
1702 info!(
1703 target: "fsqlite_wal::group_commit",
1704 frames_written = total_frames,
1705 bytes_written,
1706 batches = batches.len(),
1707 "consolidated write + fsync complete"
1708 );
1709
1710 Ok(total_frames)
1711}
1712
1713#[cfg(test)]
1718mod tests {
1719 use fsqlite_types::flags::VfsOpenFlags;
1720 use fsqlite_vfs::MemoryVfs;
1721 use fsqlite_vfs::traits::Vfs;
1722
1723 use super::*;
1724 use crate::checksum::WalSalts;
1725 use crate::test_support::FutureResultTestExt as _;
1726
1727 const PAGE_SIZE: u32 = 4096;
1728
1729 fn test_cx() -> Cx {
1730 Cx::default()
1731 }
1732
1733 fn test_salts() -> WalSalts {
1734 WalSalts {
1735 salt1: 0xDEAD_BEEF,
1736 salt2: 0xCAFE_BABE,
1737 }
1738 }
1739
1740 fn sample_page(seed: u8) -> Vec<u8> {
1741 let page_size = usize::try_from(PAGE_SIZE).expect("page size fits usize");
1742 let mut page = vec![0u8; page_size];
1743 for (i, byte) in page.iter_mut().enumerate() {
1744 let reduced = u8::try_from(i % 251).expect("modulo fits u8");
1745 *byte = reduced ^ seed;
1746 }
1747 page
1748 }
1749
1750 fn open_wal_file(vfs: &MemoryVfs, cx: &Cx) -> <MemoryVfs as Vfs>::File {
1751 let flags = VfsOpenFlags::READWRITE | VfsOpenFlags::CREATE | VfsOpenFlags::WAL;
1752 let (file, _) = vfs
1753 .open(cx, Some(std::path::Path::new("test.db-wal")), flags)
1754 .expect("open WAL file");
1755 file
1756 }
1757
1758 struct ResetGlobalConsolidationMetrics;
1759
1760 impl Drop for ResetGlobalConsolidationMetrics {
1761 fn drop(&mut self) {
1762 GLOBAL_CONSOLIDATION_METRICS.reset();
1763 }
1764 }
1765
1766 fn with_global_consolidation_metrics<T>(body: impl FnOnce() -> T) -> T {
1767 let _guard = GLOBAL_CONSOLIDATION_METRICS_TEST_LOCK
1768 .lock()
1769 .expect("global consolidation metrics test lock poisoned");
1770 let _reset = ResetGlobalConsolidationMetrics;
1771 GLOBAL_CONSOLIDATION_METRICS.reset();
1772 body()
1773 }
1774
1775 #[test]
1778 fn test_consolidator_initial_state() {
1779 let c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1780 assert_eq!(c.phase(), ConsolidationPhase::Filling);
1781 assert_eq!(c.epoch(), 0);
1782 assert_eq!(c.pending_frame_count(), 0);
1783 assert_eq!(c.pending_batch_count(), 0);
1784 }
1785
1786 #[test]
1787 fn test_consolidator_first_writer_becomes_flusher() {
1788 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1789 let batch = TransactionFrameBatch::new(vec![FrameSubmission {
1790 page_number: 1,
1791 page_data: sample_page(0x01),
1792 db_size_if_commit: 0,
1793 }]);
1794 let receipt = c.submit_batch(batch).unwrap();
1795 assert_eq!(receipt.outcome, SubmitOutcome::Flusher);
1796 assert_eq!(receipt.target_epoch, 1);
1797 assert_eq!(c.pending_frame_count(), 1);
1798 assert_eq!(c.pending_batch_count(), 1);
1799 }
1800
1801 #[test]
1802 fn test_consolidator_second_writer_becomes_waiter() {
1803 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1804
1805 let batch1 = TransactionFrameBatch::new(vec![FrameSubmission {
1806 page_number: 1,
1807 page_data: sample_page(0x01),
1808 db_size_if_commit: 0,
1809 }]);
1810 assert_eq!(
1811 c.submit_batch(batch1).unwrap().outcome,
1812 SubmitOutcome::Flusher
1813 );
1814
1815 let batch2 = TransactionFrameBatch::new(vec![FrameSubmission {
1816 page_number: 2,
1817 page_data: sample_page(0x02),
1818 db_size_if_commit: 0,
1819 }]);
1820 assert_eq!(
1821 c.submit_batch(batch2).unwrap().outcome,
1822 SubmitOutcome::Waiter
1823 );
1824 assert_eq!(c.pending_frame_count(), 2);
1825 assert_eq!(c.pending_batch_count(), 2);
1826 }
1827
1828 #[test]
1829 fn test_consolidator_cancelled_filling_epoch_is_consumed_atomically() {
1830 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1831 for page_number in 1..=2 {
1832 let receipt = c
1833 .submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
1834 page_number,
1835 page_data: sample_page(u8::try_from(page_number).unwrap()),
1836 db_size_if_commit: page_number,
1837 }]))
1838 .unwrap();
1839 assert_eq!(
1840 receipt.target_epoch, 1,
1841 "every member of the filling group must share the failed epoch"
1842 );
1843 }
1844
1845 assert_eq!(c.abort_filling(1).unwrap(), 1);
1846 assert_eq!(c.phase(), ConsolidationPhase::Complete);
1847 assert_eq!(c.epoch(), 1);
1848 assert_eq!(c.pending_batch_count(), 0);
1849 assert_eq!(c.pending_frame_count(), 0);
1850
1851 let replacement = c
1852 .submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
1853 page_number: 3,
1854 page_data: sample_page(0x03),
1855 db_size_if_commit: 3,
1856 }]))
1857 .unwrap();
1858 assert_eq!(replacement.outcome, SubmitOutcome::Flusher);
1859 assert_eq!(
1860 replacement.target_epoch, 2,
1861 "a retained failure for epoch 1 must not poison the next group"
1862 );
1863 }
1864
1865 #[test]
1866 fn test_consolidator_cancelled_filling_obligation_cannot_consume_newer_epoch() {
1867 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1868 let receipt = c
1869 .submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
1870 page_number: 1,
1871 page_data: sample_page(0x01),
1872 db_size_if_commit: 1,
1873 }]))
1874 .unwrap();
1875 assert_eq!(receipt.target_epoch, 1);
1876
1877 let error = c
1878 .abort_filling(2)
1879 .expect_err("a stale obligation must not consume the active filling epoch");
1880 assert!(
1881 error.to_string().contains("expected epoch 2"),
1882 "unexpected error: {error}"
1883 );
1884 assert_eq!(c.phase(), ConsolidationPhase::Filling);
1885 assert_eq!(c.epoch(), 0);
1886 assert_eq!(c.pending_batch_count(), 1);
1887 assert_eq!(c.pending_frame_count(), 1);
1888 }
1889
1890 #[test]
1891 fn test_consolidator_filling_flushing_complete_cycle() {
1892 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1893
1894 for i in 0..3u8 {
1896 let batch = TransactionFrameBatch::new(vec![FrameSubmission {
1897 page_number: u32::from(i) + 1,
1898 page_data: sample_page(i),
1899 db_size_if_commit: if i == 2 { 3 } else { 0 },
1900 }]);
1901 c.submit_batch(batch).unwrap();
1902 }
1903 assert_eq!(c.phase(), ConsolidationPhase::Filling);
1904 assert_eq!(c.pending_frame_count(), 3);
1905
1906 let batches = c.begin_flush().unwrap();
1908 assert_eq!(c.phase(), ConsolidationPhase::Flushing);
1909 assert_eq!(batches.len(), 3);
1910 assert_eq!(c.epoch(), 1);
1911 assert_eq!(c.pending_frame_count(), 0);
1912
1913 let batch_extra = TransactionFrameBatch::new(vec![FrameSubmission {
1915 page_number: 10,
1916 page_data: sample_page(0x10),
1917 db_size_if_commit: 0,
1918 }]);
1919 let receipt = c.submit_batch(batch_extra).unwrap();
1920 assert_eq!(receipt.outcome, SubmitOutcome::Waiter);
1921 assert_eq!(
1922 receipt.target_epoch, 2,
1923 "pipelined submissions belong to the promoted next epoch"
1924 );
1925
1926 let promoted = c.complete_flush().unwrap();
1928 assert!(promoted);
1929 assert_eq!(c.phase(), ConsolidationPhase::Filling);
1930 assert_eq!(c.completed_epoch(), 1);
1931 assert_eq!(c.pending_batch_count(), 1);
1932 assert!(c.has_flusher_vacancy());
1933
1934 let batches = c.begin_flush().unwrap();
1936 assert_eq!(c.phase(), ConsolidationPhase::Flushing);
1937 assert_eq!(c.epoch(), 2);
1938 assert_eq!(batches.len(), 1);
1939 }
1940
1941 #[test]
1942 fn test_consolidator_auto_transitions_complete_to_filling() {
1943 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
1944
1945 let batch1 = TransactionFrameBatch::new(vec![FrameSubmission {
1947 page_number: 1,
1948 page_data: sample_page(0x01),
1949 db_size_if_commit: 1,
1950 }]);
1951 c.submit_batch(batch1).unwrap();
1952 c.begin_flush().unwrap();
1953 c.complete_flush().unwrap();
1954 assert_eq!(c.phase(), ConsolidationPhase::Complete);
1955
1956 let batch2 = TransactionFrameBatch::new(vec![FrameSubmission {
1958 page_number: 2,
1959 page_data: sample_page(0x02),
1960 db_size_if_commit: 2,
1961 }]);
1962 let receipt = c.submit_batch(batch2).unwrap();
1963 assert_eq!(receipt.outcome, SubmitOutcome::Flusher);
1964 assert_eq!(receipt.target_epoch, 2);
1965 assert_eq!(c.phase(), ConsolidationPhase::Filling);
1966 }
1967
1968 #[test]
1969 fn test_consolidator_should_flush_on_max_group_size() {
1970 let config = GroupCommitConfig {
1971 max_group_size: 3,
1972 ..GroupCommitConfig::default()
1973 };
1974 let mut c = GroupCommitConsolidator::new(config);
1975
1976 for i in 0..2u8 {
1978 c.submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
1979 page_number: u32::from(i) + 1,
1980 page_data: sample_page(i),
1981 db_size_if_commit: 0,
1982 }]))
1983 .unwrap();
1984 }
1985 assert!(!c.should_flush_now());
1986
1987 c.submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
1989 page_number: 3,
1990 page_data: sample_page(2),
1991 db_size_if_commit: 3,
1992 }]))
1993 .unwrap();
1994 assert!(c.should_flush_now());
1995 }
1996
1997 #[test]
1998 fn test_consolidator_begin_flush_errors_in_wrong_phase() {
1999 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
2000
2001 c.submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
2003 page_number: 1,
2004 page_data: sample_page(0x01),
2005 db_size_if_commit: 1,
2006 }]))
2007 .unwrap();
2008 c.begin_flush().unwrap();
2009
2010 assert!(c.begin_flush().is_err());
2012 }
2013
2014 #[test]
2015 fn test_consolidator_complete_flush_errors_in_wrong_phase() {
2016 let c = &mut GroupCommitConsolidator::new(GroupCommitConfig::default());
2017 assert!(c.complete_flush().is_err());
2019 }
2020
2021 #[test]
2022 fn test_consolidator_abort_flush_releases_epoch_and_allows_next_cycle() {
2023 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
2024
2025 c.submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
2026 page_number: 1,
2027 page_data: sample_page(0x01),
2028 db_size_if_commit: 1,
2029 }]))
2030 .unwrap();
2031 c.begin_flush().unwrap();
2032 c.abort_flush().unwrap();
2033 assert_eq!(c.phase(), ConsolidationPhase::Complete);
2034 assert_eq!(c.completed_epoch(), 0);
2035
2036 let receipt = c
2037 .submit_batch(TransactionFrameBatch::new(vec![FrameSubmission {
2038 page_number: 2,
2039 page_data: sample_page(0x02),
2040 db_size_if_commit: 2,
2041 }]))
2042 .unwrap();
2043 assert_eq!(receipt.outcome, SubmitOutcome::Flusher);
2044 assert_eq!(receipt.target_epoch, 2);
2045 assert_eq!(c.phase(), ConsolidationPhase::Filling);
2046 assert_eq!(c.pending_batch_count(), 1);
2047 assert_eq!(c.epoch(), 1);
2048 }
2049
2050 #[test]
2051 fn test_consolidator_promoted_epoch_exposes_flusher_takeover_claim_if_original_stops() {
2052 let mut c = GroupCommitConsolidator::new(GroupCommitConfig::default());
2053
2054 let batch1 = TransactionFrameBatch::new(vec![FrameSubmission {
2055 page_number: 1,
2056 page_data: sample_page(0x01),
2057 db_size_if_commit: 1,
2058 }]);
2059 assert_eq!(
2060 c.submit_batch(batch1).unwrap().outcome,
2061 SubmitOutcome::Flusher
2062 );
2063
2064 let _flushing_batches = c.begin_flush().unwrap();
2065 assert_eq!(c.epoch(), 1);
2066 assert_eq!(c.phase(), ConsolidationPhase::Flushing);
2067
2068 let pipelined_batch = TransactionFrameBatch::new(vec![FrameSubmission {
2069 page_number: 2,
2070 page_data: sample_page(0x02),
2071 db_size_if_commit: 2,
2072 }]);
2073 let receipt = c.submit_batch(pipelined_batch).unwrap();
2074 assert_eq!(receipt.outcome, SubmitOutcome::Waiter);
2075 assert_eq!(receipt.target_epoch, 2);
2076
2077 let promoted = c.complete_flush().unwrap();
2078 assert!(
2079 promoted,
2080 "pipelined epoch must be promoted back to FILLING for the next flush"
2081 );
2082 assert_eq!(c.phase(), ConsolidationPhase::Filling);
2083 assert_eq!(c.pending_batch_count(), 1);
2084 assert_eq!(c.pending_frame_count(), 1);
2085 assert_eq!(c.epoch(), 1);
2086 assert_eq!(c.completed_epoch(), 1);
2087 assert!(c.has_flusher_vacancy());
2088
2089 let takeover_batch = TransactionFrameBatch::new(vec![FrameSubmission {
2090 page_number: 3,
2091 page_data: sample_page(0x03),
2092 db_size_if_commit: 3,
2093 }]);
2094 let receipt = c.submit_batch(takeover_batch).unwrap();
2095 assert_eq!(
2096 receipt.outcome,
2097 SubmitOutcome::Waiter,
2098 "promoted work stays queued until someone explicitly claims the flusher vacancy"
2099 );
2100 assert_eq!(receipt.target_epoch, 2);
2101 assert!(c.claim_flusher_vacancy());
2102 assert!(!c.has_flusher_vacancy());
2103 assert!(!c.claim_flusher_vacancy());
2104
2105 let takeover_batches = c.begin_flush().unwrap();
2106 assert_eq!(c.phase(), ConsolidationPhase::Flushing);
2107 assert_eq!(c.epoch(), 2);
2108 assert_eq!(takeover_batches.len(), 2);
2109 }
2110
2111 #[test]
2114 fn test_consolidated_write_single_batch() {
2115 let cx = test_cx();
2116 let vfs = MemoryVfs::new();
2117 let file = open_wal_file(&vfs, &cx);
2118 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2119
2120 let batches = vec![TransactionFrameBatch::new(vec![
2121 FrameSubmission {
2122 page_number: 1,
2123 page_data: sample_page(0x01),
2124 db_size_if_commit: 0,
2125 },
2126 FrameSubmission {
2127 page_number: 2,
2128 page_data: sample_page(0x02),
2129 db_size_if_commit: 0,
2130 },
2131 FrameSubmission {
2132 page_number: 3,
2133 page_data: sample_page(0x03),
2134 db_size_if_commit: 3,
2135 },
2136 ])];
2137
2138 let written = write_consolidated_frames(&cx, &mut wal, &batches).expect("write");
2139 assert_eq!(written, 3);
2140 assert_eq!(wal.frame_count(), 3);
2141
2142 for i in 0..3u32 {
2144 let (header, data) = wal
2145 .read_frame(&cx, usize::try_from(i).unwrap())
2146 .expect("read frame");
2147 assert_eq!(header.page_number, i + 1);
2148 let seed = u8::try_from(i + 1).expect("fits");
2149 assert_eq!(data, sample_page(seed));
2150 }
2151
2152 let last_header = wal.read_frame_header(&cx, 2).expect("read header");
2154 assert!(last_header.is_commit());
2155 assert_eq!(last_header.db_size, 3);
2156
2157 wal.close(&cx).expect("close WAL");
2158 }
2159
2160 #[test]
2161 fn test_consolidated_write_multiple_batches() {
2162 let cx = test_cx();
2163 let vfs = MemoryVfs::new();
2164 let file = open_wal_file(&vfs, &cx);
2165 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2166
2167 let batches = vec![
2169 TransactionFrameBatch::new(vec![
2170 FrameSubmission {
2171 page_number: 10,
2172 page_data: sample_page(0x10),
2173 db_size_if_commit: 0,
2174 },
2175 FrameSubmission {
2176 page_number: 11,
2177 page_data: sample_page(0x11),
2178 db_size_if_commit: 11,
2179 },
2180 ]),
2181 TransactionFrameBatch::new(vec![
2182 FrameSubmission {
2183 page_number: 20,
2184 page_data: sample_page(0x20),
2185 db_size_if_commit: 0,
2186 },
2187 FrameSubmission {
2188 page_number: 21,
2189 page_data: sample_page(0x21),
2190 db_size_if_commit: 21,
2191 },
2192 ]),
2193 ];
2194
2195 let written = write_consolidated_frames(&cx, &mut wal, &batches).expect("write");
2196 assert_eq!(written, 4);
2197 assert_eq!(wal.frame_count(), 4);
2198
2199 let expected_pages = [10, 11, 20, 21];
2201 for (i, &expected_page) in expected_pages.iter().enumerate() {
2202 let header = wal.read_frame_header(&cx, i).expect("read header");
2203 assert_eq!(header.page_number, expected_page);
2204 }
2205
2206 wal.close(&cx).expect("close WAL");
2207 }
2208
2209 #[test]
2210 fn test_consolidated_write_preserves_checksum_chain() {
2211 let cx = test_cx();
2212 let vfs = MemoryVfs::new();
2213 let file = open_wal_file(&vfs, &cx);
2214 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2215
2216 wal.append_frame(&cx, 1, &sample_page(0x01), 0)
2218 .expect("append");
2219 wal.append_frame(&cx, 2, &sample_page(0x02), 2)
2220 .expect("append commit");
2221 assert_eq!(wal.frame_count(), 2);
2222 let _checksum_after_2 = wal.running_checksum();
2223
2224 let batches = vec![TransactionFrameBatch::new(vec![
2226 FrameSubmission {
2227 page_number: 3,
2228 page_data: sample_page(0x03),
2229 db_size_if_commit: 0,
2230 },
2231 FrameSubmission {
2232 page_number: 4,
2233 page_data: sample_page(0x04),
2234 db_size_if_commit: 4,
2235 },
2236 ])];
2237
2238 let written = write_consolidated_frames(&cx, &mut wal, &batches).expect("write");
2239 assert_eq!(written, 2);
2240 assert_eq!(wal.frame_count(), 4);
2241
2242 wal.close(&cx).expect("close WAL");
2244 let file2 = open_wal_file(&vfs, &cx);
2245 let wal2 = WalFile::open(&cx, file2).expect("reopen WAL");
2246 assert_eq!(
2247 wal2.frame_count(),
2248 4,
2249 "all 4 frames should be valid on reopen (checksum chain intact)"
2250 );
2251
2252 wal2.close(&cx).expect("close WAL");
2253 }
2254
2255 #[test]
2256 fn test_consolidated_write_empty_batch() {
2257 let cx = test_cx();
2258 let vfs = MemoryVfs::new();
2259 let file = open_wal_file(&vfs, &cx);
2260 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2261
2262 let written = write_consolidated_frames(&cx, &mut wal, &[]).expect("write empty");
2263 assert_eq!(written, 0);
2264 assert_eq!(wal.frame_count(), 0);
2265
2266 wal.close(&cx).expect("close WAL");
2267 }
2268
2269 #[test]
2270 fn test_consolidated_write_page_size_mismatch_rejected() {
2271 let cx = test_cx();
2272 let vfs = MemoryVfs::new();
2273 let file = open_wal_file(&vfs, &cx);
2274 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2275
2276 let batches = vec![TransactionFrameBatch::new(vec![FrameSubmission {
2277 page_number: 1,
2278 page_data: vec![0u8; 100], db_size_if_commit: 0,
2280 }])];
2281
2282 assert!(
2283 write_consolidated_frames(&cx, &mut wal, &batches).is_err(),
2284 "wrong page size should be rejected"
2285 );
2286
2287 wal.close(&cx).expect("close WAL");
2288 }
2289
2290 #[test]
2293 fn test_consolidation_metrics_basic() {
2294 let m = ConsolidationMetrics::new();
2295 m.record_flush(10, 3, 500);
2296 m.record_flush(20, 5, 1000);
2297 m.record_wait(100);
2298 m.record_busy_retry();
2299 m.record_busy_retry();
2300
2301 let snap = m.snapshot();
2302 assert_eq!(snap.groups_flushed, 2);
2303 assert_eq!(snap.frames_consolidated, 30);
2304 assert_eq!(snap.transactions_batched, 8);
2305 assert_eq!(snap.fsyncs_total, 2);
2306 assert_eq!(snap.flush_duration_us_total, 1500);
2307 assert_eq!(snap.wait_duration_us_total, 100);
2308 assert_eq!(snap.max_group_size_observed, 20);
2309 assert_eq!(snap.busy_retries, 2);
2310 assert_eq!(snap.avg_group_size(), 15);
2311 assert_eq!(snap.avg_transactions_per_group(), 4);
2312 assert_eq!(snap.avg_flush_duration_us(), 750);
2313 assert_eq!(snap.fsync_reduction_ratio(), 4);
2314 }
2315
2316 #[test]
2317 fn test_consolidation_metrics_reset() {
2318 let m = ConsolidationMetrics::new();
2319 m.record_flush(10, 3, 500);
2320 m.record_busy_retry();
2321 m.reset();
2322 let snap = m.snapshot();
2323 assert_eq!(snap.groups_flushed, 0);
2324 assert_eq!(snap.frames_consolidated, 0);
2325 assert_eq!(snap.busy_retries, 0);
2326 }
2327
2328 #[test]
2329 fn test_consolidation_metrics_display() {
2330 let m = ConsolidationMetrics::new();
2331 m.record_flush(10, 5, 500);
2332 m.record_busy_retry();
2333 let s = m.snapshot().to_string();
2334 assert!(s.contains("groups=1"));
2335 assert!(s.contains("frames=10"));
2336 assert!(s.contains("txns=5"));
2337 assert!(s.contains("busy_retries=1"));
2338 assert!(s.contains("reduction=5x"));
2339 }
2340
2341 #[test]
2342 fn test_consolidation_metrics_snapshot_serializes_phase_distributions() {
2343 let m = ConsolidationMetrics::new();
2344 m.record_phase_timing(10, 5, 2, true, 20, 3, 8, 50, 30, 0);
2345 m.record_phase_timing(11, 6, 2, false, 0, 0, 0, 0, 0, 100);
2346 m.wake_reasons.notify.fetch_add(1, Ordering::Relaxed);
2347 m.wake_reasons.timeout.fetch_add(2, Ordering::Relaxed);
2348
2349 let encoded =
2350 serde_json::to_value(m.snapshot()).expect("consolidation snapshot should serialize");
2351
2352 assert_eq!(
2353 encoded["hist_wal_append"]["count"].as_u64(),
2354 Some(1),
2355 "flusher histogram should serialize sample counts"
2356 );
2357 assert_eq!(
2358 encoded["hist_waiter_epoch_wait"]["count"].as_u64(),
2359 Some(1),
2360 "waiter histogram should serialize sample counts"
2361 );
2362 assert_eq!(
2363 encoded["wake_reasons"]["notify"].as_u64(),
2364 Some(1),
2365 "wake reasons should serialize nested counters"
2366 );
2367 assert_eq!(
2368 encoded["wake_reasons"]["timeout"].as_u64(),
2369 Some(2),
2370 "wake reasons should preserve all fields"
2371 );
2372 }
2373
2374 #[test]
2375 fn test_phase_histogram_recent_tail_decays_without_snapshot() {
2376 let h = PhaseHistogram::new();
2377 h.record(1_600);
2378 assert_eq!(h.recent_tail_us(), 1_600);
2379
2380 h.record(0);
2381 assert_eq!(
2382 h.recent_tail_us(),
2383 1_500,
2384 "recent tail should decay by one sixteenth per sample"
2385 );
2386
2387 h.record(2_000);
2388 assert_eq!(
2389 h.recent_tail_us(),
2390 2_000,
2391 "new spikes should replace the decayed tail immediately"
2392 );
2393
2394 h.reset();
2395 assert_eq!(h.recent_tail_us(), 0);
2396 }
2397
2398 #[test]
2404 fn test_fsync_reduction_deterministic_proof() {
2405 with_global_consolidation_metrics(|| {
2406 let n = 10_u64;
2407 GLOBAL_CONSOLIDATION_METRICS.record_flush(n * 2, n, 1000);
2408
2409 let snap = GLOBAL_CONSOLIDATION_METRICS.snapshot();
2410 assert_eq!(snap.fsyncs_total, 1);
2411 assert_eq!(snap.transactions_batched, n);
2412 assert_eq!(
2413 snap.fsync_reduction_ratio(),
2414 n,
2415 "10 transactions in 1 fsync = 10x reduction"
2416 );
2417 });
2418 }
2419
2420 #[test]
2423 fn test_config_validated_clamps_zero_group_size() {
2424 let config = GroupCommitConfig {
2425 max_group_size: 0,
2426 ..GroupCommitConfig::default()
2427 };
2428 let validated = config.validated();
2429 assert_eq!(validated.max_group_size, 1);
2430 }
2431
2432 #[test]
2433 fn test_config_validated_clamps_excessive_delay() {
2434 let config = GroupCommitConfig {
2435 max_group_delay: Duration::from_millis(100),
2436 max_group_delay_ceiling: Duration::from_millis(10),
2437 ..GroupCommitConfig::default()
2438 };
2439 let validated = config.validated();
2440 assert_eq!(validated.max_group_delay, Duration::from_millis(10));
2441 }
2442
2443 #[test]
2446 fn test_batch_has_commit_frame() {
2447 let batch_with_commit = TransactionFrameBatch::new(vec![
2448 FrameSubmission {
2449 page_number: 1,
2450 page_data: vec![],
2451 db_size_if_commit: 0,
2452 },
2453 FrameSubmission {
2454 page_number: 2,
2455 page_data: vec![],
2456 db_size_if_commit: 5,
2457 },
2458 ]);
2459 assert!(batch_with_commit.has_commit_frame());
2460
2461 let batch_without = TransactionFrameBatch::new(vec![FrameSubmission {
2462 page_number: 1,
2463 page_data: vec![],
2464 db_size_if_commit: 0,
2465 }]);
2466 assert!(!batch_without.has_commit_frame());
2467 }
2468
2469 #[test]
2472 fn test_full_consolidation_cycle_with_wal_write() {
2473 let cx = test_cx();
2474 let vfs = MemoryVfs::new();
2475 let file = open_wal_file(&vfs, &cx);
2476 let mut wal = WalFile::create(&cx, file, PAGE_SIZE, 0, test_salts()).expect("create WAL");
2477
2478 let mut consolidator = GroupCommitConsolidator::new(GroupCommitConfig {
2479 max_group_size: 10,
2480 ..GroupCommitConfig::default()
2481 });
2482
2483 let batch1 = TransactionFrameBatch::new(vec![
2485 FrameSubmission {
2486 page_number: 1,
2487 page_data: sample_page(0x01),
2488 db_size_if_commit: 0,
2489 },
2490 FrameSubmission {
2491 page_number: 2,
2492 page_data: sample_page(0x02),
2493 db_size_if_commit: 2,
2494 },
2495 ]);
2496 let receipt1 = consolidator.submit_batch(batch1).unwrap();
2497 assert_eq!(receipt1.outcome, SubmitOutcome::Flusher);
2498 assert_eq!(receipt1.target_epoch, 1);
2499
2500 let batch2 = TransactionFrameBatch::new(vec![FrameSubmission {
2501 page_number: 3,
2502 page_data: sample_page(0x03),
2503 db_size_if_commit: 3,
2504 }]);
2505 let receipt2 = consolidator.submit_batch(batch2).unwrap();
2506 assert_eq!(receipt2.outcome, SubmitOutcome::Waiter);
2507 assert_eq!(receipt2.target_epoch, 1);
2508
2509 let batch3 = TransactionFrameBatch::new(vec![
2510 FrameSubmission {
2511 page_number: 4,
2512 page_data: sample_page(0x04),
2513 db_size_if_commit: 0,
2514 },
2515 FrameSubmission {
2516 page_number: 5,
2517 page_data: sample_page(0x05),
2518 db_size_if_commit: 5,
2519 },
2520 ]);
2521 let receipt3 = consolidator.submit_batch(batch3).unwrap();
2522 assert_eq!(receipt3.outcome, SubmitOutcome::Waiter);
2523 assert_eq!(receipt3.target_epoch, 1);
2524
2525 let batches = consolidator.begin_flush().unwrap();
2527 assert_eq!(batches.len(), 3);
2528
2529 let written = write_consolidated_frames(&cx, &mut wal, &batches).expect("write");
2531 assert_eq!(written, 5);
2532
2533 consolidator.complete_flush().unwrap();
2535 assert_eq!(consolidator.phase(), ConsolidationPhase::Complete);
2536
2537 assert_eq!(wal.frame_count(), 5);
2539
2540 wal.close(&cx).expect("close WAL");
2542 let file2 = open_wal_file(&vfs, &cx);
2543 let wal2 = WalFile::open(&cx, file2).expect("reopen WAL");
2544 assert_eq!(wal2.frame_count(), 5, "all frames valid on reopen");
2545 wal2.close(&cx).expect("close WAL");
2546 }
2547
2548 #[test]
2551 fn phase_histogram_empty_returns_zeros() {
2552 let h = PhaseHistogram::new();
2553 let p = h.percentiles();
2554 assert_eq!(p.count, 0);
2555 assert_eq!(p.p50, 0);
2556 assert_eq!(p.p99, 0);
2557 assert_eq!(p.max, 0);
2558 assert_eq!(p.mean_us, 0);
2559 }
2560
2561 #[test]
2562 fn phase_histogram_single_sample() {
2563 let h = PhaseHistogram::new();
2564 h.record(42);
2565 let p = h.percentiles();
2566 assert_eq!(p.count, 1);
2567 assert_eq!(p.p50, 42);
2568 assert_eq!(p.p95, 42);
2569 assert_eq!(p.p99, 42);
2570 assert_eq!(p.max, 42);
2571 assert_eq!(p.mean_us, 42);
2572 }
2573
2574 #[test]
2575 fn phase_histogram_percentiles_ordered() {
2576 let h = PhaseHistogram::new();
2577 for i in 1..=100 {
2578 h.record(i);
2579 }
2580 let p = h.percentiles();
2581 assert_eq!(p.count, 100);
2582 assert!(p.p50 <= p.p95, "p50={} should be <= p95={}", p.p50, p.p95);
2583 assert!(p.p95 <= p.p99, "p95={} should be <= p99={}", p.p95, p.p99);
2584 assert!(p.p99 <= p.max, "p99={} should be <= max={}", p.p99, p.max);
2585 assert_eq!(p.max, 100);
2586 assert_eq!(p.mean_us, 50);
2587 }
2588
2589 #[test]
2590 fn phase_histogram_max_tracks_outlier() {
2591 let h = PhaseHistogram::new();
2592 for _ in 0..100 {
2593 h.record(10);
2594 }
2595 h.record(99999);
2596 let p = h.percentiles();
2597 assert_eq!(p.max, 99999);
2598 assert_eq!(p.p50, 10);
2599 }
2600
2601 #[test]
2602 fn phase_histogram_reset_clears_state() {
2603 let h = PhaseHistogram::new();
2604 for i in 0..50 {
2605 h.record(i * 10);
2606 }
2607 h.reset();
2608 let p = h.percentiles();
2609 assert_eq!(p.count, 0);
2610 assert_eq!(p.max, 0);
2611 }
2612
2613 #[test]
2614 fn phase_histogram_concurrent_writers_no_panic() {
2615 use std::sync::Arc;
2616 let h = Arc::new(PhaseHistogram::new());
2617 let barrier = Arc::new(std::sync::Barrier::new(4));
2618 let mut handles = Vec::new();
2619 for t in 0..4u64 {
2620 let h = Arc::clone(&h);
2621 let b = Arc::clone(&barrier);
2622 handles.push(std::thread::spawn(move || {
2623 b.wait();
2624 for i in 0..500 {
2625 h.record(t * 1000 + i);
2626 }
2627 }));
2628 }
2629 for handle in handles {
2630 handle.join().unwrap();
2631 }
2632 let p = h.percentiles();
2633 assert_eq!(p.count, 2000);
2634 assert!(p.max >= 3499);
2635 }
2636
2637 #[test]
2640 fn wake_reason_counters_track_all_reasons() {
2641 let w = WakeReasonCounters::new();
2642 w.notify.fetch_add(10, Ordering::Relaxed);
2643 w.timeout.fetch_add(3, Ordering::Relaxed);
2644 w.flusher_takeover.fetch_add(1, Ordering::Relaxed);
2645 w.failed_epoch.fetch_add(2, Ordering::Relaxed);
2646 w.busy_retry.fetch_add(5, Ordering::Relaxed);
2647 let s = w.snapshot();
2648 assert_eq!(s.notify, 10);
2649 assert_eq!(s.timeout, 3);
2650 assert_eq!(s.flusher_takeover, 1);
2651 assert_eq!(s.failed_epoch, 2);
2652 assert_eq!(s.busy_retry, 5);
2653 assert_eq!(s.total(), 21);
2654 }
2655
2656 #[test]
2657 fn wake_reason_reset_clears() {
2658 let w = WakeReasonCounters::new();
2659 w.notify.fetch_add(99, Ordering::Relaxed);
2660 w.reset();
2661 let s = w.snapshot();
2662 assert_eq!(s.total(), 0);
2663 }
2664
2665 #[test]
2668 fn consolidation_metrics_snapshot_includes_distributions() {
2669 with_global_consolidation_metrics(|| {
2670 for i in 0..10u64 {
2671 GLOBAL_CONSOLIDATION_METRICS.record_phase_timing(
2672 10 + i,
2673 5 + i,
2674 2,
2675 true,
2676 20 + i,
2677 3 + i,
2678 8 + i,
2679 50 + i,
2680 30 + i,
2681 0,
2682 );
2683 }
2684 for i in 0..5u64 {
2685 GLOBAL_CONSOLIDATION_METRICS.record_phase_timing(
2686 10 + i,
2687 5 + i,
2688 2,
2689 false,
2690 0,
2691 0,
2692 0,
2693 0,
2694 0,
2695 100 + i,
2696 );
2697 }
2698
2699 let snap = GLOBAL_CONSOLIDATION_METRICS.snapshot();
2700 assert_eq!(snap.hist_consolidator_lock_wait.count, 15);
2701 assert_eq!(snap.hist_arrival_wait.count, 10);
2702 assert_eq!(snap.hist_wal_append.count, 10);
2703 assert_eq!(snap.hist_waiter_epoch_wait.count, 5);
2704 assert_eq!(snap.hist_phase_b.count, 15);
2705 assert!(snap.hist_wal_append.p50 > 0);
2706 assert!(snap.hist_wal_append.max >= 59);
2707 });
2708 }
2709
2710 #[test]
2711 fn transaction_conflict_snapshot_debug_clone_copy_eq() {
2712 let generation = WalGenerationIdentity {
2713 checkpoint_seq: 0,
2714 salts: WalSalts { salt1: 0, salt2: 0 },
2715 };
2716 let a = TransactionConflictSnapshot {
2717 generation,
2718 last_commit_frame: Some(42),
2719 commit_count: 7,
2720 };
2721 let copied = a;
2722 assert_eq!(copied, a);
2723 let b = TransactionConflictSnapshot {
2724 generation,
2725 last_commit_frame: None,
2726 commit_count: 7,
2727 };
2728 assert_ne!(a, b);
2729 let dbg = format!("{a:?}");
2730 assert!(dbg.contains("TransactionConflictSnapshot"));
2731 }
2732
2733 #[test]
2734 fn transaction_frame_batch_context_default_and_eq() {
2735 let def = TransactionFrameBatchContext::default();
2736 assert_eq!(def.batch_id, 0);
2737 assert_eq!(def.lane_id, 0);
2738 assert_eq!(def.staged_frame_count, 0);
2739 assert_eq!(def.staging_elapsed_ns, 0);
2740 let other = TransactionFrameBatchContext {
2741 batch_id: 1,
2742 lane_id: 3,
2743 staged_frame_count: 10,
2744 staging_elapsed_ns: 500,
2745 };
2746 assert_ne!(def, other);
2747 let copied = other;
2748 assert_eq!(copied, other);
2749 let dbg = format!("{def:?}");
2750 assert!(dbg.contains("TransactionFrameBatchContext"));
2751 }
2752
2753 #[test]
2754 fn consolidation_phase_and_submit_outcome_all_variants() {
2755 let phases = [
2756 ConsolidationPhase::Filling,
2757 ConsolidationPhase::Flushing,
2758 ConsolidationPhase::Complete,
2759 ];
2760 for (i, p) in phases.iter().enumerate() {
2761 let copied = *p;
2762 assert_eq!(copied, *p);
2763 for (j, q) in phases.iter().enumerate() {
2764 assert_eq!(i == j, p == q);
2765 }
2766 }
2767 assert_ne!(SubmitOutcome::Flusher, SubmitOutcome::Waiter);
2768 let copied = SubmitOutcome::Flusher;
2769 assert_eq!(copied, SubmitOutcome::Flusher);
2770 let dbg = format!("{:?}", SubmitOutcome::Waiter);
2771 assert!(dbg.contains("Waiter"));
2772 }
2773
2774 #[test]
2775 fn transaction_frame_batch_builders() {
2776 let frame = FrameSubmission {
2777 page_number: 5,
2778 page_data: vec![0u8; 16],
2779 db_size_if_commit: 0,
2780 };
2781 let batch = TransactionFrameBatch::new(vec![frame.clone()])
2782 .with_conflict_snapshot(vec![5, 10], None)
2783 .with_context(TransactionFrameBatchContext {
2784 batch_id: 99,
2785 lane_id: 2,
2786 staged_frame_count: 1,
2787 staging_elapsed_ns: 100,
2788 });
2789 assert_eq!(batch.frame_count(), 1);
2790 assert!(!batch.has_commit_frame());
2791 assert_eq!(batch.conflict_pages, vec![5, 10]);
2792 assert!(batch.conflict_snapshot.is_none());
2793 assert_eq!(batch.context.batch_id, 99);
2794 assert_eq!(batch.context.lane_id, 2);
2795 }
2796
2797 #[test]
2798 fn group_commit_config_default_copy_debug() {
2799 let cfg = GroupCommitConfig::default();
2800 let copied = cfg;
2801 assert_eq!(copied.max_group_size, 64);
2802 assert_eq!(copied.max_group_delay, Duration::from_millis(1));
2803 assert_eq!(copied.max_group_delay_ceiling, Duration::from_millis(10));
2804 let dbg = format!("{cfg:?}");
2805 assert!(dbg.contains("GroupCommitConfig"));
2806 }
2807
2808 #[test]
2809 fn frame_submission_debug_clone() {
2810 let fs = FrameSubmission {
2811 page_number: 42,
2812 page_data: vec![0xAB; 8],
2813 db_size_if_commit: 0,
2814 };
2815 let cloned = fs.clone();
2816 assert_eq!(cloned.page_number, 42);
2817 assert_eq!(cloned.page_data.len(), 8);
2818 assert_eq!(cloned.db_size_if_commit, 0);
2819 let dbg = format!("{fs:?}");
2820 assert!(dbg.contains("FrameSubmission"));
2821 }
2822
2823 #[test]
2824 fn phase_percentiles_default_copy_eq() {
2825 let pp = PhasePercentiles::default();
2826 let copied = pp;
2827 assert_eq!(copied, pp);
2828 assert_eq!(pp.p50, 0);
2829 assert_eq!(pp.p99, 0);
2830 assert_eq!(pp.max, 0);
2831 assert_eq!(pp.count, 0);
2832 }
2833
2834 #[test]
2835 fn wake_reason_snapshot_default_total_zero() {
2836 let ws = WakeReasonSnapshot::default();
2837 assert_eq!(ws.total(), 0);
2838 let copied = ws;
2839 assert_eq!(copied, ws);
2840 let dbg = format!("{ws:?}");
2841 assert!(dbg.contains("WakeReasonSnapshot"));
2842 }
2843}