An Micro-benchmark for OQueue Kernel-User Space Round Trip Time - #277
An Micro-benchmark for OQueue Kernel-User Space Round Trip Time#277ioeddk wants to merge 12 commits into
Conversation
|
This is truely huge. I'm quite surprised we need this much code. I would much prefer this be integrated into the existing benchmark launcher. @gvipat can you help with this if needed? |
…trip RAID-1 read selection can be delegated to a userspace policy server over OQFS: the kernel produces a request, blocks, and the server replies. When that server actually runs is up to the scheduler, so the cost and -- more importantly -- the variance of that round trip are unknown. This component measures them in isolation, as a bare ping-pong with no RAID involvement. It exports two OQueues under `/oqueues/oqbench`: a request queue the userspace peer observes via `strong_observe`, and a reply queue the peer writes through `produce`. A dedicated kernel thread runs a strict one-request-in-flight loop, capturing four timestamps on the shared guest TSC -- two in the kernel, two carried back in the reply -- so each round trip decomposes into the kernel->user wakeup, the peer's compute, and the user->kernel wakeup. Those wakeups are the quantity that decides whether latency-sensitive policies need synchronous IPC with a directed context switch. Every measured sample is stored verbatim in an array preallocated before the run, and streamed to the peer over a separate queue once the loop has finished, so nothing is aggregated away and nothing touches an OQueue while a measurement is in flight. Any anomaly -- a reply timeout, an out-of-sequence reply, a stale reply -- prints a diagnosis and powers the machine off with a failure exit code rather than being counted and survived. The component is compiled into every build and does nothing unless `oqbench.enable` is passed. Iteration and warmup counts, the reply timeout, the queue capacities, the peer's synthetic compute, the number of competing busy processes, and the driver thread's scheduling policy are all kernel command-line parameters, so a run can measure both the default and the real-time case the RAID worker actually uses.
`oqbench_server` is the userspace half of the round trip: it blocks reading the request stream, timestamps with `rdtsc`, optionally burns a configured amount of synthetic compute to model a policy that does real work, and writes one reply. After the run it drains the kernel's stored samples and writes them as CSV. It is built statically into the initramfs -- a dynamically linked binary's interpreter lives in the nix store, which the guest cannot reach -- and `init` launches it only when the benchmark is enabled on the kernel command line. `AUTO_TEST=oqbench` runs the whole pipeline at a small iteration count and fails the build if the round trip does not complete, so the feature cannot rot unnoticed. `tools/oqbench/run.sh` is the interface for real runs: it takes the scenario (iterations, warmup, peer compute, competing load, vCPUs, KVM, scheduling policy), boots the guest, fetches the results over scp using the initramfs's existing dropbear/sftp support, and shuts the guest down. It exits non-zero with a specific message on a failed boot, an incomplete run, or a results file whose record count does not match what the run reported -- a silently truncated result file being the one outcome worth engineering against.
1c56423 to
107b565
Compare
arthurp
left a comment
There was a problem hiding this comment.
I stand by my original comment that this is crazy complex. I feel like you rebuilt a lot of things which already have implementations. Some of these are kinda justified (capturing all data into a preallocated array), but many are not.
Read through my comments, and then we will probably want to talk.
There was a problem hiding this comment.
Let's create a "mariposa_bench" component instead. We can move the OQueue benchmarks into it as well (not in this PR). That will allow all the benchmarks to share code more easily. There will be a bunch of benchmark utilities.
| //! | ||
| //! A kernel driver thread produces a request into one OQueue and blocks; the userspace peer | ||
| //! (`oqbench_server`) replies into a second OQueue; the kernel wakes on the reply. Each iteration | ||
| //! captures four timestamps on the shared guest TSC -- t0 before producing, t1 after the request |
There was a problem hiding this comment.
NIT: Your documentation tends to be very verbose and one reason is things like this: "on the shared guest TSC". This is of course true, but it doesn't actually matter in this context. By including these things that are true but unimportant you create text which will guide people to focus on the wrong thing.
This is a lesson about documentation, but also and maybe more so, writing academic papers.
| /// Prints an `OQBENCH|error` line and powers the machine off with a failure exit code. A plain | ||
| /// `panic!` here is only a per-thread oops, which would hang the boot, so anomalies power off. | ||
| fn fatal(message: core::fmt::Arguments<'_>) -> ! { | ||
| println!("OQBENCH|error {}", message); |
There was a problem hiding this comment.
Is there a reason not to use the Asterinas logging framework?
There was a problem hiding this comment.
println! streams to the qemu.log like a serial console, so I want to add this OQBENCH| prefix so I can easily fetch from the log for the OQueue Bench-related prints. With Asterinas logging, it begins with something like a [timestamp] INFO: <rest of the log>. Also, the main reason is that I think it's not any kind of log. Putting it in an INFO-level log will get massive noise printed in the serial console as well, and it's certainly not a warning.
| /// Warmup iterations excluded from the dumped samples (`oqbench.warmup`). | ||
| static WARMUP: AtomicU32 = AtomicU32::new(10_000); | ||
| aster_cmdline::define_kv_param!("oqbench.warmup", WARMUP); |
There was a problem hiding this comment.
If you are just dumping all the samples anyway, then you don't need this. You can drop the samples in post-processing. This has the advantage of allowing the analysis to look at the warm-up process which is useful to make sure you are actually dropping enough warm-up iterations.
There was a problem hiding this comment.
Good call. I'll remove the warm-ups.
| /// Measured iteration count (`oqbench.iterations`). | ||
| static ITERATIONS: AtomicU32 = AtomicU32::new(1_000_000); | ||
| aster_cmdline::define_kv_param!("oqbench.iterations", ITERATIONS); |
There was a problem hiding this comment.
NIT: If we are going all in with good interface (which you seem to be here). It's useful for this parameter to be in seconds and then the framework will do an initial run of say 1000 iterations, compute the average, and then use that to estimate the final number of iterations. This makes the "how long" parameter at least somewhat independent of the actual thing being benchmarked. We can do this later though.
There was a problem hiding this comment.
You mean we use "how long the benchmark run" as the parameter, rather than how many iterations to run?
|
|
||
| usage() { | ||
| cat <<'EOF' | ||
| oqbench/run.sh -- run the OQFS kernel<->user round-trip microbenchmark and collect its samples. |
There was a problem hiding this comment.
All this basically duplicates the README. Better to just have it here and then reference it from the README. That way it's less likely to bitrot.
|
|
||
| [[ -n "$OUTPUT" ]] || OUTPUT="oqbench-samples.csv" | ||
| # Fail early on an unwritable output location rather than after a long boot. | ||
| : >"$OUTPUT" || die "cannot write output file '$OUTPUT'" |
There was a problem hiding this comment.
This is to test whether we can write to the location where we want to put the output file.
| # The authorized_keys build file is regenerated only when absent, so drop any stale one to force the | ||
| # current public keys into the guest. | ||
| rm -f "${ROOT}/test/initramfs/build/authorized_keys" |
There was a problem hiding this comment.
This is a good reason NOT to generate new keys. If you ran into specific cases where keys were wrong, then we should fix that, instead of working around it here.
| # Remove any stale qemu.log first, so leftovers from a prior run cannot be parsed as this run's. | ||
| rm -f "$QEMU_LOG" |
There was a problem hiding this comment.
I think qemu.log is overwritten instead of appended to anyway.
There was a problem hiding this comment.
This is really complicated AND doesn't match the benchmark conventions set upstream. Let's either follow their conventions and keep it simple, or let's use Python.
This should get simpler once we use fewer custom steps like the SCP stuff.
04e79c2 to
81ddcda
Compare
The benchmark no longer starts or stops the machine itself. The userspace
peer attaching is what begins a run, and the kernel ends one by sending
the peer a verdict rather than calling `poweroff`:
* The request stream carries `Measure(seq)`, `Finished` or `Failed`,
replacing the `Option<u64>` that could only say "keep going" or
"stop". The peer turns the terminal variant into its exit status, so
a failed run cannot leave the same trace as a finished one.
* `init` runs the peer in the foreground and powers the guest off once
it returns, echoing its status.
* Bad parameters are carried to the point where a peer is listening
instead of stopping the machine on the spot, so the run always ends
with a verdict somebody can hear.
Both waits are now bounded on the userspace side, since nothing in the
kernel force-stops the guest any more: the peer gives up if no request
arrives, and end-of-stream before a verdict counts as a failed run. The
kernel holds the queues open until the peer detaches, because tearing
them down revokes the observer, which reads as end-of-stream and would
otherwise turn a finished run into a reported failure.
This also drops the `BENCHMARK=oqbench/roundtrip` job, which routed the
benchmark through the userspace application harness. That harness exists
to compare Asterinas against Linux on whole applications and pulled the
entire suite into the initramfs. Configuration stays on the kernel
command line, matching the in-kernel microbenchmarks.
Failures are now typed on both sides: the kernel prints `MARIPOSA_BENCH|
error` at the call site rather than through a wrapper that only wrapped
`println!`, and the peer uses a `snafu` error enum instead of loose exit
status constants.
The hand-rolled parser had to restate every option in a USAGE constant, so the help text could drift from the fields it described. clap derives it from them instead, and reports a bad command line itself with the same exit status (2) the Usage error variant used to carry. Same crate and major version as cargo-osdk.
The kernel stopped powering the guest off when the lifecycle moved to userspace; --timeout-ms still said it did.
|
I addressed basically all the comments except: "we should use an existing dummy load", I can't think of one that runs in the userspace. |
Yea. That's a later problem. And it's actually something to ask the larger LDOS lab about. I can't remember who, but somebody is studying generating loads and while we probably want something simpler. They can definitely tell us what the options are and how we could choose between them. |
arthurp
left a comment
There was a problem hiding this comment.
Much better. Thank you.
In case it isn't clear, when I say "NIT:", I mean that if it's easy fix it, but it's not important enough to spend much time on.
The things I would specifically like to see fixed are:
- You still seem to REALLY REALLY want to use custom representations and encodings. :-) See my comments below. I want either the simple version or comments specifically justifying the complex code you added.
- Make the KVM defaults correct.
I don't need to look at the PR again. I think we got close enough.
| share — collecting a sample per iteration, capturing the samples, reporting the run, and giving up on | ||
| it. | ||
|
|
||
| ## `oqueue_roundtrip` — the OQFS kernel ↔ user round trip |
There was a problem hiding this comment.
| The always-on smoke test runs the whole pipeline at a small iteration count: | ||
|
|
||
| ``` | ||
| make run_kernel AUTO_TEST=oqbench ENABLE_KVM=1 |
There was a problem hiding this comment.
ENABLE_KVM=1 is the default.
| while !self.stopped.load(core::sync::atomic::Ordering::Relaxed) { | ||
| ostd::task::Task::yield_now(); | ||
| } | ||
| self.stopped_wait_queue.wait_until(|| { | ||
| self.stopped | ||
| .load(core::sync::atomic::Ordering::SeqCst) | ||
| .then_some(()) | ||
| }); |
| enum RequestKind { | ||
| /// Time the round trip identified by the request's sequence number. | ||
| Measure = 0, | ||
| /// Every sample is captured; the peer may shut the machine down. | ||
| Finished = 1, | ||
| /// The run failed and the reason is on the console; the peer should shut down and say so. | ||
| Failed = 2, | ||
| } | ||
|
|
||
| impl Serialize for RequestKind { | ||
| fn serialize<S: Serializer>(&self, serializer: S) -> Result<S::Ok, S::Error> { | ||
| serializer.serialize_u8(*self as u8) | ||
| } | ||
| } | ||
|
|
||
| #[derive(Clone, Copy, Debug, TupleSerialize)] | ||
| struct Request { | ||
| seq: u64, | ||
| kind: RequestKind, | ||
| } | ||
|
|
||
| impl Request { | ||
| /// A request to time the round trip numbered `seq`. | ||
| fn measure(seq: u64) -> Self { | ||
| Self { | ||
| seq, | ||
| kind: RequestKind::Measure, | ||
| } | ||
| } | ||
|
|
||
| /// The request that ends a run, reporting whether it succeeded. | ||
| fn ending(outcome: &Result<(), Error>) -> Self { | ||
| Self { | ||
| seq: 0, | ||
| kind: match outcome { | ||
| Ok(()) => RequestKind::Finished, | ||
| Err(_) => RequestKind::Failed, | ||
| }, | ||
| } | ||
| } | ||
| } |
There was a problem hiding this comment.
Why all this instead of
enum RequestKind {
Measure(u64),
Finished,
Failed,
}
Is this simply to avoid the serialization overhead? Part of the goal was to measure that, and you actually still have serialization overhead here, so this doesn't actually measure the "fast" version anyway.
There was a problem hiding this comment.
TupleSerializer doesn't work for enum; it expects a struct.
| #[snafu(display("oqbench.iterations must be non-zero ({context})"))] | ||
| ZeroIterations, | ||
|
|
||
| #[snafu(display("oqbench.rt_prio must be in 1..=99, got {rt_prio} ({context})"))] | ||
| BadRealTimePriority { rt_prio: u32 }, | ||
|
|
||
| #[snafu(display( | ||
| "stale reply in the queue before producing seq {seq} (its seq={stale_seq}) ({context})" | ||
| ))] | ||
| StaleReply { seq: u64, stale_seq: u64 }, | ||
|
|
||
| #[snafu(display( | ||
| "out-of-sequence reply: expected seq {seq}, got seq {replied_seq} ({context})" | ||
| ))] | ||
| OutOfSequence { seq: u64, replied_seq: u64 }, | ||
|
|
||
| #[snafu(display( | ||
| "reply timeout at seq {seq} after {timeout_ms}ms ({elapsed} cycles) ({context})" | ||
| ))] | ||
| ReplyTimeout { | ||
| seq: u64, | ||
| timeout_ms: u32, | ||
| elapsed: u64, | ||
| }, | ||
|
|
||
| #[snafu(display( | ||
| "the userspace peer did not send {expected:?} within {PEER_SIGNAL_TIMEOUT_MS}ms ({context})" | ||
| ))] | ||
| PeerSilent { expected: PeerSignal }, | ||
|
|
||
| #[snafu(display( | ||
| "the userspace peer sent {received:?} while waiting for {expected:?} ({context})" | ||
| ))] | ||
| UnexpectedSignal { | ||
| expected: PeerSignal, | ||
| received: PeerSignal, | ||
| }, |
There was a problem hiding this comment.
I don't need you to change anything, but there is something worth knowing if you don't already:
There are significant differences of opinion on how to divide up error handling. Part of this is because errors actually serve two purposes: programatic error handling and debugging (configuration or program). You have written something here that is very granular and useful for debugging, but if you actually had to handle errors it would be really irritating. Code calling into this probably only cares if the error is: a bad configuration or a runtime failure. I suspect the ideal design here would be a simple error type with just a couple of cases and those cases containing &str or another type that can be formatted the as required. This moves the granular details inward to code calling this doesn't have to know about it.
Like I said, I don't need you to change this. It's fine. However, this is something to think about as we build out the system.
| if let Some(problem) = config_problem { | ||
| return Err(problem); | ||
| } |
There was a problem hiding this comment.
I didn't find the callsite, but I think this shouldn't be here and you should use ? or some map function instead. Calling a function and telling it stuff has already failed is just weird. Is there a specific reason to do it here?
| fn decode_request(bytes: &[u8]) -> Result<Option<(Request, usize)>, Error> { | ||
| let mut decoder = minicbor::decode::Decoder::new(bytes); | ||
| let Ok(fields) = decoder.array() else { | ||
| return Ok(None); | ||
| }; | ||
| if fields != Some(2) { | ||
| return NotARequestSnafu { fields }.fail(); | ||
| } | ||
| let Ok(seq) = decoder.u64() else { | ||
| return Ok(None); | ||
| }; | ||
| let Ok(kind) = decoder.u8() else { | ||
| return Ok(None); | ||
| }; | ||
| let request = match kind { | ||
| 0 => Request::Measure(seq), | ||
| 1 => Request::Finished, | ||
| 2 => Request::Failed, | ||
| kind => return UnknownRequestKindSnafu { kind }.fail(), | ||
| }; | ||
| Ok(Some((request, decoder.position()))) | ||
| } |
There was a problem hiding this comment.
It looks like you are manually implementing "TupleDeserialize". See my previous comment about the Request type on the kernel side.
(It's a little ironic that here you have exactly the type, I wrote up for kernel space. I had not read this code.)
| "--vcpus", type=int, default=1, metavar="N", help="guest vCPU count" | ||
| ) | ||
| parser.add_argument( | ||
| "--no-kvm", action="store_true", help="run without KVM acceleration" |
There was a problem hiding this comment.
The default in general is to enable KVM. We should do the same here.
There was a problem hiding this comment.
For a future PR:
It would be good to recommend people use howdone. You don't need to get into details. Just reference it. I want to try to get people used to capturing provenance correctly. We should also make sure howdone picks up the output file correctly.
| let outcome = measure(&config, config_problem, &producer, &consumer, capture_file) | ||
| .inspect_err(report); |
There was a problem hiding this comment.
I think you can just write:
match config_problem {
case None => measure(...),
case Some(err) => report(err)
}
That said. I'm unsure why config and config_problem are split up at all. But you may have a good reason.

As requested in #273, this is a benchmark for the kernel-to-user-to-kernel space round-trip latency via OQFS.