1use std::{
2 cell::RefCell,
3 env,
4 sync::{
5 LazyLock,
6 atomic::{AtomicU64, Ordering},
7 },
8 time::{Duration, Instant},
9};
10
11use rustc_hash::FxHashSet;
12
13static ORE_PROFILE_ENABLED: LazyLock<bool> =
14 LazyLock::new(|| env::var_os("STEEL_ORE_PROFILE").is_some());
15static ORE_PROFILE_LOG_EVERY: LazyLock<u64> = LazyLock::new(|| {
16 env::var("STEEL_ORE_PROFILE_LOG_EVERY")
17 .ok()
18 .and_then(|value| value.parse::<u64>().ok())
19 .unwrap_or(10_000)
20});
21
22static ORE_TOTALS: OreProfileTotals = OreProfileTotals::new();
23
24type SectionKey = (i32, i32, usize);
25
26pub(crate) fn ore_profile_enabled() -> bool {
27 *ORE_PROFILE_ENABLED
28}
29
30pub(crate) struct OreFeatureProfile {
31 stats: Option<RefCell<OreFeatureStats>>,
32}
33
34impl OreFeatureProfile {
35 pub(crate) fn new(config_size: i32) -> Self {
36 Self {
37 stats: ore_profile_enabled().then(|| RefCell::new(OreFeatureStats::new(config_size))),
38 }
39 }
40
41 pub(crate) const fn stats(&self) -> Option<&RefCell<OreFeatureStats>> {
42 self.stats.as_ref()
43 }
44
45 pub(crate) fn finish(self, placed: u64) {
46 if let Some(stats) = self.stats {
47 ORE_TOTALS.publish(stats.into_inner(), placed);
48 }
49 }
50}
51
52pub(crate) struct OreFeatureStats {
53 started_at: Instant,
54 config_size: i32,
55 candidate_positions: u64,
56 unique_positions: u64,
57 write_allowed_positions: u64,
58 target_reads: u64,
59 neighbor_reads: u64,
60 section_read_attempts: u64,
61 section_write_attempts: u64,
62 section_read_contentions: u64,
63 section_write_contentions: u64,
64 chunk_cache_misses: u64,
65 chunk_status_upgrades: u64,
66 writes: u64,
67 candidate_time: Duration,
68 batch_apply_time: Duration,
69 read_time: Duration,
70 write_time: Duration,
71 read_contention_wait_time: Duration,
72 write_contention_wait_time: Duration,
73 read_sections: FxHashSet<SectionKey>,
74 write_sections: FxHashSet<SectionKey>,
75}
76
77impl OreFeatureStats {
78 fn new(config_size: i32) -> Self {
79 Self {
80 started_at: Instant::now(),
81 config_size,
82 candidate_positions: 0,
83 unique_positions: 0,
84 write_allowed_positions: 0,
85 target_reads: 0,
86 neighbor_reads: 0,
87 section_read_attempts: 0,
88 section_write_attempts: 0,
89 section_read_contentions: 0,
90 section_write_contentions: 0,
91 chunk_cache_misses: 0,
92 chunk_status_upgrades: 0,
93 writes: 0,
94 candidate_time: Duration::ZERO,
95 batch_apply_time: Duration::ZERO,
96 read_time: Duration::ZERO,
97 write_time: Duration::ZERO,
98 read_contention_wait_time: Duration::ZERO,
99 write_contention_wait_time: Duration::ZERO,
100 read_sections: FxHashSet::default(),
101 write_sections: FxHashSet::default(),
102 }
103 }
104
105 pub(crate) const fn record_candidate_position(&mut self) {
106 self.candidate_positions += 1;
107 }
108
109 pub(crate) const fn record_unique_position(&mut self) {
110 self.unique_positions += 1;
111 }
112
113 pub(crate) const fn record_write_allowed_position(&mut self) {
114 self.write_allowed_positions += 1;
115 }
116
117 pub(crate) const fn record_write_allowed_positions(&mut self, count: u64) {
118 self.write_allowed_positions += count;
119 }
120
121 pub(crate) const fn record_target_read(&mut self) {
122 self.target_reads += 1;
123 }
124
125 pub(crate) const fn record_neighbor_read(&mut self) {
126 self.neighbor_reads += 1;
127 }
128
129 pub(crate) fn record_section_read_attempt(
130 &mut self,
131 chunk_x: i32,
132 chunk_z: i32,
133 section: usize,
134 ) {
135 self.section_read_attempts += 1;
136 self.read_sections.insert((chunk_x, chunk_z, section));
137 }
138
139 pub(crate) const fn record_section_read_contention(&mut self) {
140 self.section_read_contentions += 1;
141 }
142
143 pub(crate) fn record_section_write_attempt(
144 &mut self,
145 chunk_x: i32,
146 chunk_z: i32,
147 section: usize,
148 ) {
149 self.section_write_attempts += 1;
150 self.write_sections.insert((chunk_x, chunk_z, section));
151 }
152
153 pub(crate) const fn record_section_write_contention(&mut self) {
154 self.section_write_contentions += 1;
155 }
156
157 pub(crate) const fn record_chunk_cache_miss(&mut self) {
158 self.chunk_cache_misses += 1;
159 }
160
161 pub(crate) const fn record_chunk_status_upgrade(&mut self) {
162 self.chunk_status_upgrades += 1;
163 }
164
165 pub(crate) const fn record_write(&mut self) {
166 self.writes += 1;
167 }
168
169 pub(crate) fn record_candidate_time(&mut self, elapsed: Duration) {
170 self.candidate_time += elapsed;
171 }
172
173 pub(crate) fn record_batch_apply_time(&mut self, elapsed: Duration) {
174 self.batch_apply_time += elapsed;
175 }
176
177 pub(crate) fn record_read_time(&mut self, elapsed: Duration) {
178 self.read_time += elapsed;
179 }
180
181 pub(crate) fn record_write_time(&mut self, elapsed: Duration) {
182 self.write_time += elapsed;
183 }
184
185 pub(crate) fn record_read_contention_wait_time(&mut self, elapsed: Duration) {
186 self.read_contention_wait_time += elapsed;
187 }
188
189 pub(crate) fn record_write_contention_wait_time(&mut self, elapsed: Duration) {
190 self.write_contention_wait_time += elapsed;
191 }
192}
193
194struct OreProfileTotals {
195 veins: AtomicU64,
196 placed_veins: AtomicU64,
197 placed_blocks: AtomicU64,
198 config_size_total: AtomicU64,
199 candidate_positions: AtomicU64,
200 unique_positions: AtomicU64,
201 write_allowed_positions: AtomicU64,
202 target_reads: AtomicU64,
203 neighbor_reads: AtomicU64,
204 section_read_attempts: AtomicU64,
205 section_write_attempts: AtomicU64,
206 section_read_contentions: AtomicU64,
207 section_write_contentions: AtomicU64,
208 chunk_cache_misses: AtomicU64,
209 chunk_status_upgrades: AtomicU64,
210 writes: AtomicU64,
211 candidate_time_nanos: AtomicU64,
212 batch_apply_time_nanos: AtomicU64,
213 read_time_nanos: AtomicU64,
214 write_time_nanos: AtomicU64,
215 read_contention_wait_time_nanos: AtomicU64,
216 write_contention_wait_time_nanos: AtomicU64,
217 elapsed_nanos: AtomicU64,
218 unique_read_sections: AtomicU64,
219 unique_write_sections: AtomicU64,
220 max_unique_read_sections: AtomicU64,
221 max_unique_write_sections: AtomicU64,
222}
223
224impl OreProfileTotals {
225 const fn new() -> Self {
226 Self {
227 veins: AtomicU64::new(0),
228 placed_veins: AtomicU64::new(0),
229 placed_blocks: AtomicU64::new(0),
230 config_size_total: AtomicU64::new(0),
231 candidate_positions: AtomicU64::new(0),
232 unique_positions: AtomicU64::new(0),
233 write_allowed_positions: AtomicU64::new(0),
234 target_reads: AtomicU64::new(0),
235 neighbor_reads: AtomicU64::new(0),
236 section_read_attempts: AtomicU64::new(0),
237 section_write_attempts: AtomicU64::new(0),
238 section_read_contentions: AtomicU64::new(0),
239 section_write_contentions: AtomicU64::new(0),
240 chunk_cache_misses: AtomicU64::new(0),
241 chunk_status_upgrades: AtomicU64::new(0),
242 writes: AtomicU64::new(0),
243 candidate_time_nanos: AtomicU64::new(0),
244 batch_apply_time_nanos: AtomicU64::new(0),
245 read_time_nanos: AtomicU64::new(0),
246 write_time_nanos: AtomicU64::new(0),
247 read_contention_wait_time_nanos: AtomicU64::new(0),
248 write_contention_wait_time_nanos: AtomicU64::new(0),
249 elapsed_nanos: AtomicU64::new(0),
250 unique_read_sections: AtomicU64::new(0),
251 unique_write_sections: AtomicU64::new(0),
252 max_unique_read_sections: AtomicU64::new(0),
253 max_unique_write_sections: AtomicU64::new(0),
254 }
255 }
256
257 fn publish(&self, stats: OreFeatureStats, placed: u64) {
258 let vein_index = self.veins.fetch_add(1, Ordering::Relaxed) + 1;
259 if placed > 0 {
260 self.placed_veins.fetch_add(1, Ordering::Relaxed);
261 self.placed_blocks.fetch_add(placed, Ordering::Relaxed);
262 }
263
264 self.config_size_total
265 .fetch_add(stats.config_size.max(0) as u64, Ordering::Relaxed);
266 self.candidate_positions
267 .fetch_add(stats.candidate_positions, Ordering::Relaxed);
268 self.unique_positions
269 .fetch_add(stats.unique_positions, Ordering::Relaxed);
270 self.write_allowed_positions
271 .fetch_add(stats.write_allowed_positions, Ordering::Relaxed);
272 self.target_reads
273 .fetch_add(stats.target_reads, Ordering::Relaxed);
274 self.neighbor_reads
275 .fetch_add(stats.neighbor_reads, Ordering::Relaxed);
276 self.section_read_attempts
277 .fetch_add(stats.section_read_attempts, Ordering::Relaxed);
278 self.section_write_attempts
279 .fetch_add(stats.section_write_attempts, Ordering::Relaxed);
280 self.section_read_contentions
281 .fetch_add(stats.section_read_contentions, Ordering::Relaxed);
282 self.section_write_contentions
283 .fetch_add(stats.section_write_contentions, Ordering::Relaxed);
284 self.chunk_cache_misses
285 .fetch_add(stats.chunk_cache_misses, Ordering::Relaxed);
286 self.chunk_status_upgrades
287 .fetch_add(stats.chunk_status_upgrades, Ordering::Relaxed);
288 self.writes.fetch_add(stats.writes, Ordering::Relaxed);
289 self.candidate_time_nanos
290 .fetch_add(duration_nanos(stats.candidate_time), Ordering::Relaxed);
291 self.batch_apply_time_nanos
292 .fetch_add(duration_nanos(stats.batch_apply_time), Ordering::Relaxed);
293 self.read_time_nanos
294 .fetch_add(duration_nanos(stats.read_time), Ordering::Relaxed);
295 self.write_time_nanos
296 .fetch_add(duration_nanos(stats.write_time), Ordering::Relaxed);
297 self.read_contention_wait_time_nanos.fetch_add(
298 duration_nanos(stats.read_contention_wait_time),
299 Ordering::Relaxed,
300 );
301 self.write_contention_wait_time_nanos.fetch_add(
302 duration_nanos(stats.write_contention_wait_time),
303 Ordering::Relaxed,
304 );
305 self.elapsed_nanos.fetch_add(
306 duration_nanos(stats.started_at.elapsed()),
307 Ordering::Relaxed,
308 );
309
310 let read_section_count = stats.read_sections.len() as u64;
311 let write_section_count = stats.write_sections.len() as u64;
312 self.unique_read_sections
313 .fetch_add(read_section_count, Ordering::Relaxed);
314 self.unique_write_sections
315 .fetch_add(write_section_count, Ordering::Relaxed);
316 atomic_max(&self.max_unique_read_sections, read_section_count);
317 atomic_max(&self.max_unique_write_sections, write_section_count);
318
319 let log_every = *ORE_PROFILE_LOG_EVERY;
320 if log_every != 0 && vein_index.is_multiple_of(log_every) {
321 self.log_snapshot(vein_index);
322 }
323 }
324
325 fn log_snapshot(&self, veins: u64) {
326 let placed_veins = self.placed_veins.load(Ordering::Relaxed);
327 let placed_blocks = self.placed_blocks.load(Ordering::Relaxed);
328 let candidate_positions = self.candidate_positions.load(Ordering::Relaxed);
329 let unique_positions = self.unique_positions.load(Ordering::Relaxed);
330 let write_allowed_positions = self.write_allowed_positions.load(Ordering::Relaxed);
331 let target_reads = self.target_reads.load(Ordering::Relaxed);
332 let neighbor_reads = self.neighbor_reads.load(Ordering::Relaxed);
333 let section_read_attempts = self.section_read_attempts.load(Ordering::Relaxed);
334 let section_write_attempts = self.section_write_attempts.load(Ordering::Relaxed);
335 let section_read_contentions = self.section_read_contentions.load(Ordering::Relaxed);
336 let section_write_contentions = self.section_write_contentions.load(Ordering::Relaxed);
337 let chunk_cache_misses = self.chunk_cache_misses.load(Ordering::Relaxed);
338 let chunk_status_upgrades = self.chunk_status_upgrades.load(Ordering::Relaxed);
339 let writes = self.writes.load(Ordering::Relaxed);
340 let candidate_time_ms = nanos_to_ms(self.candidate_time_nanos.load(Ordering::Relaxed));
341 let batch_apply_time_ms = nanos_to_ms(self.batch_apply_time_nanos.load(Ordering::Relaxed));
342 let read_time_ms = nanos_to_ms(self.read_time_nanos.load(Ordering::Relaxed));
343 let write_time_ms = nanos_to_ms(self.write_time_nanos.load(Ordering::Relaxed));
344 let read_wait_ms =
345 nanos_to_ms(self.read_contention_wait_time_nanos.load(Ordering::Relaxed));
346 let write_wait_ms = nanos_to_ms(
347 self.write_contention_wait_time_nanos
348 .load(Ordering::Relaxed),
349 );
350 let elapsed_ms = nanos_to_ms(self.elapsed_nanos.load(Ordering::Relaxed));
351 let avg_config_size = ratio(self.config_size_total.load(Ordering::Relaxed), veins);
352 let avg_read_sections = ratio(self.unique_read_sections.load(Ordering::Relaxed), veins);
353 let avg_write_sections = ratio(self.unique_write_sections.load(Ordering::Relaxed), veins);
354 let max_read_sections = self.max_unique_read_sections.load(Ordering::Relaxed);
355 let max_write_sections = self.max_unique_write_sections.load(Ordering::Relaxed);
356
357 let message = format!(
358 "ore profile veins={veins} placed_veins={placed_veins} placed_blocks={placed_blocks} \
359 avg_size={avg_config_size:.2} candidates={candidate_positions} unique={unique_positions} \
360 write_allowed={write_allowed_positions} writes={writes} target_reads={target_reads} \
361 neighbor_reads={neighbor_reads} read_locks={section_read_attempts} \
362 read_contentions={section_read_contentions} write_locks={section_write_attempts} \
363 write_contentions={section_write_contentions} chunk_cache_misses={chunk_cache_misses} \
364 chunk_status_upgrades={chunk_status_upgrades} avg_read_sections={avg_read_sections:.2} \
365 avg_write_sections={avg_write_sections:.2} max_read_sections={max_read_sections} \
366 max_write_sections={max_write_sections} candidate_ms={candidate_time_ms:.2} \
367 batch_apply_ms={batch_apply_time_ms:.2} read_ms={read_time_ms:.2} \
368 write_ms={write_time_ms:.2} read_wait_ms={read_wait_ms:.2} \
369 write_wait_ms={write_wait_ms:.2} elapsed_ms={elapsed_ms:.2}"
370 );
371 if log::log_enabled!(log::Level::Info) {
372 log::info!("{message}");
373 } else {
374 eprintln!("{message}");
375 }
376 }
377}
378
379fn duration_nanos(duration: Duration) -> u64 {
380 u64::try_from(duration.as_nanos()).unwrap_or(u64::MAX)
381}
382
383fn nanos_to_ms(nanos: u64) -> f64 {
384 nanos as f64 / 1_000_000.0
385}
386
387fn ratio(total: u64, count: u64) -> f64 {
388 if count == 0 {
389 0.0
390 } else {
391 total as f64 / count as f64
392 }
393}
394
395fn atomic_max(target: &AtomicU64, value: u64) {
396 let mut current = target.load(Ordering::Relaxed);
397 while value > current {
398 match target.compare_exchange_weak(current, value, Ordering::Relaxed, Ordering::Relaxed) {
399 Ok(_) => return,
400 Err(next) => current = next,
401 }
402 }
403}