Skip to content

Commit

Permalink
feat(ui): persist logs on failure (#7805)
Browse files Browse the repository at this point in the history
### Description

If a task fails when using the UI, it isn't easy to find the reason for
the failure.

This PR makes it so that if a task fails, we'll persist the logs to the
terminal so they remain after the UI exits.

### Testing Instructions

<img width="1034" alt="Screenshot 2024-03-21 at 9 46 11 AM"
src="https://github.com/vercel/turbo/assets/4131117/31a6f29d-22c2-4ad9-a569-a95afb200f54">



Closes TURBO-2681
  • Loading branch information
chris-olszewski authored Mar 21, 2024
1 parent 1644246 commit 893dfd5
Show file tree
Hide file tree
Showing 6 changed files with 92 additions and 64 deletions.
24 changes: 17 additions & 7 deletions crates/turborepo-lib/src/task_graph/visitor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -803,19 +803,23 @@ impl ExecContext {
}
}

fn prefixed_ui<W: Write>(&self, stdout: W, stderr: W) -> PrefixedUI<W> {
Visitor::prefixed_ui(
self.ui,
self.is_github_actions,
stdout,
stderr,
self.pretty_prefix.clone(),
)
}

async fn execute_inner(
&mut self,
output_client: &TaskOutput<impl std::io::Write>,
telemetry: &PackageTaskEventBuilder,
) -> ExecOutcome {
let task_start = Instant::now();
let mut prefixed_ui = Visitor::prefixed_ui(
self.ui,
self.is_github_actions,
output_client.stdout(),
output_client.stderr(),
self.pretty_prefix.clone(),
);
let mut prefixed_ui = self.prefixed_ui(output_client.stdout(), output_client.stderr());

if self.experimental_ui {
if let TaskOutput::UI(task) = output_client {
Expand Down Expand Up @@ -968,6 +972,12 @@ impl ExecContext {
if let Err(e) = stdout_writer.flush() {
error!("error flushing logs: {e}");
}
if let TaskOutput::UI(task) = output_client {
let mut persisted_ui = self.prefixed_ui(task.stdout(), task.stdout());
let _ = self
.task_cache
.replay_log_file(persisted_ui.output_prefixed_writer());
}
if let Err(e) = self
.task_cache
.on_error(prefixed_ui.output_prefixed_writer())
Expand Down
2 changes: 2 additions & 0 deletions crates/turborepo-ui/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
#![feature(deadline_api)]

mod color_selector;
mod line;
mod logs;
mod output;
mod prefixed;
Expand All @@ -19,6 +20,7 @@ use thiserror::Error;

pub use crate::{
color_selector::ColorSelector,
line::LineWriter,
logs::{replay_logs, LogWriter},
output::{OutputClient, OutputClientBehavior, OutputSink, OutputWriter},
prefixed::{PrefixedUI, PrefixedWriter},
Expand Down
43 changes: 43 additions & 0 deletions crates/turborepo-ui/src/line.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,43 @@
use std::io::Write;

/// Writer that will buffer writes so the underlying writer is only called with
/// writes that end in a newline
pub struct LineWriter<W> {
writer: W,
buffer: Vec<u8>,
}

impl<W: Write> LineWriter<W> {
pub fn new(writer: W) -> Self {
Self {
writer,
buffer: Vec::with_capacity(512),
}
}
}

impl<W: Write> Write for LineWriter<W> {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
for line in buf.split_inclusive(|c| *c == b'\n') {
if line.ends_with(b"\n") {
if self.buffer.is_empty() {
self.writer.write_all(line)?;
} else {
self.buffer.extend_from_slice(line);
self.writer.write_all(&self.buffer)?;
self.buffer.clear();
}
} else {
// This should only happen on the last chunk?
self.buffer.extend_from_slice(line)
}
}

Ok(buf.len())
}

fn flush(&mut self) -> std::io::Result<()> {
// We don't flush our buffer as that would lead to a write without a newline
self.writer.flush()
}
}
59 changes: 6 additions & 53 deletions crates/turborepo-ui/src/prefixed.rs
Original file line number Diff line number Diff line change
@@ -1,12 +1,12 @@
use std::{
fmt::{Debug, Display, Formatter},
fmt::{Debug, Display},
io::Write,
};

use console::{Style, StyledObject};
use tracing::error;

use crate::UI;
use crate::{LineWriter, UI};

/// Writes messages with different prefixes, depending on log level. Note that
/// this does output the prefix when message is empty, unlike the Go
Expand Down Expand Up @@ -109,14 +109,6 @@ pub struct PrefixedWriter<W> {
inner: LineWriter<PrefixedWriterInner<W>>,
}

impl<W> Debug for PrefixedWriter<W> {
fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result {
f.debug_struct("PrefixedWriter")
.field("prefix", &self.inner.writer.prefix)
.finish()
}
}

impl<W: Write> PrefixedWriter<W> {
pub fn new(ui: UI, prefix: StyledObject<impl Display>, writer: W) -> Self {
Self {
Expand Down Expand Up @@ -177,48 +169,6 @@ impl<W: Write> Write for PrefixedWriterInner<W> {
}
}

/// Writer that will buffer writes so the underlying writer is only called with
/// writes that end in a newline
struct LineWriter<W> {
writer: W,
buffer: Vec<u8>,
}

impl<W: Write> LineWriter<W> {
pub fn new(writer: W) -> Self {
Self {
writer,
buffer: Vec::with_capacity(512),
}
}
}

impl<W: Write> Write for LineWriter<W> {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
for line in buf.split_inclusive(|c| *c == b'\n') {
if line.ends_with(b"\n") {
if self.buffer.is_empty() {
self.writer.write_all(line)?;
} else {
self.buffer.extend_from_slice(line);
self.writer.write_all(&self.buffer)?;
self.buffer.clear();
}
} else {
// This should only happen on the last chunk?
self.buffer.extend_from_slice(line)
}
}

Ok(buf.len())
}

fn flush(&mut self) -> std::io::Result<()> {
// We don't flush our buffer as that would lead to a write without a newline
self.writer.flush()
}
}

#[cfg(test)]
mod test {
use test_case::test_case;
Expand Down Expand Up @@ -290,6 +240,7 @@ mod test {
}

#[test_case(&["foo"], "" ; "no newline")]
#[test_case(&["\n"], "\n" ; "one newline")]
#[test_case(&["foo\n"], "foo\n" ; "single newline")]
#[test_case(&["foo ", "bar ", "baz\n"], "foo bar baz\n" ; "building line")]
#[test_case(&["multiple\nlines\nin\none"], "multiple\nlines\nin\n" ; "multiple lines")]
Expand Down Expand Up @@ -317,9 +268,11 @@ mod test {
.write_all(b", now\nbut \ranother one starts")
.unwrap();
writer.write_all(b" done\n").unwrap();
writer.write_all(b"\n").unwrap();
assert_eq!(
String::from_utf8(buffer).unwrap(),
"turbo > not a line yet, now\nturbo > but \rturbo > another one starts done\n"
"turbo > not a line yet, now\nturbo > but \rturbo > another one starts done\nturbo > \
\n"
);
}
}
26 changes: 23 additions & 3 deletions crates/turborepo-ui/src/tui/handle.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,10 @@ use std::{
time::Instant,
};

use tracing::debug;

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / JS Native Package Tests (ubuntu, self-hosted, linux, x64, metal)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / JS Native Package Tests (ubuntu, self-hosted, linux, x64, metal)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / JS Native Package Tests (macos, macos-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / JS Native Package Tests (macos, macos-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Build Turborepo (ubuntu, self-hosted, linux, x64, metal)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Build Turborepo (macos, macos-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Build Turborepo (windows, windows-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Turborepo Integration (ubuntu-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Turborepo Integration (macos-latest)

unused import: `tracing::debug`

Check warning on line 6 in crates/turborepo-ui/src/tui/handle.rs

View workflow job for this annotation

GitHub Actions / Turborepo Integration (windows-latest)

unused import: `tracing::debug`

use super::Event;
use crate::LineWriter;

/// Struct for sending app events to TUI rendering
#[derive(Debug, Clone)]
Expand All @@ -27,8 +30,13 @@ pub struct TuiTask {
}

/// Writer that will correctly render writes to the persisted part of the screen
#[derive(Debug, Clone)]
pub struct PersistedWriter {
writer: LineWriter<PersistedWriterInner>,
}

/// Writer that will correctly render writes to the persisted part of the screen
#[derive(Debug, Clone)]
pub struct PersistedWriterInner {
handle: AppSender,
}

Expand Down Expand Up @@ -132,7 +140,9 @@ impl TuiTask {
/// pass in a PersistedWriter instead.
pub fn stdout(&self) -> PersistedWriter {
PersistedWriter {
handle: self.as_app().clone(),
writer: LineWriter::new(PersistedWriterInner {
handle: self.as_app().clone(),
}),
}
}
}
Expand Down Expand Up @@ -162,10 +172,20 @@ impl std::io::Write for TuiTask {
}

impl std::io::Write for PersistedWriter {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
self.writer.write(buf)
}

fn flush(&mut self) -> std::io::Result<()> {
self.writer.flush()
}
}

impl std::io::Write for PersistedWriterInner {
fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
let bytes = buf.to_vec();
self.handle
.primary
.priority
.send(Event::Log { message: bytes })
.map_err(|_| std::io::Error::new(std::io::ErrorKind::Other, "receiver dropped"))?;
Ok(buf.len())
Expand Down
2 changes: 1 addition & 1 deletion crates/turborepo-ui/src/tui/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ mod task_duration;

pub use app::run_app;
use event::Event;
pub use handle::{AppReceiver, AppSender, PersistedWriter, TuiTask};
pub use handle::{AppReceiver, AppSender, PersistedWriterInner, TuiTask};
use input::input;
pub use pane::TerminalPane;
pub use table::TaskTable;
Expand Down

0 comments on commit 893dfd5

Please sign in to comment.