Uploaded image for project: 'Hadoop Common'
  1. Hadoop Common
  2. HADOOP-12602

TestMetricsSystemImpl#testQSize occasionally fail

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.8.0, 2.7.3, 3.0.0-alpha1
    • Component/s: test
    • Labels:
      None
    • Hadoop Flags:
      Reviewed

      Description

      I have seen this test failed a few times in the past.
      Error Message

      metricsSink.putMetrics(<Capturing argument>);
      Wanted 2 times:
      -> at org.apache.hadoop.metrics2.impl.TestMetricsSystemImpl.testQSize(TestMetricsSystemImpl.java:472)
      But was 1 time:
      -> at org.apache.hadoop.metrics2.impl.MetricsSinkAdapter.consume(MetricsSinkAdapter.java:183)
      

      Stacktrace

      org.mockito.exceptions.verification.TooLittleActualInvocations: 
      metricsSink.putMetrics(<Capturing argument>);
      Wanted 2 times:
      -> at org.apache.hadoop.metrics2.impl.TestMetricsSystemImpl.testQSize(TestMetricsSystemImpl.java:472)
      But was 1 time:
      -> at org.apache.hadoop.metrics2.impl.MetricsSinkAdapter.consume(MetricsSinkAdapter.java:183)
      
      	at org.apache.hadoop.metrics2.impl.TestMetricsSystemImpl.testQSize(TestMetricsSystemImpl.java:472)
      

      Standard Output

      2015-11-25 19:07:49,867 INFO  impl.MetricsConfig (MetricsConfig.java:loadFirst(115)) - loaded properties from hadoop-metrics2-test.properties
      2015-11-25 19:07:49,932 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:startTimer(374)) - Scheduled snapshot period at 10 second(s).
      2015-11-25 19:07:49,932 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:start(192)) - Test metrics system started
      2015-11-25 19:07:50,134 INFO  impl.MetricsSinkAdapter (MetricsSinkAdapter.java:start(203)) - Sink slowSink started
      2015-11-25 19:07:50,135 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:registerSink(301)) - Registered sink slowSink
      2015-11-25 19:07:50,135 INFO  impl.MetricsSinkAdapter (MetricsSinkAdapter.java:start(203)) - Sink dataSink started
      2015-11-25 19:07:50,136 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:registerSink(301)) - Registered sink dataSink
      2015-11-25 19:07:50,746 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(211)) - Stopping Test metrics system...
      2015-11-25 19:07:50,747 INFO  impl.MetricsSinkAdapter (MetricsSinkAdapter.java:publishMetricsFromQueue(140)) - slowSink thread interrupted.
      2015-11-25 19:07:50,748 INFO  impl.MetricsSinkAdapter (MetricsSinkAdapter.java:publishMetricsFromQueue(140)) - dataSink thread interrupted.
      2015-11-25 19:07:50,748 INFO  impl.MetricsSystemImpl (MetricsSystemImpl.java:stop(217)) - Test metrics system stopped.
      
      1. HADOOP-12602.001.patch
        0.9 kB
        Masatake Iwasaki

        Activity

        Hide
        iwasakims Masatake Iwasaki added a comment -

        Thanks for reporting this, Wei-Chiu Chuang. I could reproduce the failure. The cause is that the metrics published by 2nd MetricsSystemImpl#onTimerEvent could be dropped.

        Because the default capacity of SinkQueue is 1, if MetricsSystemImpl#onTimerEvent is called before the 1st MetricsBuffer is consumed by sink, it can not enqueue the 2nd MetricsBuffer. The dataSink.putMetrics is expected to be called twice but it never be if 2nd MetricsBuffer is dropped.

        Increasing the capacity of SinkQueue solved the test failure.

        Show
        iwasakims Masatake Iwasaki added a comment - Thanks for reporting this, Wei-Chiu Chuang . I could reproduce the failure. The cause is that the metrics published by 2nd MetricsSystemImpl#onTimerEvent could be dropped. Because the default capacity of SinkQueue is 1, if MetricsSystemImpl#onTimerEvent is called before the 1st MetricsBuffer is consumed by sink, it can not enqueue the 2nd MetricsBuffer. The dataSink.putMetrics is expected to be called twice but it never be if 2nd MetricsBuffer is dropped. Increasing the capacity of SinkQueue solved the test failure.
        Hide
        hadoopqa Hadoop QA added a comment -
        -1 overall



        Vote Subsystem Runtime Comment
        0 reexec 0m 0s Docker mode activated.
        +1 @author 0m 0s The patch does not contain any @author tags.
        +1 test4tests 0m 0s The patch appears to include 1 new or modified test files.
        +1 mvninstall 7m 57s trunk passed
        +1 compile 8m 32s trunk passed with JDK v1.8.0_66
        +1 compile 9m 24s trunk passed with JDK v1.7.0_85
        +1 checkstyle 0m 16s trunk passed
        +1 mvnsite 1m 4s trunk passed
        +1 mvneclipse 0m 15s trunk passed
        +1 findbugs 1m 58s trunk passed
        +1 javadoc 0m 57s trunk passed with JDK v1.8.0_66
        +1 javadoc 1m 7s trunk passed with JDK v1.7.0_85
        +1 mvninstall 1m 40s the patch passed
        +1 compile 8m 59s the patch passed with JDK v1.8.0_66
        +1 javac 8m 59s the patch passed
        +1 compile 10m 47s the patch passed with JDK v1.7.0_85
        +1 javac 10m 47s the patch passed
        +1 checkstyle 0m 18s the patch passed
        +1 mvnsite 1m 14s the patch passed
        +1 mvneclipse 0m 15s the patch passed
        +1 whitespace 0m 0s Patch has no whitespace issues.
        +1 findbugs 2m 25s the patch passed
        +1 javadoc 1m 7s the patch passed with JDK v1.8.0_66
        +1 javadoc 1m 17s the patch passed with JDK v1.7.0_85
        -1 unit 8m 58s hadoop-common in the patch failed with JDK v1.8.0_66.
        -1 unit 8m 48s hadoop-common in the patch failed with JDK v1.7.0_85.
        +1 asflicense 0m 27s Patch does not generate ASF License warnings.
        79m 3s



        Reason Tests
        JDK v1.8.0_66 Failed junit tests hadoop.fs.shell.TestCopyPreserveFlag
        JDK v1.7.0_85 Failed junit tests hadoop.ipc.TestIPC



        Subsystem Report/Notes
        Docker Image:yetus/hadoop:0ca8df7
        JIRA Patch URL https://issues.apache.org/jira/secure/attachment/12774560/HADOOP-12602.001.patch
        JIRA Issue HADOOP-12602
        Optional Tests asflicense compile javac javadoc mvninstall mvnsite unit findbugs checkstyle
        uname Linux 45874c48e840 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux
        Build tool maven
        Personality /testptch/hadoop/patchprocess/precommit/personality/provided.sh
        git revision trunk / 9f256d1
        findbugs v3.0.0
        unit https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.8.0_66.txt
        unit https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.7.0_85.txt
        unit test logs https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.8.0_66.txt https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.7.0_85.txt
        JDK v1.7.0_85 Test Results https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/testReport/
        modules C: hadoop-common-project/hadoop-common U: hadoop-common-project/hadoop-common
        Max memory used 76MB
        Powered by Apache Yetus http://yetus.apache.org
        Console output https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/console

        This message was automatically generated.

        Show
        hadoopqa Hadoop QA added a comment - -1 overall Vote Subsystem Runtime Comment 0 reexec 0m 0s Docker mode activated. +1 @author 0m 0s The patch does not contain any @author tags. +1 test4tests 0m 0s The patch appears to include 1 new or modified test files. +1 mvninstall 7m 57s trunk passed +1 compile 8m 32s trunk passed with JDK v1.8.0_66 +1 compile 9m 24s trunk passed with JDK v1.7.0_85 +1 checkstyle 0m 16s trunk passed +1 mvnsite 1m 4s trunk passed +1 mvneclipse 0m 15s trunk passed +1 findbugs 1m 58s trunk passed +1 javadoc 0m 57s trunk passed with JDK v1.8.0_66 +1 javadoc 1m 7s trunk passed with JDK v1.7.0_85 +1 mvninstall 1m 40s the patch passed +1 compile 8m 59s the patch passed with JDK v1.8.0_66 +1 javac 8m 59s the patch passed +1 compile 10m 47s the patch passed with JDK v1.7.0_85 +1 javac 10m 47s the patch passed +1 checkstyle 0m 18s the patch passed +1 mvnsite 1m 14s the patch passed +1 mvneclipse 0m 15s the patch passed +1 whitespace 0m 0s Patch has no whitespace issues. +1 findbugs 2m 25s the patch passed +1 javadoc 1m 7s the patch passed with JDK v1.8.0_66 +1 javadoc 1m 17s the patch passed with JDK v1.7.0_85 -1 unit 8m 58s hadoop-common in the patch failed with JDK v1.8.0_66. -1 unit 8m 48s hadoop-common in the patch failed with JDK v1.7.0_85. +1 asflicense 0m 27s Patch does not generate ASF License warnings. 79m 3s Reason Tests JDK v1.8.0_66 Failed junit tests hadoop.fs.shell.TestCopyPreserveFlag JDK v1.7.0_85 Failed junit tests hadoop.ipc.TestIPC Subsystem Report/Notes Docker Image:yetus/hadoop:0ca8df7 JIRA Patch URL https://issues.apache.org/jira/secure/attachment/12774560/HADOOP-12602.001.patch JIRA Issue HADOOP-12602 Optional Tests asflicense compile javac javadoc mvninstall mvnsite unit findbugs checkstyle uname Linux 45874c48e840 3.13.0-36-lowlatency #63-Ubuntu SMP PREEMPT Wed Sep 3 21:56:12 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux Build tool maven Personality /testptch/hadoop/patchprocess/precommit/personality/provided.sh git revision trunk / 9f256d1 findbugs v3.0.0 unit https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.8.0_66.txt unit https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.7.0_85.txt unit test logs https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.8.0_66.txt https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/artifact/patchprocess/patch-unit-hadoop-common-project_hadoop-common-jdk1.7.0_85.txt JDK v1.7.0_85 Test Results https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/testReport/ modules C: hadoop-common-project/hadoop-common U: hadoop-common-project/hadoop-common Max memory used 76MB Powered by Apache Yetus http://yetus.apache.org Console output https://builds.apache.org/job/PreCommit-HADOOP-Build/8161/console This message was automatically generated.
        Hide
        iwasakims Masatake Iwasaki added a comment -

        The failure of TestCopyPreserveFlag was already filed as HADOOP-12589.

        Show
        iwasakims Masatake Iwasaki added a comment - The failure of TestCopyPreserveFlag was already filed as HADOOP-12589 .
        Hide
        xiaochen Xiao Chen added a comment -

        Thanks Masatake Iwasaki for working on this. The analysis and fix makes sense to me. +1 (non-binding).

        Show
        xiaochen Xiao Chen added a comment - Thanks Masatake Iwasaki for working on this. The analysis and fix makes sense to me. +1 (non-binding).
        Hide
        jojochuang Wei-Chiu Chuang added a comment -

        The cause analysis looks reasonable to me.

        Before the patch, this test fails in about 1 in 10 runs.
        After the patch, I tested it whole day, and no test failures in 700 runs so far.

        So +1 (non-binding). Thanks for the patch.

        Show
        jojochuang Wei-Chiu Chuang added a comment - The cause analysis looks reasonable to me. Before the patch, this test fails in about 1 in 10 runs. After the patch, I tested it whole day, and no test failures in 700 runs so far. So +1 (non-binding). Thanks for the patch.
        Hide
        iwasakims Masatake Iwasaki added a comment -

        Wei-Chiu Chuang and Xiao Chen, Thanks for reviewing and testing the patch.

        Show
        iwasakims Masatake Iwasaki added a comment - Wei-Chiu Chuang and Xiao Chen , Thanks for reviewing and testing the patch.
        Hide
        ajisakaa Akira Ajisaka added a comment -

        +1, committing this.

        Show
        ajisakaa Akira Ajisaka added a comment - +1, committing this.
        Hide
        hudson Hudson added a comment -

        FAILURE: Integrated in Hadoop-trunk-Commit #8953 (See https://builds.apache.org/job/Hadoop-trunk-Commit/8953/)
        HADOOP-12602. TestMetricsSystemImpl#testQSize occasionally fails. (aajisaka: rev eee0cf4611b02171e8a043f1cc5f7dbad47fc3b4)

        • hadoop-common-project/hadoop-common/CHANGES.txt
        • hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/metrics2/impl/TestMetricsSystemImpl.java
        Show
        hudson Hudson added a comment - FAILURE: Integrated in Hadoop-trunk-Commit #8953 (See https://builds.apache.org/job/Hadoop-trunk-Commit/8953/ ) HADOOP-12602 . TestMetricsSystemImpl#testQSize occasionally fails. (aajisaka: rev eee0cf4611b02171e8a043f1cc5f7dbad47fc3b4) hadoop-common-project/hadoop-common/CHANGES.txt hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/metrics2/impl/TestMetricsSystemImpl.java
        Hide
        ajisakaa Akira Ajisaka added a comment -

        Committed to trunk, branch-2, branch-2.8, and branch-2.7. Thanks Masatake Iwasaki for the contribution, Xiao Chen for reviewing, and Wei-Chiu Chuang for testing.

        Show
        ajisakaa Akira Ajisaka added a comment - Committed to trunk, branch-2, branch-2.8, and branch-2.7. Thanks Masatake Iwasaki for the contribution, Xiao Chen for reviewing, and Wei-Chiu Chuang for testing.
        Hide
        hudson Hudson added a comment -

        FAILURE: Integrated in Hadoop-Hdfs-trunk-Java8 #685 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk-Java8/685/)
        HADOOP-12602. TestMetricsSystemImpl#testQSize occasionally fails. (aajisaka: rev eee0cf4611b02171e8a043f1cc5f7dbad47fc3b4)

        • hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/metrics2/impl/TestMetricsSystemImpl.java
        • hadoop-common-project/hadoop-common/CHANGES.txt
        Show
        hudson Hudson added a comment - FAILURE: Integrated in Hadoop-Hdfs-trunk-Java8 #685 (See https://builds.apache.org/job/Hadoop-Hdfs-trunk-Java8/685/ ) HADOOP-12602 . TestMetricsSystemImpl#testQSize occasionally fails. (aajisaka: rev eee0cf4611b02171e8a043f1cc5f7dbad47fc3b4) hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/metrics2/impl/TestMetricsSystemImpl.java hadoop-common-project/hadoop-common/CHANGES.txt
        Hide
        iwasakims Masatake Iwasaki added a comment -

        Thanks, Akira Ajisaka!

        Show
        iwasakims Masatake Iwasaki added a comment - Thanks, Akira Ajisaka !
        Hide
        vinodkv Vinod Kumar Vavilapalli added a comment -

        Closing the JIRA as part of 2.7.3 release.

        Show
        vinodkv Vinod Kumar Vavilapalli added a comment - Closing the JIRA as part of 2.7.3 release.

          People

          • Assignee:
            iwasakims Masatake Iwasaki
            Reporter:
            jojochuang Wei-Chiu Chuang
          • Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development