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.org/pipermail/hotspot-gc-dev/attachments/20160618/5cb70f05/attachment.htm>
More information about the hotspot-gc-dev
mailing list