small integration test improvements. #194

cpu · 2023-03-07T17:38:54Z

Description

This branch adds some quality of life improvements to the integration tests that I found helpful while debugging #193

Their effect is perhaps best observed comparing the output of the test when the fix for #193 is reverted.

Without this branch's changes:

[nix-shell:~/Code/Rust/hyper-rustls]$ git rev-parse HEAD
d7fa80318a96e356e4a41dd0964498cae340fa6

[nix-shell:~/Code/Rust/hyper-rustls]$ cargo test
   Compiling hyper-rustls v0.23.2 (/home/daniel/Code/Rust/hyper-rustls)
    Finished test [unoptimized + debuginfo] target(s) in 1.47s
     Running unittests src/lib.rs (target/debug/deps/hyper_rustls-4f585a9d68b5c42a)

running 1 test
test connector::builder::tests::test_reject_predefined_alpn - should panic ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

     Running tests/tests.rs (target/debug/deps/tests-ca3314d7ee35e116)

running 3 tests
Starting to serve on https://127.0.0.1:1338.
Starting to serve on https://127.0.0.1:1337.
test client ... ok
test server ... FAILED
test custom_ca_store ... ok

failures:

---- server stdout ----
client output: []
thread 'server' panicked at 'assertion failed: `(left == right)`
  left: `[]`,
 right: `[84, 114, 121, 32, 80, 79, 83, 84, 32, 47, 101, 99, 104, 111, 10]`', tests/tests.rs:52:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    server

test result: FAILED. 2 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.01s

error: test failed, to rerun pass '--test tests'

[nix-shell:~/Code/Rust/hyper-rustls]$ ps aux | grep [1]337
daniel   1303117  0.0  0.0 1362672 6936 pts/1    Sl   12:34   0:00 target/debug/examples/server 1337

With this branch's changes:

[nix-shell:~/Code/Rust/hyper-rustls]$ git rev-parse HEAD
988d6aeb1e8604a726e3cafbcabba993682273d4

[nix-shell:~/Code/Rust/hyper-rustls]$ cargo test
    Finished test [unoptimized + debuginfo] target(s) in 0.05s
     Running unittests src/lib.rs (target/debug/deps/hyper_rustls-4f585a9d68b5c42a)

running 1 test
test connector::builder::tests::test_reject_predefined_alpn - should panic ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

     Running tests/tests.rs (target/debug/deps/tests-ca3314d7ee35e116)

running 3 tests
Starting to serve on https://127.0.0.1:1338.
Starting to serve on https://127.0.0.1:1337.
test custom_ca_store ... ok
test server ... FAILED
test client ... ok

failures:

---- server stdout ----
curl version: curl 7.88.0 (x86_64-pc-linux-gnu) libcurl/7.88.0 OpenSSL/3.0.8 zlib/1.2.13 brotli/1.0.9 zstd/1.5.4 libidn2/2.3.2 libssh2/1.10.0 nghttp2/1.51.0
Release-Date: 2023-02-15
Protocols: dict file ftp ftps gopher gophers http https imap imaps mqtt pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM NTLM_WB SPNEGO SSL threadsafe TLS-SRP UnixSockets zstd

curl stderr:
curl: (35) OpenSSL/3.0.8: error:0A000460:SSL routines::reason(1120)

thread 'server' panicked at 'assertion failed: `(left == right)`
  left: `""`,
 right: `"Try POST /echo\n"`', tests/tests.rs:78:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    server

test result: FAILED. 2 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.24s

error: test failed, to rerun pass '--test tests'

[nix-shell:~/Code/Rust/hyper-rustls]$ ps aux | grep [1]337

In the updated version:

We show the stderr with the root cause of the failure (error:0A000460:SSL routines::reason(1120))
We show the curl version (7.88.0)
We show the expected content as a string not a byte slice.
We don't leak the server process.

chore: avoid fixed sleep in integration tests. - `9531fbc`

Prior to this commit the tests/tests.rs integration tests had an unconditional 1 second sleep waiting for a server to become available. This is slightly problematic:

Waiting a full second if the server becomes available sooner is unnecessarily slow.
Conversely, we can't be sure the server is available after the 1s sleep.

This commit replaces the sleeps with a loop of up to 10 iterations that tries to connect to the server port. If any iteration succeeds we return immediately to avoid unnecessary waiting. If an iteration fails, we wait longer, increasing the duration each time we wait (up to a maximum of 10 iterations).

fix: kill server before asserting on output. - `2b7da58`

Prior to this commit the server() test would call assert_eq! to assert on client output matching expected before calling srv.kill() on the Child spawned by server_command().

The upstream rustdocs for std.process.Child mention:

There is no implementation of Drop for child processes, so if you do not ensure the Child has exited then it will continue to run, even after the Child handle to the child process has gone out of scope.

The net result is that if the assertion in server() fails, we leave a running server instance behind. This manifests as a port conflict when re-running the test without first killing the orphan.

This commit moves the srv.kill() call to before the assert_eq. This avoids leaking the server process if the assertion fails.

chore: improve server integration test output. - `fd8a111`

This commit adds a few quality of life improvements to the server integration test:

The --silent curl arg is removed so that we can get diagnostic info from curl on stderr in the event of a failure. Our test only asserts on stdout content, which remains unaffected by this change.
If the curl command invocation status isn't success, we print the stderr content enabled by not using --silent. This will provide more diagnostic context to investigate the failure.
The assert_eq is changed to assert on a string value created from stdout instead of raw bytes. This is easier for humans to diff in the test output compared to a slice of byte values.

Combined these changes should make it easier to diagnose future test failures without needing to iterate in CI.

chore: output curl version in server test failure. - `ffa7677`

In the event the server() integration test fails it's helpful to know the version of curl that was used. This commit includes this
information when the curl client invocation returns a non-zero status code.

cpu · 2023-03-07T17:44:06Z

rustls / Build+test (stable, ubuntu-18.04) (pull_request) Failing after 2m

...

The --silent curl arg is replaced by --no-progress-meter so that we can get diagnostic info from curl on stderr in the event of a failure. Our test only asserts on stdout content, which remains unaffected by this change.

Oops, looks like that flag might not exist on the older curl the non-macOS builds are using. I will adjust.

Prior to this commit the `tests/tests.rs` integration tests had an unconditional 1 second sleep waiting for a server to become available. This is slightly problematic: * Waiting a full second if the server becomes available sooner is unnecessarily slow. * Conversely, we can't be sure the server is available after the 1s sleep. This commit replaces the sleeps with a loop of up to 10 iterations that tries to connect to the server port. If any iteration succeeds we return immediately to avoid unnecessary waiting. If an iteration fails, we wait longer, increasing the duration each time we wait (up to a maximum of 10 iteration).

Prior to this commit the `server()` test would call `assert_eq!` to assert on client output matching expected _before_ calling `srv.kill()` on the `Child` spawned by `server_command()`. The upstream rustdocs for `std.process.Child` mention: > There is no implementation of Drop for child processes, so if you do > not ensure the Child has exited then it will continue to run, even > after the Child handle to the child process has gone out of scope. The net result is that if the assertion in `server()` fails, we leave a running server instance behind. This manifests as a port conflict when re-running the test without first killing the orphan. This commit moves the `srv.kill()` call to before the `assert_eq`. This avoids leaking the server process if the assertion fails.

This commit adds a few quality of life improvements to the server integration test: 1. The `--silent` curl arg is removed so that we can get diagnostic info from curl on stderr in the event of a failure. Our test only asserts on stdout content, which remains unaffected by this change. 2. If the `curl` command invocation status isn't success, we print the stderr content enabled by not using `--silent`. This will provide more diagnostic context to investigate the failure. 3. The `assert_eq` is changed to assert on a string value created from stdout instead of raw bytes. This is easier for humans to diff in the test output compared to a slice of byte values. Combined these changes should make it easier to diagnose future test failures without needing to iterate in CI.

cpu · 2023-03-07T18:25:56Z

Oops, looks like that flag might not exist on the older curl the non-macOS builds are using. I will adjust.

Fixed this by removing --silent outright instead of replacing it with the --no-progress-meter flag that isn't universally available in CI. This includes some progress meter output, but only in the case the test fails. This seemed like the best path forward.

I also fixed some rustfmt errs, and the use of inline format string vars that didn't compile with Rust 1.57.

rustls / Clippy (pull_request) Failing after 1m

This looks like a transient error from the GitHub checkout action: "Error: The process '/usr/bin/git' failed with exit code 128". I was seeing this on other branches as well :-/

I think this branch is ready to review now 🙏

ctz · 2023-03-07T18:31:08Z

I reran the failing clippy job - seems like some internet weather affecting GH actions runners.

tests/tests.rs

In the event the `server()` integration test fails it's helpful to know the version of `curl` that was used. This commit includes this information when the `curl` client invocation returns a non-zero status code.

cpu added 3 commits March 7, 2023 13:04

cpu force-pushed the cpu-test-tidying branch from 988d6ae to e943c46 Compare March 7, 2023 18:15

ctz approved these changes Mar 7, 2023

View reviewed changes

djc approved these changes Mar 8, 2023

View reviewed changes

tests/tests.rs Outdated Show resolved Hide resolved

chore: output curl version in server test failure.

ffa7677

In the event the `server()` integration test fails it's helpful to know the version of `curl` that was used. This commit includes this information when the `curl` client invocation returns a non-zero status code.

cpu force-pushed the cpu-test-tidying branch from e943c46 to ffa7677 Compare March 8, 2023 14:30

djc merged commit aa1506a into rustls:main Mar 8, 2023

cpu deleted the cpu-test-tidying branch March 8, 2023 15:02

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

small integration test improvements. #194

small integration test improvements. #194

cpu commented Mar 7, 2023 •

edited

Loading

cpu commented Mar 7, 2023

cpu commented Mar 7, 2023

ctz commented Mar 7, 2023

small integration test improvements. #194

small integration test improvements. #194

Conversation

cpu commented Mar 7, 2023 • edited Loading

Description

chore: avoid fixed sleep in integration tests. - 9531fbc

fix: kill server before asserting on output. - 2b7da58

chore: improve server integration test output. - fd8a111

chore: output curl version in server test failure. - ffa7677

cpu commented Mar 7, 2023

cpu commented Mar 7, 2023

ctz commented Mar 7, 2023

cpu commented Mar 7, 2023 •

edited

Loading

chore: avoid fixed sleep in integration tests. - `9531fbc`

fix: kill server before asserting on output. - `2b7da58`

chore: improve server integration test output. - `fd8a111`

chore: output curl version in server test failure. - `ffa7677`