Add a metric to capture write enqueue latency#193
Conversation
This allows to spot issues where evcache is overloaded and supports some basic prediction of whether an instance might become overloaded with a significant traffic increase or whether the thread pool could be tuned.
akhaku
left a comment
There was a problem hiding this comment.
technically not sent on the wire but passed to the non-blocking socket, right?
Generally LGTM
| if (wc <= 0L || wc < operationAttachedNs) return; | ||
| loopEnqueueToWriteLatency.record(wc - operationAttachedNs, TimeUnit.NANOSECONDS); | ||
| } catch (Throwable t) { | ||
| if (log.isDebugEnabled()) log.debug("recordLoopEnqueueToWriteLatency failed", t); |
There was a problem hiding this comment.
we don't really need the isDebugEnabled check here right since the expression in log.debug is cheap
There was a problem hiding this comment.
Yes. Updated the comments to make that more clear, and dropped that catch there since the onyl thing we have is a record() call. -> a6d34e2
The previous name implied a percent (0-100) and suggested it measured the loop's own runtime. The value is actually a fraction (0-1) of thread CPU time over wall time, which excludes time the thread is parked in selector.select() and time it was runnable but descheduled. Renaming makes the units and the underlying measurement explicit so consumers don't accidentally treat it as a percent or as a direct measure of loop load.
This captures from when the caller tries to send a request until the request is finally sent on the wire, primarily so we can see when the enqueue time is increasing (a signal for pressure on the IO loop).
a6d34e2 to
e6f6073
Compare
|
I think this needs a little work. Even though per-op latency is OK, when we multiply it by 100x for a 100-element bulk call the latency can stack up to 10's of microseconds. Not a lot, but, if we can reorder the PR i think we can do a bit better. (TODO note for myself - this code should, instead of writing directly to metrics, accumulate metrics in a TimerBatchUpdater). Likely this batching can be applied to other evcache batch query metrics too. |
5c09926 to
e685956
Compare
This captures from when the caller tries to send a request until the request is finally sent on the wire, primarily so we can see when the enqueue time is increasing (a signal for pressure on the IO loop).