chore: add canister message queue latency metric #1510
Conversation
maksymar
changed the title
| let message_type_label = "request"; | ||
| let call_tree_depth_label = &metadata.call_tree_depth().to_string(); | ||
| let latency = current_time() | ||
| .saturating_duration_since(*metadata.call_tree_start_time()) |
There was a problem hiding this comment.
IIRC the call tree start time is the time when the message at the root of the call tree started execution. Regardless, it has to do with the call tree, not with the individual message being executed. So a message enqueued in the same block (i.e. at the same time) when it's executed could have a call tree start time that is arbitrarily old.
| let now = current_time(); | ||
| let expiry_duration = expiry_time_from_now().saturating_duration_since(now); | ||
| let start = ingress.expiry_time.saturating_sub(expiry_duration); | ||
| let latency = now.saturating_duration_since(start).as_secs_f64(); |
There was a problem hiding this comment.
Based on your PR description you are very likely aware of this, but I will still mention that the expiry time can be set by the caller to an arbitrary value, i.e. much lower than the maximum 5 minutes. So this calculation may also be way off.
(In fact, I seem to remember subnets where this is consistently significantly less than 5 minutes. There's an mr_unreliable_induct_ingress_message_duration_seconds metric that uses similar logic to estimate ingress induction latency. You can go here, unhide the first query and try selecting various subnets.)
This PR adds a metric to measure the queue latency of canister messages for both
ingressandrequestmessages.For
ingressmessages, since the start time is not stored, the start time is estimated using the expiry time and the current expiration limit. The metric also tracks the call depth forrequestmessages, as it is relevant for them.