Skip to content

Commit

Permalink
Fix a flaky error log test (#219)
Browse files Browse the repository at this point in the history
```
// TODO: Could this cause problems where we get an event and a final stderr line is only
// processed after we write the error log?
```

Turns out the answer is "yes"!
  • Loading branch information
9999years authored May 1, 2024
1 parent ee8f035 commit 330a590
Show file tree
Hide file tree
Showing 3 changed files with 37 additions and 4 deletions.
1 change: 1 addition & 0 deletions src/ghci/error_log.rs
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,7 @@ impl ErrorLog {
}

for diagnostic in &log.diagnostics {
tracing::debug!(%diagnostic, "Writing diagnostic");
writer
.write_all(diagnostic.to_string().as_bytes())
.await
Expand Down
35 changes: 31 additions & 4 deletions src/ghci/stderr.rs
Original file line number Diff line number Diff line change
@@ -1,5 +1,9 @@
use std::time::Duration;
use std::time::Instant;

use backoff::backoff::Backoff;
use backoff::ExponentialBackoff;
use miette::Context;
use miette::IntoDiagnostic;
use tokio::io::AsyncWriteExt;
use tokio::io::BufReader;
Expand Down Expand Up @@ -56,8 +60,6 @@ impl GhciStderr {

pub async fn run_inner(&mut self) -> miette::Result<()> {
loop {
// TODO: Could this cause problems where we get an event and a final stderr line is only
// processed after we write the error log?
tokio::select! {
Ok(Some(line)) = self.reader.next_line() => {
self.ingest_line(line).await?;
Expand All @@ -84,7 +86,7 @@ impl GhciStderr {
self.clear_buffer().await;
}
StderrEvent::GetBuffer { sender } => {
self.get_buffer(sender).await;
self.get_buffer(sender).await?;
}
}

Expand All @@ -109,8 +111,33 @@ impl GhciStderr {
}

#[instrument(skip(self, sender), level = "debug")]
async fn get_buffer(&mut self, sender: oneshot::Sender<String>) {
async fn get_buffer(&mut self, sender: oneshot::Sender<String>) -> miette::Result<()> {
// Read lines from the stderr stream until we can't read a line within 0.05 seconds.
//
// This helps make sure we've read all the available data.
//
// In testing, this takes ~52ms.
let start_instant = Instant::now();
while let Ok(maybe_line) =
tokio::time::timeout(Duration::from_millis(50), self.reader.next_line()).await
{
match maybe_line
.into_diagnostic()
.wrap_err("Failed to read stderr line")?
{
Some(line) => {
self.ingest_line(line).await?;
}
None => {
tracing::debug!("No more lines available from stderr");
}
}
}
tracing::debug!("Drained stderr buffer in {:.2?}", start_instant.elapsed());

// TODO: Does it make more sense to clear the buffer here?
let _ = sender.send(self.buffer.clone());

Ok(())
}
}
5 changes: 5 additions & 0 deletions tests/error_log.rs
Original file line number Diff line number Diff line change
Expand Up @@ -73,6 +73,11 @@ async fn can_write_error_log_compilation_errors() {
.await
.expect("ghciwatch writes ghcid.txt");

session
.wait_for_log(BaseMatcher::reload_completes())
.await
.expect("ghciwatch finishes reloading");

let error_contents = session
.fs()
.read(&error_path)
Expand Down

0 comments on commit 330a590

Please sign in to comment.