dsi_progress_logger/lib.rs
1/*
2 * SPDX-FileCopyrightText: 2023 Inria
3 * SPDX-FileCopyrightText: 2023 Sebastiano Vigna
4 * SPDX-FileCopyrightText: 2024 Fondation Inria
5 *
6 * SPDX-License-Identifier: Apache-2.0 OR LGPL-2.1-or-later
7 */
8
9#![doc = include_str!("../README.md")]
10
11use log::{Level, debug, error, info, log, trace, warn};
12use num_format::{Locale, ToFormattedString};
13use pluralizer::pluralize;
14use std::fmt::{Arguments, Display, Formatter, Result};
15use std::sync::{Arc, Mutex};
16use std::time::{Duration, Instant};
17use sysinfo::{MemoryRefreshKind, Pid, ProcessRefreshKind, ProcessesToUpdate, RefreshKind, System};
18mod utils;
19pub use utils::*;
20
21/// Logging trait.
22///
23/// To log the progress of an activity, you call [`start`](ProgressLog::start).
24/// Then, each time you want to mark progress, you call
25/// [`update`](ProgressLog::update), which increases the item counter, and will
26/// log progress information if enough time has passed since the last log.
27/// [`light_update`](ProgressLog::light_update) will perform a time check only
28/// on a subset of updates (e.g., for [`ProgressLogger`], multiples of
29/// [`LIGHT_UPDATE_MASK`](ProgressLogger::LIGHT_UPDATE_MASK) + 1); it should be
30/// used when the activity has an extremely low cost that is comparable to that
31/// of the time check (a call to [`Instant::now()`]) itself.
32///
33/// A few setters can be called at any time to customize the logger (e.g.,
34/// [`item_name`](ProgressLog::item_name),
35/// [`log_interval`](ProgressLog::log_interval),
36/// [`expected_updates`](ProgressLog::expected_updates), etc.). The setters take
37/// and return a mutable reference to the logger, so you must first assign the
38/// logger to a variable, and then you can chain-call the setters on the
39/// variable in fluent style. The disadvantage of this approach is that you must
40/// assign the logger to a variable, but the advantage is that you can call any
41/// setter without having to reassign the variable holding the logger.
42///
43/// It is also possible to log used and free memory at each log interval by
44/// calling [`display_memory`](ProgressLog::display_memory). Memory is read from
45/// system data by the [`sysinfo`] crate, and will be updated at each log
46/// interval (note that this will slightly slow down the logging process).
47/// However, never use this feature in a
48/// [`rayon`](https://crates.io/crates/rayon) environment if another crate in
49/// your compilation unit depends on
50/// [`sysinfo`](https://crates.io/crates/sysinfo)'s (default) `multithread`
51/// feature, as [this can lead to a
52/// deadlock](https://github.com/rayon-rs/rayon/issues/592) .
53///
54///
55/// At any time, displaying the progress logger will give you time information
56/// up to the present. However, since it is impossible to update the memory
57/// information from the [`Display::fmt`] implementation, you should call
58/// [`refresh`](ProgressLog::refresh) before displaying the logger on your own.
59///
60/// When the activity is over, you call [`stop`](ProgressLog::stop), which fixes
61/// the final time, and possibly display again the logger.
62/// [`done`](ProgressLog::done) will stop the logger, print `Completed.`, and
63/// display the final stats.
64///
65/// After you finish a run of the progress logger, can call
66/// [`start`](ProgressLog::start) again measure another activity.
67///
68/// As explained in the [crate documentation](crate), we suggest using `&mut
69/// impl ProgressLog` to pass a logger as an argument, to be able to use
70/// optional logging.
71///
72/// # Examples
73///
74/// See the [`ProgressLogger`] documentation.
75pub trait ProgressLog {
76 /// The type returned by [`concurrent`](ProgressLog::concurrent).
77 type Concurrent: ConcurrentProgressLog;
78
79 /// Forces a log of `self` assuming `now` is the current time.
80 ///
81 /// This is a low-level method that should not be called directly.
82 fn log(&mut self, now: Instant);
83
84 /// Logs `self` if it is time to log.
85 ///
86 /// This is a low-level method that should not be called directly.
87 fn log_if(&mut self, now: Instant);
88
89 /// Sets the display of memory information.
90 ///
91 /// Memory information includes:
92 /// - the [resident-set size](sysinfo::Process::memory) of the process that
93 /// created the logger;
94 /// - the [virtual-memory size](sysinfo::Process::virtual_memory) of the
95 /// process that created the logger;
96 /// - the [available memory](sysinfo::System::available_memory);
97 /// - the [free memory](sysinfo::System::free_memory);
98 /// - the [total amount](sysinfo::System::total_memory) of memory.
99 ///
100 /// Never use this feature in a [`rayon`](https://crates.io/crates/rayon)
101 /// environment if another crate in your compilation unit depends on
102 /// [`sysinfo`](https://crates.io/crates/sysinfo)'s (default) `multithread`
103 /// feature, as [this can lead to a
104 /// deadlock](https://github.com/rayon-rs/rayon/issues/592) .
105 fn display_memory(&mut self, display_memory: bool) -> &mut Self;
106
107 /// Sets the name of an item.
108 fn item_name(&mut self, item_name: impl AsRef<str>) -> &mut Self;
109
110 /// Sets the log interval.
111 fn log_interval(&mut self, log_interval: Duration) -> &mut Self;
112
113 /// Sets the expected number of updates.
114 ///
115 /// If not [`None`], the logger will display the percentage of completion
116 /// and an estimate of the time to completion.
117 ///
118 /// Note that there is no need to use a [`Some`]
119 /// wrapper around the argument, as the method will automatically convert it
120 /// to an [`Option`] type.
121 fn expected_updates(&mut self, expected_updates: impl Into<Option<usize>>) -> &mut Self;
122
123 /// Sets the time unit to use for speed.
124 ///
125 /// If not [`None`], the logger will always display the speed in this unit
126 /// instead of making a choice of readable unit based on the elapsed time.
127 /// Moreover, large numbers will not be thousands separated. This behavior
128 /// is useful when the output of the logger must be parsed.
129 ///
130 /// Note that there is no need to use a [`Some`]
131 /// wrapper around the argument, as the method will automatically convert it
132 /// to an [`Option`] type.
133 fn time_unit(&mut self, time_unit: impl Into<Option<TimeUnit>>) -> &mut Self;
134
135 /// Sets whether to display additionally the speed achieved during the last
136 /// log interval.
137 fn local_speed(&mut self, local_speed: bool) -> &mut Self;
138
139 /// Sets the [`mod@log`] target.
140 ///
141 /// This should often be the path of the module logging progress, which is
142 /// obtained with [`std::module_path!`].
143 ///
144 /// Note that the macro [`progress_logger!`] sets this field automatically
145 /// to [`std::module_path!`].
146 ///
147 /// Calling this method clears any suffixes previously pushed with
148 /// [`push_log_target`](ProgressLog::push_log_target).
149 ///
150 /// # Examples
151 ///
152 /// ```rust
153 /// # fn main() -> Result<(), Box<dyn std::error::Error>> {
154 /// # use dsi_progress_logger::prelude::*;
155 /// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
156 ///
157 /// let mut pl = ProgressLogger::default();
158 /// pl.item_name("pumpkin");
159 /// pl.log_target(std::module_path!());
160 /// pl.start("Smashing pumpkins from a module...");
161 /// for _ in 0..100 {
162 /// // do something on each pumpkin
163 /// pl.update();
164 /// }
165 /// pl.done();
166 /// # Ok(())
167 /// # }
168 /// ```
169 fn log_target(&mut self, target: impl AsRef<str>) -> &mut Self;
170
171 /// Pushes a suffix to the [`mod@log`] target.
172 ///
173 /// The suffix is appended to the current log target as-is, with no
174 /// separator. The caller controls the format (e.g., `" > subtask"` or
175 /// `"::phase2"`).
176 ///
177 /// Each push records the current length of the log target so that
178 /// [`pop_log_target`](ProgressLog::pop_log_target) can restore it.
179 ///
180 /// # Examples
181 ///
182 /// ```rust
183 /// # fn main() -> Result<(), Box<dyn std::error::Error>> {
184 /// # use dsi_progress_logger::prelude::*;
185 /// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
186 ///
187 /// let mut pl = ProgressLogger::default();
188 /// pl.item_name("pumpkin");
189 /// pl.log_target(std::module_path!());
190 /// pl.start("Smashing pumpkins from a module...");
191 /// for _ in 0..100 {
192 /// // do something on each pumpkin
193 /// pl.update();
194 /// }
195 /// pl.done();
196 ///
197 /// // Entering subtask
198 /// pl.push_log_target(" > smoothing");
199 /// pl.start("Smashing pumpkins...");
200 /// for _ in 0..100 {
201 /// // do something on each pumpkin
202 /// pl.update();
203 /// }
204 /// pl.done();
205 /// pl.pop_log_target();
206 /// # Ok(())
207 /// # }
208 /// ```
209 fn push_log_target(&mut self, suffix: impl AsRef<str>) -> &mut Self;
210
211 /// Pops the last suffix pushed with
212 /// [`push_log_target`](ProgressLog::push_log_target).
213 ///
214 /// If no suffix has been pushed, this method is a no-op.
215 fn pop_log_target(&mut self) -> &mut Self;
216
217 /// Sets the [`mod@log`] level used for progress messages.
218 ///
219 /// By default, progress messages are logged at the
220 /// [`Info`](`log::Level::Info`) level.
221 fn log_level(&mut self, log_level: Level) -> &mut Self;
222
223 /// Adds a value to the counter.
224 ///
225 /// This method is mainly useful for wrappers or to implement a custom
226 /// update strategy.
227 fn add_to_count(&mut self, count: usize);
228
229 /// Starts the logger, displaying the given message.
230 ///
231 /// An empty string can be passed to display nothing.
232 fn start(&mut self, msg: impl AsRef<str>);
233
234 /// Increases the count and checks whether it is time to log.
235 fn update(&mut self);
236
237 /// Sets the count and checks whether it is time to log.
238 fn update_with_count(&mut self, count: usize) {
239 self.update_with_count_and_time(count, Instant::now());
240 }
241
242 /// Sets the count and checks whether it is time to log, given the current
243 /// time.
244 ///
245 /// This method is mainly useful for wrappers that want to avoid unnecessary
246 /// calls to [`Instant::now`].
247 fn update_with_count_and_time(&mut self, count: usize, now: Instant);
248
249 /// Increases the count but checks whether it is time to log only after an
250 /// implementation-defined number of calls.
251 ///
252 /// Useful for very short activities with respect to which checking the
253 /// time is expensive.
254 fn light_update(&mut self);
255
256 /// Increases the count and forces a log.
257 fn update_and_display(&mut self);
258
259 /// Stops the logger, fixing the final time.
260 fn stop(&mut self);
261
262 /// Stops the logger, prints `Completed.`, and displays the final stats.
263 /// The number of expected updates will be cleared.
264 fn done(&mut self);
265
266 /// Stops the logger, sets the count, prints `Completed.`, and displays the
267 /// final stats. The number of expected updates will be cleared.
268 ///
269 /// This method is particularly useful in two circumstances:
270 /// * the logger has been updated with some approximate values (e.g., in a
271 /// multicore computation) but before printing the final stats the
272 /// internal counter should contain an exact value;
273 /// * the logger has been used as a handy timer, calling just
274 /// [`start`](ProgressLog::start) and this method.
275 fn done_with_count(&mut self, count: usize);
276
277 /// Returns the elapsed time since the logger was started, or `None` if the
278 /// logger has not been started.
279 fn elapsed(&self) -> Option<Duration>;
280
281 /// Returns the last count the logger has been set to.
282 ///
283 /// Note that this method can be called even after the logger has been
284 /// [stopped](ProgressLog::stop).
285 fn count(&self) -> usize;
286
287 /// Refreshes memory information, if previously requested with
288 /// [`display_memory`](#method.display_memory). There is no need to call
289 /// this method unless the logger is displayed manually.
290 fn refresh(&mut self);
291
292 /// Outputs the given message at the [trace](`log::Level::Trace`) level.
293 ///
294 /// See [`info`](ProgressLog::info) for an example.
295 fn trace(&self, args: Arguments<'_>);
296
297 /// Outputs the given message at the [debug](`log::Level::Debug`) level.
298 ///
299 /// See [`info`](ProgressLog::info) for an example.
300 fn debug(&self, args: Arguments<'_>);
301
302 /// Outputs the given message at the [info](`log::Level::Info`) level.
303 ///
304 /// For maximum flexibility, this method takes as argument the result of a
305 /// [`std::format_args!`] macro. Note that there will be no output if the
306 /// logger is [`None`].
307 ///
308 /// # Examples
309 ///
310 /// ```rust
311 /// # fn main() -> Result<(), Box<dyn std::error::Error>> {
312 /// # use dsi_progress_logger::*;
313 /// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
314 ///
315 /// let logger_name = "my_logger";
316 /// let mut pl = progress_logger![];
317 /// pl.info(format_args!("My logger named {}", logger_name));
318 /// # Ok(())
319 /// # }
320 /// ```
321 fn info(&self, args: Arguments<'_>);
322
323 /// Outputs the given message at the [warn](`log::Level::Warn`) level.
324 ///
325 /// See [`info`](ProgressLog::info) for an example.
326 fn warn(&self, args: Arguments<'_>);
327
328 /// Outputs the given message at the [error](`log::Level::Error`) level.
329 ///
330 /// See [`info`](ProgressLog::info) for an example.
331 fn error(&self, args: Arguments<'_>);
332
333 /// Returns a concurrent copy of the logger.
334 ///
335 /// Some methods require both sequential and concurrent logging. To keep
336 /// optional logging efficient, it is suggested to use `&mut impl
337 /// ProgressLog` to pass a logger as an argument, and then create a
338 /// concurrent copy of the logger with this method. If the original logger
339 /// is `None`, the concurrent copy will be `None` as well.
340 ///
341 /// Note that the result of the method is a copy—it will not share the state
342 /// of the original logger.
343 ///
344 /// Concurrent logger implementations can just return a duplicate of
345 /// themselves via [`dup`](ConcurrentProgressLog::dup).
346 fn concurrent(&self) -> Self::Concurrent;
347}
348
349/// Concurrent logging trait.
350///
351/// This trait extends [`ProgressLog`] by adding a
352/// [`dup`](ConcurrentProgressLog::dup) method that duplicates the logger and
353/// adding the [`Clone`], [`Sync`], and [`Send`] traits.
354///
355/// By contract, [`Clone`] implementations must return a new logger updating the
356/// same internal state, so you can easily use a [`ConcurrentProgressLog`] in
357/// methods like
358/// [`rayon::ParallelIterator::for_each_with`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.for_each_with),
359/// [`rayon::ParallelIterator::map_with`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.map_with),
360/// and so on. In a [`rayon`](https://docs.rs/rayon) environment, however, you
361/// cannot use [`display_memory`](ProgressLog::display_memory) if another crate
362/// in your compilation unit depends on
363/// [`sysinfo`](https://crates.io/crates/sysinfo)'s (default) `multithread`
364/// feature, as [this can lead to a
365/// deadlock](https://github.com/rayon-rs/rayon/issues/592) .
366///
367/// Note that [`ProgressLogger`]'s [`Clone`
368/// implementation](ProgressLogger#impl-Clone-for-ProgressLogger) has a
369/// completely different semantics.
370///
371/// As explained in the [crate documentation](crate), we suggest using `&mut
372/// Self::Concurrent` to pass a concurrent logger as an argument, to be able to
373/// use optional logging.
374///
375/// # Examples
376///
377/// See the [`ConcurrentWrapper`] documentation.
378pub trait ConcurrentProgressLog: ProgressLog + Sync + Send + Clone {
379 /// The type returned by [`dup`](ConcurrentProgressLog::dup).
380 type Duplicated: ConcurrentProgressLog;
381
382 /// Duplicates the concurrent progress logger, obtaining a new one.
383 ///
384 /// Note that this method has the same semantics of [`ProgressLogger`'s
385 /// `Clone` implementation](ProgressLogger#impl-Clone-for-ProgressLogger),
386 /// but in a [`ConcurrentProgressLog`] by contract [cloning must generate
387 /// copies with the same underlying logger](ConcurrentProgressLog).
388 fn dup(&self) -> Self::Duplicated;
389}
390
391impl<P: ProgressLog> ProgressLog for &mut P {
392 type Concurrent = P::Concurrent;
393
394 fn log(&mut self, now: Instant) {
395 (**self).log(now);
396 }
397
398 fn log_if(&mut self, now: Instant) {
399 (**self).log_if(now);
400 }
401
402 fn add_to_count(&mut self, count: usize) {
403 (**self).add_to_count(count);
404 }
405
406 fn display_memory(&mut self, display_memory: bool) -> &mut Self {
407 (**self).display_memory(display_memory);
408 self
409 }
410
411 fn item_name(&mut self, item_name: impl AsRef<str>) -> &mut Self {
412 (**self).item_name(item_name);
413 self
414 }
415
416 fn log_interval(&mut self, log_interval: Duration) -> &mut Self {
417 (**self).log_interval(log_interval);
418 self
419 }
420
421 fn expected_updates(&mut self, expected_updates: impl Into<Option<usize>>) -> &mut Self {
422 (**self).expected_updates(expected_updates.into());
423 self
424 }
425
426 fn time_unit(&mut self, time_unit: impl Into<Option<TimeUnit>>) -> &mut Self {
427 (**self).time_unit(time_unit.into());
428 self
429 }
430
431 fn local_speed(&mut self, local_speed: bool) -> &mut Self {
432 (**self).local_speed(local_speed);
433 self
434 }
435
436 fn log_target(&mut self, target: impl AsRef<str>) -> &mut Self {
437 (**self).log_target(target);
438 self
439 }
440
441 fn push_log_target(&mut self, suffix: impl AsRef<str>) -> &mut Self {
442 (**self).push_log_target(suffix);
443 self
444 }
445
446 fn pop_log_target(&mut self) -> &mut Self {
447 (**self).pop_log_target();
448 self
449 }
450
451 fn log_level(&mut self, log_level: Level) -> &mut Self {
452 (**self).log_level(log_level);
453 self
454 }
455
456 fn start(&mut self, msg: impl AsRef<str>) {
457 (**self).start(msg);
458 }
459
460 fn update(&mut self) {
461 (**self).update();
462 }
463
464 fn update_with_count_and_time(&mut self, count: usize, now: Instant) {
465 (**self).update_with_count_and_time(count, now);
466 }
467
468 fn light_update(&mut self) {
469 (**self).light_update();
470 }
471
472 fn update_and_display(&mut self) {
473 (**self).update_and_display();
474 }
475
476 fn stop(&mut self) {
477 (**self).stop();
478 }
479
480 fn done(&mut self) {
481 (**self).done();
482 }
483
484 fn done_with_count(&mut self, count: usize) {
485 (**self).done_with_count(count);
486 }
487
488 fn elapsed(&self) -> Option<Duration> {
489 (**self).elapsed()
490 }
491
492 fn count(&self) -> usize {
493 (**self).count()
494 }
495
496 fn refresh(&mut self) {
497 (**self).refresh();
498 }
499
500 fn trace(&self, args: Arguments<'_>) {
501 (**self).trace(args);
502 }
503
504 fn debug(&self, args: Arguments<'_>) {
505 (**self).debug(args);
506 }
507
508 fn info(&self, args: Arguments<'_>) {
509 (**self).info(args);
510 }
511
512 fn warn(&self, args: Arguments<'_>) {
513 (**self).warn(args);
514 }
515
516 fn error(&self, args: Arguments<'_>) {
517 (**self).error(args);
518 }
519
520 fn concurrent(&self) -> Self::Concurrent {
521 (**self).concurrent()
522 }
523}
524
525impl<P: ProgressLog> ProgressLog for Option<P> {
526 type Concurrent = Option<P::Concurrent>;
527
528 fn log(&mut self, now: Instant) {
529 if let Some(pl) = self {
530 pl.log(now);
531 }
532 }
533
534 fn log_if(&mut self, now: Instant) {
535 if let Some(pl) = self {
536 pl.log_if(now);
537 }
538 }
539
540 fn add_to_count(&mut self, count: usize) {
541 if let Some(pl) = self {
542 pl.add_to_count(count);
543 }
544 }
545
546 fn display_memory(&mut self, display_memory: bool) -> &mut Self {
547 if let Some(pl) = self {
548 pl.display_memory(display_memory);
549 }
550 self
551 }
552
553 fn item_name(&mut self, item_name: impl AsRef<str>) -> &mut Self {
554 if let Some(pl) = self {
555 pl.item_name(item_name);
556 }
557 self
558 }
559
560 fn log_interval(&mut self, log_interval: Duration) -> &mut Self {
561 if let Some(pl) = self {
562 pl.log_interval(log_interval);
563 }
564 self
565 }
566
567 fn expected_updates(&mut self, expected_updates: impl Into<Option<usize>>) -> &mut Self {
568 if let Some(pl) = self {
569 pl.expected_updates(expected_updates.into());
570 }
571 self
572 }
573
574 fn time_unit(&mut self, time_unit: impl Into<Option<TimeUnit>>) -> &mut Self {
575 if let Some(pl) = self {
576 pl.time_unit(time_unit.into());
577 }
578 self
579 }
580
581 fn local_speed(&mut self, local_speed: bool) -> &mut Self {
582 if let Some(pl) = self {
583 pl.local_speed(local_speed);
584 }
585 self
586 }
587
588 fn log_target(&mut self, target: impl AsRef<str>) -> &mut Self {
589 if let Some(pl) = self {
590 pl.log_target(target);
591 }
592 self
593 }
594
595 fn push_log_target(&mut self, suffix: impl AsRef<str>) -> &mut Self {
596 if let Some(pl) = self {
597 pl.push_log_target(suffix);
598 }
599 self
600 }
601
602 fn pop_log_target(&mut self) -> &mut Self {
603 if let Some(pl) = self {
604 pl.pop_log_target();
605 }
606 self
607 }
608
609 fn log_level(&mut self, log_level: Level) -> &mut Self {
610 if let Some(pl) = self {
611 pl.log_level(log_level);
612 }
613 self
614 }
615
616 fn start(&mut self, msg: impl AsRef<str>) {
617 if let Some(pl) = self {
618 pl.start(msg);
619 }
620 }
621
622 fn update(&mut self) {
623 if let Some(pl) = self {
624 pl.update();
625 }
626 }
627
628 fn update_with_count_and_time(&mut self, count: usize, now: Instant) {
629 if let Some(pl) = self {
630 pl.update_with_count_and_time(count, now);
631 }
632 }
633
634 fn light_update(&mut self) {
635 if let Some(pl) = self {
636 pl.light_update();
637 }
638 }
639
640 fn update_and_display(&mut self) {
641 if let Some(pl) = self {
642 pl.update_and_display();
643 }
644 }
645
646 fn stop(&mut self) {
647 if let Some(pl) = self {
648 pl.stop();
649 }
650 }
651
652 fn done(&mut self) {
653 if let Some(pl) = self {
654 pl.done();
655 }
656 }
657
658 fn done_with_count(&mut self, count: usize) {
659 if let Some(pl) = self {
660 pl.done_with_count(count);
661 }
662 }
663
664 fn elapsed(&self) -> Option<Duration> {
665 self.as_ref().and_then(|pl| pl.elapsed())
666 }
667
668 fn count(&self) -> usize {
669 self.as_ref().map(|pl| pl.count()).unwrap_or(0)
670 }
671
672 fn refresh(&mut self) {
673 if let Some(pl) = self {
674 pl.refresh();
675 }
676 }
677
678 fn trace(&self, args: Arguments<'_>) {
679 if let Some(pl) = self {
680 pl.trace(args);
681 }
682 }
683
684 fn debug(&self, args: Arguments<'_>) {
685 if let Some(pl) = self {
686 pl.debug(args);
687 }
688 }
689
690 fn info(&self, args: Arguments<'_>) {
691 if let Some(pl) = self {
692 pl.info(args);
693 }
694 }
695
696 fn warn(&self, args: Arguments<'_>) {
697 if let Some(pl) = self {
698 pl.warn(args);
699 }
700 }
701
702 fn error(&self, args: Arguments<'_>) {
703 if let Some(pl) = self {
704 pl.error(args);
705 }
706 }
707
708 fn concurrent(&self) -> Self::Concurrent {
709 self.as_ref().map(|pl| pl.concurrent())
710 }
711}
712
713impl<P: ConcurrentProgressLog> ConcurrentProgressLog for Option<P> {
714 type Duplicated = Option<P::Duplicated>;
715
716 fn dup(&self) -> Self::Duplicated {
717 self.as_ref().map(|pl| pl.dup())
718 }
719}
720
721/// An implementation of [`ProgressLog`] with output generated using the
722/// [`log`](https://docs.rs/log) crate at a configurable level (default:
723/// `info`).
724///
725/// Instances can be created by using fluent setters, or by using the
726/// [`progress_logger`] macro.
727///
728/// You can [clone](#impl-Clone-for-ProgressLogger) a logger to create a new one
729/// with the same setup but with all the counters reset. This behavior is useful
730/// when you want to configure a logger and then use its configuration for other
731/// loggers.
732///
733/// # Examples
734///
735/// A typical call sequence to a progress logger is as follows:
736///
737/// ```rust
738/// # fn main() -> Result<(), Box<dyn std::error::Error>> {
739/// # use dsi_progress_logger::prelude::*;
740/// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
741///
742/// let mut pl = ProgressLogger::default();
743/// pl.item_name("pumpkin");
744/// pl.start("Smashing pumpkins...");
745/// for _ in 0..100 {
746/// // do something on each pumpkin
747/// pl.update();
748/// }
749/// pl.done();
750/// # Ok(())
751/// # }
752/// ```
753///
754/// The [`progress_logger`] macro will create the progress logger for you and
755/// set its [`log_target`](ProgressLog::log_target) to [`std::module_path!()`],
756/// which is usually what you want. You can also call any setter with a
757/// key-value syntax:
758///
759/// ```rust
760/// # fn main() -> Result<(), Box<dyn std::error::Error>> {
761/// # use dsi_progress_logger::prelude::*;
762/// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
763///
764/// let mut pl = progress_logger![item_name="pumpkin"];
765/// pl.start("Smashing pumpkins...");
766/// for _ in 0..100 {
767/// // do something on each pumpkin
768/// pl.update();
769/// }
770/// pl.done();
771/// # Ok(())
772/// # }
773/// ```
774///
775/// A progress logger can also be used as a handy timer:
776///
777/// ```rust
778/// # fn main() -> Result<(), Box<dyn std::error::Error>> {
779/// # use dsi_progress_logger::prelude::*;
780/// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
781///
782/// let mut pl = progress_logger![item_name="pumpkin"];
783/// pl.start("Smashing pumpkins...");
784/// for _ in 0..100 {
785/// // do something on each pumpkin
786/// }
787/// pl.done_with_count(100);
788/// # Ok(())
789/// # }
790/// ```
791///
792/// This progress logger will display information about memory usage:
793///
794/// ```rust
795/// # fn main() -> Result<(), Box<dyn std::error::Error>> {
796/// # use dsi_progress_logger::prelude::*;
797/// env_logger::builder().filter_level(log::LevelFilter::Info).try_init()?;
798///
799/// let mut pl = progress_logger![display_memory=true];
800/// # Ok(())
801/// # }
802/// ```
803pub struct ProgressLogger {
804 /// The name of an item. Defaults to `item`.
805 item_name: String,
806 /// The pluralized name of an item. Defaults to `items`. It is quite
807 /// expensive to compute with [`pluralize`], hence the caching.
808 items_name: String,
809 /// The log interval. Defaults to 10 seconds.
810 log_interval: Duration,
811 /// The expected number of updates. If set, the logger will display the percentage of completion and
812 /// an estimate of the time to completion.
813 expected_updates: Option<usize>,
814 /// The time unit to use for speed. If set, the logger will always display the speed in this unit
815 /// instead of making a choice of readable unit based on the elapsed time. Moreover, large numbers
816 /// will not be thousands separated. This is useful when the output of the logger must be parsed.
817 time_unit: Option<TimeUnit>,
818 /// Display additionally the speed achieved during the last log interval.
819 local_speed: bool,
820 /// [`mod@log`] target
821 ///
822 /// This is often the path of the module logging progress.
823 log_target: String,
824 /// Stack of cut positions for [`push_log_target`](ProgressLog::push_log_target)/[`pop_log_target`](ProgressLog::pop_log_target).
825 log_target_cut_positions: Vec<usize>,
826 /// [`mod@log`] level for progress messages. Defaults to [`Level::Info`].
827 log_level: Level,
828 /// When the logger was started.
829 start_time: Option<Instant>,
830 /// The last time we logged the activity (to compute speed).
831 last_log_time: Instant,
832 /// The next time we will log the activity.
833 next_log_time: Instant,
834 /// When the logger was stopped.
835 stop_time: Option<Instant>,
836 /// The number of items.
837 count: usize,
838 /// The number of items at the last log (to compute speed).
839 last_count: usize,
840 /// Display additionally the amount of used and free memory using this [`sysinfo::System`]
841 system: Option<System>,
842 /// The pid of the current process
843 pid: Pid,
844}
845
846impl Default for ProgressLogger {
847 /// Creates a default [`ProgressLogger`] with a log interval of 10 seconds and
848 /// item name set to “item”.
849 fn default() -> Self {
850 Self {
851 item_name: "item".into(),
852 items_name: "items".into(),
853 log_interval: Duration::from_secs(10),
854 expected_updates: None,
855 time_unit: None,
856 local_speed: false,
857 log_target: std::env::current_exe()
858 .ok()
859 .and_then(|path| {
860 path.file_name()
861 .and_then(|s| s.to_owned().into_string().ok())
862 })
863 .unwrap_or_else(|| "main".to_string()),
864 log_target_cut_positions: Vec::new(),
865 log_level: Level::Info,
866 start_time: None,
867 last_log_time: Instant::now(),
868 next_log_time: Instant::now(),
869 stop_time: None,
870 count: 0,
871 last_count: 0,
872 system: None,
873 pid: Pid::from(std::process::id() as usize),
874 }
875 }
876}
877
878impl Clone for ProgressLogger {
879 /// Clones the logger, returning a logger with the same setup but with all the
880 /// counters reset.
881 #[allow(clippy::manual_map)]
882 fn clone(&self) -> Self {
883 Self {
884 item_name: self.item_name.clone(),
885 items_name: self.items_name.clone(),
886 log_interval: self.log_interval,
887 time_unit: self.time_unit,
888 local_speed: self.local_speed,
889 log_level: self.log_level,
890 log_target: self.log_target.clone(),
891 log_target_cut_positions: self.log_target_cut_positions.clone(),
892 system: match self.system {
893 Some(_) => Some(System::new_with_specifics(
894 RefreshKind::nothing().with_memory(MemoryRefreshKind::nothing().with_ram()),
895 )),
896 None => None,
897 },
898 ..ProgressLogger::default()
899 }
900 }
901}
902
903/// Macro to create a [`ProgressLogger`] with default log target set to
904/// [`std::module_path!`], and key-value pairs instead of setters.
905///
906/// # Examples
907///
908/// ```rust
909/// # use dsi_progress_logger::prelude::*;
910/// let mut pl = progress_logger![item_name = "pumpkin", display_memory = true];
911/// ```
912#[macro_export]
913macro_rules! progress_logger {
914 ($($method:ident = $arg:expr),* $(,)?) => {
915 {
916 let mut pl = $crate::ProgressLogger::default();
917 $crate::ProgressLog::log_target(&mut pl, ::std::module_path!());
918 $(
919 $crate::ProgressLog::$method(&mut pl, $arg);
920 )*
921 pl
922 }
923 }
924}
925
926impl ProgressLogger {
927 /// Calls to [light_update](ProgressLog::light_update) will cause a call to
928 /// [`Instant::now`] only if the current count is a multiple of this mask
929 /// plus one.
930 pub const LIGHT_UPDATE_MASK: usize = (1 << 20) - 1;
931
932 fn fmt_timing_speed(&self, f: &mut Formatter<'_>, seconds_per_item: f64) -> Result {
933 let items_per_second = 1.0 / seconds_per_item;
934
935 let time_unit_timing = self
936 .time_unit
937 .unwrap_or_else(|| TimeUnit::nice_time_unit(seconds_per_item));
938
939 let time_unit_speed = self
940 .time_unit
941 .unwrap_or_else(|| TimeUnit::nice_speed_unit(seconds_per_item));
942
943 f.write_fmt(format_args!(
944 "{:.2} {}/{}, {:.2} {}/{}",
945 items_per_second * time_unit_speed.as_seconds(),
946 self.items_name,
947 time_unit_speed.label(),
948 seconds_per_item / time_unit_timing.as_seconds(),
949 time_unit_timing.label(),
950 self.item_name
951 ))?;
952
953 Ok(())
954 }
955}
956
957impl ProgressLog for ProgressLogger {
958 type Concurrent = ConcurrentWrapper<Self>;
959
960 fn log(&mut self, now: Instant) {
961 self.refresh();
962 log!(target: &self.log_target, self.log_level, "{}", self);
963 self.last_count = self.count;
964 self.last_log_time = now;
965 self.next_log_time = now + self.log_interval;
966 }
967
968 fn log_if(&mut self, now: Instant) {
969 if self.next_log_time <= now {
970 self.log(now);
971 }
972 }
973
974 fn add_to_count(&mut self, count: usize) {
975 self.count += count;
976 }
977
978 fn display_memory(&mut self, display_memory: bool) -> &mut Self {
979 match (display_memory, &self.system) {
980 (true, None) => {
981 self.system = Some(System::new_with_specifics(
982 RefreshKind::nothing().with_memory(MemoryRefreshKind::nothing().with_ram()),
983 ));
984 }
985 (false, Some(_)) => {
986 self.system = None;
987 }
988 _ => (),
989 }
990 self
991 }
992
993 fn item_name(&mut self, item_name: impl AsRef<str>) -> &mut Self {
994 self.item_name = item_name.as_ref().into();
995 self.items_name = pluralize(item_name.as_ref(), 2, false);
996 self
997 }
998
999 fn log_interval(&mut self, log_interval: Duration) -> &mut Self {
1000 self.log_interval = log_interval;
1001 self
1002 }
1003
1004 fn expected_updates(&mut self, expected_updates: impl Into<Option<usize>>) -> &mut Self {
1005 self.expected_updates = expected_updates.into();
1006 self
1007 }
1008
1009 fn time_unit(&mut self, time_unit: impl Into<Option<TimeUnit>>) -> &mut Self {
1010 self.time_unit = time_unit.into();
1011 self
1012 }
1013
1014 fn local_speed(&mut self, local_speed: bool) -> &mut Self {
1015 self.local_speed = local_speed;
1016 self
1017 }
1018
1019 fn log_target(&mut self, target: impl AsRef<str>) -> &mut Self {
1020 self.log_target = target.as_ref().into();
1021 self.log_target_cut_positions.clear();
1022 self
1023 }
1024
1025 fn push_log_target(&mut self, suffix: impl AsRef<str>) -> &mut Self {
1026 self.log_target_cut_positions.push(self.log_target.len());
1027 self.log_target.push_str(suffix.as_ref());
1028 self
1029 }
1030
1031 fn pop_log_target(&mut self) -> &mut Self {
1032 if let Some(pos) = self.log_target_cut_positions.pop() {
1033 self.log_target.truncate(pos);
1034 }
1035 self
1036 }
1037
1038 fn log_level(&mut self, log_level: Level) -> &mut Self {
1039 self.log_level = log_level;
1040 self
1041 }
1042
1043 fn start(&mut self, msg: impl AsRef<str>) {
1044 let now = Instant::now();
1045 self.start_time = Some(now);
1046 self.stop_time = None;
1047 self.count = 0;
1048 self.last_count = 0;
1049 self.last_log_time = now;
1050 self.next_log_time = now + self.log_interval;
1051 if !msg.as_ref().is_empty() {
1052 log!(target: &self.log_target, self.log_level, "{}", msg.as_ref());
1053 }
1054 }
1055
1056 fn refresh(&mut self) {
1057 if let Some(system) = &mut self.system {
1058 system.refresh_processes_specifics(
1059 ProcessesToUpdate::Some(&[self.pid]),
1060 false,
1061 ProcessRefreshKind::nothing().with_memory(),
1062 );
1063 }
1064 }
1065
1066 fn update(&mut self) {
1067 self.count += 1;
1068 self.log_if(Instant::now());
1069 }
1070
1071 fn update_with_count_and_time(&mut self, count: usize, now: Instant) {
1072 self.count += count;
1073 self.log_if(now);
1074 }
1075
1076 /// Increases the count and, once every
1077 /// [`LIGHT_UPDATE_MASK`](#fields.LIGHT_UPDATE_MASK) + 1 calls, checks
1078 /// whether it is time to log.
1079 #[inline(always)]
1080 fn light_update(&mut self) {
1081 self.count += 1;
1082 if (self.count & Self::LIGHT_UPDATE_MASK) == 0 {
1083 self.log_if(Instant::now());
1084 }
1085 }
1086
1087 fn update_and_display(&mut self) {
1088 self.count += 1;
1089 self.log(Instant::now());
1090 }
1091
1092 fn stop(&mut self) {
1093 self.stop_time = Some(Instant::now());
1094 // just to avoid wrong reuses
1095 self.expected_updates = None;
1096 }
1097
1098 fn done(&mut self) {
1099 self.stop();
1100 log!(target: &self.log_target, self.log_level, "Completed.");
1101 self.refresh();
1102 log!(target: &self.log_target, self.log_level, "{}", self);
1103 }
1104
1105 fn done_with_count(&mut self, count: usize) {
1106 self.count = count;
1107 self.done();
1108 }
1109
1110 fn elapsed(&self) -> Option<Duration> {
1111 let start_time = self.start_time?;
1112 Some(self.stop_time.unwrap_or_else(Instant::now) - start_time)
1113 }
1114
1115 fn count(&self) -> usize {
1116 self.count
1117 }
1118
1119 fn trace(&self, args: Arguments<'_>) {
1120 trace!(target: &self.log_target, "{}", std::fmt::format(args));
1121 }
1122
1123 fn debug(&self, args: Arguments<'_>) {
1124 debug!(target: &self.log_target, "{}", std::fmt::format(args));
1125 }
1126
1127 fn info(&self, args: Arguments<'_>) {
1128 info!(target: &self.log_target, "{}", std::fmt::format(args));
1129 }
1130
1131 fn warn(&self, args: Arguments<'_>) {
1132 warn!(target: &self.log_target, "{}", std::fmt::format(args));
1133 }
1134
1135 fn error(&self, args: Arguments<'_>) {
1136 error!(target: &self.log_target, "{}", std::fmt::format(args));
1137 }
1138
1139 fn concurrent(&self) -> Self::Concurrent {
1140 ConcurrentWrapper::wrap(self.clone())
1141 }
1142}
1143
1144impl Display for ProgressLogger {
1145 fn fmt(&self, f: &mut Formatter<'_>) -> Result {
1146 if let Some(start_time) = self.start_time {
1147 let count_fmtd = if self.time_unit.is_none() {
1148 self.count.to_formatted_string(&Locale::en)
1149 } else {
1150 self.count.to_string()
1151 };
1152
1153 if let Some(stop_time) = self.stop_time {
1154 let elapsed = stop_time - start_time;
1155 let seconds_per_item = elapsed.as_secs_f64() / self.count as f64;
1156
1157 f.write_fmt(format_args!(
1158 "Elapsed: {}",
1159 TimeUnit::pretty_print(elapsed.as_millis())
1160 ))?;
1161
1162 if self.count != 0 {
1163 f.write_fmt(format_args!(
1164 " [{} {}, ",
1165 count_fmtd,
1166 if self.count == 1 {
1167 &self.item_name
1168 } else {
1169 &self.items_name
1170 }
1171 ))?;
1172 self.fmt_timing_speed(f, seconds_per_item)?;
1173 f.write_fmt(format_args!("]"))?
1174 }
1175 } else {
1176 let now = Instant::now();
1177
1178 let elapsed = now - start_time;
1179
1180 f.write_fmt(format_args!(
1181 "{} {}, {}",
1182 count_fmtd,
1183 if self.count == 1 {
1184 &self.item_name
1185 } else {
1186 &self.items_name
1187 },
1188 TimeUnit::pretty_print(elapsed.as_millis()),
1189 ))?;
1190
1191 if self.count != 0 {
1192 let seconds_per_item = elapsed.as_secs_f64() / self.count as f64;
1193 f.write_fmt(format_args!(", "))?;
1194 self.fmt_timing_speed(f, seconds_per_item)?;
1195
1196 if let Some(expected_updates) = self.expected_updates {
1197 let millis_to_end: u128 = (expected_updates.saturating_sub(self.count)
1198 as u128
1199 * elapsed.as_millis())
1200 / (self.count as u128 + 1);
1201 f.write_fmt(format_args!(
1202 "; {:.2}% done, {} to end",
1203 100.0 * self.count as f64 / expected_updates as f64,
1204 TimeUnit::pretty_print(millis_to_end)
1205 ))?;
1206 }
1207
1208 if self.local_speed && self.stop_time.is_none() && self.count != self.last_count
1209 {
1210 f.write_fmt(format_args!(" ["))?;
1211
1212 let elapsed = now - self.last_log_time;
1213 let seconds_per_item =
1214 elapsed.as_secs_f64() / (self.count - self.last_count) as f64;
1215 self.fmt_timing_speed(f, seconds_per_item)?;
1216
1217 f.write_fmt(format_args!("]"))?;
1218 }
1219 }
1220 }
1221
1222 // It would be ideal to refresh self.system here, but this operation
1223 // would require an &mut self reference.
1224 if let Some(system) = &self.system {
1225 f.write_fmt(format_args!(
1226 "; res/vir/avail/free/total mem {}/{}/{}B/{}B/{}B",
1227 system
1228 .process(self.pid)
1229 .map(|process| humanize(process.memory() as _) + "B")
1230 .unwrap_or("N/A".to_string()),
1231 system
1232 .process(self.pid)
1233 .map(|process| humanize(process.virtual_memory() as _) + "B")
1234 .unwrap_or("N/A".to_string()),
1235 humanize(system.available_memory() as _),
1236 humanize(system.free_memory() as _),
1237 humanize(system.total_memory() as _)
1238 ))?;
1239 }
1240
1241 Ok(())
1242 } else {
1243 write!(f, "ProgressLogger not started")
1244 }
1245 }
1246}
1247
1248/// A [`ConcurrentProgressLog`] implementation that wraps a [`ProgressLog`] in
1249/// an [`Arc`]/[`Mutex`].
1250///
1251/// The methods [`update`](ProgressLog::update) and
1252/// [`update_with_count`](ProgressLog::update_with_count) buffer the increment
1253/// and add it to the underlying logger only when the buffer reaches a
1254/// threshold; this prevents locking the underlying logger too often. The
1255/// threshold is set at creation using the methods
1256/// [`with_threshold`](Self::with_threshold) and
1257/// [`wrap_with_threshold`](Self::wrap_with_threshold), or by calling the method
1258/// [`threshold`](Self::threshold).
1259///
1260/// The method [`light_update`](ProgressLog::light_update), as in the case of
1261/// [`ProgressLogger`], further delays updates using an even faster check.
1262///
1263/// # Examples
1264///
1265/// In this example, we manually spawn processes:
1266///
1267/// ```rust
1268/// # use dsi_progress_logger::prelude::*;
1269/// # use std::thread;
1270/// let mut cpl = concurrent_progress_logger![item_name = "pumpkin"];
1271/// cpl.start("Smashing pumpkins (using many threads)...");
1272///
1273/// std::thread::scope(|s| {
1274/// for i in 0..100 {
1275/// let mut pl = cpl.clone();
1276/// s.spawn(move || {
1277/// for _ in 0..100000 {
1278/// // do something on each pumpkin
1279/// pl.update();
1280/// }
1281/// });
1282/// }
1283/// });
1284///
1285/// cpl.done();
1286/// ```
1287///
1288/// You can obtain the same behavior with
1289/// [`rayon`](https://crates.io/crates/rayon) using methods such as
1290/// [`for_each_with`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.for_each_with)
1291/// and
1292/// [`map_with`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.map_with):
1293///
1294/// ```rust
1295/// # use dsi_progress_logger::prelude::*;
1296/// # use rayon::prelude::*;
1297/// let mut cpl = concurrent_progress_logger![item_name = "pumpkin"];
1298/// cpl.start("Smashing pumpkins (using many threads)...");
1299///
1300/// (0..1000000).into_par_iter().
1301/// with_min_len(1000). // optional, might reduce the amount of cloning
1302/// for_each_with(cpl.clone(), |pl, i| {
1303/// // do something on each pumpkin
1304/// pl.update();
1305/// }
1306/// );
1307///
1308/// cpl.done();
1309/// ```
1310///
1311/// Note that you have to pass `cpl.clone()` to avoid a move that would make the
1312/// call to [`done`](ProgressLog::done) impossible. Also, since
1313/// [`for_each_with`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.for_each_with)
1314/// might perform excessive cloning if jobs are too short, you can use
1315/// [`with_min_len`](https://docs.rs/rayon/latest/rayon/iter/trait.ParallelIterator.html#method.with_min_len)
1316/// to reduce the amount of cloning.
1317pub struct ConcurrentWrapper<P: ProgressLog = ProgressLogger> {
1318 /// Underlying logger
1319 inner: Arc<Mutex<P>>,
1320 /// The number of items processed by the current thread.
1321 local_count: u32,
1322 /// The threshold for updating the underlying logger.
1323 threshold: u32,
1324}
1325
1326impl Default for ConcurrentWrapper {
1327 /// Creates a new [`ConcurrentWrapper`] based on a default
1328 /// [`ProgressLogger`], with a threshold of
1329 /// [`DEFAULT_THRESHOLD`](Self::DEFAULT_THRESHOLD).
1330 fn default() -> Self {
1331 Self {
1332 inner: Arc::new(Mutex::new(ProgressLogger::default())),
1333 local_count: 0,
1334 threshold: Self::DEFAULT_THRESHOLD,
1335 }
1336 }
1337}
1338
1339impl<P: ProgressLog + Clone> Clone for ConcurrentWrapper<P> {
1340 /// Clones the concurrent wrapper, obtaining a new one with the same
1341 /// threshold, with a local count of zero, and with the same inner
1342 /// [`ProgressLog`].
1343 fn clone(&self) -> Self {
1344 Self {
1345 inner: self.inner.clone(),
1346 local_count: 0,
1347 threshold: self.threshold,
1348 }
1349 }
1350}
1351
1352/// Macro to create a [`ConcurrentWrapper`] based on a
1353/// [`ProgressLogger`], with default log target set to [`std::module_path!`],
1354/// and key-value pairs instead of setters.
1355///
1356/// # Examples
1357///
1358/// ```rust
1359/// # use dsi_progress_logger::prelude::*;
1360/// let mut pl = concurrent_progress_logger![item_name = "pumpkin", display_memory = true];
1361/// ```
1362#[macro_export]
1363macro_rules! concurrent_progress_logger {
1364 ($($method:ident = $arg:expr),* $(,)?) => {
1365 {
1366 let mut cpl = $crate::ConcurrentWrapper::default();
1367 $crate::ProgressLog::log_target(&mut cpl, ::std::module_path!());
1368 $(
1369 $crate::ProgressLog::$method(&mut cpl, $arg);
1370 )*
1371 cpl
1372 }
1373 }
1374}
1375
1376impl ConcurrentWrapper {
1377 /// Creates a new [`ConcurrentWrapper`] based on a default
1378 /// [`ProgressLogger`], using the [default
1379 /// threshold](Self::DEFAULT_THRESHOLD).
1380 pub fn new() -> Self {
1381 Self::with_threshold(Self::DEFAULT_THRESHOLD)
1382 }
1383
1384 /// Creates a new [`ConcurrentWrapper`] wrapping a default
1385 /// [`ProgressLogger`], using the given threshold.
1386 pub fn with_threshold(threshold: u32) -> Self {
1387 Self {
1388 inner: Arc::new(Mutex::new(ProgressLogger::default())),
1389 local_count: 0,
1390 threshold,
1391 }
1392 }
1393}
1394
1395impl<P: ProgressLog> ConcurrentWrapper<P> {
1396 /// The default threshold for updating the underlying logger.
1397 pub const DEFAULT_THRESHOLD: u32 = 1 << 15;
1398
1399 /// Calls to [`light_update`](ProgressLog::light_update) will cause a call
1400 /// to [`update_with_count`](ProgressLog::update_with_count) only if the
1401 /// current local count is a multiple of this mask plus one.
1402 ///
1403 /// Note that this constant is significantly smaller than the one used in
1404 /// [`ProgressLogger`], as updates will be further delayed by the threshold
1405 /// mechanism.
1406 pub const LIGHT_UPDATE_MASK: u32 = (1 << 10) - 1;
1407
1408 /// Sets the threshold for updating the underlying logger.
1409 ///
1410 /// Note that concurrent loggers with the same underlying logger
1411 /// have independent thresholds.
1412 pub fn threshold(&mut self, threshold: u32) -> &mut Self {
1413 self.threshold = threshold;
1414 self
1415 }
1416
1417 /// Wraps a given [`ProgressLog`] in a [`ConcurrentWrapper`]
1418 /// using the [default threshold](Self::DEFAULT_THRESHOLD).
1419 pub fn wrap(inner: P) -> Self {
1420 Self {
1421 inner: Arc::new(Mutex::new(inner)),
1422 local_count: 0,
1423 threshold: Self::DEFAULT_THRESHOLD,
1424 }
1425 }
1426
1427 /// Wraps a given [`ProgressLog`] in a [`ConcurrentWrapper`] using a
1428 /// given threshold.
1429 pub fn wrap_with_threshold(inner: P, threshold: u32) -> Self {
1430 Self {
1431 inner: Arc::new(Mutex::new(inner)),
1432 local_count: 0,
1433 threshold,
1434 }
1435 }
1436
1437 /// Forces an update of the underlying logger with the current local count.
1438 pub fn flush(&mut self) {
1439 self.inner
1440 .lock()
1441 .unwrap()
1442 .update_with_count(self.local_count as _);
1443 self.local_count = 0;
1444 }
1445}
1446
1447impl<P: ProgressLog + Clone> ConcurrentWrapper<P> {
1448 /// Duplicates the concurrent wrapper, obtaining a new one with the same
1449 /// threshold, with a local count of zero, and with an inner
1450 /// [`ProgressLog`] that is a clone of the original one.
1451 pub fn dup(&self) -> Self {
1452 Self {
1453 inner: Arc::new(Mutex::new(self.inner.lock().unwrap().clone())),
1454 local_count: 0,
1455 threshold: self.threshold,
1456 }
1457 }
1458}
1459
1460impl<P: ProgressLog + Clone + Send> ConcurrentProgressLog for ConcurrentWrapper<P> {
1461 type Duplicated = ConcurrentWrapper<P>;
1462 fn dup(&self) -> Self {
1463 Self {
1464 inner: Arc::new(Mutex::new(self.inner.lock().unwrap().clone())),
1465 local_count: 0,
1466 threshold: self.threshold,
1467 }
1468 }
1469}
1470
1471impl<P: ProgressLog + Clone + Send> ProgressLog for ConcurrentWrapper<P> {
1472 type Concurrent = Self;
1473
1474 fn log(&mut self, now: Instant) {
1475 self.inner.lock().unwrap().log(now);
1476 }
1477
1478 fn log_if(&mut self, now: Instant) {
1479 self.inner.lock().unwrap().log_if(now);
1480 }
1481
1482 fn add_to_count(&mut self, count: usize) {
1483 self.inner.lock().unwrap().add_to_count(count);
1484 }
1485
1486 fn display_memory(&mut self, display_memory: bool) -> &mut Self {
1487 self.inner.lock().unwrap().display_memory(display_memory);
1488 self
1489 }
1490
1491 fn item_name(&mut self, item_name: impl AsRef<str>) -> &mut Self {
1492 self.inner.lock().unwrap().item_name(item_name);
1493 self
1494 }
1495
1496 fn log_interval(&mut self, log_interval: Duration) -> &mut Self {
1497 self.inner.lock().unwrap().log_interval(log_interval);
1498 self
1499 }
1500
1501 fn expected_updates(&mut self, expected_updates: impl Into<Option<usize>>) -> &mut Self {
1502 self.inner
1503 .lock()
1504 .unwrap()
1505 .expected_updates(expected_updates.into());
1506 self
1507 }
1508
1509 fn time_unit(&mut self, time_unit: impl Into<Option<TimeUnit>>) -> &mut Self {
1510 self.inner.lock().unwrap().time_unit(time_unit.into());
1511 self
1512 }
1513
1514 fn local_speed(&mut self, local_speed: bool) -> &mut Self {
1515 self.inner.lock().unwrap().local_speed(local_speed);
1516 self
1517 }
1518
1519 fn log_target(&mut self, target: impl AsRef<str>) -> &mut Self {
1520 self.inner.lock().unwrap().log_target(target);
1521 self
1522 }
1523
1524 fn push_log_target(&mut self, suffix: impl AsRef<str>) -> &mut Self {
1525 self.inner.lock().unwrap().push_log_target(suffix);
1526 self
1527 }
1528
1529 fn pop_log_target(&mut self) -> &mut Self {
1530 self.inner.lock().unwrap().pop_log_target();
1531 self
1532 }
1533
1534 fn log_level(&mut self, log_level: Level) -> &mut Self {
1535 self.inner.lock().unwrap().log_level(log_level);
1536 self
1537 }
1538
1539 fn start(&mut self, msg: impl AsRef<str>) {
1540 self.inner.lock().unwrap().start(msg);
1541 self.local_count = 0;
1542 }
1543
1544 #[inline]
1545 fn update(&mut self) {
1546 self.update_with_count(1)
1547 }
1548
1549 #[inline]
1550 fn update_with_count_and_time(&mut self, count: usize, _now: Instant) {
1551 self.update_with_count(count);
1552 }
1553
1554 #[inline]
1555 fn update_with_count(&mut self, count: usize) {
1556 match (self.local_count as usize).checked_add(count) {
1557 None => {
1558 // Sum overflows, update in two steps
1559 {
1560 let now = Instant::now();
1561 let mut inner = self.inner.lock().unwrap();
1562 inner.update_with_count_and_time(self.local_count as _, now);
1563 inner.update_with_count_and_time(count, now);
1564 }
1565 self.local_count = 0;
1566 }
1567 Some(total_count) => {
1568 if total_count >= self.threshold as usize {
1569 self.local_count = 0;
1570 // Threshold reached, time to flush to the inner ProgressLog
1571 let now = Instant::now();
1572 self.inner
1573 .lock()
1574 .unwrap()
1575 .update_with_count_and_time(total_count, now);
1576 } else {
1577 // total_count is lower than self.threshold, which is a u32;
1578 // so total_count fits in u32.
1579 self.local_count = total_count as u32;
1580 }
1581 }
1582 }
1583 }
1584
1585 #[inline]
1586 fn light_update(&mut self) {
1587 self.local_count += 1;
1588 if (self.local_count & Self::LIGHT_UPDATE_MASK) == 0 && self.local_count >= self.threshold {
1589 // Threshold reached, time to flush to the inner ProgressLog
1590 let local_count = self.local_count as usize;
1591 self.local_count = 0;
1592 let now = Instant::now();
1593 self.inner
1594 .lock()
1595 .unwrap()
1596 .update_with_count_and_time(local_count, now);
1597 }
1598 }
1599
1600 fn update_and_display(&mut self) {
1601 {
1602 let mut inner = self.inner.lock().unwrap();
1603 inner.add_to_count(self.local_count as _);
1604 inner.update_and_display();
1605 }
1606 self.local_count = 0;
1607 }
1608
1609 fn stop(&mut self) {
1610 self.flush();
1611 self.inner.lock().unwrap().stop();
1612 }
1613
1614 fn done(&mut self) {
1615 self.flush();
1616 self.inner.lock().unwrap().done();
1617 }
1618
1619 fn done_with_count(&mut self, count: usize) {
1620 self.flush();
1621 self.inner.lock().unwrap().done_with_count(count);
1622 }
1623
1624 fn elapsed(&self) -> Option<Duration> {
1625 self.inner.lock().unwrap().elapsed()
1626 }
1627
1628 fn count(&self) -> usize {
1629 self.inner.lock().unwrap().count()
1630 }
1631
1632 fn refresh(&mut self) {
1633 self.inner.lock().unwrap().refresh();
1634 }
1635
1636 fn trace(&self, args: Arguments<'_>) {
1637 self.inner.lock().unwrap().trace(args);
1638 }
1639
1640 fn debug(&self, args: Arguments<'_>) {
1641 self.inner.lock().unwrap().debug(args);
1642 }
1643
1644 fn info(&self, args: Arguments<'_>) {
1645 self.inner.lock().unwrap().info(args);
1646 }
1647
1648 fn warn(&self, args: Arguments<'_>) {
1649 self.inner.lock().unwrap().warn(args);
1650 }
1651
1652 fn error(&self, args: Arguments<'_>) {
1653 self.inner.lock().unwrap().error(args);
1654 }
1655
1656 fn concurrent(&self) -> Self::Concurrent {
1657 self.dup()
1658 }
1659}
1660
1661/// This implementation just calls [`flush`](ConcurrentWrapper::flush),
1662/// to guarantee that all updates are correctly passed to the underlying logger.
1663impl<P: ProgressLog> Drop for ConcurrentWrapper<P> {
1664 fn drop(&mut self) {
1665 self.flush();
1666 }
1667}
1668
1669impl Display for ConcurrentWrapper {
1670 fn fmt(&self, f: &mut Formatter<'_>) -> Result {
1671 self.inner.lock().unwrap().fmt(f)
1672 }
1673}
1674
1675/// Convenience macro specifying that no (concurrent) logging should be
1676/// performed.
1677#[macro_export]
1678macro_rules! no_logging {
1679 () => {
1680 &mut Option::<$crate::ConcurrentWrapper<$crate::ProgressLogger>>::None
1681 };
1682}
1683
1684pub mod prelude {
1685 pub use log::Level;
1686
1687 pub use super::{
1688 ConcurrentProgressLog, ConcurrentWrapper, ProgressLog, ProgressLogger, TimeUnit,
1689 concurrent_progress_logger, no_logging, progress_logger,
1690 };
1691}