Fix spurious failure in api_server::tests::test_serve_vmm_action_request

The test calls the `serve_vmm_action_request` function and tries to
check whether it correctly updates specific metrices related to
measuring how long a request took. However, since the VMM side is mocked
out in this test (the receiver end of the channel through which the
API server communicates is simply pre-filled with VmmData::Empty, and
not passed to any implementation that handles the requests), the
`serve_vmm_action_request` function only goes through the following
steps:

1. Put something into a channel
2. Read a pre-submitted value from another channel
3. Update the metrics

This can happen very fast (below 1us, which is the resolution of our
metrics), in which cases the unittests fails at the assertion that tries
to check whether the metric of "how long did handling this request take"
was correctly set (as this assertion only checks that the metric is not
0).

I suspect that the reason we have been encountering this more often
recently is due to the Rust 1.67.0 update (#3576), which replaced the
old stdlib implementation of mpsc channels with that from the crossbeam
crate. Since channel operations are most of what the test does, this
could have a performance impact if the new rust version has a more
performant implementation (which the changelog implies [1]).

We fix this by subtracting 1 from the start time inside the test, so
make sure that the difference "now - start time" which
serve_vmm_action_request uses to compute the metric value is always at
least 1.

[1]: https://blog.rust-lang.org/2023/01/26/Rust-1.67.0.html

Signed-off-by: Patrick Roy <[email protected]>

Author: roypat

src/api_server/src/lib.rs

@@ -338,7 +338,12 @@ mod tests {
         let response = api_server.serve_vmm_action_request(Box::new(VmmAction::StartMicroVm), 0);
         assert_eq!(response.status(), StatusCode::BadRequest);
 
-        let start_time_us = utils::time::get_time_us(ClockType::Monotonic);
+        // Since the vmm side is mocked out in this test, the call to serve_vmm_action_request can
+        // complete very fast (under 1us, the resolution of our metrics). In these cases, the
+        // latencies_us.pause_vm metric can be set to 0, failing the assertion below. By
+        // subtracting 1 we assure that the metric will always be set to at least 1 (if it gets set
+        // at all, which is what this test is trying to prove).
+        let start_time_us = utils::time::get_time_us(ClockType::Monotonic) - 1;
         assert_eq!(METRICS.latencies_us.pause_vm.fetch(), 0);
         to_api.send(Box::new(Ok(VmmData::Empty))).unwrap();
         let response =