Skip to content

Fix races in tracing-appender unit tests #737

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 2 commits into from
Jun 12, 2020
Merged

Fix races in tracing-appender unit tests #737

Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
908c41f
Fix races in tracing-appender unit tests
May 26, 2020
7e991d3
wrap long comments
May 27, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
37 changes: 24 additions & 13 deletions tracing-appender/src/non_blocking.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -333,6 +333,13 @@ mod test {
assert_eq!(line, ", World");
}

fn write_non_blocking(non_blocking: &mut NonBlocking, msg: &[u8]) {
non_blocking.write_all(msg).expect("Failed to write");

// Sleep a bit to prevent races.
thread::sleep(Duration::from_millis(200));
Comment on lines +339 to +340
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not a huge fan of tests that rely on load-bearing sleeps to work correctly. But, if there's no other solution, I'm fine with merging this.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let me know if this test is still being problematic. We can probably use some retry logic instead of sleeps here instead now that I think about it.

}

#[test]
fn logs_dropped_if_lossy() {
let (mock_writer, rx) = MockWriter::new(1);
Expand All @@ -344,27 +351,31 @@ mod test {

let error_count = non_blocking.error_counter();

non_blocking.write_all(b"Hello").expect("Failed to write");
// First write will not block
write_non_blocking(&mut non_blocking, b"Hello");
assert_eq!(0, error_count.load(Ordering::Acquire));

non_blocking.write_all(b", World").expect("Failed to write");
assert_eq!(1, error_count.load(Ordering::Acquire));
// Second write will not block as Worker will have called `recv` on channel. "Hello" not yet consumed. MockWriter call to write_all will block until "Hello" is consumed.
write_non_blocking(&mut non_blocking, b", World");
assert_eq!(0, error_count.load(Ordering::Acquire));

non_blocking.write_all(b".").expect("Failed to write");
assert_eq!(2, error_count.load(Ordering::Acquire));
// Will sit in NonBlocking channel's buffer.
write_non_blocking(&mut non_blocking, b"Test");
assert_eq!(0, error_count.load(Ordering::Acquire));

// Allow a line to be written
// Allow a line to be written. "Hello" message will be consumed. ", World" will be able to write to MockWriter.
// "Test" will block on call to MockWriter's `write_all`
let line = rx.recv().unwrap();
assert_eq!(line, "Hello");

// Now, there is once again capacity in the buffer.
non_blocking
.write_all(b"Universe")
.expect("Failed to write");
assert_eq!(2, error_count.load(Ordering::Acquire));
// This will block as NonBlocking channel is full.
write_non_blocking(&mut non_blocking, b"Universe");
assert_eq!(1, error_count.load(Ordering::Acquire));

// Finally the second message sent will be consumed.
let line = rx.recv().unwrap();
assert_eq!(line, "Universe");
assert_eq!(line, ", World");
assert_eq!(1, error_count.load(Ordering::Acquire));
}

#[test]
Expand Down Expand Up @@ -394,7 +405,7 @@ mod test {

let mut hello_count: u8 = 0;

while let Ok(event_str) = rx.try_recv() {
while let Ok(event_str) = rx.recv_timeout(Duration::from_secs(5)) {
assert!(event_str.contains("Hello"));
hello_count += 1;
}
Expand Down