debug could make the CLI more chatty about API requests

[iximeow]

Target component

• CLI
• SDK
• Something else
• Not sure

Overview

in getting to oxidecomputer/omicron#7532, i'd started with a CLI invocation that clearly did something wrong.

./target/debug/oxide --profile dogfood \
    experimental timeseries query \
    --project ixi \
    --query "\
        get virtual_machine:vcpu_usage | \
          filter timestamp >= @2025-02-11T00:59:44.938 && timestamp < @2025-02-11T01:20:24.938 && \
            instance_id == \"cdffcf35-6ae3-488d-a03d-64cf45f88fb2\" && state == \"emulation\" | \
          align mean_within(20s) | group_by [instance_id], sum"

returned

Error Response: status: 400 Bad Request; headers: {"content-type":
"application/json", "x-request-id": "f96ba139-2229-4a39-8435-7f6b39d640fb",
"content-length": "551", "date": "Wed, 12 Feb 2025 20:15:45 GMT"}; value: Error
{ error_code: Some("InvalidRequest"), message: "The filter expression
\"(silo_id == \"7bd7623a-68ed-4636-8ecb-b59e3b068787\") && (project_id ==
\"9c4152f9-4317-4269-9018-66142964d21c\")\" is not valid, the following errors
were encountered\n  > The filter expression refers to identifiers that are not
valid for its input table \"virtual_machine:vcpu_usage\". Invalid identifiers:
[\"silo_id\", \"project_id\"], valid identifiers: [\"datum\", \"instance_id\",
\"start_time\", \"timestamp\"]", request_id:
"f96ba139-2229-4a39-8435-7f6b39d640fb" }

in there is something about a filter expression using silo_id and project_id. that wasn't in my command. was it added by the CLI? SDK? i really wanted to know exactly what the HTTP request was that the CLI made on my behalf. --debug did not really help:

./target/debug/oxide --profile dogfood experimental timeseries query --project ixi --query "\
        get virtual_machine:vcpu_usage | \
          filter timestamp >= @2025-02-11T00:59:44.938 && timestamp < @2025-02-11T01:20:24.938 && \
            instance_id == \"cdffcf35-6ae3-488d-a03d-64cf45f88fb2\" && state == \"emulation\" | \
          align mean_within(20s) | group_by [instance_id, project_id, silo_id], sum"
[2025-02-12T20:43:07Z DEBUG reqwest::connect] starting new connection: https://oxide.sys.rack2.eng.oxide.computer/
{
  "tables": [
... snip ...

i can't really tell why the one random reqwest::connect log is there and nothing else. maybe because we're only configuring env_logger and the dependencies involved use tracing?

so for myself, i'd added eprintln!("request: {:?}", request); in the function handling the project-scoped timeseries query and that got me about what i'd wanted:

• request method
• request path
• query parameters
• headers - unfortunately not all! i stole a cookie from my browser login to auth in my curl reproduction.

(the hostname is good! but i already knew i was talking to dogfood.)

this did not get me the query body for /v1/timeseries/query, unfortunately. i'd guessed at the right POST body and happened to get it first try.

Implementation details

it would be really nice if --debug caused the CLI to log at least a request head before getting to client.client.execute(request) in the various handlers. i think that gets 90% of the way there without sweating request bodies.

Anything else you would like to add?

obviously not all CLI operations are a single HTTP request, and even ones that are, you might not want to log a 100MB POST body. i don't think we have a clever way to know which endpoints we'd expect have reasonably-loggable POST bodies either. ideally for some operations like timeseries queries with these relatively small json POST bodies we could know to log the body for easy reproduction. disk upload in particular is where i would be concerned that is a footgun if used carelessly.

[iximeow]

i suppose it's worth saying: i'd just go Do This but particularly with --debug doing so little i'm not totally sure i'm not just holding it wrong.