feat(metrics): add IO queue len and backend latency metrics

[kalyazin]

Changes

This adds the following accumulated metrics:

• block IO: read and write backend latencies (read_agg, write_agg)
• block IO: length of the queue backlog (remaining_reqs_count)
• net: tap write backend latencies (tap_agg)
• net: length of the Tx queue backlog (tx_remaining_reqs_count)

The latency metrics show how long the VMM thread spends waiting for the requests being processed by the block/net backend. The queue backlog metrics show how many requests are still waiting to be processed by the VMM thread. They are updated during processing of every request, so dividing it by the total number of requests would show the average queue length per request processing.

Reason

We would like to have more visibility on how block and network backends are saturated.

License Acceptance

By submitting this pull request, I confirm that my contribution is made under
the terms of the Apache 2.0 license. For more information on following Developer
Certificate of Origin and signing off your commits, please check
CONTRIBUTING.md.

PR Checklist

• [ ] If a specific issue led to this PR, this PR closes the issue.
• The description of changes is clear and encompassing.
• Any required documentation changes (code and docs) are included in this
  PR.
• [ ] API changes follow the Runbook for Firecracker API changes.
• User-facing changes are mentioned in CHANGELOG.md.
• All added/changed functionality is tested.
• [ ] New TODOs link to an issue.
• Commits meet
  contribution quality standards.

---

• This functionality cannot be added in rust-vmm.

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 81.65%. Comparing base (8d09bae) to head (d2131e3).

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #4486      +/-   ##
==========================================
+ Coverage   81.61%   81.65%   +0.03%     
==========================================
  Files         243      243              
  Lines       29794    29825      +31     
==========================================
+ Hits        24316    24353      +37     
+ Misses       5478     5472       -6     

Flag	Coverage Δ
4.14-c5n.metal	78.97% <100.00%> (?)
4.14-c7g.metal	?
4.14-m5d.metal	?
4.14-m5n.metal	78.96% <100.00%> (?)
4.14-m6a.metal	78.10% <100.00%> (+0.02%)	⬆️
4.14-m6g.metal	77.05% <100.00%> (+0.02%)	⬆️
4.14-m6i.metal	78.95% <100.00%> (+0.02%)	⬆️
4.14-m7g.metal	77.05% <100.00%> (?)
5.10-c5n.metal	81.62% <100.00%> (?)
5.10-c7g.metal	?
5.10-m5d.metal	?
5.10-m5n.metal	81.61% <100.00%> (?)
5.10-m6a.metal	80.85% <100.00%> (+0.02%)	⬆️
5.10-m6g.metal	79.94% <100.00%> (+0.02%)	⬆️
5.10-m6i.metal	81.61% <100.00%> (+0.02%)	⬆️
5.10-m7g.metal	79.94% <100.00%> (?)
6.1-c5n.metal	81.62% <100.00%> (?)
6.1-m5n.metal	81.61% <100.00%> (?)
6.1-m6a.metal	80.85% <100.00%> (+0.02%)	⬆️
6.1-m6g.metal	79.94% <100.00%> (+0.02%)	⬆️
6.1-m6i.metal	81.61% <100.00%> (+0.02%)	⬆️
6.1-m7g.metal	79.94% <100.00%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[bchalios]

Generally LGTM.

I would like it if there was more information in the commit messages about what the commit does and mainly why. Right now, the descriptions make sense reading the PR description, but by themselves are a bit cryptic.

Other than that, right now, the new latency metrics only measure the backend. I think it would make sense to also measure the time we spend in Firecracker to handle each request. Ideally, this should give us a sense of the "overhead" of Firecracker's processing and could point to low-hanging fruit optimizations in the short term, as well as protect us from doing stupid things in the long term. WDYT?

[wearyzen]

The queue backlog metrics show how many requests are still waiting to be processed by the VMM thread. They are updated during processing of every request,

remaining_reqs_count and tx_remaining_reqs_count could be bit confusing since they are reset every time we flush. So technically there could be requests still pending in the queue but metrics won't report them because they have already been reported. I think its fine the way they are right now but we should explicitly call out that these 2 metrics being 0 does not mean that there are no requests in queue. This could be confusing if we are debugging a crash where the last metrics showed that there are no requests but there actually were.

so dividing it by the total number of requests would show the average queue length per request processing.

Can we document it in CHANGELOG or in code saying divide by the metric queue_event_count to get avg queue lenght?
Maybe worth adding a small section in https://github.com./firecracker-microvm/firecracker/blob/main/docs/metrics.md to highlight how these metrics can help with analysing saturation.

[kalyazin]

The queue backlog metrics show how many requests are still waiting to be processed by the VMM thread. They are updated during processing of every request,

remaining_reqs_count and tx_remaining_reqs_count could be bit confusing since they are reset every time we flush. So technically there could be requests still pending in the queue but metrics won't report them because they have already been reported. I think its fine the way they are right now but we should explicitly call out that these 2 metrics being 0 does not mean that there are no requests in queue. This could be confusing if we are debugging a crash where the last metrics showed that there are no requests but there actually were.

so dividing it by the total number of requests would show the average queue length per request processing.

Can we document it in CHANGELOG or in code saying divide by the metric queue_event_count to get avg queue lenght? Maybe worth adding a small section in https://github.com./firecracker-microvm/firecracker/blob/main/docs/metrics.md to highlight how these metrics can help with analysing saturation.

added a note in the changelog, but not in doc for now.

[kalyazin]

Generally LGTM.

I would like it if there was more information in the commit messages about what the commit does and mainly why. Right now, the descriptions make sense reading the PR description, but by themselves are a bit cryptic.

Other than that, right now, the new latency metrics only measure the backend. I think it would make sense to also measure the time we spend in Firecracker to handle each request. Ideally, this should give us a sense of the "overhead" of Firecracker's processing and could point to low-hanging fruit optimizations in the short term, as well as protect us from doing stupid things in the long term. WDYT?

Added more info in commit messages. I agree, it would be useful to have a pie chart of VMM time split by idling, being busy and blocked on lower layers. That could be the next step.

[wearyzen]

LGTM, thanks for adding latency_agg_metrics in the fcmetrics.py tests as well!