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

ahmet mırçık ahmetmircik at gmail.com
Sat Jun 18 22:56:57 UTC 2016


Adding all logs from start of run:

java -verbose:gc  -Xms60G -Xmx60G -XX:CMSInitiatingOccupancyFraction=2
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -cp
target/free-memory-issue-1.0-SNAPSHOT.jar FreeMemory

[GC (Allocation Failure)  886080K->21645K(62803840K), 0.0743103 secs]
[GC (Allocation Failure)  907725K->568287K(62803840K), 0.4186990 secs]
[GC (Allocation Failure)  1454367K->1232520K(62803840K), 0.2885866 secs]
[GC (Allocation Failure)  2118600K->1985828K(62803840K), 0.3087718 secs]
[GC (CMS Initial Mark)  2042073K(62803840K), 0.0037783 secs]
[GC (Allocation Failure)  2871908K->2786446K(62803840K), 0.3650447 secs]
[GC (Allocation Failure)  3672526K->3670514K(62803840K), 0.3675287 secs]
[GC (Allocation Failure)  4556594K->4445914K(62803840K), 0.3455842 secs]
[GC (Allocation Failure)  5331994K->5302365K(62803840K), 0.3627719 secs]
[GC (CMS Final Remark)  5304053K(62803840K), 0.0586894 secs]
runtime.maxMemory=61331M, runtime.totalMemory=61331M,
runtime.freeMemory=509M, runtime.usedMemory=60822M,
runTime.availableMemory=509M, freeHeapPercentage=0.83
runtime.maxMemory=61331M, runtime.totalMemory=61331M,
runtime.freeMemory=509M, runtime.usedMemory=60822M,
runTime.availableMemory=509M, freeHeapPercentage=0.83

End of run and free-memory returned expected values: (55734M instead of
509M)

runtime.maxMemory=61331M, runtime.totalMemory=61331M,
runtime.freeMemory=55734M, runtime.usedMemory=5597M,
runTime.availableMemory=55734M, freeHeapPercentage=90.87

​



19 Haz 2016 Paz, 01:44 tarihinde <ecki at zusammenkunft.net> şunu yazdı:

> Hello,
>
> Maybe you should show output and gclog as well.
>
> However I would argue that logging and alerting memory usage numbers is
> next to useless in most situations. If you want to have some usefull
> numbers I would restrict myself to log free memory for the various pools
> after related GC runs. The JMX beans have a metric for that.
>
> Gruss
> Bernd
>
> --
> http://bernd.eckenfels.net
>
> -----Original Message-----
> From: "ahmet mırçık" <ahmetmircik at gmail.com>
> To: hotspot-gc-dev at openjdk.java.net
> Sent: So., 19 Juni 2016 0:31
> Subject: Runtime.getRuntime().freeMemory() can report wrong values when
> collector is CMS?
>
> 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)
>
> 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,
>
-- 
ahmet
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/hotspot-gc-dev/attachments/20160618/5cb70f05/attachment.htm>


More information about the hotspot-gc-dev mailing list