[ 
https://issues.apache.org/jira/browse/METRON-1505?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16422848#comment-16422848
 ] 

ASF GitHub Bot commented on METRON-1505:
----------------------------------------

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

    https://github.com/apache/metron/pull/977#discussion_r178600804
  
    --- Diff: 
metron-analytics/metron-profiler/src/test/java/org/apache/metron/profiler/integration/ProfilerIntegrationTest.java
 ---
    @@ -70,247 +66,103 @@
       private static final String TEST_RESOURCES = 
"../../metron-analytics/metron-profiler/src/test";
       private static final String FLUX_PATH = 
"../metron-profiler/src/main/flux/profiler/remote.yaml";
     
    -  /**
    -   * {
    -   * "ip_src_addr": "10.0.0.1",
    -   * "protocol": "HTTPS",
    -   * "length": 10,
    -   * "bytes_in": 234
    -   * }
    -   */
    -  @Multiline
    -  private static String message1;
    -
    -  /**
    -   * {
    -   * "ip_src_addr": "10.0.0.2",
    -   * "protocol": "HTTP",
    -   * "length": 20,
    -   * "bytes_in": 390
    -   * }
    -   */
    -  @Multiline
    -  private static String message2;
    -
    -  /**
    -   * {
    -   * "ip_src_addr": "10.0.0.3",
    -   * "protocol": "DNS",
    -   * "length": 30,
    -   * "bytes_in": 560
    -   * }
    -   */
    -  @Multiline
    -  private static String message3;
    -
    -  private static ColumnBuilder columnBuilder;
    -  private static ZKServerComponent zkComponent;
    -  private static FluxTopologyComponent fluxComponent;
    -  private static KafkaComponent kafkaComponent;
    -  private static ConfigUploadComponent configUploadComponent;
    -  private static ComponentRunner runner;
    -  private static MockHTable profilerTable;
    +  public static final long startAt = 10;
    +  public static final String entity = "10.0.0.1";
     
       private static final String tableName = "profiler";
       private static final String columnFamily = "P";
    -  private static final double epsilon = 0.001;
       private static final String inputTopic = Constants.INDEXING_TOPIC;
       private static final String outputTopic = "profiles";
       private static final int saltDivisor = 10;
     
    -  private static final long windowLagMillis = TimeUnit.SECONDS.toMillis(5);
    +  private static final long windowLagMillis = TimeUnit.SECONDS.toMillis(1);
       private static final long windowDurationMillis = 
TimeUnit.SECONDS.toMillis(5);
    -  private static final long periodDurationMillis = 
TimeUnit.SECONDS.toMillis(15);
    -  private static final long profileTimeToLiveMillis = 
TimeUnit.SECONDS.toMillis(20);
    +  private static final long periodDurationMillis = 
TimeUnit.SECONDS.toMillis(10);
    +  private static final long profileTimeToLiveMillis = 
TimeUnit.SECONDS.toMillis(15);
       private static final long maxRoutesPerBolt = 100000;
     
    -  /**
    -   * Tests the first example contained within the README.
    -   */
    -  @Test
    -  public void testExample1() throws Exception {
    -
    -    uploadConfig(TEST_RESOURCES + "/config/zookeeper/readme-example-1");
    -
    -    // start the topology and write test messages to kafka
    -    fluxComponent.submitTopology();
    -    kafkaComponent.writeMessages(inputTopic, message1, message1, message1);
    -    kafkaComponent.writeMessages(inputTopic, message2, message2, message2);
    -    kafkaComponent.writeMessages(inputTopic, message3, message3, message3);
    -
    -    // verify - ensure the profile is being persisted
    -    waitOrTimeout(() -> profilerTable.getPutLog().size() > 0,
    -            timeout(seconds(180)));
    -
    -    // verify - only 10.0.0.2 sends 'HTTP', thus there should be only 1 
value
    -    List<Double> actuals = read(profilerTable.getPutLog(), columnFamily,
    -            columnBuilder.getColumnQualifier("value"), Double.class);
    -
    -    // verify - there are 3 'HTTP' each with 390 bytes
    -    Assert.assertTrue(actuals.stream().anyMatch(val ->
    -            MathUtils.equals(390.0 * 3, val, epsilon)
    -    ));
    -  }
    -
    -  /**
    -   * Tests the second example contained within the README.
    -   */
    -  @Test
    -  public void testExample2() throws Exception {
    -
    -    uploadConfig(TEST_RESOURCES + "/config/zookeeper/readme-example-2");
    -
    -    // start the topology and write test messages to kafka
    -    fluxComponent.submitTopology();
    -    kafkaComponent.writeMessages(inputTopic, message1, message1, message1);
    -    kafkaComponent.writeMessages(inputTopic, message2, message2, message2);
    -    kafkaComponent.writeMessages(inputTopic, message3, message3, message3);
    -
    -    // expect 2 values written by the profile; one for 10.0.0.2 and 
another for 10.0.0.3
    -    final int expected = 2;
    -
    -    // verify - ensure the profile is being persisted
    -    waitOrTimeout(() -> profilerTable.getPutLog().size() >= expected,
    -            timeout(seconds(90)));
    -
    -    // verify - expect 2 results as 2 hosts involved; 10.0.0.2 sends 
'HTTP' and 10.0.0.3 send 'DNS'
    -    List<Double> actuals = read(profilerTable.getPutLog(), columnFamily,
    -            columnBuilder.getColumnQualifier("value"), Double.class);
    -
    -    // verify - 10.0.0.3 -> 1/4
    -    Assert.assertTrue( "Could not find a value near 1/4. Actual values 
read are are: " + Joiner.on(",").join(actuals),
    -            actuals.stream().anyMatch(val -> MathUtils.equals(val, 
1.0/4.0, epsilon)
    -    ));
    -
    -    // verify - 10.0.0.2 -> 4/1
    -    Assert.assertTrue("Could not find a value near 4. Actual values read 
are are: " + Joiner.on(",").join(actuals),
    -            actuals.stream().anyMatch(val -> MathUtils.equals(val, 
4.0/1.0, epsilon)
    -    ));
    -  }
    -
    -  /**
    -   * Tests the third example contained within the README.
    -   */
    -  @Test
    -  public void testExample3() throws Exception {
    -
    -    uploadConfig(TEST_RESOURCES + "/config/zookeeper/readme-example-3");
    +  private static ColumnBuilder columnBuilder;
    +  private static ZKServerComponent zkComponent;
    +  private static FluxTopologyComponent fluxComponent;
    +  private static KafkaComponent kafkaComponent;
    +  private static ConfigUploadComponent configUploadComponent;
    +  private static ComponentRunner runner;
    +  private static MockHTable profilerTable;
     
    -    // start the topology and write test messages to kafka
    -    fluxComponent.submitTopology();
    -    kafkaComponent.writeMessages(inputTopic, message1, message1, message1);
    -    kafkaComponent.writeMessages(inputTopic, message2, message2, message2);
    -    kafkaComponent.writeMessages(inputTopic, message3, message3, message3);
    -
    -    // verify - ensure the profile is being persisted
    -    waitOrTimeout(() -> profilerTable.getPutLog().size() > 0,
    -            timeout(seconds(90)));
    -
    -    // verify - only 10.0.0.2 sends 'HTTP', thus there should be only 1 
value
    -    List<Double> actuals = read(profilerTable.getPutLog(), columnFamily,
    -            columnBuilder.getColumnQualifier("value"), Double.class);
    -
    -    // verify - there are 5 'HTTP' messages each with a length of 20, thus 
the average should be 20
    -    Assert.assertTrue("Could not find a value near 20. Actual values read 
are are: " + Joiner.on(",").join(actuals),
    -            actuals.stream().anyMatch(val -> MathUtils.equals(val, 20.0, 
epsilon)
    -    ));
    -  }
    +  private static String message1;
    +  private static String message2;
    +  private static String message3;
     
       /**
    -   * Tests the fourth example contained within the README.
    +   * The Profiler can generate profiles based on processing time.  With 
processing time,
    +   * the Profiler builds profiles based on when the telemetry was 
processed.
    +   *
    +   * <p>Not defining a 'timestampField' within the Profiler configuration 
tells the Profiler
    +   * to use processing time.
        */
       @Test
    -  public void testExample4() throws Exception {
    +  public void testProcessingTime() throws Exception {
    --- End diff --
    
    Integration tests now only have a `testProcessingTime` and `testEventTime`.


> Intermittent Profiler Integration Test Failure
> ----------------------------------------------
>
>                 Key: METRON-1505
>                 URL: https://issues.apache.org/jira/browse/METRON-1505
>             Project: Metron
>          Issue Type: Bug
>            Reporter: Nick Allen
>            Assignee: Nick Allen
>            Priority: Major
>
> The Profiler integration tests which use processing time fail intermittently 
> when run in Travis CI.
> {code:java}
> 2018-03-22 22:00:35 DEBUG FixedFrequencyFlushSignal:67 - Flush counters reset
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 0 route(s) for 
> message with timestamp=1521756035759
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 0 route(s) for 
> message with timestamp=1521756035802
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 0 route(s) for 
> message with timestamp=1521756035806
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.2, timestamp=1521756035807
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035807
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.2, timestamp=1521756035808
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035808
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.2, timestamp=1521756035813
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035813
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.3, timestamp=1521756035814
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035814
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.3, timestamp=1521756035816
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035816
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:195 - Found route for message; 
> profile=example2, entity=10.0.0.3, timestamp=1521756035817
> 2018-03-22 22:00:35 DEBUG ProfileSplitterBolt:201 - Found 1 route(s) for 
> message with timestamp=1521756035817
> 2018-03-22 22:00:41 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756041122}
> 2018-03-22 22:00:41 DEBUG WindowManager:212 - [6] events expired from window.
> 2018-03-22 22:00:41 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:00:41 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:00:46 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756046122}
> 2018-03-22 22:00:46 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:00:46 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:00:51 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756051122}
> 2018-03-22 22:00:51 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:00:51 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:00:56 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756056122}
> 2018-03-22 22:00:56 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:00:56 DEBUG WindowManager:144 - invoking 
> windowLifecycleListener onActivation, [1] events in window.
> 2018-03-22 22:00:56 DEBUG ProfileBuilderBolt:276 - Tuple window contains 1 
> tuple(s), 0 expired, 1 new
> 2018-03-22 22:00:56 DEBUG ProfileBuilderBolt:365 - Emitted 0 measurement(s).
> 2018-03-22 22:00:56 DEBUG ProfileBuilderBolt:325 - Flushed expired profiles 
> and found 0 measurement(s).
> 2018-03-22 22:00:56 DEBUG FixedFrequencyFlushSignal:114 - Flush=false, '0' ms 
> until flush; currentTime=0, flushTime=0
> 2018-03-22 22:01:01 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756061122}
> 2018-03-22 22:01:01 DEBUG WindowManager:212 - [1] events expired from window.
> 2018-03-22 22:01:01 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:01:01 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:06 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756066122}
> 2018-03-22 22:01:06 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:06 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:11 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756071122}
> 2018-03-22 22:01:11 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:11 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:16 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756076122}
> 2018-03-22 22:01:16 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:16 DEBUG WindowManager:144 - invoking 
> windowLifecycleListener onActivation, [1] events in window.
> 2018-03-22 22:01:16 DEBUG ProfileBuilderBolt:276 - Tuple window contains 1 
> tuple(s), 0 expired, 1 new
> 2018-03-22 22:01:16 DEBUG ProfileBuilderBolt:365 - Emitted 0 measurement(s).
> 2018-03-22 22:01:16 DEBUG ProfileBuilderBolt:325 - Flushed expired profiles 
> and found 0 measurement(s).
> 2018-03-22 22:01:16 DEBUG FixedFrequencyFlushSignal:114 - Flush=false, '0' ms 
> until flush; currentTime=0, flushTime=0
> 2018-03-22 22:01:21 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756081122}
> 2018-03-22 22:01:21 DEBUG WindowManager:212 - [1] events expired from window.
> 2018-03-22 22:01:21 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:01:21 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:26 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756086122}
> 2018-03-22 22:01:26 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:26 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:31 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756091122}
> 2018-03-22 22:01:31 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:31 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:36 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756096122}
> 2018-03-22 22:01:36 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:36 DEBUG WindowManager:144 - invoking 
> windowLifecycleListener onActivation, [1] events in window.
> 2018-03-22 22:01:36 DEBUG ProfileBuilderBolt:276 - Tuple window contains 1 
> tuple(s), 0 expired, 1 new
> 2018-03-22 22:01:36 DEBUG ProfileBuilderBolt:365 - Emitted 0 measurement(s).
> 2018-03-22 22:01:36 DEBUG ProfileBuilderBolt:325 - Flushed expired profiles 
> and found 0 measurement(s).
> 2018-03-22 22:01:36 DEBUG FixedFrequencyFlushSignal:114 - Flush=false, '0' ms 
> until flush; currentTime=0, flushTime=0
> 2018-03-22 22:01:41 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756101122}
> 2018-03-22 22:01:41 DEBUG WindowManager:212 - [1] events expired from window.
> 2018-03-22 22:01:41 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:01:41 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:46 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756106122}
> 2018-03-22 22:01:46 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:46 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:51 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756111122}
> 2018-03-22 22:01:51 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:51 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:01:56 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756116122}
> 2018-03-22 22:01:56 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:01:56 DEBUG WindowManager:144 - invoking 
> windowLifecycleListener onActivation, [1] events in window.
> 2018-03-22 22:01:56 DEBUG ProfileBuilderBolt:276 - Tuple window contains 1 
> tuple(s), 0 expired, 1 new
> 2018-03-22 22:01:56 DEBUG ProfileBuilderBolt:365 - Emitted 0 measurement(s).
> 2018-03-22 22:01:56 DEBUG ProfileBuilderBolt:325 - Flushed expired profiles 
> and found 0 measurement(s).
> 2018-03-22 22:01:56 DEBUG FixedFrequencyFlushSignal:114 - Flush=false, '0' ms 
> until flush; currentTime=0, flushTime=0
> 2018-03-22 22:02:01 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756121122}
> 2018-03-22 22:02:01 DEBUG WindowManager:212 - [1] events expired from window.
> 2018-03-22 22:02:01 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:02:01 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:06 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756126122}
> 2018-03-22 22:02:06 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:02:06 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:11 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756131122}
> 2018-03-22 22:02:11 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:02:11 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:16 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756136122}
> 2018-03-22 22:02:16 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:02:16 DEBUG WindowManager:144 - invoking 
> windowLifecycleListener onActivation, [1] events in window.
> 2018-03-22 22:02:16 DEBUG ProfileBuilderBolt:276 - Tuple window contains 1 
> tuple(s), 0 expired, 1 new
> 2018-03-22 22:02:16 DEBUG ProfileBuilderBolt:365 - Emitted 0 measurement(s).
> 2018-03-22 22:02:16 DEBUG ProfileBuilderBolt:325 - Flushed expired profiles 
> and found 0 measurement(s).
> 2018-03-22 22:02:16 DEBUG FixedFrequencyFlushSignal:114 - Flush=false, '0' ms 
> until flush; currentTime=0, flushTime=0
> 2018-03-22 22:02:21 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756141122}
> 2018-03-22 22:02:21 DEBUG WindowManager:212 - [1] events expired from window.
> 2018-03-22 22:02:21 DEBUG WindowManager:214 - invoking 
> windowLifecycleListener.onExpiry
> 2018-03-22 22:02:21 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:26 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756146122}
> 2018-03-22 22:02:26 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:02:26 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:31 DEBUG WindowManager:189 - Scan events, eviction policy 
> TimeEvictionPolicy{windowLength=5000, referenceTime=1521756151122}
> 2018-03-22 22:02:31 DEBUG WindowManager:212 - [0] events expired from window.
> 2018-03-22 22:02:31 DEBUG WindowManager:147 - No events in the window, 
> skipping onActivation
> 2018-03-22 22:02:34 DEBUG WindowManager:154 - Shutting down WindowManager
> 2018-03-22 22:02:46 DEBUG FixedFrequencyFlushSignal:67 - Flush counters 
> reset{code}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to