title: Java - Loop performance drop
body: <p>The scenario goes as such...</p>
  
  <p>I have two functions Function A() and Function B(). The Function A() has a for-loop which calls Function B() in every iteration. Function B() has a for-loop which iterates around 10 million times. </p>
  
  <pre><code>Function A()
  {
      for (i = 0; i &lt; 10; i++)
          Function B();
  }
  
  Function B()
  {
      for (i = 0; i &lt; 10000000; i++)
          certain_operations()
  }
  </code></pre>
  
  <p>Now, the problem I am facing is that, A()'s for-loop's first iteration takes 1 minute to execute, second iteration takes 2 mins, third iteration takes 4 mins and so on... Even though the number of iterations is the same, the subsequent loop execution in A() increases. I have generated the following logs. </p>
  
  <pre><code>Cluster :  1
   INFO 2014-09-17 16:36:20,496 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 16:37:11,762 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 16:37:11,762 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 1 - Critical Operations : 160000
  
  Cluster :  2
   INFO 2014-09-17 16:37:11,767 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 16:38:02,365 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 16:38:02,365 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 2 - Critical Operations : 40000
  
  Cluster :  3
   INFO 2014-09-17 16:38:02,366 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 16:41:35,675 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 16:41:35,675 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 3 - Critical Operations : 80000
  
  Cluster :  4
   INFO 2014-09-17 16:41:35,676 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 16:50:17,875 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 16:50:17,875 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 4 - Critical Operations : 120000
  
  Cluster :  5
   INFO 2014-09-17 16:50:17,886 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 17:02:42,819 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 17:02:42,819 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 5 - Critical Operations : 160000
  
  Cluster :  6
   INFO 2014-09-17 17:02:42,820 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 17:07:01,916 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 17:07:01,916 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 6 - Critical Operations : 40000
  
  Cluster :  7
   INFO 2014-09-17 17:07:01,917 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 17:16:21,122 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 17:16:21,122 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 7 - Critical Operations : 100000
  
  Cluster :  8
   INFO 2014-09-17 17:16:21,123 [pool-8-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-17 17:22:40,371 [pool-8-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-17 17:22:40,371 [pool-8-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 8 - Critical Operations : 60000
  </code></pre>
  
  <p><strong>HERE, THE TIME BETWEEN Print 1 AND Print 2 IS THE EXECUTION TIME OF Function A()'s ONE ITERATION.</strong></p>
  
  <p>Any idea why this problem is occurring ? Suggestions regarding how to solve this issue will be greatly appreciated. Thanks a lot.</p>
  
  <p>This is my code in case there are anomalies you can get...</p>
  
  <pre><code>Function A()
  {
      for(Data d : packList)              
              List&lt;Data&gt; region  = getRegionData(d, dataList, axisEN, eN, cluster++);         
  
              //dataList -&gt; 10 million records
              //d -&gt; single instance of dataList
  }
  
  public List&lt;Data&gt; getRegionData(Data data, List&lt;Data&gt; listData, int axisEN, int eN, int cluster)    //Function B()
      {   
          List&lt;Data&gt; region = new ArrayList&lt;Data&gt;();
          Data temp = new Data();
          int distance;
  
          Logger.sysLog(LogValues.info, this.getClass().getName(), "Print 1");
          for(Data d : listData)
          {
              temp.setOffnet(java.lang.Math.abs(data.getOffnet() - d.getOffnet()));
              temp.setOnnet(java.lang.Math.abs(data.getOnnet() - d.getOnnet()));
              temp.setInet(java.lang.Math.abs(data.getInet() - d.getInet()));
  
              distance = temp.getOffnet() + temp.getOnnet() + temp.getInet();
  
              if(distance &lt;= eN)
                  if(temp.getOffnet() &lt;= axisEN &amp;&amp; temp.getOnnet() &lt;= axisEN &amp;&amp; temp.getInet() &lt;= axisEN)
                  {                   
                      d.setId(listData.indexOf(d));
                      d.setCluster(cluster);
                      d.setDistance(distance);
                      d.setCount(d.getCount() + 1);
                      region.add(d);  
                  }
          }
  
  
  
          Logger.sysLog(LogValues.info, this.getClass().getName(), "Print 2");
          Logger.sysLog(LogValues.info, this.getClass().getName(), "Cluster " + cluster + " : " + region.size());
          return region;
      }
  }
  </code></pre>
  
  <p>.
  .</p>
  
  <hr>
  
  <p>EDIT 1 : Removing the listData.indexOf(d)</p>
  
  <hr>
  
  <pre><code> Cluster :  1
   INFO 2014-09-18 14:58:28,306 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 14:59:04,233 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 14:59:04,233 [pool-1-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 1  - Critical Operations : 120000
   Cluster :  2
   INFO 2014-09-18 14:59:04,236 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:01:32,566 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:01:32,566 [pool-2-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 2  - Critical Operations : 120000
   Cluster :  3
   INFO 2014-09-18 15:01:32,567 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:09:15,873 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:09:15,873 [pool-3-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 3  - Critical Operations : 200000
   Cluster :  4
   INFO 2014-09-18 15:09:15,874 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:13:30,019 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:13:30,019 [pool-4-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 4  - Critical Operations : 80000
   Cluster :  5
   INFO 2014-09-18 15:13:30,019 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:24:10,602 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:24:10,602 [pool-5-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 5  - Critical Operations : 160000
   Cluster :  6
   INFO 2014-09-18 15:24:10,603 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:29:47,132 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:29:47,132 [pool-6-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 6  - Critical Operations : 60000
   Cluster :  7
   INFO 2014-09-18 15:29:47,133 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 1
   INFO 2014-09-18 15:38:49,182 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Print 2
   INFO 2014-09-18 15:38:49,182 [pool-7-thread-1][] com.bng.dbscan.util.GenerateCluster - Cluster 6  - Critical Operations : 60000
  </code></pre>
  
  <p>PrintGCDetails for three iterations</p>
  
  <pre><code>After Iter1
  Heap
   PSYoungGen      total 18432K, used 952K [0x9ee80000, 0xa0300000, 0xb3540000)
    eden space 15872K, 6% used [0x9ee80000,0x9ef6e248,0x9fe00000)
    from space 2560K, 0% used [0xa0080000,0xa0080000,0xa0300000)
    to   space 2560K, 0% used [0x9fe00000,0x9fe00000,0xa0080000)
   ParOldGen       total 41728K, used 0K [0x76140000, 0x78a00000, 0x9ee80000)
    object space 41728K, 0% used [0x76140000,0x76140000,0x78a00000)
   PSPermGen       total 16384K, used 1771K [0x72140000, 0x73140000, 0x76140000)
    object space 16384K, 10% used [0x72140000,0x722faf00,0x73140000)
  
  
  After Iter2
  Heap
   PSYoungGen      total 18432K, used 952K [0x9ef00000, 0xa0380000, 0xb35c0000)
    eden space 15872K, 6% used [0x9ef00000,0x9efee260,0x9fe80000)
    from space 2560K, 0% used [0xa0100000,0xa0100000,0xa0380000)
    to   space 2560K, 0% used [0x9fe80000,0x9fe80000,0xa0100000)
   ParOldGen       total 41728K, used 0K [0x761c0000, 0x78a80000, 0x9ef00000)
    object space 41728K, 0% used [0x761c0000,0x761c0000,0x78a80000)
   PSPermGen       total 16384K, used 1771K [0x721c0000, 0x731c0000, 0x761c0000)
    object space 16384K, 10% used [0x721c0000,0x7237af00,0x731c0000)
  
  
  After Iter3
  Heap
   PSYoungGen      total 18432K, used 952K [0x9ee80000, 0xa0300000, 0xb3540000)
    eden space 15872K, 6% used [0x9ee80000,0x9ef6e248,0x9fe00000)
    from space 2560K, 0% used [0xa0080000,0xa0080000,0xa0300000)
    to   space 2560K, 0% used [0x9fe00000,0x9fe00000,0xa0080000)
   ParOldGen       total 41728K, used 0K [0x76140000, 0x78a00000, 0x9ee80000)
    object space 41728K, 0% used [0x76140000,0x76140000,0x78a00000)
   PSPermGen       total 16384K, used 1771K [0x72140000, 0x73140000, 0x76140000)
    object space 16384K, 10% used [0x72140000,0x722faf00,0x73140000)
  </code></pre>