Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Fixed
-
3.3.6
-
Reviewed
Description
Currently, FSEditLogAsync is enabled by default.
We have below codes in method Server$RpcCall#run:
if (!isResponseDeferred()) { long deltaNanos = Time.monotonicNowNanos() - startNanos; ProcessingDetails details = getProcessingDetails(); details.set(Timing.PROCESSING, deltaNanos, TimeUnit.NANOSECONDS); deltaNanos -= details.get(Timing.LOCKWAIT, TimeUnit.NANOSECONDS); deltaNanos -= details.get(Timing.LOCKSHARED, TimeUnit.NANOSECONDS); deltaNanos -= details.get(Timing.LOCKEXCLUSIVE, TimeUnit.NANOSECONDS); details.set(Timing.LOCKFREE, deltaNanos, TimeUnit.NANOSECONDS); startNanos = Time.monotonicNowNanos(); setResponseFields(value, responseParams); sendResponse(); deltaNanos = Time.monotonicNowNanos() - startNanos; details.set(Timing.RESPONSE, deltaNanos, TimeUnit.NANOSECONDS); } else { if (LOG.isDebugEnabled()) { LOG.debug("Deferring response for callId: " + this.callId); } }
It computes Timing.RESPONSE of a RpcCall using Time.monotonicNowNanos() - startNanos;
However, if we use async editlogging, we will not send response here but in FSEditLogAsync.RpcEdit#logSyncNotify.
This causes the Timing.RESPONSE of a RpcCall not be exactly accurate.
@Override public void logSyncNotify(RuntimeException syncEx) { try { if (syncEx == null) { call.sendResponse(); } else { call.abortResponse(syncEx); } } catch (Exception e) {} // don't care if not sent. }
Attachments
Issue Links
- links to