diff --git a/testing/geckodriver/Cargo.lock b/testing/geckodriver/Cargo.lock index f4eed0ad3a2a..fcede98befd2 100644 --- a/testing/geckodriver/Cargo.lock +++ b/testing/geckodriver/Cargo.lock @@ -62,6 +62,11 @@ name = "cc" version = "1.0.3" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "cfg-if" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" + [[package]] name = "chrono" version = "0.2.25" @@ -91,11 +96,6 @@ dependencies = [ "time 0.1.38 (registry+https://github.com/rust-lang/crates.io-index)", ] -[[package]] -name = "crossbeam" -version = "0.2.10" -source = "registry+https://github.com/rust-lang/crates.io-index" - [[package]] name = "flate2" version = "0.2.20" @@ -129,16 +129,12 @@ dependencies = [ "clap 2.29.0 (registry+https://github.com/rust-lang/crates.io-index)", "hyper 0.10.13 (registry+https://github.com/rust-lang/crates.io-index)", "lazy_static 0.1.16 (registry+https://github.com/rust-lang/crates.io-index)", - "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", + "log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)", "mozprofile 0.3.0", "mozrunner 0.5.0", "mozversion 0.1.2", "regex 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", "rustc-serialize 0.3.24 (registry+https://github.com/rust-lang/crates.io-index)", - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-atomic 0.4.3 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-stdlog 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-stream 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)", "uuid 0.1.18 (registry+https://github.com/rust-lang/crates.io-index)", "webdriver 0.33.0", "zip 0.1.19 (registry+https://github.com/rust-lang/crates.io-index)", @@ -177,16 +173,6 @@ dependencies = [ "unicode-normalization 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)", ] -[[package]] -name = "isatty" -version = "0.1.5" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)", - "libc 0.2.33 (registry+https://github.com/rust-lang/crates.io-index)", - "winapi 0.2.8 (registry+https://github.com/rust-lang/crates.io-index)", -] - [[package]] name = "kernel32-sys" version = "0.1.4" @@ -239,6 +225,14 @@ name = "log" version = "0.3.8" source = "registry+https://github.com/rust-lang/crates.io-index" +[[package]] +name = "log" +version = "0.4.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +dependencies = [ + "cfg-if 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", +] + [[package]] name = "matches" version = "0.1.6" @@ -416,63 +410,6 @@ name = "semver-parser" version = "0.7.0" source = "registry+https://github.com/rust-lang/crates.io-index" -[[package]] -name = "slog" -version = "1.6.0" -source = "registry+https://github.com/rust-lang/crates.io-index" - -[[package]] -name = "slog-atomic" -version = "0.4.3" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "crossbeam 0.2.10 (registry+https://github.com/rust-lang/crates.io-index)", - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", -] - -[[package]] -name = "slog-extra" -version = "0.1.2" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", - "thread_local 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", -] - -[[package]] -name = "slog-stdlog" -version = "1.1.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "crossbeam 0.2.10 (registry+https://github.com/rust-lang/crates.io-index)", - "lazy_static 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)", - "log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)", - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-term 1.5.0 (registry+https://github.com/rust-lang/crates.io-index)", -] - -[[package]] -name = "slog-stream" -version = "1.2.1" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-extra 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)", - "thread_local 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", -] - -[[package]] -name = "slog-term" -version = "1.5.0" -source = "registry+https://github.com/rust-lang/crates.io-index" -dependencies = [ - "chrono 0.2.25 (registry+https://github.com/rust-lang/crates.io-index)", - "isatty 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)", - "slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)", - "slog-stream 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)", - "thread_local 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)", -] - [[package]] name = "strsim" version = "0.6.0" @@ -660,17 +597,16 @@ dependencies = [ "checksum bzip2 0.3.2 (registry+https://github.com/rust-lang/crates.io-index)" = "c3eafc42c44e0d827de6b1c131175098fe7fb53b8ce8a47e65cb3ea94688be24" "checksum bzip2-sys 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)" = "2c5162604199bbb17690ede847eaa6120a3f33d5ab4dcc8e7c25b16d849ae79b" "checksum cc 1.0.3 (registry+https://github.com/rust-lang/crates.io-index)" = "a9b13a57efd6b30ecd6598ebdb302cca617930b5470647570468a65d12ef9719" +"checksum cfg-if 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "d4c819a1287eb618df47cc647173c5c4c66ba19d888a6e50d605672aed3140de" "checksum chrono 0.2.25 (registry+https://github.com/rust-lang/crates.io-index)" = "9213f7cd7c27e95c2b57c49f0e69b1ea65b27138da84a170133fd21b07659c00" "checksum clap 2.29.0 (registry+https://github.com/rust-lang/crates.io-index)" = "110d43e343eb29f4f51c1db31beb879d546db27998577e5715270a54bcf41d3f" "checksum cookie 0.10.1 (registry+https://github.com/rust-lang/crates.io-index)" = "746858cae4eae40fff37e1998320068df317bc247dc91a67c6cfa053afdc2abb" -"checksum crossbeam 0.2.10 (registry+https://github.com/rust-lang/crates.io-index)" = "0c5ea215664ca264da8a9d9c3be80d2eaf30923c259d03e870388eb927508f97" "checksum flate2 0.2.20 (registry+https://github.com/rust-lang/crates.io-index)" = "e6234dd4468ae5d1e2dbb06fe2b058696fdc50a339c68a393aefbf00bc81e423" "checksum fuchsia-zircon 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "f6c0581a4e363262e52b87f59ee2afe3415361c6ec35e665924eb08afe8ff159" "checksum fuchsia-zircon-sys 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "43f3795b4bae048dc6123a6b972cadde2e676f9ded08aef6bb77f5f157684a82" "checksum httparse 1.2.3 (registry+https://github.com/rust-lang/crates.io-index)" = "af2f2dd97457e8fb1ae7c5a420db346af389926e36f43768b96f101546b04a07" "checksum hyper 0.10.13 (registry+https://github.com/rust-lang/crates.io-index)" = "368cb56b2740ebf4230520e2b90ebb0461e69034d85d1945febd9b3971426db2" "checksum idna 0.1.4 (registry+https://github.com/rust-lang/crates.io-index)" = "014b298351066f1512874135335d62a789ffe78a9974f94b43ed5621951eaf7d" -"checksum isatty 0.1.5 (registry+https://github.com/rust-lang/crates.io-index)" = "00c9301a947a2eaee7ce2556b80285dcc89558d07088962e6e8b9c25730f9dc6" "checksum kernel32-sys 0.1.4 (registry+https://github.com/rust-lang/crates.io-index)" = "e014dab1082fd9d80ea1fa6fcb261b47ed3eb511612a14198bb507701add083e" "checksum kernel32-sys 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)" = "7507624b29483431c0ba2d82aece8ca6cdba9382bff4ddd0f7490560c056098d" "checksum ktmw32-sys 0.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "7f9313a869ff779ae08dd990b75a92dc06aa16d771f41305f7286649cd39a0ee" @@ -679,6 +615,7 @@ dependencies = [ "checksum lazy_static 0.2.11 (registry+https://github.com/rust-lang/crates.io-index)" = "76f033c7ad61445c5b347c7382dd1237847eb1bce590fe50365dcb33d546be73" "checksum libc 0.2.33 (registry+https://github.com/rust-lang/crates.io-index)" = "5ba3df4dcb460b9dfbd070d41c94c19209620c191b0340b929ce748a2bcd42d2" "checksum log 0.3.8 (registry+https://github.com/rust-lang/crates.io-index)" = "880f77541efa6e5cc74e76910c9884d9859683118839d6a1dc3b11e63512565b" +"checksum log 0.4.1 (registry+https://github.com/rust-lang/crates.io-index)" = "89f010e843f2b1a31dbd316b3b8d443758bc634bed37aabade59c686d644e0a2" "checksum matches 0.1.6 (registry+https://github.com/rust-lang/crates.io-index)" = "100aabe6b8ff4e4a7e32c1c13523379802df0772b82466207ac25b013f193376" "checksum memchr 1.0.2 (registry+https://github.com/rust-lang/crates.io-index)" = "148fab2e51b4f1cfc66da2a7c32981d1d3c083a803978268bb11fe4b86925e7a" "checksum mime 0.2.6 (registry+https://github.com/rust-lang/crates.io-index)" = "ba626b8a6de5da682e1caa06bdb42a335aee5a84db8e5046a3e8ab17ba0a3ae0" @@ -700,12 +637,6 @@ dependencies = [ "checksum safemem 0.2.0 (registry+https://github.com/rust-lang/crates.io-index)" = "e27a8b19b835f7aea908818e871f5cc3a5a186550c30773be987e155e8163d8f" "checksum semver 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)" = "7a3186ec9e65071a2095434b1f5bb24838d4e8e130f584c790f6033c79943537" "checksum semver-parser 0.7.0 (registry+https://github.com/rust-lang/crates.io-index)" = "388a1df253eca08550bef6c72392cfe7c30914bf41df5269b68cbd6ff8f570a3" -"checksum slog 1.6.0 (registry+https://github.com/rust-lang/crates.io-index)" = "5b965551440d867da261b10d50871ae608537c56fbeb872a296b12add733acf1" -"checksum slog-atomic 0.4.3 (registry+https://github.com/rust-lang/crates.io-index)" = "d6f5a4e4908d6818fe553b6126ba5377801556ab885c65ebf960b722a6778864" -"checksum slog-extra 0.1.2 (registry+https://github.com/rust-lang/crates.io-index)" = "511581f4dd1dc90e4eca99b60be8a692d9c975e8757558aa774f16007d27492a" -"checksum slog-stdlog 1.1.0 (registry+https://github.com/rust-lang/crates.io-index)" = "56cc08f40c45e0ab41dcfde0a19a22c5b7176d3827fc7d078450ebfdc080a37c" -"checksum slog-stream 1.2.1 (registry+https://github.com/rust-lang/crates.io-index)" = "3fac4af71007ddb7338f771e059a46051f18d1454d8ac556f234a0573e719daa" -"checksum slog-term 1.5.0 (registry+https://github.com/rust-lang/crates.io-index)" = "cb53c0bae0745898fd5a7b75b1c389507333470ac4c645ae431890c0f828b6ca" "checksum strsim 0.6.0 (registry+https://github.com/rust-lang/crates.io-index)" = "b4d15c810519a91cf877e7e36e63fe068815c678181439f2f29e2562147c3694" "checksum tempdir 0.3.5 (registry+https://github.com/rust-lang/crates.io-index)" = "87974a6f5c1dfb344d733055601650059a3363de2a6104819293baff662132d6" "checksum term_size 0.3.0 (registry+https://github.com/rust-lang/crates.io-index)" = "e2b6b55df3198cc93372e85dd2ed817f0e38ce8cc0f22eb32391bfad9c4bf209" diff --git a/testing/geckodriver/Cargo.toml b/testing/geckodriver/Cargo.toml index c3e74d733f14..4edfd6da57b5 100644 --- a/testing/geckodriver/Cargo.toml +++ b/testing/geckodriver/Cargo.toml @@ -14,16 +14,12 @@ chrono = "^0.2" clap = { version = "^2.19", default-features = false, features = ["suggestions", "wrap_help"] } hyper = "0.10" lazy_static = "0.1" -log = "0.3" +log = { version = "0.4", features = ["std"] } mozprofile = { path = "../mozbase/rust/mozprofile" } mozrunner = { path = "../mozbase/rust/mozrunner" } mozversion = { path = "../mozbase/rust/mozversion" } regex = "0.2" rustc-serialize = "0.3" -slog = "1" -slog-atomic = "0.4" -slog-stdlog = "1" -slog-stream = "1" uuid = "0.1.18" webdriver = { path = "../webdriver" } zip = "0.1" diff --git a/testing/geckodriver/src/capabilities.rs b/testing/geckodriver/src/capabilities.rs index 9a925dea60df..c5adfcecaf9f 100644 --- a/testing/geckodriver/src/capabilities.rs +++ b/testing/geckodriver/src/capabilities.rs @@ -1,4 +1,4 @@ -use logging::LogLevel; +use logging::Level; use marionette::LogOptions; use mozprofile::preferences::Pref; use mozprofile::profile::Profile; @@ -200,11 +200,10 @@ impl<'a> BrowserCapabilities for FirefoxCapabilities<'a> { let level = try_opt!(log_value.as_string(), ErrorStatus::InvalidArgument, "log level is not a string"); - if LogLevel::from_str(level).is_err() { + if Level::from_str(level).is_err() { return Err(WebDriverError::new( ErrorStatus::InvalidArgument, - format!("{} is not a valid log level", - level))) + format!("Not a valid log level: {}", level))) } } x => return Err(WebDriverError::new( @@ -342,25 +341,26 @@ impl FirefoxOptions { fn load_log(options: &Capabilities) -> WebDriverResult { if let Some(json) = options.get("log") { - let log = try!(json.as_object() - .ok_or(WebDriverError::new(ErrorStatus::InvalidArgument, - "Log section is not an object"))); + let log = json.as_object().ok_or(WebDriverError::new( + ErrorStatus::InvalidArgument, + "Log section is not an object", + ))?; let level = match log.get("level") { Some(json) => { - let s = try!(json.as_string() - .ok_or(WebDriverError::new(ErrorStatus::InvalidArgument, - "Log level is not a string"))); - Some(try!(LogLevel::from_str(s) - .ok() - .ok_or(WebDriverError::new(ErrorStatus::InvalidArgument, - "Log level is unknown")))) + let s = json.as_string().ok_or(WebDriverError::new( + ErrorStatus::InvalidArgument, + "Log level is not a string", + ))?; + Some(Level::from_str(s).ok().ok_or(WebDriverError::new( + ErrorStatus::InvalidArgument, + "Log level is unknown", + ))?) } None => None, }; - Ok(LogOptions { level: level }) - + Ok(LogOptions { level }) } else { Ok(Default::default()) } diff --git a/testing/geckodriver/src/logging.rs b/testing/geckodriver/src/logging.rs index a1c99a7b0930..4b3ad8c57953 100644 --- a/testing/geckodriver/src/logging.rs +++ b/testing/geckodriver/src/logging.rs @@ -1,158 +1,290 @@ +//! Gecko-esque logger implementation for the [`log`] crate. +//! +//! The [`log`] crate provides a single logging API that abstracts over the +//! actual logging implementation. This module uses the logging API +//! to provide a log implementation that shares many aesthetical traits with +//! [Log.jsm] from Gecko. +//! +//! Using the [`error!`], [`warn!`], [`info!`], [`debug!`], and +//! [`trace!`] macros from `log` will output a timestamp field, followed by the +//! log level, and then the message. The fields are separated by a tab +//! character, making the output suitable for further text processing with +//! `awk(1)`. +//! +//! This module shares the same API as `log`, except it provides additional +//! entry functions [`init`] and [`init_with_level`] and additional log levels +//! `Level::Fatal` and `Level::Config`. Converting these into the +//! [`log::Level`] is lossy so that `Level::Fatal` becomes `log::Level::Error` +//! and `Level::Config` becomes `log::Level::Debug`. +//! +//! [`log`]: https://docs.rs/log/newest/log/ +//! [Log.jsm]: https://developer.mozilla.org/en/docs/Mozilla/JavaScript_code_modules/Log.jsm +//! [`error!`]: https://docs.rs/log/newest/log/macro.error.html +//! [`warn!`]: https://docs.rs/log/newest/log/macro.warn.html +//! [`info!`]: https://docs.rs/log/newest/log/macro.info.html +//! [`debug!`]: https://docs.rs/log/newest/log/macro.debug.html +//! [`trace!`]: https://docs.rs/log/newest/log/macro.trace.html +//! [`init`]: fn.init.html +//! [`init_with_level`]: fn.init_with_level.html + +use chrono; +use log; use std::fmt; use std::io; -use std::str::FromStr; -use std::sync::atomic::AtomicBool; -use std::sync::atomic::Ordering::SeqCst; +use std::io::Write; +use std::str; +use std::sync::atomic::{ATOMIC_USIZE_INIT, AtomicUsize, Ordering}; -use chrono::{DateTime, Local}; -use slog; -use slog::DrainExt; -use slog_atomic::{AtomicSwitch, AtomicSwitchCtrl}; -use slog_stream::{stream, Format, Streamer}; -use slog::Level as SlogLevel; -use slog::{LevelFilter, Logger}; -use slog::{OwnedKeyValueList, Record}; -use slog_stdlog; +static MAX_LOG_LEVEL: AtomicUsize = ATOMIC_USIZE_INIT; -lazy_static! { - static ref ATOMIC_DRAIN: AtomicSwitchCtrl = AtomicSwitch::new( - slog::Discard.map_err(|_| io::Error::new(io::ErrorKind::Other, "should not happen")) - ).ctrl(); - static ref FIRST_RUN: AtomicBool = AtomicBool::new(true); +/// Logger levels from [Log.jsm]. +/// +/// [Log.jsm]: +/// https://developer.mozilla.org/en/docs/Mozilla/JavaScript_code_modules/Log. +/// jsm +#[repr(usize)] +#[derive(Clone, Copy, Eq, Debug, Hash, PartialEq)] +pub enum Level { + Fatal = 70, + Error = 60, + Warn = 50, + Info = 40, + Config = 30, + Debug = 20, + Trace = 10, } -static DEFAULT_LEVEL: &'static LogLevel = &LogLevel::Info; - -/// Logger levels from [Log.jsm] -/// (https://developer.mozilla.org/en/docs/Mozilla/JavaScript_code_modules/Log.jsm). -#[derive(Debug, Clone)] -pub enum LogLevel { - Fatal, - Error, - Warn, - Info, - Config, - Debug, - Trace, +impl From for Level { + fn from(n: usize) -> Level { + use self::Level::*; + match n { + 70 => Fatal, + 60 => Error, + 50 => Warn, + 40 => Info, + 30 => Config, + 20 => Debug, + 10 => Trace, + _ => Info, + } + } } -impl fmt::Display for LogLevel { +impl fmt::Display for Level { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + use self::Level::*; let s = match *self { - LogLevel::Fatal => "FATAL", - LogLevel::Error => "ERROR", - LogLevel::Warn => "WARN", - LogLevel::Info => "INFO", - LogLevel::Config => "CONFIG", - LogLevel::Debug => "DEBUG", - LogLevel::Trace => "TRACE", + Fatal => "FATAL", + Error => "ERROR", + Warn => "WARN", + Info => "INFO", + Config => "CONFIG", + Debug => "DEBUG", + Trace => "TRACE", }; write!(f, "{}", s) } } -impl FromStr for LogLevel { +impl str::FromStr for Level { type Err = (); - fn from_str(s: &str) -> Result { - match s { - "fatal" => Ok(LogLevel::Fatal), - "error" => Ok(LogLevel::Error), - "warn" => Ok(LogLevel::Warn), - "info" => Ok(LogLevel::Info), - "config" => Ok(LogLevel::Config), - "debug" => Ok(LogLevel::Debug), - "trace" => Ok(LogLevel::Trace), + fn from_str(s: &str) -> Result { + use self::Level::*; + match s.to_lowercase().as_ref() { + "fatal" => Ok(Fatal), + "error" => Ok(Error), + "warn" => Ok(Warn), + "info" => Ok(Info), + "config" => Ok(Config), + "debug" => Ok(Debug), + "trace" => Ok(Trace), _ => Err(()), } } } -trait ToSlogLevel { - fn to_slog(&self) -> SlogLevel; -} - -impl ToSlogLevel for LogLevel { - fn to_slog(&self) -> SlogLevel { - match *self { - LogLevel::Fatal => SlogLevel::Critical, - LogLevel::Error => SlogLevel::Error, - LogLevel::Warn => SlogLevel::Warning, - LogLevel::Info => SlogLevel::Info, - LogLevel::Config | LogLevel::Debug => SlogLevel::Debug, - LogLevel::Trace => SlogLevel::Trace, +impl Into for Level { + fn into(self) -> log::Level { + use self::Level::*; + match self { + Fatal | Error => log::Level::Error, + Warn => log::Level::Warn, + Info => log::Level::Info, + Config | Debug => log::Level::Debug, + Trace => log::Level::Trace, } } } -trait ToGeckoLevel { - fn to_gecko(&self) -> LogLevel; -} - -impl ToGeckoLevel for SlogLevel { - fn to_gecko(&self) -> LogLevel { - match *self { - SlogLevel::Critical => LogLevel::Fatal, - SlogLevel::Error => LogLevel::Error, - SlogLevel::Warning => LogLevel::Warn, - SlogLevel::Info => LogLevel::Info, - SlogLevel::Debug => LogLevel::Debug, - SlogLevel::Trace => LogLevel::Trace, +impl From for Level { + fn from(log_level: log::Level) -> Level { + use log::Level::*; + match log_level { + Error => Level::Error, + Warn => Level::Warn, + Info => Level::Info, + Debug => Level::Debug, + Trace => Level::Trace, } } } -/// Initialise logger if it has not been already. The provided `level` -/// filters out log records below this granularity. -pub fn init(level: &Option) { - let effective_level = level.as_ref().unwrap_or(DEFAULT_LEVEL); +struct Logger; - let drain = filtered_gecko_log(&effective_level); - ATOMIC_DRAIN.set(drain); - - let first_run = FIRST_RUN.load(SeqCst); - FIRST_RUN.store(false, SeqCst); - if first_run { - let log = Logger::root(ATOMIC_DRAIN.drain().fuse(), o!()); - slog_stdlog::set_logger(log.clone()).unwrap(); +impl log::Log for Logger { + fn enabled(&self, meta: &log::Metadata) -> bool { + meta.level() <= log::max_level() } -} -fn filtered_gecko_log(level: &LogLevel) -> LevelFilter> { - let io = stream(io::stderr(), GeckoFormat {}); - slog::level_filter(level.to_slog(), io) -} - -struct GeckoFormat; - -impl Format for GeckoFormat { - fn format(&self, io: &mut io::Write, record: &Record, _: &OwnedKeyValueList) -> io::Result<()> { - // TODO(ato): Quite sure this is the wrong way to filter records with slog, - // but I do not comprehend how slog works. - let module = record.module(); - if module.starts_with("geckodriver") || module.starts_with("webdriver") || - module.starts_with("mozrunner") { - let ts = format_ts(Local::now()); - let level = record.level().to_gecko(); - let _ = try!(write!(io, "{}\t{}\t{}\t{}\n", ts, module, level, record.msg())); + fn log(&self, record: &log::Record) { + if self.enabled(record.metadata()) { + let ts = format_ts(chrono::Local::now()); + println!( + "{}\t{}\t{}\t{}", + ts, + record.target(), + record.level(), + record.args() + ); } - Ok(()) } + + fn flush(&self) { + io::stdout().flush().unwrap(); + } +} + +/// Initialises the logging subsystem with the default log level. +pub fn init() -> Result<(), log::SetLoggerError> { + init_with_level(Level::Info) +} + +/// Initialises the logging subsystem. +pub fn init_with_level(level: Level) -> Result<(), log::SetLoggerError> { + let logger = Logger {}; + set_max_level(level); + log::set_boxed_logger(Box::new(logger))?; + Ok(()) +} + +/// Returns the current maximum log level. +pub fn max_level() -> Level { + MAX_LOG_LEVEL.load(Ordering::Relaxed).into() +} + +/// Sets the global maximum log level. +pub fn set_max_level(level: Level) { + MAX_LOG_LEVEL.store(level as usize, Ordering::SeqCst); + + let slevel: log::Level = level.into(); + log::set_max_level(slevel.to_level_filter()) } /// Produces a 13-digit Unix Epoch timestamp similar to Gecko. -fn format_ts(ts: DateTime) -> String { +fn format_ts(ts: chrono::DateTime) -> String { format!("{}{:03}", ts.timestamp(), ts.timestamp_subsec_millis()) } #[cfg(test)] mod tests { - use chrono::Local; - use super::format_ts; + use super::{Level, format_ts, init, init_with_level, max_level, set_max_level}; + use chrono; + use log; + use std::str::FromStr; + + #[test] + fn test_level_repr() { + assert_eq!(Level::Fatal as usize, 70); + assert_eq!(Level::Error as usize, 60); + assert_eq!(Level::Warn as usize, 50); + assert_eq!(Level::Info as usize, 40); + assert_eq!(Level::Config as usize, 30); + assert_eq!(Level::Debug as usize, 20); + assert_eq!(Level::Trace as usize, 10); + } + + #[test] + fn test_level_eq() { + assert_eq!(Level::Fatal, Level::Fatal); + assert_eq!(Level::Error, Level::Error); + assert_eq!(Level::Warn, Level::Warn); + assert_eq!(Level::Info, Level::Info); + assert_eq!(Level::Config, Level::Config); + assert_eq!(Level::Debug, Level::Debug); + assert_eq!(Level::Trace, Level::Trace); + } + + #[test] + fn test_level_from_log() { + assert_eq!(Level::from(log::Level::Error), Level::Error); + assert_eq!(Level::from(log::Level::Warn), Level::Warn); + assert_eq!(Level::from(log::Level::Info), Level::Info); + assert_eq!(Level::from(log::Level::Debug), Level::Debug); + assert_eq!(Level::from(log::Level::Trace), Level::Trace); + } + + #[test] + fn test_level_into_log() { + assert_eq!(Into::::into(Level::Fatal), log::Level::Error); + assert_eq!(Into::::into(Level::Error), log::Level::Error); + assert_eq!(Into::::into(Level::Warn), log::Level::Warn); + assert_eq!(Into::::into(Level::Info), log::Level::Info); + assert_eq!(Into::::into(Level::Config), log::Level::Debug); + assert_eq!(Into::::into(Level::Debug), log::Level::Debug); + assert_eq!(Into::::into(Level::Trace), log::Level::Trace); + } + + #[test] + fn test_level_from_str() { + assert_eq!(Level::from_str("fatal"), Ok(Level::Fatal)); + assert_eq!(Level::from_str("error"), Ok(Level::Error)); + assert_eq!(Level::from_str("warn"), Ok(Level::Warn)); + assert_eq!(Level::from_str("info"), Ok(Level::Info)); + assert_eq!(Level::from_str("config"), Ok(Level::Config)); + assert_eq!(Level::from_str("debug"), Ok(Level::Debug)); + assert_eq!(Level::from_str("trace"), Ok(Level::Trace)); + + assert_eq!(Level::from_str("INFO"), Ok(Level::Info)); + + assert!(Level::from_str("foo").is_err()); + } + + #[test] + fn test_level_to_str() { + assert_eq!(Level::Fatal.to_string(), "FATAL"); + assert_eq!(Level::Error.to_string(), "ERROR"); + assert_eq!(Level::Warn.to_string(), "WARN"); + assert_eq!(Level::Info.to_string(), "INFO"); + assert_eq!(Level::Config.to_string(), "CONFIG"); + assert_eq!(Level::Debug.to_string(), "DEBUG"); + assert_eq!(Level::Trace.to_string(), "TRACE"); + } + + #[test] + fn test_max_level() { + set_max_level(Level::Info); + assert_eq!(max_level(), Level::Info); + } + + #[test] + fn test_set_max_level() { + set_max_level(Level::Error); + assert_eq!(max_level(), Level::Error); + set_max_level(Level::Fatal); + assert_eq!(max_level(), Level::Fatal); + } + + #[test] + fn test_init_with_level() { + init_with_level(Level::Debug).unwrap(); + assert_eq!(max_level(), Level::Debug); + assert!(init_with_level(Level::Warn).is_err()); + } #[test] fn test_format_ts() { - let ts = Local::now(); + let ts = chrono::Local::now(); let s = format_ts(ts); assert_eq!(s.len(), 13); } diff --git a/testing/geckodriver/src/main.rs b/testing/geckodriver/src/main.rs index 3c645fb356df..18df569cf761 100644 --- a/testing/geckodriver/src/main.rs +++ b/testing/geckodriver/src/main.rs @@ -9,11 +9,6 @@ extern crate mozrunner; extern crate mozversion; extern crate regex; extern crate rustc_serialize; -#[macro_use] -extern crate slog; -extern crate slog_atomic; -extern crate slog_stdlog; -extern crate slog_stream; extern crate uuid; extern crate zip; extern crate webdriver; @@ -43,7 +38,6 @@ mod prefs; mod marionette; mod capabilities; -use logging::LogLevel; use marionette::{MarionetteHandler, MarionetteSettings, extension_routes}; include!(concat!(env!("OUT_DIR"), "/build-info.rs")); @@ -180,22 +174,25 @@ fn run() -> ProgramResult { }; let log_level = if matches.is_present("log_level") { - LogLevel::from_str(matches.value_of("log_level").unwrap()).ok() + logging::Level::from_str(matches.value_of("log_level").unwrap()).ok() } else { match matches.occurrences_of("verbosity") { - 0 => Some(LogLevel::Info), - 1 => Some(LogLevel::Debug), - _ => Some(LogLevel::Trace), + 0 => Some(logging::Level::Info), + 1 => Some(logging::Level::Debug), + _ => Some(logging::Level::Trace), } }; - logging::init(&log_level); + if let Some(ref level) = log_level { + logging::init_with_level(level.clone()).unwrap(); + } else { + logging::init().unwrap(); + } info!("geckodriver {}", BuildInfo); let settings = MarionetteSettings { port: marionette_port, binary, - log_level, connect_existing: matches.is_present("connect_existing"), jsdebugger: matches.is_present("jsdebugger"), }; diff --git a/testing/geckodriver/src/marionette.rs b/testing/geckodriver/src/marionette.rs index 7d9c2b33d719..13cd45d51d55 100644 --- a/testing/geckodriver/src/marionette.rs +++ b/testing/geckodriver/src/marionette.rs @@ -1,6 +1,4 @@ use hyper::method::Method; -use logging; -use logging::LogLevel; use mozprofile::preferences::Pref; use mozprofile::profile::Profile; use mozrunner::runner::{FirefoxRunner, FirefoxProcess, Runner, RunnerProcess}; @@ -53,6 +51,7 @@ use webdriver::server::{WebDriverHandler, Session}; use webdriver::httpapi::{WebDriverExtensionRoute}; use capabilities::{FirefoxCapabilities, FirefoxOptions}; +use logging; use prefs; const DEFAULT_HOST: &'static str = "localhost"; @@ -373,7 +372,7 @@ impl ToMarionette for AddonUninstallParameters { #[derive(Default)] pub struct LogOptions { - pub level: Option, + pub level: Option, } #[derive(Default)] @@ -385,27 +384,20 @@ pub struct MarionetteSettings { /// Brings up the Browser Toolbox when starting Firefox, /// letting you debug internals. pub jsdebugger: bool, - - /// Optionally increase Marionette's verbosity by providing a log - /// level. The Gecko default is LogLevel::Info for optimised - /// builds and LogLevel::Debug for debug builds. - pub log_level: Option, } pub struct MarionetteHandler { connection: Mutex>, settings: MarionetteSettings, browser: Option, - current_log_level: Option, } impl MarionetteHandler { pub fn new(settings: MarionetteSettings) -> MarionetteHandler { MarionetteHandler { connection: Mutex::new(None), - settings: settings, + settings, browser: None, - current_log_level: None, } } @@ -427,8 +419,9 @@ impl MarionetteHandler { (options, capabilities) }; - self.current_log_level = options.log.level.clone().or(self.settings.log_level.clone()); - logging::init(&self.current_log_level); + if let Some(l) = options.log.level { + logging::set_max_level(l); + } let port = self.settings.port.unwrap_or(try!(get_free_port())); if !self.settings.connect_existing { @@ -463,7 +456,6 @@ impl MarionetteHandler { format!("Failed to set preferences: {}", e)) })?; - let mut runner = FirefoxRunner::new(&binary, profile); // https://developer.mozilla.org/docs/Environment_variables_affecting_crash_reporting @@ -515,9 +507,7 @@ impl MarionetteHandler { prefs.insert("marionette.debugging.clicktostart", Pref::new(true)); } - if let Some(ref level) = self.current_log_level { - prefs.insert("marionette.log.level", Pref::new(level.to_string())); - }; + prefs.insert("marionette.log.level", Pref::new(logging::max_level().to_string())); prefs.insert("marionette.port", Pref::new(port as i64)); prefs.write().map_err(|_| WebDriverError::new(ErrorStatus::UnknownError,