Skip to content

Commit

Permalink
fix(ui): add carraige return after cache log messages (#8015)
Browse files Browse the repository at this point in the history 
### Description

Forgot that we need to bring our own `\r` in raw mode as `\n` will only
move the cursor down and not back to the home column.

### Testing Instructions
Before
<img width="625" alt="Screenshot 2024-04-22 at 8 55 45 AM"
src="https://github.com/vercel/turbo/assets/4131117/4843b0bb-435c-42c2-a672-f222adaacf6f">

After
<img width="619" alt="Screenshot 2024-04-22 at 8 53 34 AM"
src="https://github.com/vercel/turbo/assets/4131117/459dd534-a2bf-468c-9fd5-62aa12a9d16d">



Closes TURBO-2855
  • Loading branch information
@chris-olszewski
chris-olszewski committed Apr 30, 2024
1 parent 14bb523 commit a82c8d3
Show file tree
Hide file tree
Showing 7 changed files with 149 additions and 84 deletions.
83 changes: 35 additions & 48 deletions crates/turborepo-lib/src/run/cache.rs
View file
Expand Up @@ -8,7 +8,7 @@ use turborepo_cache::{AsyncCache, CacheError, CacheHitMetadata, CacheSource};
use turborepo_repository::package_graph::PackageInfo;
use turborepo_scm::SCM;
use turborepo_telemetry::events::{task::PackageTaskEventBuilder, TrackedErrors};
use turborepo_ui::{color, replay_logs, ColorSelector, LogWriter, GREY, UI};
use turborepo_ui::{color, ColorSelector, LogWriter, GREY, UI};

use crate::{
cli::OutputLogsMode,
Expand Down Expand Up @@ -50,6 +50,13 @@ pub struct RunCache {
ui: UI,
}

/// Trait used to output cache information to user
pub trait CacheOutput {
fn status(&mut self, message: &str);
fn error(&mut self, message: &str);
fn replay_logs(&mut self, log_file: &AbsoluteSystemPath) -> Result<(), turborepo_ui::Error>;
}

impl RunCache {
pub fn new(
cache: AsyncCache,
Expand Down Expand Up @@ -134,23 +141,20 @@ pub struct TaskCache {

impl TaskCache {
/// Will read log file and write to output a line at a time
pub fn replay_log_file(&self, output: impl Write) -> Result<(), Error> {
pub fn replay_log_file(&self, output: &mut impl CacheOutput) -> Result<(), Error> {
if self.log_file_path.exists() {
replay_logs(output, &self.log_file_path)?;
output.replay_logs(&self.log_file_path)?;
}

Ok(())
}

pub fn on_error(&self, mut terminal_output: impl Write) -> Result<(), Error> {
pub fn on_error(&self, terminal_output: &mut impl CacheOutput) -> Result<(), Error> {
if self.task_output_mode == OutputLogsMode::ErrorsOnly {
fallible_write(
&mut terminal_output,
&format!(
"cache miss, executing {}\n",
color!(self.ui, GREY, "{}", self.hash)
),
);
terminal_output.status(&format!(
"cache miss, executing {}",
color!(self.ui, GREY, "{}", self.hash)
));
self.replay_log_file(terminal_output)?;
}

Expand Down Expand Up @@ -183,22 +187,18 @@ impl TaskCache {

pub async fn restore_outputs(
&mut self,
mut terminal_output: impl Write,
alternative_log_replay: Option<impl Write>,
terminal_output: &mut impl CacheOutput,
telemetry: &PackageTaskEventBuilder,
) -> Result<Option<CacheHitMetadata>, Error> {
if self.caching_disabled || self.run_cache.reads_disabled {
if !matches!(
self.task_output_mode,
OutputLogsMode::None | OutputLogsMode::ErrorsOnly
) {
fallible_write(
&mut terminal_output,
&format!(
"cache bypass, force executing {}\n",
color!(self.ui, GREY, "{}", self.hash)
),
);
terminal_output.status(&format!(
"cache bypass, force executing {}",
color!(self.ui, GREY, "{}", self.hash)
));
}

return Ok(None);
Expand Down Expand Up @@ -243,13 +243,10 @@ impl TaskCache {
self.task_output_mode,
OutputLogsMode::None | OutputLogsMode::ErrorsOnly
) {
fallible_write(
&mut terminal_output,
&format!(
"cache miss, executing {}\n",
color!(self.ui, GREY, "{}", self.hash)
),
);
terminal_output.status(&format!(
"cache miss, executing {}",
color!(self.ui, GREY, "{}", self.hash)
));
}

return Ok(None);
Expand Down Expand Up @@ -294,30 +291,20 @@ impl TaskCache {

match self.task_output_mode {
OutputLogsMode::HashOnly | OutputLogsMode::NewOnly => {
fallible_write(
&mut terminal_output,
&format!(
"cache hit{}, suppressing logs {}\n",
more_context,
color!(self.ui, GREY, "{}", self.hash)
),
);
terminal_output.status(&format!(
"cache hit{}, suppressing logs {}",
more_context,
color!(self.ui, GREY, "{}", self.hash)
));
}
OutputLogsMode::Full => {
debug!("log file path: {}", self.log_file_path);
fallible_write(
&mut terminal_output,
&format!(
"cache hit{}, replaying logs {}\n",
more_context,
color!(self.ui, GREY, "{}", self.hash)
),
);
if let Some(mut replay_writer) = alternative_log_replay {
self.replay_log_file(&mut replay_writer)?;
} else {
self.replay_log_file(&mut terminal_output)?;
}
terminal_output.status(&format!(
"cache hit{}, replaying logs {}",
more_context,
color!(self.ui, GREY, "{}", self.hash)
));
self.replay_log_file(terminal_output)?;
}
// Note that if we're restoring from cache, the task succeeded
// so we know we don't need to print anything for errors
Expand Down
2 changes: 1 addition & 1 deletion crates/turborepo-lib/src/run/mod.rs
View file
Expand Up @@ -14,7 +14,7 @@ pub mod watch;

use std::{collections::HashSet, io::Write, sync::Arc};

pub use cache::{ConfigCache, RunCache, TaskCache};
pub use cache::{CacheOutput, ConfigCache, RunCache, TaskCache};
use chrono::{DateTime, Local};
use rayon::iter::ParallelBridge;
use tracing::debug;
Expand Down
108 changes: 75 additions & 33 deletions crates/turborepo-lib/src/task_graph/visitor.rs
View file
Expand Up @@ -41,7 +41,7 @@ use crate::{
},
task_access::TaskAccess,
task_id::TaskId,
RunCache, TaskCache,
CacheOutput, RunCache, TaskCache,
},
task_hash::{self, PackageInputsHashes, TaskHashTracker, TaskHashTrackerState, TaskHasher},
};
Expand Down Expand Up @@ -803,14 +803,20 @@ 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(),
)
fn prefixed_ui<'a, W: Write>(
&self,
output_client: &'a TaskOutput<W>,
) -> TaskCacheOutput<OutputWriter<'a, W>> {
match output_client {
TaskOutput::Direct(client) => TaskCacheOutput::Direct(Visitor::prefixed_ui(
self.ui,
self.is_github_actions,
client.stdout(),
client.stderr(),
self.pretty_prefix.clone(),
)),
TaskOutput::UI(task) => TaskCacheOutput::UI(task.clone()),
}
}

async fn execute_inner(
Expand All @@ -819,27 +825,17 @@ impl ExecContext {
telemetry: &PackageTaskEventBuilder,
) -> ExecOutcome {
let task_start = Instant::now();
let mut prefixed_ui = self.prefixed_ui(output_client.stdout(), output_client.stderr());
let mut prefixed_ui = self.prefixed_ui(output_client);

if self.experimental_ui {
if let TaskOutput::UI(task) = output_client {
task.start();
}
}

// When the UI is enabled we don't want to have the prefix appear on the
// replayed logs.
let alt_log_replay_writer = match output_client {
TaskOutput::UI(task) => Some(task.clone()),
TaskOutput::Direct(_) => None,
};
match self
.task_cache
.restore_outputs(
prefixed_ui.output_prefixed_writer(),
alt_log_replay_writer,
telemetry,
)
.restore_outputs(&mut prefixed_ui, telemetry)
.await
{
Ok(Some(status)) => {
Expand All @@ -855,7 +851,7 @@ impl ExecContext {
Ok(None) => (),
Err(e) => {
telemetry.track_error(TrackedErrors::ErrorFetchingFromCache);
prefixed_ui.error(format!("error fetching from cache: {e}"));
prefixed_ui.error(&format!("error fetching from cache: {e}"));
}
}

Expand Down Expand Up @@ -897,7 +893,7 @@ impl ExecContext {
// Turbo was unable to spawn a process
Some(Err(e)) => {
// Note: we actually failed to spawn, but this matches the Go output
prefixed_ui.error(format!("command finished with error: {e}"));
prefixed_ui.error(&format!("command finished with error: {e}"));
let error_string = e.to_string();
self.errors
.lock()
Expand All @@ -922,11 +918,7 @@ impl ExecContext {
}
}

let mut stdout_writer = match self.task_cache.output_writer(if self.experimental_ui {
Either::Left(output_client.stdout())
} else {
Either::Right(prefixed_ui.output_prefixed_writer())
}) {
let mut stdout_writer = match self.task_cache.output_writer(prefixed_ui.task_writer()) {
Ok(w) => w,
Err(e) => {
telemetry.track_error(TrackedErrors::FailedToCaptureOutputs);
Expand Down Expand Up @@ -982,18 +974,15 @@ impl ExecContext {
if let Err(e) = stdout_writer.flush() {
error!("error flushing logs: {e}");
}
if let Err(e) = self
.task_cache
.on_error(prefixed_ui.output_prefixed_writer())
{
if let Err(e) = self.task_cache.on_error(&mut prefixed_ui) {
error!("error reading logs: {e}");
}
let error = TaskErrorCause::from_execution(process.label().to_string(), code);
let message = error.to_string();
if self.continue_on_error {
prefixed_ui.warn("command finished with error, but continuing...");
} else {
prefixed_ui.error(format!("command finished with error: {error}"));
prefixed_ui.error(&format!("command finished with error: {error}"));
}
self.errors.lock().expect("lock poisoned").push(TaskError {
task_id: self.task_id_for_display.clone(),
Expand Down Expand Up @@ -1050,6 +1039,59 @@ impl DryRunExecContext {
}
}

/// Struct for displaying information about task's cache
enum TaskCacheOutput<W> {
Direct(PrefixedUI<W>),
UI(TuiTask),
}

impl<W: Write> TaskCacheOutput<W> {
fn task_writer(&mut self) -> Either<turborepo_ui::PrefixedWriter<&mut W>, TuiTask> {
match self {
TaskCacheOutput::Direct(prefixed) => Either::Left(prefixed.output_prefixed_writer()),
TaskCacheOutput::UI(task) => Either::Right(task.clone()),
}
}

fn warn(&mut self, message: impl std::fmt::Display) {
match self {
TaskCacheOutput::Direct(prefixed) => prefixed.warn(message),
TaskCacheOutput::UI(task) => {
let _ = write!(task, "\r\n{message}\r\n");
}
}
}
}

impl<W: Write> CacheOutput for TaskCacheOutput<W> {
fn status(&mut self, message: &str) {
match self {
TaskCacheOutput::Direct(direct) => direct.output(message),
TaskCacheOutput::UI(task) => task.status(message),
}
}

fn error(&mut self, message: &str) {
match self {
TaskCacheOutput::Direct(prefixed) => prefixed.error(message),
TaskCacheOutput::UI(task) => {
let _ = write!(task, "{message}\r\n");
}
}
}

fn replay_logs(&mut self, log_file: &AbsoluteSystemPath) -> Result<(), turborepo_ui::Error> {
match self {
TaskCacheOutput::Direct(direct) => {
let writer = direct.output_prefixed_writer();
turborepo_ui::replay_logs(writer, log_file)
}
TaskCacheOutput::UI(task) => turborepo_ui::replay_logs(task, log_file),
}
}
}

/// Struct for displaying information about task
impl<W: Write> TaskOutput<W> {
pub fn finish(self, use_error: bool) -> std::io::Result<Option<Vec<u8>>> {
match self {
Expand Down
3 changes: 3 additions & 0 deletions crates/turborepo-ui/src/tui/app.rs
View file
Expand Up @@ -199,6 +199,9 @@ fn update<B: Backend>(
Event::TaskOutput { task, output } => {
app.pane.process_output(&task, &output)?;
}
Event::Status { task, status } => {
app.pane.set_status(&task, status)?;
}
Event::Stop => {
app.done = true;
}
Expand Down
4 changes: 4 additions & 0 deletions crates/turborepo-ui/src/tui/event.rs
View file
Expand Up @@ -9,6 +9,10 @@ pub enum Event {
EndTask {
task: String,
},
Status {
task: String,
status: String,
},
Stop,
Tick,
Log {
Expand Down
14 changes: 14 additions & 0 deletions crates/turborepo-ui/src/tui/handle.rs
View file
Expand Up @@ -119,6 +119,20 @@ impl TuiTask {
.ok();
}

pub fn status(&self, status: &str) {
// Since this will be rendered via ratatui we any ANSI escape codes will not be
// handled.
// TODO: prevent the status from having ANSI codes in this scenario
let status = console::strip_ansi_codes(status).into_owned();
self.handle
.primary
.send(Event::Status {
task: self.name.clone(),
status,
})
.ok();
}

/// Return a `PersistedWriter` which will properly write provided bytes to
/// a persisted section of the terminal.
///
Expand Down

0 comments on commit a82c8d3

Please sign in to comment.