On 9/12/19 5:41 AM, Yan Gang wrote:
hi Thomas:
Thanks you reply!
Follows is full jvm option:
-Xms6G -Xmx6G -XX:MetaspaceSize=512M -XX:MaxMetaspaceSize=512M
-XX:+UseConcMarkSweepGC -XX:+UseCMSInitiatingOccupancyOnly
-XX:CMSInitiatingOccupancyFraction=80 -XX:+HeapDumpOnOutOfMemoryError
-verbose:gc -Xloggc:/data/gc.log -XX:+UnlockCommercialFeatures
-XX:+FlightRecorder
-XX:StartFlightRecording=delay=60s,duration=1h,settings=profile,filename=/data/flight.jfr
-XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime
-XX:PrintFLSStatistics=2 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps -XX:-UseParNewGC -XX:ParallelGCThreads=32
-XX:+TraceReferenceGC -XX:+TraceScavenge -XX:MaxTenuringThreshold=1
-Dcom.sun.management.jmxremote.port=7091
-Dcom.sun.management.jmxremote.authenticate=false
-Dcom.sun.management.jmxremote.ssl=false gmcf-pmc-web-1.4.0.jar
JDK version: Java HotSpot(TM) 64-Bit Server VM (build 25.181-b13, mixed
mode)
16C64G
I check gc.log:
2019-09-10T17:42:30.071+0800: 5683.360: [GC (Allocation Failure)
2019-09-10T17:42:30.071+0800: 5683.361: [ParNew:
897542K->13611K(996800K), 0.0213537 secs] 1040925K->157022K(6180736K),
0.0219481 secs] [Times: user=0.17 sys=0.00, real=0.02 secs]
2019-09-10T17:42:35.716+0800: 5689.005: [GC (Allocation Failure)
2019-09-10T17:42:35.717+0800: 5689.006: [ParNew:
899691K->7416K(996800K), 4.6872684 secs] 1043102K->156944K(6180736K),
4.6880854 secs] [Times: user=3.76 sys=1.99, real=4.69 secs]
2019-09-10T17:42:47.524+0800: 5700.813: [GC (Allocation Failure)
2019-09-10T17:42:47.524+0800: 5700.813: [ParNew:
893496K->3500K(996800K), 0.0396484 secs] 1043024K->153075K(6180736K),
0.0406422 secs] [Times: user=0.52 sys=0.00, real=0.04 secs]
Maybe big object cause long ParNew GC?
I would check the following:
- do you really need 32 threads? Afaics the amount of data actually
touched during GC is like 20MB / GC. It makes sense that these 32
threads are fighting to evacuate these 20MB, potentially leading to the
reported stalls.
Decreasing the number of parallel GC threads may help.
Contradictory to your setting of ParallelGCThreads=32, you try disable
parallel evacuation anyway (-XX:-UseParNewGC), which looks weird because
the user/real time ratio indicates that indeed parallel evacuation is
going on. Potentially manually setting ParallelGCThreads after
-XX:-UseParnewGC) re-enables ParNew.
Not sure if this is what you want; but I would look at the suggestion
below first.
> 2019-09-10T17:42:35.717+0800: 5689.006: [ParNew:
> 899691K->7416K(996800K), 4.6872684 secs] 1043102K->156944K(6180736K),
> 4.6880854 secs] [Times: user=3.76 sys=1.99, real=4.69 secs]
Whatever causes the high sys time may be the actual cause for your
troubles. Did you try the setup recommendations outlined in the tuning
guide [0]?
I.e. disable THP, and move the log file to a separate (ram-)disk? The
options you used indicate that -XX:+AlwaysPreTouch is not enabled either.
Please also look if some swapping activity might be going on on your
machine.
Thanks,
Thomas
[0]
https://docs.oracle.com/en/java/javase/12/gctuning/garbage-first-garbage-collector-tuning.html#GUID-8D9B2530-E370-4B8B-8ADD-A43674FC6658
Thanks!
----- 回复邮件 -----
*发信人:*Thomas Schatzl <thomas.scha...@oracle.com
<mailto:thomas.scha...@oracle.com>>
*收信人:*"Yan Gang" <yang...@ec.com.cn
<mailto:yang...@ec.com.cn>>,"hotspot-gc-use"
<hotspot-gc-use@openjdk.java.net <mailto:hotspot-gc-use@openjdk.java.net>>
*时 间:*2019年09月11日 19时57分35秒
*主 题:*Re: question of ParNewGeneration::real_forwardee_slow
Hi,
On Wed, 2019-09-11 at 17:08 +0000, Yan Gang wrote:
> hi all:
> I run 100 threads performance test, use perf top display:
>
> 71.13% libjvm.so [.]
> ParNewGeneration::real_forwardee_slow
>
> ParNewGeneration::real_forwardee_slow waste some CPU time. I search
> google
>
> ParNewGeneration::real_forwardee_slow belong
> of parNewGeneration.cpp, also is JDK bug:
> https://bugs.openjdk.java.net/browse/JDK-7171273.
The referenced CR only says that this busy-loop is inefficient cpu-
wise, not that waiting for another thread should be made substantially
faster :)
The other problem is that the waste_some_time() is probably completely
optimized away with current compilers (constant folded), so hammering
that cacheline (with reads) quite a bit. (I believe that there is a CR
for that as well somewhere, but maybe we haven't because of CMS
obsolescence).
If that real_forwardee_slow() method shows up a lot, *maybe* the amount
of parallel gc threads used is too high, i.e. threads stepping on each
other's toes all the time.
> replaced to G1?
Our (Oracle's) general advice when having problems with CMS is to try
G1, but recent JDKs ship with other GCs that may be suitable to your
application (ZGC, Shenandoah, potentially Parallel GC).
CMS is on the way out in _future_ releases (see _draft_ JEP
https://openjdk.java.net/jeps/8229049). We at Oracle recommend looking
into alternatives.
Thanks,
Thomas
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use@openjdk.java.net
https://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
