HBase
  1. HBase
  2. HBASE-5706

"Dropping fs latency stats since buffer is full" spam

    Details

    • Type: Improvement Improvement
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 0.94.0, 0.95.0
    • Component/s: None
    • Labels:
      None
    • Hadoop Flags:
      Reviewed

      Description

      I see tons of this while running tests (note that it's a WARN):

      2012-04-03 18:54:47,172 WARN org.apache.hadoop.hbase.io.hfile.HFile: Dropping fs latency stats since buffer is full
      

      While the code says this:

        // we don't want to fill up the logs with this message, so only log it 
        // once every 30 seconds at most
        // I also want to avoid locks on the 'critical path' (the common case will be
        // uncontended) - hence the CAS
        private static void logDroppedLatencyStat() {
      

      It doesn't seem like this message is actionnable and even though it's printed "only" every 30 seconds it's still very spammy.

      We should get rid of it or make it more useful (I don't know which).

      1. HBASE-5706.patch
        2 kB
        Shaneal Manek

        Activity

        Hide
        Hudson added a comment -

        Integrated in HBase-TRUNK-security #157 (See https://builds.apache.org/job/HBase-TRUNK-security/157/)
        HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309457)

        Result = FAILURE
        stack :
        Files :

        • /hbase/trunk/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Show
        Hudson added a comment - Integrated in HBase-TRUNK-security #157 (See https://builds.apache.org/job/HBase-TRUNK-security/157/ ) HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309457) Result = FAILURE stack : Files : /hbase/trunk/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Hide
        Hudson added a comment -

        Integrated in HBase-0.94-security #7 (See https://builds.apache.org/job/HBase-0.94-security/7/)
        HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309459)

        Result = SUCCESS
        stack :
        Files :

        • /hbase/branches/0.94/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Show
        Hudson added a comment - Integrated in HBase-0.94-security #7 (See https://builds.apache.org/job/HBase-0.94-security/7/ ) HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309459) Result = SUCCESS stack : Files : /hbase/branches/0.94/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Hide
        Hudson added a comment -

        Integrated in HBase-0.94 #85 (See https://builds.apache.org/job/HBase-0.94/85/)
        HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309459)

        Result = FAILURE
        stack :
        Files :

        • /hbase/branches/0.94/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Show
        Hudson added a comment - Integrated in HBase-0.94 #85 (See https://builds.apache.org/job/HBase-0.94/85/ ) HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309459) Result = FAILURE stack : Files : /hbase/branches/0.94/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Hide
        Hudson added a comment -

        Integrated in HBase-TRUNK #2709 (See https://builds.apache.org/job/HBase-TRUNK/2709/)
        HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309457)

        Result = FAILURE
        stack :
        Files :

        • /hbase/trunk/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Show
        Hudson added a comment - Integrated in HBase-TRUNK #2709 (See https://builds.apache.org/job/HBase-TRUNK/2709/ ) HBASE-5706 'Dropping fs latency stats since buffer is full' spam (Revision 1309457) Result = FAILURE stack : Files : /hbase/trunk/src/main/java/org/apache/hadoop/hbase/io/hfile/HFile.java
        Hide
        stack added a comment -

        Committed branch and trunk. Thanks for the patch Shaneal.

        Show
        stack added a comment - Committed branch and trunk. Thanks for the patch Shaneal.
        Hide
        Hadoop QA added a comment -

        -1 overall. Here are the results of testing the latest attachment
        http://issues.apache.org/jira/secure/attachment/12521260/HBASE-5706.patch
        against trunk revision .

        +1 @author. The patch does not contain any @author tags.

        -1 tests included. The patch doesn't appear to include any new or modified tests.
        Please justify why no new tests are needed for this patch.
        Also please list what manual steps were performed to verify this patch.

        +1 javadoc. The javadoc tool did not generate any warning messages.

        +1 javac. The applied patch does not increase the total number of javac compiler warnings.

        -1 findbugs. The patch appears to introduce 2 new Findbugs (version 1.3.9) warnings.

        +1 release audit. The applied patch does not increase the total number of release audit warnings.

        -1 core tests. The patch failed these unit tests:
        org.apache.hadoop.hbase.mapreduce.TestMultithreadedTableMapper
        org.apache.hadoop.hbase.mapreduce.TestImportTsv
        org.apache.hadoop.hbase.mapred.TestTableMapReduce
        org.apache.hadoop.hbase.mapreduce.TestHFileOutputFormat
        org.apache.hadoop.hbase.mapreduce.TestTableMapReduce

        Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//testReport/
        Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//artifact/trunk/patchprocess/newPatchFindbugsWarnings.html
        Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//console

        This message is automatically generated.

        Show
        Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12521260/HBASE-5706.patch against trunk revision . +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. -1 findbugs. The patch appears to introduce 2 new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. -1 core tests. The patch failed these unit tests: org.apache.hadoop.hbase.mapreduce.TestMultithreadedTableMapper org.apache.hadoop.hbase.mapreduce.TestImportTsv org.apache.hadoop.hbase.mapred.TestTableMapReduce org.apache.hadoop.hbase.mapreduce.TestHFileOutputFormat org.apache.hadoop.hbase.mapreduce.TestTableMapReduce Test results: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//artifact/trunk/patchprocess/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-HBASE-Build/1383//console This message is automatically generated.
        Hide
        Shaneal Manek added a comment -

        Patch just removes the (rate limited) log message.

        Show
        Shaneal Manek added a comment - Patch just removes the (rate limited) log message.
        Hide
        Shaneal Manek added a comment -

        On consideration, I think JD and Andrew are right. It's relatively expensive to log (although we're talking less than a micro of overhead per PUT near as I can tell) and, more importantly, not at all actionable. We could make the queue size tweakable via configs, but I don't think that's something users should have to care about.

        So let's just get rid of it. I've attached a patch that seems to apply cleanly to 0.94/0.96/trunk.

        Thanks for pointing it out! I think I'm just used to working on smaller projects where the original devs are the only ones who will ever see the system logs I'm personally interested in that log message out of idle curiosity, but users of HBase do not (and should not) care.

        Show
        Shaneal Manek added a comment - On consideration, I think JD and Andrew are right. It's relatively expensive to log (although we're talking less than a micro of overhead per PUT near as I can tell) and, more importantly, not at all actionable. We could make the queue size tweakable via configs, but I don't think that's something users should have to care about. So let's just get rid of it. I've attached a patch that seems to apply cleanly to 0.94/0.96/trunk. Thanks for pointing it out! I think I'm just used to working on smaller projects where the original devs are the only ones who will ever see the system logs I'm personally interested in that log message out of idle curiosity, but users of HBase do not (and should not) care.
        Hide
        Andrew Purtell added a comment -

        Interesting, this came up today here too. I've been playing around with a slightly modified version of this patch. Under high load the FS latency stat buffers can fill up before the metrics thread drains them, doesn't seem an exceptional condition. Removing logDroppedLatencyStat() and logging around it gets rid of a number of branches and a CAS from a hot code path, so that's what we did.

        Show
        Andrew Purtell added a comment - Interesting, this came up today here too. I've been playing around with a slightly modified version of this patch. Under high load the FS latency stat buffers can fill up before the metrics thread drains them, doesn't seem an exceptional condition. Removing logDroppedLatencyStat() and logging around it gets rid of a number of branches and a CAS from a hot code path, so that's what we did.
        Hide
        stack added a comment -

        Assigning Shaneal so he'll at least take a look at it. Make a recommendation boss and one of us can fix it. Good on you.

        Show
        stack added a comment - Assigning Shaneal so he'll at least take a look at it. Make a recommendation boss and one of us can fix it. Good on you.

          People

          • Assignee:
            Shaneal Manek
            Reporter:
            Jean-Daniel Cryans
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development