refactor(stack/loadshed): unit test instruments spawned tasks (#3755)

this commit performs a small refactor to one of the unit tests in
`linkerd-stack`'s load-shedding middleware.

this adds a span to the worker tasks spawned in this test, so that
tracing logs can be associated with particular oneshot services.

see #3744 for more information on upgrading our tower dependency. this
is cherry-picked from investigations on that branch related to breaking
changes in 0.5 related to the `Buffer` middleware.

after this change, logs now look like this:

```
; RUST_LOG="trace" cargo test -p linkerd-stack buffer_load_shed -- --nocapture

running 1 test
[     0.002770s] TRACE worker{id=oneshot1}: tower::buffer::service: sending request to buffer worker
[     0.002809s] TRACE worker{id=oneshot2}: tower::buffer::service: sending request to buffer worker
[     0.002823s] TRACE worker{id=oneshot3}: tower::buffer::service: sending request to buffer worker
[     0.002843s] DEBUG worker{id=oneshot4}: linkerd_stack::loadshed: Service has become unavailable
[     0.002851s] DEBUG worker{id=oneshot4}: linkerd_stack::loadshed: Service shedding load
[     0.002878s] TRACE tower::buffer::worker: worker polling for next message
[     0.002885s] TRACE tower::buffer::worker: processing new request
[     0.002892s] TRACE worker{id=oneshot1}: tower::buffer::worker: resumed=false worker received request; waiting for service readiness
[     0.002901s] DEBUG worker{id=oneshot1}: tower::buffer::worker: service.ready=true processing request
[     0.002914s] TRACE worker{id=oneshot1}: tower::buffer::worker: returning response future
[     0.002926s] TRACE tower::buffer::worker: worker polling for next message
[     0.002931s] TRACE tower::buffer::worker: processing new request
[     0.002935s] TRACE worker{id=oneshot2}: tower::buffer::worker: resumed=false worker received request; waiting for service readiness
[     0.002946s] TRACE worker{id=oneshot2}: tower::buffer::worker: service.ready=false delay
[     0.002983s] TRACE worker{id=oneshot5}: tower::buffer::service: sending request to buffer worker
[     0.003001s] DEBUG worker{id=oneshot6}: linkerd_stack::loadshed: Service has become unavailable
[     0.003007s] DEBUG worker{id=oneshot6}: linkerd_stack::loadshed: Service shedding load
[     0.003017s] DEBUG worker{id=oneshot7}: linkerd_stack::loadshed: Service has become unavailable
[     0.003024s] DEBUG worker{id=oneshot7}: linkerd_stack::loadshed: Service shedding load
[     0.003035s] TRACE tower::buffer::worker: worker polling for next message
[     0.003041s] TRACE tower::buffer::worker: resuming buffered request
[     0.003045s] TRACE worker{id=oneshot2}: tower::buffer::worker: resumed=true worker received request; waiting for service readiness
[     0.003052s] DEBUG worker{id=oneshot2}: tower::buffer::worker: service.ready=true processing request
[     0.003060s] TRACE worker{id=oneshot2}: tower::buffer::worker: returning response future
[     0.003068s] TRACE tower::buffer::worker: worker polling for next message
[     0.003073s] TRACE tower::buffer::worker: processing new request
[     0.003077s] TRACE worker{id=oneshot3}: tower::buffer::worker: resumed=false worker received request; waiting for service readiness
[     0.003084s] DEBUG worker{id=oneshot3}: tower::buffer::worker: service.ready=true processing request
[     0.003091s] TRACE worker{id=oneshot3}: tower::buffer::worker: returning response future
[     0.003099s] TRACE tower::buffer::worker: worker polling for next message
[     0.003103s] TRACE tower::buffer::worker: processing new request
[     0.003107s] TRACE worker{id=oneshot5}: tower::buffer::worker: resumed=false worker received request; waiting for service readiness
[     0.003114s] DEBUG worker{id=oneshot5}: tower::buffer::worker: service.ready=true processing request
[     0.003121s] TRACE worker{id=oneshot5}: tower::buffer::worker: returning response future
[     0.003129s] TRACE tower::buffer::worker: worker polling for next message
test loadshed::tests::buffer_load_shed ... ok
```

Signed-off-by: katelyn martin <kate@buoyant.io>
This commit is contained in:
katelyn martin 2025-03-13 13:26:21 -04:00 committed by GitHub
parent 5fa3745b57
commit 11e990ee16
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
1 changed files with 16 additions and 7 deletions

View File

@ -138,20 +138,29 @@ mod tests {
let (service, mut handle) = mock::pair::<(), ()>();
let service = LoadShed::new(Buffer::new(service, 3));
let spawn_svc = |id: &'static str| {
use tracing::{error_span, Instrument};
task::spawn(
service
.clone()
.oneshot(())
.instrument(error_span!("worker", %id)),
)
};
// The inner starts unavailable...
handle.allow(0);
// ...but the buffer will accept requests while it has capacity.
let mut oneshot1 = task::spawn(service.clone().oneshot(()));
let mut oneshot1 = spawn_svc("oneshot1");
assert_pending!(oneshot1.poll());
let mut oneshot2 = task::spawn(service.clone().oneshot(()));
let mut oneshot2 = spawn_svc("oneshot2");
assert_pending!(oneshot2.poll());
let mut oneshot3 = task::spawn(service.clone().oneshot(()));
let mut oneshot3 = spawn_svc("oneshot3");
assert_pending!(oneshot3.poll());
// The buffer is now full, so the loadshed service should fail this
// request.
let mut oneshot4 = task::spawn(service.clone().oneshot(()));
let mut oneshot4 = spawn_svc("oneshot4");
assert_ready_err!(oneshot4.poll());
// Complete one request.
@ -166,13 +175,13 @@ mod tests {
// Now that there's space in the buffer, the service should no longer be
// shedding load.
let mut oneshot5 = task::spawn(service.clone().oneshot(()));
let mut oneshot5 = spawn_svc("oneshot5");
assert_pending!(oneshot5.poll());
// The buffer is now full, so the loadshed service should fail any
// additional requests.
let mut oneshot6 = task::spawn(service.clone().oneshot(()));
let mut oneshot7 = task::spawn(service.clone().oneshot(()));
let mut oneshot6 = spawn_svc("oneshot6");
let mut oneshot7 = spawn_svc("oneshot7");
assert_ready_err!(oneshot6.poll());
assert_ready_err!(oneshot7.poll());