Sent log messages to the constellation.

components/constellation/Cargo.toml

@@ -10,6 +10,7 @@ name = "constellation"
 path = "lib.rs"
 
 [dependencies]
+backtrace = "0.2.1"
 canvas = {path = "../canvas"}
 canvas_traits = {path = "../canvas_traits"}
 clipboard = {git = "https://github.com/aweinstock314/rust-clipboard"}

components/constellation/constellation.rs

@@ -9,6 +9,7 @@
 //! navigation context, each `Pipeline` encompassing a `ScriptThread`,
 //! `LayoutThread`, and `PaintThread`.
 
+use backtrace::Backtrace;
 use canvas::canvas_paint_thread::CanvasPaintThread;
 use canvas::webgl_paint_thread::WebGLPaintThread;
 use canvas_traits::CanvasMsg;
@@ -24,6 +25,7 @@ use gfx_traits::Epoch;
 use ipc_channel::ipc::{self, IpcSender};
 use ipc_channel::router::ROUTER;
 use layout_traits::LayoutThreadFactory;
+use log::{Log, LogLevel, LogLevelFilter, LogMetadata, LogRecord};
 use msg::constellation_msg::{FrameId, FrameType, PipelineId};
 use msg::constellation_msg::{Key, KeyModifiers, KeyState, LoadData};
 use msg::constellation_msg::{PipelineNamespace, PipelineNamespaceId, NavigationDirection};
@@ -45,14 +47,16 @@ use script_traits::{ConstellationControlMsg, ConstellationMsg as FromCompositorM
 use script_traits::{DocumentState, LayoutControlMsg};
 use script_traits::{IFrameLoadInfo, IFrameSandboxState, TimerEventRequest};
 use script_traits::{LayoutMsg as FromLayoutMsg, ScriptMsg as FromScriptMsg, ScriptThreadFactory};
-use script_traits::{MozBrowserEvent, MozBrowserErrorType, WebDriverCommandMsg, WindowSizeData};
+use script_traits::{LogEntry, MozBrowserEvent, MozBrowserErrorType, WebDriverCommandMsg, WindowSizeData};
 use std::borrow::ToOwned;
-use std::collections::HashMap;
+use std::collections::{HashMap, VecDeque};
 use std::io::Error as IOError;
 use std::marker::PhantomData;
 use std::mem::replace;
 use std::process;
 use std::sync::mpsc::{Sender, channel, Receiver};
+use std::sync::{Arc, Mutex};
+use std::thread;
 use style_traits::PagePx;
 use style_traits::cursor::Cursor;
 use style_traits::viewport::ViewportConstraints;
@@ -182,6 +186,10 @@ pub struct Constellation<Message, LTF, STF> {
     /// Have we seen any panics? Hopefully always false!
     handled_panic: bool,
 
+    /// Have we seen any warnings? Hopefully always empty!
+    /// The buffer contains `(thread_name, reason)` entries.
+    handled_warnings: VecDeque<(Option<String>, String)>,
+
     /// The random number generator and probability for closing pipelines.
     /// This is for testing the hardening of the constellation.
     random_pipeline_closure: Option<(StdRng, f32)>,
@@ -304,6 +312,100 @@ enum ExitPipelineMode {
     Force,
 }
 
+/// A logger directed at the constellation from content processes
+#[derive(Clone)]
+pub struct FromScriptLogger {
+    /// A channel to the constellation
+    pub constellation_chan: Arc<Mutex<IpcSender<FromScriptMsg>>>,
+}
+
+impl FromScriptLogger {
+    /// Create a new constellation logger.
+    pub fn new(constellation_chan: IpcSender<FromScriptMsg>) -> FromScriptLogger {
+        FromScriptLogger {
+            constellation_chan: Arc::new(Mutex::new(constellation_chan))
+        }
+    }
+
+    /// The maximum log level the constellation logger is interested in.
+    pub fn filter(&self) -> LogLevelFilter {
+        LogLevelFilter::Warn
+    }
+}
+
+impl Log for FromScriptLogger {
+    fn enabled(&self, metadata: &LogMetadata) -> bool {
+        metadata.level() <= LogLevel::Warn
+    }
+
+    fn log(&self, record: &LogRecord) {
+        if let Some(entry) = log_entry(record) {
+            // TODO: Store the pipeline id in TLS so we can recover it here
+            let thread_name = thread::current().name().map(ToOwned::to_owned);
+            let msg = FromScriptMsg::LogEntry(None, thread_name, entry);
+            if let Ok(chan) = self.constellation_chan.lock() {
+                let _ = chan.send(msg);
+            }
+        }
+    }
+}
+
+/// A logger directed at the constellation from the compositor
+#[derive(Clone)]
+pub struct FromCompositorLogger {
+    /// A channel to the constellation
+    pub constellation_chan: Arc<Mutex<Sender<FromCompositorMsg>>>,
+}
+
+impl FromCompositorLogger {
+    /// Create a new constellation logger.
+    pub fn new(constellation_chan: Sender<FromCompositorMsg>) -> FromCompositorLogger {
+        FromCompositorLogger {
+            constellation_chan: Arc::new(Mutex::new(constellation_chan))
+        }
+    }
+
+    /// The maximum log level the constellation logger is interested in.
+    pub fn filter(&self) -> LogLevelFilter {
+        LogLevelFilter::Warn
+    }
+}
+
+impl Log for FromCompositorLogger {
+    fn enabled(&self, metadata: &LogMetadata) -> bool {
+        metadata.level() <= LogLevel::Warn
+    }
+
+    fn log(&self, record: &LogRecord) {
+        if let Some(entry) = log_entry(record) {
+            // TODO: Store the pipeline id in TLS so we can recover it here
+            let thread_name = thread::current().name().map(ToOwned::to_owned);
+            let msg = FromCompositorMsg::LogEntry(None, thread_name, entry);
+            if let Ok(chan) = self.constellation_chan.lock() {
+                let _ = chan.send(msg);
+            }
+        }
+    }
+}
+
+fn log_entry(record: &LogRecord) -> Option<LogEntry> {
+    match record.level() {
+        LogLevel::Error if thread::panicking() => Some(LogEntry::Panic(
+            format!("{}", record.args()),
+            format!("{:?}", Backtrace::new())
+        )),
+        LogLevel::Error => Some(LogEntry::Error(
+            format!("{}", record.args())
+        )),
+        LogLevel::Warn => Some(LogEntry::Warn(
+            format!("{}", record.args())
+        )),
+        _ => None,
+    }
+}
+
+const WARNINGS_BUFFER_SIZE: usize = 32;
+
 impl<Message, LTF, STF> Constellation<Message, LTF, STF>
     where LTF: LayoutThreadFactory<Message=Message>,
           STF: ScriptThreadFactory<Message=Message>
@@ -367,6 +469,7 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
                 webrender_api_sender: state.webrender_api_sender,
                 shutting_down: false,
                 handled_panic: false,
+                handled_warnings: VecDeque::new(),
                 random_pipeline_closure: opts::get().random_pipeline_closure_probability.map(|prob| {
                     let seed = opts::get().random_pipeline_closure_seed.unwrap_or_else(random);
                     let rng = StdRng::from_seed(&[seed]);
@@ -621,6 +724,9 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
                 debug!("constellation got reload message");
                 self.handle_reload_msg();
             }
+            FromCompositorMsg::LogEntry(pipeline_id, thread_name, entry) => {
+                self.handle_log_entry(pipeline_id, thread_name, entry);
+            }
         }
     }
 
@@ -798,6 +904,9 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
             FromScriptMsg::Exit => {
                 self.compositor_proxy.send(ToCompositorMsg::Exit);
             }
+            FromScriptMsg::LogEntry(pipeline_id, thread_name, entry) => {
+                self.handle_log_entry(pipeline_id, thread_name, entry);
+            }
 
             FromScriptMsg::SetTitle(pipeline_id, title) => {
                 self.compositor_proxy.send(ToCompositorMsg::ChangePageTitle(pipeline_id, title))
@@ -973,6 +1082,21 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
         self.handled_panic = true;
     }
 
+    // TODO: trigger a mozbrowsererror even if there's no pipeline id
+    fn handle_log_entry(&mut self, pipeline_id: Option<PipelineId>, thread_name: Option<String>, entry: LogEntry) {
+        match (pipeline_id, entry) {
+            (Some(pipeline_id), LogEntry::Panic(reason, backtrace)) =>
+                self.trigger_mozbrowsererror(pipeline_id, reason, backtrace),
+            (None, LogEntry::Panic(reason, _)) | (_, LogEntry::Error(reason)) | (_, LogEntry::Warn(reason)) => {
+                // VecDeque::truncate is unstable
+                if WARNINGS_BUFFER_SIZE <= self.handled_warnings.len() {
+                    self.handled_warnings.pop_front();
+                }
+                self.handled_warnings.push_back((thread_name, reason));
+            },
+        }
+    }
+
     fn handle_init_load(&mut self, url: Url) {
         let window_size = self.window_size.visible_viewport;
         let root_pipeline_id = PipelineId::new();
@@ -2050,7 +2174,7 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
                     } else {
                         // Note that we deliberately do not do any of the tidying up
                         // associated with closing a pipeline. The constellation should cope!
-                        info!("Randomly closing pipeline {}.", pipeline_id);
+                        warn!("Randomly closing pipeline {}.", pipeline_id);
                         pipeline.force_exit();
                     }
                 }
@@ -2156,7 +2280,8 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
 
     // https://developer.mozilla.org/en-US/docs/Web/Events/mozbrowsererror
     // Note that this does not require the pipeline to be an immediate child of the root
-    fn trigger_mozbrowsererror(&self, pipeline_id: PipelineId, reason: String, backtrace: String) {
+    // TODO: allow the pipeline id to be optional, triggering the error on the root if it's not provided.
+    fn trigger_mozbrowsererror(&mut self, pipeline_id: PipelineId, reason: String, backtrace: String) {
         if !PREFS.is_mozbrowser_enabled() { return; }
 
         let ancestor_info = self.get_mozbrowser_ancestor_info(pipeline_id);
@@ -2164,7 +2289,21 @@ impl<Message, LTF, STF> Constellation<Message, LTF, STF>
         if let Some(ancestor_info) = ancestor_info {
             match self.pipelines.get(&ancestor_info.0) {
                 Some(ancestor) => {
-                    let event = MozBrowserEvent::Error(MozBrowserErrorType::Fatal, Some(reason), Some(backtrace));
+                    let mut report = String::new();
+                    for (thread_name, warning) in self.handled_warnings.drain(..) {
+                        report.push_str("\nWARNING: ");
+                        if let Some(thread_name) = thread_name {
+                            report.push_str("<");
+                            report.push_str(&*thread_name);
+                            report.push_str(">: ");
+                        }
+                        report.push_str(&*warning);
+                    }
+                    report.push_str("\nERROR: ");
+                    report.push_str(&*reason);
+                    report.push_str("\n\n");
+                    report.push_str(&*backtrace);
+                    let event = MozBrowserEvent::Error(MozBrowserErrorType::Fatal, Some(reason), Some(report));
                     ancestor.trigger_mozbrowser_event(ancestor_info.1, event);
                 },
                 None => return warn!("Mozbrowsererror via closed pipeline {:?}.", ancestor_info.0),

components/constellation/lib.rs

@@ -12,6 +12,7 @@
 #![deny(unsafe_code)]
 #![plugin(serde_macros)]
 
+extern crate backtrace;
 extern crate canvas;
 extern crate canvas_traits;
 extern crate clipboard;
@@ -47,7 +48,7 @@ mod pipeline;
 mod sandboxing;
 mod timer_scheduler;
 
-pub use constellation::{Constellation, InitialConstellationState};
+pub use constellation::{Constellation, FromCompositorLogger, FromScriptLogger, InitialConstellationState};
 pub use pipeline::UnprivilegedPipelineContent;
 #[cfg(not(target_os = "windows"))]
 pub use sandboxing::content_process_sandbox_profile;

components/constellation/pipeline.rs

@@ -535,6 +535,10 @@ impl UnprivilegedPipelineContent {
         process::exit(1);
     }
 
+    pub fn constellation_chan(&self) -> IpcSender<ScriptMsg> {
+        self.constellation_chan.clone()
+    }
+
     pub fn opts(&self) -> Opts {
         self.opts.clone()
     }

components/script_traits/lib.rs

@@ -66,7 +66,7 @@ use url::Url;
 use util::ipc::OptionalOpaqueIpcSender;
 use webdriver_msg::{LoadStatus, WebDriverScriptCommand};
 
-pub use script_msg::{LayoutMsg, ScriptMsg, EventResult};
+pub use script_msg::{LayoutMsg, ScriptMsg, EventResult, LogEntry};
 
 /// The address of a node. Layout sends these back. They must be validated via
 /// `from_untrusted_node_address` before they can be used, because we do not trust layout.
@@ -436,6 +436,7 @@ pub enum MozBrowserEvent {
     /// handling `<menuitem>` element available within the browser `<iframe>`'s content.
     ContextMenu,
     /// Sent when an error occurred while trying to load content within a browser `<iframe>`.
+    /// Includes an optional human-readable description, and an optional machine-readable report.
     Error(MozBrowserErrorType, Option<String>, Option<String>),
     /// Sent when the favicon of a browser `<iframe>` changes.
     IconChange(String, String, String),
@@ -599,4 +600,6 @@ pub enum ConstellationMsg {
     WebDriverCommand(WebDriverCommandMsg),
     /// Reload the current page.
     Reload,
+    /// A log entry, with the pipeline id and thread name
+    LogEntry(Option<PipelineId>, Option<String>, LogEntry),
 }

components/script_traits/script_msg.rs

@@ -40,6 +40,19 @@ pub enum EventResult {
     DefaultPrevented,
 }
 
+/// A log entry reported to the constellation
+/// We don't report all log entries, just serious ones.
+/// We need a separate type for this because LogLevel isn't serializable.
+#[derive(Clone, Debug, Deserialize, Serialize)]
+pub enum LogEntry {
+    /// Panic, with a reason and backtrace
+    Panic(String, String),
+    /// Error, with a reason
+    Error(String),
+    /// warning, with a reason
+    Warn(String)
+}
+
 /// Messages from the script to the constellation.
 #[derive(Deserialize, Serialize)]
 pub enum ScriptMsg {
@@ -114,6 +127,8 @@ pub enum ScriptMsg {
     TouchEventProcessed(EventResult),
     /// Get Scroll Offset
     GetScrollOffset(PipelineId, LayerId, IpcSender<Point2D<f32>>),
+    /// A log entry, with the pipeline id and thread name
+    LogEntry(Option<PipelineId>, Option<String>, LogEntry),
     /// Notifies the constellation that this pipeline has exited.
     PipelineExited(PipelineId),
     /// Requests that the compositor shut down.

components/servo/Cargo.lock

@@ -12,7 +12,7 @@ dependencies = [
  "constellation 0.0.1",
  "devtools 0.0.1",
  "devtools_traits 0.0.1",
- "env_logger 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)",
+ "env_logger 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)",
  "euclid 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "gaol 0.0.1 (git+https://github.com/servo/gaol)",
  "gfx 0.0.1",
@@ -357,6 +357,7 @@ dependencies = [
 name = "constellation"
 version = "0.0.1"
 dependencies = [
+ "backtrace 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)",
  "canvas 0.0.1",
  "canvas_traits 0.0.1",
  "clipboard 0.1.2 (git+https://github.com/aweinstock314/rust-clipboard)",
@@ -670,7 +671,7 @@ dependencies = [
 
 [[package]]
 name = "env_logger"
-version = "0.3.3"
+version = "0.3.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 dependencies = [
  "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)",

components/servo/lib.rs

@@ -17,10 +17,12 @@
 //! The `Browser` is fed events from a generic type that implements the
 //! `WindowMethods` trait.
 
+extern crate env_logger;
 #[cfg(not(target_os = "windows"))]
 extern crate gaol;
 #[macro_use]
 extern crate gleam;
+extern crate log;
 
 pub extern crate canvas;
 pub extern crate canvas_traits;
@@ -65,10 +67,13 @@ use compositing::{CompositorProxy, IOCompositor};
 #[cfg(not(target_os = "windows"))]
 use constellation::content_process_sandbox_profile;
 use constellation::{Constellation, InitialConstellationState, UnprivilegedPipelineContent};
+use constellation::{FromScriptLogger, FromCompositorLogger};
+use env_logger::Logger as EnvLogger;
 #[cfg(not(target_os = "windows"))]
 use gaol::sandbox::{ChildSandbox, ChildSandboxMethods};
 use gfx::font_cache_thread::FontCacheThread;
 use ipc_channel::ipc::{self, IpcSender};
+use log::{Log, LogMetadata, LogRecord};
 use net::bluetooth_thread::BluetoothThreadFactory;
 use net::image_cache_thread::new_image_cache_thread;
 use net::resource_thread::new_resource_threads;
@@ -78,7 +83,8 @@ use profile::mem as profile_mem;
 use profile::time as profile_time;
 use profile_traits::mem;
 use profile_traits::time;
-use script_traits::ConstellationMsg;
+use script_traits::{ConstellationMsg, ScriptMsg};
+use std::cmp::max;
 use std::rc::Rc;
 use std::sync::mpsc::Sender;
 use util::opts;
@@ -100,6 +106,7 @@ pub use gleam::gl;
 /// various browser components.
 pub struct Browser<Window: WindowMethods + 'static> {
     compositor: IOCompositor<Window>,
+    constellation_chan: Sender<ConstellationMsg>,
 }
 
 impl<Window> Browser<Window> where Window: WindowMethods + 'static {
@@ -172,7 +179,7 @@ impl<Window> Browser<Window> where Window: WindowMethods + 'static {
         let compositor = IOCompositor::create(window, InitialCompositorState {
             sender: compositor_proxy,
             receiver: compositor_receiver,
-            constellation_chan: constellation_chan,
+            constellation_chan: constellation_chan.clone(),
             time_profiler_chan: time_profiler_chan,
             mem_profiler_chan: mem_profiler_chan,
             webrender: webrender,
@@ -181,6 +188,7 @@ impl<Window> Browser<Window> where Window: WindowMethods + 'static {
 
         Browser {
             compositor: compositor,
+            constellation_chan: constellation_chan,
         }
     }
 
@@ -199,6 +207,18 @@ impl<Window> Browser<Window> where Window: WindowMethods + 'static {
     pub fn request_title_for_main_frame(&self) {
         self.compositor.title_for_main_frame()
     }
+
+    pub fn setup_logging(&self) {
+        let constellation_chan = self.constellation_chan.clone();
+        log::set_logger(|max_log_level| {
+            let env_logger = EnvLogger::new();
+            let con_logger = FromCompositorLogger::new(constellation_chan);
+            let filter = max(env_logger.filter(), con_logger.filter());
+            let logger = BothLogger(env_logger, con_logger);
+            max_log_level.set(filter);
+            Box::new(logger)
+        }).expect("Failed to set logger.")
+    }
 }
 
 fn create_constellation(opts: opts::Opts,
@@ -244,6 +264,32 @@ fn create_constellation(opts: opts::Opts,
     constellation_chan
 }
 
+// A logger that logs to two downstream loggers.
+// This should probably be in the log crate.
+struct BothLogger<Log1, Log2>(Log1, Log2);
+
+impl<Log1, Log2> Log for BothLogger<Log1, Log2> where Log1: Log, Log2: Log {
+    fn enabled(&self, metadata: &LogMetadata) -> bool {
+        self.0.enabled(metadata) || self.1.enabled(metadata)
+    }
+
+    fn log(&self, record: &LogRecord) {
+        self.0.log(record);
+        self.1.log(record);
+    }
+}
+
+pub fn set_logger(constellation_chan: IpcSender<ScriptMsg>) {
+    log::set_logger(|max_log_level| {
+        let env_logger = EnvLogger::new();
+        let con_logger = FromScriptLogger::new(constellation_chan);
+        let filter = max(env_logger.filter(), con_logger.filter());
+        let logger = BothLogger(env_logger, con_logger);
+        max_log_level.set(filter);
+        Box::new(logger)
+    }).expect("Failed to set logger.")
+}
+
 /// Content process entry point.
 pub fn run_content_process(token: String) {
     let (unprivileged_content_sender, unprivileged_content_receiver) =
@@ -255,6 +301,7 @@ pub fn run_content_process(token: String) {
     let unprivileged_content = unprivileged_content_receiver.recv().unwrap();
     opts::set_defaults(unprivileged_content.opts());
     PREFS.extend(unprivileged_content.prefs());
+    set_logger(unprivileged_content.constellation_chan());
 
     // Enter the sandbox if necessary.
     if opts::get().sandbox {

components/servo/main.rs

@@ -22,7 +22,6 @@
 extern crate android_glue;
 #[cfg(not(target_os = "android"))]
 extern crate backtrace;
-extern crate env_logger;
 // The window backed by glutin
 extern crate glutin_app as app;
 #[cfg(target_os = "android")]
@@ -96,8 +95,6 @@ fn main() {
     };
 
     initiate_panic_hook();
-    env_logger::init().unwrap();
-
     setup_logging();
 
     if let Some(token) = content_process_token {
@@ -117,6 +114,8 @@ fn main() {
         browser: Browser::new(window.clone()),
     };
 
+    browser.browser.setup_logging();
+
     register_glutin_resize_handler(&window, &mut browser);
 
     browser.browser.handle_events(vec![WindowEvent::InitializeCompositing]);

ports/cef/Cargo.lock

@@ -316,6 +316,7 @@ dependencies = [
 name = "constellation"
 version = "0.0.1"
 dependencies = [
+ "backtrace 0.2.2 (registry+https://github.com/rust-lang/crates.io-index)",
  "canvas 0.0.1",
  "canvas_traits 0.0.1",
  "clipboard 0.1.2 (git+https://github.com/aweinstock314/rust-clipboard)",
@@ -588,7 +589,7 @@ dependencies = [
 
 [[package]]
 name = "env_logger"
-version = "0.3.3"
+version = "0.3.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 dependencies = [
  "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -1939,7 +1940,7 @@ dependencies = [
  "constellation 0.0.1",
  "devtools 0.0.1",
  "devtools_traits 0.0.1",
- "env_logger 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)",
+ "env_logger 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)",
  "euclid 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "gaol 0.0.1 (git+https://github.com/servo/gaol)",
  "gfx 0.0.1",

ports/geckolib/Cargo.lock

@@ -4,7 +4,7 @@ version = "0.0.1"
 dependencies = [
  "app_units 0.2.5 (registry+https://github.com/rust-lang/crates.io-index)",
  "cssparser 0.5.6 (registry+https://github.com/rust-lang/crates.io-index)",
- "env_logger 0.3.3 (registry+https://github.com/rust-lang/crates.io-index)",
+ "env_logger 0.3.4 (registry+https://github.com/rust-lang/crates.io-index)",
  "euclid 0.7.1 (registry+https://github.com/rust-lang/crates.io-index)",
  "gecko_bindings 0.0.1",
  "lazy_static 0.2.1 (registry+https://github.com/rust-lang/crates.io-index)",
@@ -124,7 +124,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"
 
 [[package]]
 name = "env_logger"
-version = "0.3.3"
+version = "0.3.4"
 source = "registry+https://github.com/rust-lang/crates.io-index"
 dependencies = [
  "log 0.3.6 (registry+https://github.com/rust-lang/crates.io-index)",