Minor GC และ GC เต็มในเวลาเดียวกัน?

นี่คือบันทึก GC ส่วนหนึ่งที่แสดงเหตุการณ์ CMS GC แบบเต็ม:

2016-12-29T22:44:34.741-0500: 27572.982: [GC (CMS Initial Mark) [1 CMS-initial-mark: 2508212K(23068672K)] 2931097K(26843584K), 0.0213349 secs] [Times: user=0.22 sys=0.00, real=0.02 secs] 
2016-12-29T22:44:34.763-0500: 27573.004: [CMS-concurrent-mark-start]
2016-12-29T22:44:36.013-0500: 27574.254: [CMS-concurrent-mark: 0.208/1.250 secs] [Times: user=3.07 sys=0.10, real=1.25 secs] 
2016-12-29T22:44:36.014-0500: 27574.255: [CMS-concurrent-preclean-start]
2016-12-29T22:44:36.061-0500: 27574.303: [CMS-concurrent-preclean: 0.047/0.048 secs] [Times: user=0.12 sys=0.00, real=0.05 secs] 
2016-12-29T22:44:36.062-0500: 27574.303: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 2016-12-29T22:44:41.339-0500: 27579.580: [CMS-concurrent-abortable-preclean: 4.084/5.277 secs] [Times: user=9.53 sys=0.46, real=5.27 secs] 
2016-12-29T22:44:41.356-0500: 27579.598: [GC (CMS Final Remark) [YG occupancy: 3509179 K (3774912 K)]2016-12-29T22:44:41.357-0500: 27579.598: [Rescan (parallel) , 0.0816014 secs]2016-12-29T22:44:41.438-0500: 27579.680: [weak refs processing, 0.0000347 secs]2016-12-29T22:44:41.438-0500: 27579.680: [class unloading, 0.0292451 secs]2016-12-29T22:44:41.468-0500: 27579.709: [scrub symbol table, 0.0069857 secs]2016-12-29T22:44:41.475-0500: 27579.716: [scrub string table, 0.0010933 secs][1 CMS-remark: 2508212K(23068672K)] 6017391K(26843584K), 0.1194737 secs] [Times: user=2.18 sys=0.00, real=0.12 secs] 
2016-12-29T22:44:41.477-0500: 27579.718: [CMS-concurrent-sweep-start]
2016-12-29T22:44:41.618-0500: 27579.860: [GC (Allocation Failure) 2016-12-29T22:44:41.619-0500: 27579.860: [ParNew: 3579431K->419392K(3774912K), 5.7752364 secs] 6080306K->3302237K(26843584K), 5.7769753 secs] [Times: user=4.70 sys=8.50, real=5.78 secs] 
2016-12-29T22:44:47.698-0500: 27585.940: [CMS-concurrent-sweep: 0.230/6.221 secs] [Times: user=5.76 sys=8.55, real=6.22 secs] 
2016-12-29T22:44:47.699-0500: 27585.940: [CMS-concurrent-reset-start]
2016-12-29T22:44:47.717-0500: 27585.958: [GC (System.gc()) 2016-12-29T22:44:47.718-0500: 27585.959: [ParNew: 527384K->155025K(3774912K), 0.7351766 secs] 3405551K->3441841K(26843584K), 0.7366514 secs] [Times: user=5.61 sys=1.44, real=0.74 secs] 
2016-12-29T22:44:48.503-0500: 27586.744: [CMS-concurrent-reset: 0.049/0.804 secs] [Times: user=5.81 sys=1.45, real=0.81 secs] 

ดูเหมือนว่าจะมีเหตุการณ์ GC เล็กน้อยในขณะที่ CMS กำลังทำงาน:

2016-12-29T22:44:41.618-0500: 27579.860: [GC (Allocation Failure) 2016-12-29T22:44:41.619-0500: 27579.860: [ParNew: 3579431K->419392K(3774912K), 5.7752364 secs] 6080306K->3302237K(26843584K), 5.7769753 secs] [Times: user=4.70 sys=8.50, real=5.78 secs] 

ไม่เป็นไร? GC รองจะบล็อก GC ทั้งหมดหรือไม่

นั่นสามารถอธิบายเวลาระบบที่สูงมากที่เราเห็นได้หรือไม่? (sys=8.55 วินาที, sys=8.50 วินาที)


person benji    schedule 30.12.2016    source แหล่งที่มา


คำตอบ (3)


ในกรณีของคุณอัลกอริทึม GC ที่ใช้คือ: -

ใหม่แบบขนานสำหรับคนรุ่นใหม่ + ทำเครื่องหมายและกวาดล้าง (CMS) พร้อมกันสำหรับคนรุ่นเก่า

ดูเหมือนว่าจะมีเหตุการณ์ GC เล็กน้อยในขณะที่ CMS กำลังทำงานอยู่ ตกลงไหม
ใช่ ParNew และ CMS สามารถทำงานแบบคู่ขนานได้

GC รองบล็อก GC ทั้งหมดหรือไม่
ใช่ คอลเลกชัน CMS ที่เกิดขึ้นพร้อมกันถูก "ขัดจังหวะ" โดยคอลเลกชันรองของ ParNew การสะสมของคนรุ่นใหม่สามารถเกิดขึ้นได้ตลอดเวลาในระหว่างการรวบรวมคนรุ่นเก่าไปพร้อมๆ กัน ในกรณีเช่นนี้ คอลเลกชันหลักจะถูกแทรกเข้ากับงาน Minor GC

นั่นช่วยอธิบายเวลาของระบบที่เราเห็นอยู่สูงมากได้ไหม
คุณต้องตรวจสอบความถี่และระยะเวลาของกิจกรรม Stop-the-world ใน GC

  1. เครื่องหมายเริ่มต้น CMS
  2. CMS หมายเหตุสุดท้าย
  3. พาร์นิว

เมื่อดูบันทึกของคุณ ฉันสามารถทราบได้ว่า Minor GC (ParNew) ของคุณใช้เวลามากเกินไปในการดำเนินการให้เสร็จสิ้น
5.7752364 วินาที : เวลาที่ผู้รวบรวมขยะใช้ในการทำเครื่องหมายและคัดลอกแบบสด อ็อบเจ็กต์ในค่าใช้จ่ายการสื่อสาร Young Generation+ ด้วยตัวรวบรวม ConcurrentMarkSweep

ข้อมูลอ้างอิงที่ดีสำหรับ Java GC น่าอ่าน .

person Amit Bhati    schedule 30.12.2016

แน่นอนว่าคอลเลกชันรุ่นเยาว์สามารถเกิดขึ้นได้ระหว่างคอลเลกชันเก่า โดยปกติแล้วนั่นไม่ใช่ปัญหาใหญ่ แต่ในกรณีของขั้นตอนคำพูดของ CMS ต่อจากคอลเลกชันรุ่นเยาว์โดยตรง (หรือวิธีอื่นด้วยเหตุนี้ ทั้งสองจึงเป็นการหยุดโลกชั่วคราว) อาจส่งผลเสียต่อประสิทธิภาพการทำงานได้ CMS จะพยายามหลีกเลี่ยงสิ่งนั้นด้วยการคำนวณว่าคอลเลกชันใหม่ครั้งต่อไปจะเกิดขึ้นเมื่อใด แต่นั่นเป็นเพียงทฤษฎีเท่านั้น

person Kevin Peters    schedule 30.12.2016

เป็นเรื่องปกติหาก Young GC ทำงานระหว่างเฟส CMS การทำคอลเลกชันใหม่ก่อนเครื่องหมายเริ่มต้นของ CMS หรือหมายเหตุของ CMS สามารถลดการหยุดโลกชั่วคราวของ GC หลักได้

สิ่งที่ ไม่ ปกติคือ เวลาของระบบ ที่มีขนาดใหญ่ (เวลา CPU ที่ใช้ในเคอร์เนล) ในขณะที่ทำ GC โดยปกติแล้วสิ่งนี้ไม่ควรเกิดขึ้นเนื่องจากการรวบรวมขยะส่วนใหญ่เป็นงานพื้นที่ผู้ใช้

ตรวจสอบ top, perf ฯลฯ เพื่อค้นหาสาเหตุที่ทำให้ระบบมีเวลาสูง โดยทั่วไปจะเกี่ยวข้องกับปัญหาหน่วยความจำ: การสลับหรือจัดเรียงหน้าขนาดใหญ่แบบโปร่งใส

person apangin    schedule 30.12.2016