Runtime.getRuntime().freeMemory() can report wrong values when collector is CMS?

[Jon Masamitsu]

On 06/18/2016 03:21 PM, ahmet mırçık wrote:
>
> Hi,
>
> I am running a test which is trying to log memory info. when 
> free-heap-percentage is under a certain threshold. But noticed that 
> when heap is around `-XX:CMSInitiatingOccupancyFraction`, 
> Runtime.getRuntime().freeMemory() can report wrong values when 
> compared to memory info from GC logs. It reports as if whole heap is 
> nearly occupied, but actually there exists lots of free-memory. Issue 
> is observable for a short-time period. Later it starts to report 
> expected values. (Also tried my test with G1 defaults and 
> Runtime.getRuntime().freeMemory() reported as expected)
>

 From the latest log (with PrintGCDetails) is this an example of the
freeMemory being wrong but it gets better?

runtime.maxMemory=61207M, runtime.totalMemory=61207M, 
runtime.freeMemory=319M, runtime.usedMemory=60887M, 
runTime.availableMemory=319M, freeHeapPercentage=0.52
99.641: [CMS-concurrent-reset: 0.122/0.122 secs] [Times: user=0.67 
sys=0.01, real=0.12 secs]
99.896: [GC99.896: [ParNew: 2146944K->238528K(2146944K), 0.5846780 secs] 
51929136K->51910762K(62676032K), 0.5847860 secs] [Times: user=5.33 
sys=0.92, real=0.58 secs]
100.484: [GC [1 CMS-initial-mark: 51672234K(60529088K)] 
51925538K(62676032K), 0.0461750 secs] [Times: user=0.05 sys=0.00, 
real=0.05 secs]
100.530: [CMS-concurrent-mark-start]
102.959: [GC102.959: [ParNew: 2146944K->238528K(2146944K), 0.5868320 
secs] 53819178K->53798644K(62676032K), 0.5869410 secs] [Times: user=6.25 
sys=0.88, real=0.59 secs]
runtime.maxMemory=61207M,runtime.totalMemory=61207M, 
runtime.freeMemory=7344M, runtime.usedMemory=53862M, 
runTime.availableMemory=7344M, freeHeapPercentage=12.00

Jon

> Issue is easily visible on large heaps.
>
> Is my assumption correct? Can Runtime.getRuntime().freeMemory() report 
> wrong free-memory info for a while? Or how can we explain this situation?
>
> Here is my test and how i run it from command line:
>
> [PROBLEMATIC RUN WITH CMS]--> java -verbose:gc -Xms60G -Xmx60G 
> -XX:CMSInitiatingOccupancyFraction=2 -XX:+UseConcMarkSweepGC 
> -XX:+UseParNewGC -cp target/free-memory-issue-1.0-SNAPSHOT.jar FreeMemory
> [OK RUN WITH G1]--> java -verbose:gc  -Xms60G -Xmx60G -XX:+UseG1GC -cp target/free-memory-issue-1.0-SNAPSHOT.jar FreeMemory
> public class FreeMemory {
>
>      static final int MB = 1024 * 1024;
>      static final String MESSAGE = "runtime.maxMemory=%d%s, runtime.totalMemory=%d%s, runtime.freeMemory=%d%s," +
>              " runtime.usedMemory=%d%s, runTime.availableMemory=%d%s, freeHeapPercentage=%.2f";
>
>      public static void main(String[] args) throws InterruptedException {
>          final ConcurrentHashMap map = new ConcurrentHashMap();
>
>          Runtime runtime = Runtime.getRuntime();
>          int availableProcessors = runtime.availableProcessors();
>          int threadCount = availableProcessors * 4;
>
>          ArrayList<Thread> threads = new ArrayList<Thread>();
>
>          for (int i = 0; i < threadCount; i++) {
>              threads.add(new Thread(new Runnable() {
>
>                  @Override
>                  public void run() {
>                      Random random = new Random();
>                      while (true) {
>                          byte[] value = new byte[1024];
>                          random.nextBytes(value);
>
>                          map.put(random.nextInt(), value);
>
>                          if (hasReachedMinFreeHeapPercentage(12)) {
>                              break;
>                          }
>                      }
>                  }
>              }));
>          }
>
>          for (Thread thread : threads) {
>              thread.start();
>          }
>
>          for (Thread thread : threads) {
>              thread.join();
>          }
>
>          out.print("\n\n\nEnd of run...now we expect to see actual used-memory value\n");
>
>          while (true) {
>              printCurrentMemoryInfo();
>              parkNanos(SECONDS.toNanos(5));
>          }
>      }
>
>      static boolean hasReachedMinFreeHeapPercentage(int minFreeHeapPercentage) {
>          Runtime runtime = Runtime.getRuntime();
>
>          long maxMemory = runtime.maxMemory();
>          long totalMemory = runtime.totalMemory();
>          long freeMemory = runtime.freeMemory();
>          long availableMemory = freeMemory + (maxMemory - totalMemory);
>          double freeHeapPercentage = 100D * availableMemory / maxMemory;
>
>          if (freeHeapPercentage < minFreeHeapPercentage) {
>              String unit = "M";
>              out.println(format(MESSAGE, toMB(maxMemory), unit, toMB(totalMemory), unit, toMB(freeMemory), unit,
>                      toMB(totalMemory - freeMemory), unit, toMB(availableMemory), unit, freeHeapPercentage));
>              return true;
>          }
>
>          return false;
>      }
>
>      static void printCurrentMemoryInfo() {
>          Runtime runtime = Runtime.getRuntime();
>
>          long maxMemory = runtime.maxMemory();
>          long totalMemory = runtime.totalMemory();
>          long freeMemory = runtime.freeMemory();
>          long availableMemory = freeMemory + (maxMemory - totalMemory);
>          double freeHeapPercentage = 100D * availableMemory / maxMemory;
>
>          String unit = "M";
>          out.println(format(MESSAGE, toMB(maxMemory), unit, toMB(totalMemory), unit, toMB(freeMemory), unit,
>                  toMB(totalMemory - freeMemory), unit, toMB(availableMemory), unit, freeHeapPercentage));
>      }
>
>      static int toMB(long bytes) {
>          return (int) Math.rint(bytes / MB);
>      }
> }
>
> Java version:
>
> openjdk version "1.8.0_91"
>
> OpenJDK Runtime Environment (build 1.8.0_91-8u91-b14-0ubuntu4~14.04-b14)
>
> OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode)
>
>
> OS info:
>
> Linux version 3.13.0-74-generic (buildd at lcy01-07) (gcc version 4.8.2 
> (Ubuntu 4.8.2-19ubuntu1) ) #118-Ubuntu SMP Thu Dec 17 22:52:10 UTC 2015
>
> Distributor ID: Ubuntu
>
> Description: Ubuntu 14.04.3 LTS
>
> Release: 14.04
>
>
> Thanks in advance,
>
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20160622/232bba44/attachment.htm>