<div dir="ltr"><div></div><div class="markdown-here-wrapper" style=""><p style="margin:1.2em 0px!important">Adding all logs from start of run: </p>
<pre style="font-size:0.85em;font-family:Consolas,Inconsolata,Courier,monospace;font-size:1em;line-height:1.2em;margin:1.2em 0px"><code style="font-size:0.85em;font-family:Consolas,Inconsolata,Courier,monospace;margin:0px 0.15em;padding:0px 0.3em;white-space:pre-wrap;border:1px solid rgb(234,234,234);border-radius:3px;display:inline;background-color:rgb(248,248,248);white-space:pre;overflow:auto;border-radius:3px;border:1px solid rgb(204,204,204);padding:0.5em 0.7em;display:block!important;display:block;padding:0.5em;color:rgb(51,51,51);background:rgb(248,248,255)">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
</code></pre><p style="margin:1.2em 0px!important">End of run and free-memory returned expected values: (<span style="color:rgb(51,51,51);font-family:consolas,inconsolata,courier,monospace;font-size:11.05px;line-height:15.6px;white-space:pre;background-color:rgb(248,248,255)">55734M instead of 509M)</span></p>
<pre style="font-size:0.85em;font-family:Consolas,Inconsolata,Courier,monospace;font-size:1em;line-height:1.2em;margin:1.2em 0px"><code style="font-size:0.85em;font-family:Consolas,Inconsolata,Courier,monospace;margin:0px 0.15em;padding:0px 0.3em;white-space:pre-wrap;border:1px solid rgb(234,234,234);border-radius:3px;display:inline;background-color:rgb(248,248,248);white-space:pre;overflow:auto;border-radius:3px;border:1px solid rgb(204,204,204);padding:0.5em 0.7em;display:block!important;display:block;padding:0.5em;color:rgb(51,51,51);background:rgb(248,248,255)">runtime.maxMemory=61331M, runtime.totalMemory=61331M, runtime.freeMemory=55734M, runtime.usedMemory=5597M, runTime.availableMemory=55734M, freeHeapPercentage=90.87
</code></pre><div title="MDH:PGRpdj5IZXJlIGFsbCBsb2dzIGZyb20gc3RhcnQgb2YgcnVuOiZuYnNwOzwvZGl2PjxkaXY+YGBg
PC9kaXY+PGRpdj5qYXZhIC12ZXJib3NlOmdjICZuYnNwOy1YbXM2MEcgLVhteDYwRyAtWFg6Q01T
SW5pdGlhdGluZ09jY3VwYW5jeUZyYWN0aW9uPTIgLVhYOitVc2VDb25jTWFya1N3ZWVwR0MgLVhY
OitVc2VQYXJOZXdHQyAtY3AgdGFyZ2V0L2ZyZWUtbWVtb3J5LWlzc3VlLTEuMC1TTkFQU0hPVC5q
YXIgRnJlZU1lbW9yeTwvZGl2PjxkaXY+PGJyPjwvZGl2PjxkaXY+W0dDIChBbGxvY2F0aW9uIEZh
aWx1cmUpICZuYnNwOzg4NjA4MEstJmd0OzIxNjQ1Syg2MjgwMzg0MEspLCAwLjA3NDMxMDMgc2Vj
c108L2Rpdj48ZGl2PltHQyAoQWxsb2NhdGlvbiBGYWlsdXJlKSAmbmJzcDs5MDc3MjVLLSZndDs1
NjgyODdLKDYyODAzODQwSyksIDAuNDE4Njk5MCBzZWNzXTwvZGl2PjxkaXY+W0dDIChBbGxvY2F0
aW9uIEZhaWx1cmUpICZuYnNwOzE0NTQzNjdLLSZndDsxMjMyNTIwSyg2MjgwMzg0MEspLCAwLjI4
ODU4NjYgc2Vjc108L2Rpdj48ZGl2PltHQyAoQWxsb2NhdGlvbiBGYWlsdXJlKSAmbmJzcDsyMTE4
NjAwSy0mZ3Q7MTk4NTgyOEsoNjI4MDM4NDBLKSwgMC4zMDg3NzE4IHNlY3NdPC9kaXY+PGRpdj5b
R0MgKENNUyBJbml0aWFsIE1hcmspICZuYnNwOzIwNDIwNzNLKDYyODAzODQwSyksIDAuMDAzNzc4
MyBzZWNzXTwvZGl2PjxkaXY+W0dDIChBbGxvY2F0aW9uIEZhaWx1cmUpICZuYnNwOzI4NzE5MDhL
LSZndDsyNzg2NDQ2Syg2MjgwMzg0MEspLCAwLjM2NTA0NDcgc2Vjc108L2Rpdj48ZGl2PltHQyAo
QWxsb2NhdGlvbiBGYWlsdXJlKSAmbmJzcDszNjcyNTI2Sy0mZ3Q7MzY3MDUxNEsoNjI4MDM4NDBL
KSwgMC4zNjc1Mjg3IHNlY3NdPC9kaXY+PGRpdj5bR0MgKEFsbG9jYXRpb24gRmFpbHVyZSkgJm5i
c3A7NDU1NjU5NEstJmd0OzQ0NDU5MTRLKDYyODAzODQwSyksIDAuMzQ1NTg0MiBzZWNzXTwvZGl2
PjxkaXY+W0dDIChBbGxvY2F0aW9uIEZhaWx1cmUpICZuYnNwOzUzMzE5OTRLLSZndDs1MzAyMzY1
Syg2MjgwMzg0MEspLCAwLjM2Mjc3MTkgc2Vjc108L2Rpdj48ZGl2PltHQyAoQ01TIEZpbmFsIFJl
bWFyaykgJm5ic3A7NTMwNDA1M0soNjI4MDM4NDBLKSwgMC4wNTg2ODk0IHNlY3NdPC9kaXY+PGRp
dj5ydW50aW1lLm1heE1lbW9yeT02MTMzMU0sIHJ1bnRpbWUudG90YWxNZW1vcnk9NjEzMzFNLCBy
dW50aW1lLmZyZWVNZW1vcnk9NTA5TSwgcnVudGltZS51c2VkTWVtb3J5PTYwODIyTSwgcnVuVGlt
ZS5hdmFpbGFibGVNZW1vcnk9NTA5TSwgZnJlZUhlYXBQZXJjZW50YWdlPTAuODM8L2Rpdj48ZGl2
PnJ1bnRpbWUubWF4TWVtb3J5PTYxMzMxTSwgcnVudGltZS50b3RhbE1lbW9yeT02MTMzMU0sIHJ1
bnRpbWUuZnJlZU1lbW9yeT01MDlNLCBydW50aW1lLnVzZWRNZW1vcnk9NjA4MjJNLCBydW5UaW1l
LmF2YWlsYWJsZU1lbW9yeT01MDlNLCBmcmVlSGVhcFBlcmNlbnRhZ2U9MC44MzwvZGl2PjxkaXY+
YGBgPC9kaXY+PGRpdj48YnI+PC9kaXY+PGRpdj48ZGl2PkVuZCBvZiBydW4gYW5kIGZyZWUtbWVt
b3J5IHJldHVybmVkIGV4cGVjdGVkIHZhbHVlczo8L2Rpdj48ZGl2PmBgYDwvZGl2PjxkaXY+cnVu
dGltZS5tYXhNZW1vcnk9NjEzMzFNLCBydW50aW1lLnRvdGFsTWVtb3J5PTYxMzMxTSwgcnVudGlt
ZS5mcmVlTWVtb3J5PTU1NzM0TSwgcnVudGltZS51c2VkTWVtb3J5PTU1OTdNLCBydW5UaW1lLmF2
YWlsYWJsZU1lbW9yeT01NTczNE0sIGZyZWVIZWFwUGVyY2VudGFnZT05MC44NzwvZGl2PjwvZGl2
PjxkaXY+YGBgPC9kaXY+PGRpdj48YnI+PC9kaXY+PGRpdj48L2Rpdj4=" style="height:0;width:0;max-height:0;max-width:0;overflow:hidden;font-size:0em;padding:0;margin:0"></div></div><div><br></div><div><br></div><br><div class="gmail_quote"><div dir="ltr">19 Haz 2016 Paz, 01:44 tarihinde <<a href="mailto:ecki@zusammenkunft.net">ecki@zusammenkunft.net</a>> şunu yazdı:<br></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hello,<br>
<br>
Maybe you should show output and gclog as well.<br>
<br>
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.<br>
<br>
Gruss<br>
Bernd<br>
<br>
--<br>
<a href="http://bernd.eckenfels.net" rel="noreferrer" target="_blank">http://bernd.eckenfels.net</a><br>
<br>
-----Original Message-----<br>
From: "ahmet mırçık" <<a href="mailto:ahmetmircik@gmail.com" target="_blank">ahmetmircik@gmail.com</a>><br>
To: <a href="mailto:hotspot-gc-dev@openjdk.java.net" target="_blank">hotspot-gc-dev@openjdk.java.net</a><br>
Sent: So., 19 Juni 2016 0:31<br>
Subject: Runtime.getRuntime().freeMemory() can report wrong values when collector is CMS?<br>
<br>
Hi,<br>
<br>
I am running a test which is trying to log memory info. when<br>
free-heap-percentage is under a certain threshold. But noticed that when<br>
heap is around `-XX:CMSInitiatingOccupancyFraction`,<br>
Runtime.getRuntime().freeMemory() can report wrong values when compared to<br>
memory info from GC logs. It reports as if whole heap is nearly occupied,<br>
but actually there exists lots of free-memory. Issue is observable for a<br>
short-time period. Later it starts to report expected values. (Also tried<br>
my test with G1 defaults and Runtime.getRuntime().freeMemory() reported as<br>
expected)<br>
<br>
Issue is easily visible on large heaps.<br>
<br>
Is my assumption correct? Can Runtime.getRuntime().freeMemory() report<br>
wrong free-memory info for a while? Or how can we explain this situation?<br>
<br>
Here is my test and how i run it from command line:<br>
<br>
[PROBLEMATIC RUN WITH CMS]--> java -verbose:gc -Xms60G -Xmx60G<br>
-XX:CMSInitiatingOccupancyFraction=2 -XX:+UseConcMarkSweepGC<br>
-XX:+UseParNewGC -cp target/free-memory-issue-1.0-SNAPSHOT.jar<br>
FreeMemory<br>
<br>
[OK RUN WITH G1]--> java -verbose:gc -Xms60G -Xmx60G -XX:+UseG1GC -cp<br>
target/free-memory-issue-1.0-SNAPSHOT.jar FreeMemory<br>
<br>
public class FreeMemory {<br>
<br>
static final int MB = 1024 * 1024;<br>
static final String MESSAGE = "runtime.maxMemory=%d%s,<br>
runtime.totalMemory=%d%s, runtime.freeMemory=%d%s," +<br>
" runtime.usedMemory=%d%s, runTime.availableMemory=%d%s,<br>
freeHeapPercentage=%.2f";<br>
<br>
public static void main(String[] args) throws InterruptedException {<br>
final ConcurrentHashMap map = new ConcurrentHashMap();<br>
<br>
Runtime runtime = Runtime.getRuntime();<br>
int availableProcessors = runtime.availableProcessors();<br>
int threadCount = availableProcessors * 4;<br>
<br>
ArrayList<Thread> threads = new ArrayList<Thread>();<br>
<br>
for (int i = 0; i < threadCount; i++) {<br>
threads.add(new Thread(new Runnable() {<br>
<br>
@Override<br>
public void run() {<br>
Random random = new Random();<br>
while (true) {<br>
byte[] value = new byte[1024];<br>
random.nextBytes(value);<br>
<br>
map.put(random.nextInt(), value);<br>
<br>
if (hasReachedMinFreeHeapPercentage(12)) {<br>
break;<br>
}<br>
}<br>
}<br>
}));<br>
}<br>
<br>
for (Thread thread : threads) {<br>
thread.start();<br>
}<br>
<br>
for (Thread thread : threads) {<br>
thread.join();<br>
}<br>
<br>
out.print("\n\n\nEnd of run...now we expect to see actual<br>
used-memory value\n");<br>
<br>
while (true) {<br>
printCurrentMemoryInfo();<br>
parkNanos(SECONDS.toNanos(5));<br>
}<br>
}<br>
<br>
static boolean hasReachedMinFreeHeapPercentage(int minFreeHeapPercentage) {<br>
Runtime runtime = Runtime.getRuntime();<br>
<br>
long maxMemory = runtime.maxMemory();<br>
long totalMemory = runtime.totalMemory();<br>
long freeMemory = runtime.freeMemory();<br>
long availableMemory = freeMemory + (maxMemory - totalMemory);<br>
double freeHeapPercentage = 100D * availableMemory / maxMemory;<br>
<br>
if (freeHeapPercentage < minFreeHeapPercentage) {<br>
String unit = "M";<br>
out.println(format(MESSAGE, toMB(maxMemory), unit,<br>
toMB(totalMemory), unit, toMB(freeMemory), unit,<br>
toMB(totalMemory - freeMemory), unit,<br>
toMB(availableMemory), unit, freeHeapPercentage));<br>
return true;<br>
}<br>
<br>
return false;<br>
}<br>
<br>
static void printCurrentMemoryInfo() {<br>
Runtime runtime = Runtime.getRuntime();<br>
<br>
long maxMemory = runtime.maxMemory();<br>
long totalMemory = runtime.totalMemory();<br>
long freeMemory = runtime.freeMemory();<br>
long availableMemory = freeMemory + (maxMemory - totalMemory);<br>
double freeHeapPercentage = 100D * availableMemory / maxMemory;<br>
<br>
String unit = "M";<br>
out.println(format(MESSAGE, toMB(maxMemory), unit,<br>
toMB(totalMemory), unit, toMB(freeMemory), unit,<br>
toMB(totalMemory - freeMemory), unit,<br>
toMB(availableMemory), unit, freeHeapPercentage));<br>
}<br>
<br>
static int toMB(long bytes) {<br>
return (int) Math.rint(bytes / MB);<br>
}<br>
}<br>
<br>
Java version:<br>
<br>
openjdk version "1.8.0_91"<br>
<br>
OpenJDK Runtime Environment (build 1.8.0_91-8u91-b14-0ubuntu4~14.04-b14)<br>
<br>
OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode)<br>
<br>
OS info:<br>
<br>
Linux version 3.13.0-74-generic (buildd@lcy01-07) (gcc version 4.8.2<br>
(Ubuntu 4.8.2-19ubuntu1) ) #118-Ubuntu SMP Thu Dec 17 22:52:10 UTC 2015<br>
<br>
Distributor ID: Ubuntu<br>
<br>
Description: Ubuntu 14.04.3 LTS<br>
<br>
Release: 14.04<br>
<br>
<br>
Thanks in advance,<br>
</blockquote></div></div><div dir="ltr">-- <br></div><div data-smartmail="gmail_signature"><div dir="ltr">ahmet</div></div>