[GitHub] zookeeper pull request #307: ZOOKEEPER-2770 ZooKeeper slow operation log

[hanm <gi...@git.apache.org>]

Github user hanm commented on a diff in the pull request:

    https://github.com/apache/zookeeper/pull/307#discussion_r184910721
  
    --- 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;
    --- End diff --
    
    If there is no slow requests coming in between the time the task is scheduled and the time the task is executed, this count will be 0. It will not reflect the actual number of requests we want to log. Maybe log the startCount instead and reset it and leave the task only to reset the barrier?
    
    Also please use ScheduledService instead of Timer task.


---