Github user hanm commented on a diff in the pull request: https://github.com/apache/zookeeper/pull/307#discussion_r184910779 --- Diff: src/java/main/org/apache/zookeeper/server/ServerStats.java --- @@ -148,9 +174,46 @@ synchronized public void resetRequestCounters(){ packetsReceived = 0; packetsSent = 0; } + synchronized public void resetNumRequestsAboveThresholdTime() { + numRequestsAboveThresholdTime = 0; + } synchronized public void reset() { resetLatency(); resetRequestCounters(); + resetNumRequestsAboveThresholdTime(); + } + + public void checkLatency(final ZooKeeperServer zks, Request request) { + long requestLatency = Time.currentElapsedTime() - request.createTime; + boolean enabledAndAboveThreshold = (requestWarnThresholdMs == 0) || + (requestWarnThresholdMs > -1 && requestLatency > requestWarnThresholdMs); + if (enabledAndAboveThreshold) { + zks.serverStats().incNumRequestsAboveThresholdTime(); + + // Try acquiring lock only if not waiting + boolean success = waitForLoggingWarnThresholdMsg.compareAndSet(Boolean.FALSE, Boolean.TRUE); + if (success) { + LOG.warn("Request {} exceeded threshold. Took {} ms", request, requestLatency); + startCount = zks.serverStats().getNumRequestsAboveThresholdTime(); + timer.schedule(new TimerTask() { + @Override + public void run() { + long count = zks.serverStats().getNumRequestsAboveThresholdTime() - startCount; + LOG.warn("Number of requests that exceeded {} ms in past {} ms: {}", + requestWarnThresholdMs, delayTimeForLoggingWarnThresholdMsg, count); + waitForLoggingWarnThresholdMsg.set(Boolean.FALSE); + } + }, delayTimeForLoggingWarnThresholdMsg); + } + } + } + + public void setDelayTimeForLoggingWarnThresholdMsg(int delay) { + this.delayTimeForLoggingWarnThresholdMsg = delay; --- End diff -- I think it is worth to add some comment about this method. Probably also add comments in the document as well about the behavior of the log and how to control the rate using this method.
---