eval_broker: track enqueue and dequeue times

[pkazmierczak]

Adds new metrics to the eval broker that track times of evaluations enqueueing and dequeueing.

[lgfa29]

The leadership transition is probably the key point missing. Not sure if there's a "right" answer, so feel free to explore different approaches and trade-offs.

[lgfa29]

There's some potential weirdness here to consider. Ack and Nack are called with a string ID, but the eval may not exists in the unack queue, so I wonder if there's a possibility where enqueueTime and dequeueTime have an eval ID that is not in unack, causing them to never get cleaned up.

At some point I thought of passing evalID and eval here to handle the clean up but I was being lazy and dropped it 😅

[lgfa29]

It may be worth expanding https://developer.hashicorp.com/nomad/docs/operations/monitoring-nomad#scheduling to mention how to use these metrics as well.

I think tracking response_time is going to be something important to track, and then wait_time and process_time can help nail down the problem. An increase in wait_time probably means too much load. An increase in process_time points more towards a server performance issue (CPU, disk, network etc.)

We likely won't know exactly what to write until we advance in our explorations, but good to keep in mind.

[pkazmierczak]

@lgfa29 @tgross I have a suggestion on how to handle leadership changes in a48e127. I implemented something Luiz suggested in one of his comments, basically the leader calls an evalBroker.Restore method now in restoreEvals() instead of the usual evalBroker.Enqueue. This isn't very elegant, because we have to pass around the information about whether to track {en,de}queue times inside eval broker methods, but then again public methods remain the same so the interface doesn't change.

Let me know what you think about this.

[tgross]

I have a suggestion on how to handle leadership changes in a48e127. I implemented something Luiz suggested in one of his comments, basically the leader calls an evalBroker.Restore method now in restoreEvals() instead of the usual evalBroker.Enqueue. This isn't very elegant, because we have to pass around the information about whether to track {en,de}queue times inside eval broker methods, but then again public methods remain the same so the interface doesn't change.

This will resolve the issue of misleading metrics by introducing a gap across leader elections. That seems fine so long as we document the expected behavior in the metrics reference.

This doesn't yet resolve the issue of clearing the maps of timings across leader elections. We should clear the maps between terms (either on step-up or step-down, doesn't really matter so whatever is convenient for the broker API).

[pkazmierczak]

This doesn't yet resolve the issue of clearing the maps of timings across leader elections. We should clear the maps between terms (either on step-up or step-down, doesn't really matter so whatever is convenient for the broker API).

Hmm, I thought clearing the map in the flush method as we do here a48e127#diff-727104c8049d79aa6b8bcd481b366a231033732bd9ad314e408933d6ac25f891R848-R849 would solve this problem, because the revokeLeadership method on leader https://github.com/hashicorp/nomad/blob/main/nomad/leader.go#L1488 calls it with enabled set to false? I'll keep looking, perhaps I misunderstand how revoking leadership works.

[tgross]

Hmm, I thought clearing the map in the flush method as we do here a48e127#diff-727104c8049d79aa6b8bcd481b366a231033732bd9ad314e408933d6ac25f891R848-R849 would solve this problem

🤦 yes, you're right that'll do it. Somehow I missed that.