Java CMS remark collection "weak refs processing" phase takes a long time
Environment
- Oracle JDK
- OpenJDK
Issue
- The "weak refs processing" phase of a CMS remark collection takes a long time. For example:
26547.786: [GC[YG occupancy: 265341 K (513856 K)]26547.786: [Rescan (parallel) , 0.4281218 secs]26548.215: [weak refs processing, 6.3098393 secs] [1 CMS-remark: 4702208K(7193568K)] 4967549K(7707424K), 6.7428950 secs] [Times: user=7.35 sys=0.65, real=6.74 secs]
Resolution
-
If the processing of Reference Objects in the remark phase take too long, then consider enabling parallel reference processing by using the JVM option
-XX:+ParallelRefProcEnabled. Unless there are tons of Reference Objects, doing the reference processing serially is usually faster. However, this option might help if Reference Objects are extensively used in your application, etc. -
For systems with 1-2 processors that cannot dedicate processors to manage the different concurrent phases, add the
-XX:+CMSIncrementalModeJVM option to reduce "weak refs processing" times. (However, note that this option is deprecated since Java 8)
Root Cause
Using the Concurrent Mark Sweep (CMS) collector on hardware with only 1-2 processors.
Diagnostic Steps
- When the "weak refs processing" time increases, inspect the finalization queue using jmap. For example:
jmap -finalizerinfo <JBOSS_PID>
-
Test
-XX:+CMSIncrementalMode. This is useful on systems with 1 or 2 processors that cannot afford to dedicate 1-2 processors to manage the different concurrent phases and has been Content from forums.sun.com is not included.reported to reduce "weak refs processing" time. -
By enabling
-XX:+PrintReferenceGC, the issue can be broken down which Reference class was taking longer to scan during remark phase.
2020-12-02T12:18:25.940+0900: 9.477: [GC (CMS Final Remark) [YG occupancy: 9403 K (78656 K)]2020-12-02T12:18:25.940+0900: 9.477: [Rescan (parallel) , 0.0030103 secs]2020-12-02T12:18:25.943+0900: 9.480: [weak refs processing2020-12-02T12:18:25.943+0900: 9.480: [SoftReference, 0 refs, 0.0000058 secs]2020-12-02T12:18:25.943+0900: 9.480: [WeakReference, 5 refs, 0.0000053 secs]2020-12-02T12:18:25.943+0900: 9.480: [FinalReference, 183 refs, 0.0000637 secs]2020-12-02T12:18:25.944+0900: 9.480: [PhantomReference, 0 refs, 1 refs, 0.0000058 secs]2020-12-02T12:18:25.944+0900: 9.480: [JNI Weak Reference, 0.0000158 secs], 0.0001257 secs]2020-12-02T12:18:25.944+0900: 9.480: [class unloading, 0.0106136 secs]2020-12-02T12:18:25.954+0900: 9.491: [scrub symbol table, 0.0101999 secs]2020-12-02T12:18:25.964+0900: 9.501: [scrub string table, 0.0006522 secs][1 CMS-remark: 57663K(174784K)] 67066K(253440K), 0.0247799 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.