diff --git a/.travis.yml b/.travis.yml index 26cc3243943..d582eb33018 100644 --- a/.travis.yml +++ b/.travis.yml @@ -28,7 +28,7 @@ matrix: script: - cargo test - cargo test --tests --no-default-features - - cargo test --features serde-1 + - cargo test --features serde-1,log - cargo test --tests --no-default-features --features=serde-1 - cargo test --manifest-path rand-derive/Cargo.toml diff --git a/Cargo.toml b/Cargo.toml index f3df538adb7..efe1c0d2ea4 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -32,6 +32,8 @@ libc = { version = "0.2", optional = true } winapi = { version = "0.3", features = ["minwindef", "ntsecapi", "profileapi", "winnt"], optional = true } [dependencies] +log = { version = "0.4", optional = true } + serde = {version="1",optional=true} serde_derive = {version="1", optional=true} diff --git a/README.md b/README.md index 2dd47a39d88..54d069e1a64 100644 --- a/README.md +++ b/README.md @@ -33,8 +33,7 @@ changes since the `0.3` series, but nevertheless contains some significant new code, including a new "external" entropy source (`JitterRng`) and `no_std` support. -Version `0.5` is in development and contains significant performance -improvements for the ISAAC random number generators. +Version `0.5` is in development and will contain significant breaking changes. ## Examples @@ -68,21 +67,22 @@ println!("i32: {}, u32: {}", rng.gen::(), rng.gen::()) By default, `rand` is built with all stable features available. The following optional features are available: +- `alloc` can be used instead of `std` to provide `Vec` and `Box` - `i128_support` enables support for generating `u128` and `i128` values +- `log` enables some logging via the `log` crate - `nightly` enables all unstable features (`i128_support`) +- `serde-1` enables serialisation for some types, via Serde version 1 - `std` enabled by default; by setting "default-features = false" `no_std` mode is activated; this removes features depending on `std` functionality: - - - `OsRng` is entirely unavailable - - `JitterRng` code is still present, but a nanosecond timer must be - provided via `JitterRng::new_with_timer` - - Since no external entropy is available, it is not possible to create - generators with fresh seeds (user must provide entropy) - - `thread_rng`, `weak_rng` and `random` are all disabled - - exponential, normal and gamma type distributions are unavailable - since `exp` and `log` functions are not provided in `core` - - any code requiring `Vec` or `Box` -- `alloc` can be used instead of `std` to provide `Vec` and `Box` + - `OsRng` is entirely unavailable + - `JitterRng` code is still present, but a nanosecond timer must be + provided via `JitterRng::new_with_timer` + - Since no external entropy is available, it is not possible to create + generators with fresh seeds (user must provide entropy) + - `thread_rng`, `weak_rng` and `random` are all disabled + - exponential, normal and gamma type distributions are unavailable + since `exp` and `log` functions are not provided in `core` + - any code requiring `Vec` or `Box` ## Testing diff --git a/src/jitter.rs b/src/jitter.rs index c7f8ed679cf..a3914834b5d 100644 --- a/src/jitter.rs +++ b/src/jitter.rs @@ -142,6 +142,7 @@ impl JitterRng { // This allows the timer test to run multiple times; we don't care. rounds = ec.test_timer()?; JITTER_ROUNDS.store(rounds as usize, Ordering::Relaxed); + info!("JitterRng: using {} rounds per u64 output", rounds); } ec.set_rounds(rounds); Ok(ec) @@ -422,6 +423,8 @@ impl JitterRng { } fn gen_entropy(&mut self) -> u64 { + trace!("JitterRng: collecting entropy"); + // Prime `self.prev_time`, and run the noice sources to make sure the // first loop round collects the expected entropy. let _ = self.measure_jitter(); @@ -444,6 +447,7 @@ impl JitterRng { /// to collect 64 bits of entropy. Otherwise a `TimerError` with the cause /// of the failure will be returned. pub fn test_timer(&mut self) -> Result { + debug!("JitterRng: testing timer ..."); // We could add a check for system capabilities such as `clock_getres` // or check for `CONFIG_X86_TSC`, but it does not make much sense as the // following sanity checks verify that we have a high-resolution timer. diff --git a/src/lib.rs b/src/lib.rs index 089446084f0..fbec03b23f5 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -249,10 +249,18 @@ #[cfg(feature="std")] extern crate std as core; #[cfg(all(feature = "alloc", not(feature="std")))] extern crate alloc; + #[cfg(test)] #[cfg(feature="serde-1")] extern crate bincode; #[cfg(feature="serde-1")] extern crate serde; #[cfg(feature="serde-1")] #[macro_use] extern crate serde_derive; +#[cfg(feature = "log")] #[macro_use] extern crate log; +#[cfg(not(feature = "log"))] macro_rules! trace { ($($x:tt)*) => () } +#[cfg(not(feature = "log"))] macro_rules! debug { ($($x:tt)*) => () } +#[cfg(all(feature="std", not(feature = "log")))] macro_rules! info { ($($x:tt)*) => () } +#[cfg(all(feature="std", not(feature = "log")))] macro_rules! warn { ($($x:tt)*) => () } + + use core::{marker, mem}; #[cfg(feature="std")] use std::cell::RefCell; #[cfg(feature="std")] use std::rc::Rc; @@ -846,9 +854,11 @@ impl NewRng for R { T::from_rng(&mut r) } + trace!("Seeding new RNG"); new_os().or_else(|e1| { + warn!("OsRng failed [falling back to JitterRng]: {:?}", e1); new_jitter().map_err(|_e2| { - // TODO: log + warn!("JitterRng failed: {:?}", _e2); // TODO: can we somehow return both error sources? Error::with_cause( ErrorKind::Unavailable, diff --git a/src/os.rs b/src/os.rs index c36b5f52b02..fb622f9d3e2 100644 --- a/src/os.rs +++ b/src/os.rs @@ -69,23 +69,35 @@ impl Rng for OsRng { const MAX_WAIT: u32 = (10 * 1000) / WAIT_DUR_MS; // max 10s const TRANSIENT_STEP: u32 = MAX_WAIT / 8; let mut err_count = 0; + let mut log_err = 0; // log when err_count >= log_err loop { if let Err(e) = self.try_fill_bytes(dest) { - // TODO: add logging to explain why we wait and the full cause + if log_err == 0 { + warn!("OsRng failed: {:?}", e); + } + if e.kind().should_retry() { if err_count > MAX_WAIT { panic!("Too many RNG errors or timeout; last error: {}", e.msg()); } if e.kind().should_wait() { + err_count += 1; + if err_count >= log_err { + log_err += TRANSIENT_STEP; + warn!("OsRng: waiting and retrying ..."); + } #[cfg(feature="std")]{ let dur = ::std::time::Duration::from_millis(WAIT_DUR_MS as u64); ::std::thread::sleep(dur); } - err_count += 1; } else { err_count += TRANSIENT_STEP; + if err_count >= log_err { + log_err += TRANSIENT_STEP; + warn!("OsRng: retrying ..."); + } } continue; @@ -130,6 +142,7 @@ impl ReadRng { let mutex = unsafe{ READ_RNG_FILE.as_ref().unwrap() }; let mut guard = mutex.lock().unwrap(); if (*guard).is_none() { + info!("OsRng: opening random device {}", path.as_ref().display()); let file = File::open(path).map_err(|err| Error::with_cause( ErrorKind::Unavailable, "error opening random device", @@ -142,6 +155,7 @@ impl ReadRng { } fn try_fill_bytes(&mut self, dest: &mut [u8]) -> Result<(), Error> { + trace!("OsRng: reading {} bytes from random device", dest.len()); if dest.len() == 0 { return Ok(()); } // Since we have an instance of Self, we can assume that our memory was @@ -211,6 +225,7 @@ mod imp { fn getrandom(_buf: &mut [u8]) -> libc::c_long { -1 } fn getrandom_try_fill(v: &mut [u8]) -> Result<(), Error> { + trace!("OsRng: reading {} bytes via getrandom", v.len()); let mut read = 0; let len = v.len(); while read < len { @@ -253,6 +268,7 @@ mod imp { static AVAILABLE: AtomicBool = ATOMIC_BOOL_INIT; CHECKER.call_once(|| { + debug!("OsRng: testing getrandom"); let mut buf: [u8; 0] = []; let result = getrandom(&mut buf); let available = if result == -1 { @@ -262,6 +278,7 @@ mod imp { true }; AVAILABLE.store(available, Ordering::Relaxed); + info!("OsRng: using {}", if available { "getrandom" } else { "/dev/urandom" }); }); AVAILABLE.load(Ordering::Relaxed) @@ -320,6 +337,7 @@ mod imp { } pub fn try_fill_bytes(&mut self, v: &mut [u8]) -> Result<(), Error> { + trace!("OsRng: reading {} bytes via cloadabi::random_get", v.len()); if unsafe { cloudabi::random_get(v) } == cloudabi::errno::SUCCESS { Ok(()) } else { @@ -360,6 +378,7 @@ mod imp { Ok(OsRng) } pub fn try_fill_bytes(&mut self, v: &mut [u8]) -> Result<(), Error> { + trace!("OsRng: reading {} bytes via SecRandomCopyBytes", v.len()); let ret = unsafe { SecRandomCopyBytes(kSecRandomDefault, v.len() as size_t, v.as_mut_ptr()) }; @@ -395,6 +414,7 @@ mod imp { // kern.arandom permits a maximum buffer size of 256 bytes for s in v.chunks_mut(256) { let mut s_len = s.len(); + trace!("OsRng: reading {} bytes via kern.arandom", v.len()); let ret = unsafe { libc::sysctl(mib.as_ptr(), mib.len() as libc::c_uint, s.as_mut_ptr() as *mut _, &mut s_len, @@ -429,6 +449,7 @@ mod imp { pub fn try_fill_bytes(&mut self, v: &mut [u8]) -> Result<(), Error> { // getentropy(2) permits a maximum buffer size of 256 bytes for s in v.chunks_mut(256) { + trace!("OsRng: reading {} bytes via getentropy", s.len()); let ret = unsafe { libc::getentropy(s.as_mut_ptr() as *mut libc::c_void, s.len()) }; @@ -482,6 +503,7 @@ mod imp { } pub fn try_fill_bytes(&mut self, v: &mut [u8]) -> Result<(), Error> { for s in v.chunks_mut(fuchsia_zircon::sys::ZX_CPRNG_DRAW_MAX_LEN) { + trace!("OsRng: reading {} bytes via cprng_draw", s.len()); let mut filled = 0; while filled < s.len() { match fuchsia_zircon::cprng_draw(&mut s[filled..]) { @@ -523,6 +545,7 @@ mod imp { // RtlGenRandom takes an ULONG (u32) for the length so we need to // split up the buffer. for slice in v.chunks_mut(::max_value() as usize) { + trace!("OsRng: reading {} bytes via RtlGenRandom", slice.len()); let ret = unsafe { RtlGenRandom(slice.as_mut_ptr() as PVOID, slice.len() as ULONG) }; diff --git a/src/reseeding.rs b/src/reseeding.rs index e119e1c0350..b9a9b7a2f56 100644 --- a/src/reseeding.rs +++ b/src/reseeding.rs @@ -47,6 +47,7 @@ impl> ReseedingRng { /// generated exceed the threshold. pub fn reseed_if_necessary(&mut self) { if self.bytes_generated >= self.generation_threshold { + trace!("Reseeding RNG after {} bytes", self.bytes_generated); self.reseeder.reseed(&mut self.rng).unwrap(); self.bytes_generated = 0; }