process_wrapper: write all output from rustc if json parsing fails. (#2234)

Previously we were only reporting the first line of any error rustc may
emit when it panic'd or otherwise unexpectedly stopped outputting json.

Author: gigaroby

test/process_wrapper/fake_rustc.rs

@@ -1,7 +1,13 @@
 //! This binary mocks the output of rustc when run with `--error-format=json` and `--json=artifacts`.
 
 fn main() {
+    let should_error = std::env::args().any(|arg| arg == "error");
+
     eprintln!(r#"{{"rendered": "should be\nin output"}}"#);
+    if should_error {
+        eprintln!("ERROR!\nthis should all\nappear in output.");
+        std::process::exit(1);
+    }
     eprintln!(r#"{{"emit": "metadata"}}"#);
     std::thread::sleep(std::time::Duration::from_secs(1));
     eprintln!(r#"{{"rendered": "should not be in output"}}"#);

test/process_wrapper/rustc_quit_on_rmeta.rs

@@ -9,7 +9,11 @@ mod test {
     /// fake_rustc runs the fake_rustc binary under process_wrapper with the specified
     /// process wrapper arguments. No arguments are passed to fake_rustc itself.
     ///
-    fn fake_rustc(process_wrapper_args: &[&'static str]) -> String {
+    fn fake_rustc(
+        process_wrapper_args: &[&'static str],
+        fake_rustc_args: &[&'static str],
+        should_succeed: bool,
+    ) -> String {
         let r = Runfiles::create().unwrap();
         let fake_rustc = r.rlocation(
             [
@@ -45,27 +49,34 @@ mod test {
             .args(process_wrapper_args)
             .arg("--")
             .arg(fake_rustc)
+            .args(fake_rustc_args)
             .output()
             .unwrap();
 
-        assert!(
-            output.status.success(),
-            "unable to run process_wrapper: {} {}",
-            str::from_utf8(&output.stdout).unwrap(),
-            str::from_utf8(&output.stderr).unwrap(),
-        );
+        if should_succeed {
+            assert!(
+                output.status.success(),
+                "unable to run process_wrapper: {} {}",
+                str::from_utf8(&output.stdout).unwrap(),
+                str::from_utf8(&output.stderr).unwrap(),
+            );
+        }
 
         String::from_utf8(output.stderr).unwrap()
     }
 
     #[test]
     fn test_rustc_quit_on_rmeta_quits() {
-        let out_content = fake_rustc(&[
-            "--rustc-quit-on-rmeta",
-            "true",
-            "--rustc-output-format",
-            "rendered",
-        ]);
+        let out_content = fake_rustc(
+            &[
+                "--rustc-quit-on-rmeta",
+                "true",
+                "--rustc-output-format",
+                "rendered",
+            ],
+            &[],
+            true,
+        );
         assert!(
             !out_content.contains("should not be in output"),
             "output should not contain 'should not be in output' but did",
@@ -74,12 +85,16 @@ mod test {
 
     #[test]
     fn test_rustc_quit_on_rmeta_output_json() {
-        let json_content = fake_rustc(&[
-            "--rustc-quit-on-rmeta",
-            "true",
-            "--rustc-output-format",
-            "json",
-        ]);
+        let json_content = fake_rustc(
+            &[
+                "--rustc-quit-on-rmeta",
+                "true",
+                "--rustc-output-format",
+                "json",
+            ],
+            &[],
+            true,
+        );
         assert_eq!(
             json_content,
             concat!(r#"{"rendered": "should be\nin output"}"#, "\n")
@@ -88,12 +103,30 @@ mod test {
 
     #[test]
     fn test_rustc_quit_on_rmeta_output_rendered() {
-        let rendered_content = fake_rustc(&[
-            "--rustc-quit-on-rmeta",
-            "true",
-            "--rustc-output-format",
-            "rendered",
-        ]);
+        let rendered_content = fake_rustc(
+            &[
+                "--rustc-quit-on-rmeta",
+                "true",
+                "--rustc-output-format",
+                "rendered",
+            ],
+            &[],
+            true,
+        );
         assert_eq!(rendered_content, "should be\nin output");
     }
+
+    #[test]
+    fn test_rustc_panic() {
+        let rendered_content = fake_rustc(&["--rustc-output-format", "json"], &["error"], false);
+        assert_eq!(
+            rendered_content,
+            r#"{"rendered": "should be\nin output"}
+ERROR!
+this should all
+appear in output.
+Error: ProcessWrapperError("failed to process stderr: error parsing rustc output as json")
+"#
+        );
+    }
 }

util/process_wrapper/main.rs

@@ -18,6 +18,7 @@ mod output;
 mod rustc;
 mod util;
 
+use std::fmt;
 use std::fs::{copy, OpenOptions};
 use std::io;
 use std::process::{exit, Command, ExitStatus, Stdio};
@@ -49,11 +50,19 @@ fn status_code(status: ExitStatus, was_killed: bool) -> i32 {
     }
 }
 
-fn main() {
-    let opts = match options() {
-        Err(err) => panic!("process wrapper error: {}", err),
-        Ok(v) => v,
-    };
+#[derive(Debug)]
+struct ProcessWrapperError(String);
+
+impl fmt::Display for ProcessWrapperError {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        write!(f, "process wrapper error: {}", self.0)
+    }
+}
+
+impl std::error::Error for ProcessWrapperError {}
+
+fn main() -> Result<(), ProcessWrapperError> {
+    let opts = options().map_err(|e| ProcessWrapperError(e.to_string()))?;
 
     let mut child = Command::new(opts.executable)
         .args(opts.child_arguments)
@@ -65,14 +74,14 @@ fn main() {
                 .truncate(true)
                 .write(true)
                 .open(stdout_file)
-                .expect("process wrapper error: unable to open stdout file")
+                .map_err(|e| ProcessWrapperError(format!("unable to open stdout file: {}", e)))?
                 .into()
         } else {
             Stdio::inherit()
         })
         .stderr(Stdio::piped())
         .spawn()
-        .expect("process wrapper error: failed to spawn child process");
+        .map_err(|e| ProcessWrapperError(format!("failed to spawn child process: {}", e)))?;
 
     let mut stderr: Box<dyn io::Write> = if let Some(stderr_file) = opts.stderr_file {
         Box::new(
@@ -81,13 +90,15 @@ fn main() {
                 .truncate(true)
                 .write(true)
                 .open(stderr_file)
-                .expect("process wrapper error: unable to open stderr file"),
+                .map_err(|e| ProcessWrapperError(format!("unable to open stderr file: {}", e)))?,
         )
     } else {
         Box::new(io::stderr())
     };
 
-    let mut child_stderr = child.stderr.take().unwrap();
+    let mut child_stderr = child.stderr.take().ok_or(ProcessWrapperError(
+        "unable to get child stderr".to_string(),
+    ))?;
 
     let mut was_killed = false;
     let result = if let Some(format) = opts.rustc_output_format {
@@ -112,13 +123,15 @@ fn main() {
         result
     } else {
         // Process output normally by forwarding stderr
-        process_output(&mut child_stderr, stderr.as_mut(), LineOutput::Message)
+        process_output(&mut child_stderr, stderr.as_mut(), move |line| {
+            Ok(LineOutput::Message(line))
+        })
     };
-    result.expect("process wrapper error: failed to process stderr");
+    result.map_err(|e| ProcessWrapperError(format!("failed to process stderr: {}", e)))?;
 
     let status = child
         .wait()
-        .expect("process wrapper error: failed to wait for child process");
+        .map_err(|e| ProcessWrapperError(format!("failed to wait for child process: {}", e)))?;
     // If the child process is rustc and is killed after metadata generation, that's also a success.
     let code = status_code(status, was_killed);
     let success = code == 0;
@@ -128,15 +141,15 @@ fn main() {
                 .create(true)
                 .write(true)
                 .open(tf)
-                .expect("process wrapper error: failed to create touch file");
+                .map_err(|e| ProcessWrapperError(format!("failed to create touch file: {}", e)))?;
         }
         if let Some((copy_source, copy_dest)) = opts.copy_output {
-            copy(&copy_source, &copy_dest).unwrap_or_else(|_| {
-                panic!(
-                    "process wrapper error: failed to copy {} into {}",
-                    copy_source, copy_dest
-                )
-            });
+            copy(&copy_source, &copy_dest).map_err(|e| {
+                ProcessWrapperError(format!(
+                    "failed to copy {} into {}: {}",
+                    copy_source, copy_dest, e
+                ))
+            })?;
         }
     }
 

util/process_wrapper/output.rs

@@ -12,6 +12,8 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+use std::error;
+use std::fmt;
 use std::io::{self, prelude::*};
 
 /// LineOutput tells process_output what to do when a line is processed.
@@ -27,30 +29,101 @@ pub(crate) enum LineOutput {
     Terminate,
 }
 
+#[derive(Debug)]
+pub(crate) enum ProcessError {
+    IO(io::Error),
+    Process(String),
+}
+
+impl fmt::Display for ProcessError {
+    fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
+        match self {
+            Self::IO(e) => write!(f, "{}", e),
+            Self::Process(p) => write!(f, "{}", p),
+        }
+    }
+}
+
+impl error::Error for ProcessError {}
+
+impl From<io::Error> for ProcessError {
+    fn from(err: io::Error) -> Self {
+        Self::IO(err)
+    }
+}
+
+impl From<String> for ProcessError {
+    fn from(s: String) -> Self {
+        Self::Process(s)
+    }
+}
+
+pub(crate) type ProcessResult = Result<(), ProcessError>;
+
+/// If this is Err we assume there were issues processing the line.
+/// We will print the error returned and all following lines without
+/// any more processing.
+pub(crate) type LineResult = Result<LineOutput, String>;
+
 /// process_output reads lines from read_end and invokes process_line on each.
 /// Depending on the result of process_line, the modified message may be written
 /// to write_end.
 pub(crate) fn process_output<F>(
     read_end: &mut dyn Read,
     write_end: &mut dyn Write,
     mut process_line: F,
-) -> io::Result<()>
+) -> ProcessResult
 where
-    F: FnMut(String) -> LineOutput,
+    F: FnMut(String) -> LineResult,
 {
     let mut reader = io::BufReader::new(read_end);
     let mut writer = io::LineWriter::new(write_end);
+    // If there was an error parsing a line failed_on contains the offending line
+    // and the error message.
+    let mut failed_on: Option<(String, String)> = None;
     loop {
         let mut line = String::new();
         let read_bytes = reader.read_line(&mut line)?;
         if read_bytes == 0 {
             break;
         }
-        match process_line(line) {
-            LineOutput::Message(to_write) => writer.write_all(to_write.as_bytes())?,
-            LineOutput::Skip => {}
-            LineOutput::Terminate => return Ok(()),
+        match process_line(line.clone()) {
+            Ok(LineOutput::Message(to_write)) => writer.write_all(to_write.as_bytes())?,
+            Ok(LineOutput::Skip) => {}
+            Ok(LineOutput::Terminate) => return Ok(()),
+            Err(msg) => {
+                failed_on = Some((line, msg));
+                break;
+            }
         };
     }
+
+    // If we encountered an error processing a line we want to flush the rest of
+    // reader into writer and return the error.
+    if let Some((line, msg)) = failed_on {
+        writer.write_all(line.as_bytes())?;
+        io::copy(&mut reader, &mut writer)?;
+        return Err(ProcessError::Process(msg));
+    }
     Ok(())
 }
+
+#[cfg(test)]
+mod test {
+    use super::*;
+
+    #[test]
+    fn test_json_parsing_error() {
+        let mut input = io::Cursor::new(b"ok text\nsome more\nerror text");
+        let mut output: Vec<u8> = vec![];
+        let result = process_output(&mut input, &mut output, move |line| {
+            if line == "ok text\n" {
+                Ok(LineOutput::Skip)
+            } else {
+                Err("error parsing output".to_owned())
+            }
+        });
+        assert!(result.is_err());
+        assert_eq!(&output, b"some more\nerror text");
+    }
+}