159 _last_ext_root_scan_times_ms(_max_gc_threads, "%.1lf"), |
159 _last_ext_root_scan_times_ms(_max_gc_threads, "%.1lf"), |
160 _last_satb_filtering_times_ms(_max_gc_threads, "%.1lf"), |
160 _last_satb_filtering_times_ms(_max_gc_threads, "%.1lf"), |
161 _last_update_rs_times_ms(_max_gc_threads, "%.1lf"), |
161 _last_update_rs_times_ms(_max_gc_threads, "%.1lf"), |
162 _last_update_rs_processed_buffers(_max_gc_threads, "%d"), |
162 _last_update_rs_processed_buffers(_max_gc_threads, "%d"), |
163 _last_scan_rs_times_ms(_max_gc_threads, "%.1lf"), |
163 _last_scan_rs_times_ms(_max_gc_threads, "%.1lf"), |
|
164 _last_strong_code_root_scan_times_ms(_max_gc_threads, "%.1lf"), |
|
165 _last_strong_code_root_mark_times_ms(_max_gc_threads, "%.1lf"), |
164 _last_obj_copy_times_ms(_max_gc_threads, "%.1lf"), |
166 _last_obj_copy_times_ms(_max_gc_threads, "%.1lf"), |
165 _last_termination_times_ms(_max_gc_threads, "%.1lf"), |
167 _last_termination_times_ms(_max_gc_threads, "%.1lf"), |
166 _last_termination_attempts(_max_gc_threads, SIZE_FORMAT), |
168 _last_termination_attempts(_max_gc_threads, SIZE_FORMAT), |
167 _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false), |
169 _last_gc_worker_end_times_ms(_max_gc_threads, "%.1lf", false), |
168 _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"), |
170 _last_gc_worker_times_ms(_max_gc_threads, "%.1lf"), |
180 _last_ext_root_scan_times_ms.reset(); |
182 _last_ext_root_scan_times_ms.reset(); |
181 _last_satb_filtering_times_ms.reset(); |
183 _last_satb_filtering_times_ms.reset(); |
182 _last_update_rs_times_ms.reset(); |
184 _last_update_rs_times_ms.reset(); |
183 _last_update_rs_processed_buffers.reset(); |
185 _last_update_rs_processed_buffers.reset(); |
184 _last_scan_rs_times_ms.reset(); |
186 _last_scan_rs_times_ms.reset(); |
|
187 _last_strong_code_root_scan_times_ms.reset(); |
|
188 _last_strong_code_root_mark_times_ms.reset(); |
185 _last_obj_copy_times_ms.reset(); |
189 _last_obj_copy_times_ms.reset(); |
186 _last_termination_times_ms.reset(); |
190 _last_termination_times_ms.reset(); |
187 _last_termination_attempts.reset(); |
191 _last_termination_attempts.reset(); |
188 _last_gc_worker_end_times_ms.reset(); |
192 _last_gc_worker_end_times_ms.reset(); |
189 _last_gc_worker_times_ms.reset(); |
193 _last_gc_worker_times_ms.reset(); |
195 _last_ext_root_scan_times_ms.verify(); |
199 _last_ext_root_scan_times_ms.verify(); |
196 _last_satb_filtering_times_ms.verify(); |
200 _last_satb_filtering_times_ms.verify(); |
197 _last_update_rs_times_ms.verify(); |
201 _last_update_rs_times_ms.verify(); |
198 _last_update_rs_processed_buffers.verify(); |
202 _last_update_rs_processed_buffers.verify(); |
199 _last_scan_rs_times_ms.verify(); |
203 _last_scan_rs_times_ms.verify(); |
|
204 _last_strong_code_root_scan_times_ms.verify(); |
|
205 _last_strong_code_root_mark_times_ms.verify(); |
200 _last_obj_copy_times_ms.verify(); |
206 _last_obj_copy_times_ms.verify(); |
201 _last_termination_times_ms.verify(); |
207 _last_termination_times_ms.verify(); |
202 _last_termination_attempts.verify(); |
208 _last_termination_attempts.verify(); |
203 _last_gc_worker_end_times_ms.verify(); |
209 _last_gc_worker_end_times_ms.verify(); |
204 |
210 |
208 |
214 |
209 double worker_known_time = _last_ext_root_scan_times_ms.get(i) + |
215 double worker_known_time = _last_ext_root_scan_times_ms.get(i) + |
210 _last_satb_filtering_times_ms.get(i) + |
216 _last_satb_filtering_times_ms.get(i) + |
211 _last_update_rs_times_ms.get(i) + |
217 _last_update_rs_times_ms.get(i) + |
212 _last_scan_rs_times_ms.get(i) + |
218 _last_scan_rs_times_ms.get(i) + |
|
219 _last_strong_code_root_scan_times_ms.get(i) + |
|
220 _last_strong_code_root_mark_times_ms.get(i) + |
213 _last_obj_copy_times_ms.get(i) + |
221 _last_obj_copy_times_ms.get(i) + |
214 _last_termination_times_ms.get(i); |
222 _last_termination_times_ms.get(i); |
215 |
223 |
216 double worker_other_time = worker_time - worker_known_time; |
224 double worker_other_time = worker_time - worker_known_time; |
217 _last_gc_worker_other_times_ms.set(i, worker_other_time); |
225 _last_gc_worker_other_times_ms.set(i, worker_other_time); |
236 |
244 |
237 misc_time_ms += _cur_collection_par_time_ms; |
245 misc_time_ms += _cur_collection_par_time_ms; |
238 |
246 |
239 // Now subtract the time taken to fix up roots in generated code |
247 // Now subtract the time taken to fix up roots in generated code |
240 misc_time_ms += _cur_collection_code_root_fixup_time_ms; |
248 misc_time_ms += _cur_collection_code_root_fixup_time_ms; |
|
249 |
|
250 // Strong code root migration time |
|
251 misc_time_ms += _cur_strong_code_root_migration_time_ms; |
241 |
252 |
242 // Subtract the time taken to clean the card table from the |
253 // Subtract the time taken to clean the card table from the |
243 // current value of "other time" |
254 // current value of "other time" |
244 misc_time_ms += _cur_clear_ct_time_ms; |
255 misc_time_ms += _cur_clear_ct_time_ms; |
245 |
256 |
255 _last_gc_worker_start_times_ms.print(2, "GC Worker Start (ms)"); |
266 _last_gc_worker_start_times_ms.print(2, "GC Worker Start (ms)"); |
256 _last_ext_root_scan_times_ms.print(2, "Ext Root Scanning (ms)"); |
267 _last_ext_root_scan_times_ms.print(2, "Ext Root Scanning (ms)"); |
257 if (_last_satb_filtering_times_ms.sum() > 0.0) { |
268 if (_last_satb_filtering_times_ms.sum() > 0.0) { |
258 _last_satb_filtering_times_ms.print(2, "SATB Filtering (ms)"); |
269 _last_satb_filtering_times_ms.print(2, "SATB Filtering (ms)"); |
259 } |
270 } |
|
271 if (_last_strong_code_root_mark_times_ms.sum() > 0.0) { |
|
272 _last_strong_code_root_mark_times_ms.print(2, "Code Root Marking (ms)"); |
|
273 } |
260 _last_update_rs_times_ms.print(2, "Update RS (ms)"); |
274 _last_update_rs_times_ms.print(2, "Update RS (ms)"); |
261 _last_update_rs_processed_buffers.print(3, "Processed Buffers"); |
275 _last_update_rs_processed_buffers.print(3, "Processed Buffers"); |
262 _last_scan_rs_times_ms.print(2, "Scan RS (ms)"); |
276 _last_scan_rs_times_ms.print(2, "Scan RS (ms)"); |
|
277 _last_strong_code_root_scan_times_ms.print(2, "Code Root Scanning (ms)"); |
263 _last_obj_copy_times_ms.print(2, "Object Copy (ms)"); |
278 _last_obj_copy_times_ms.print(2, "Object Copy (ms)"); |
264 _last_termination_times_ms.print(2, "Termination (ms)"); |
279 _last_termination_times_ms.print(2, "Termination (ms)"); |
265 if (G1Log::finest()) { |
280 if (G1Log::finest()) { |
266 _last_termination_attempts.print(3, "Termination Attempts"); |
281 _last_termination_attempts.print(3, "Termination Attempts"); |
267 } |
282 } |
271 } else { |
286 } else { |
272 _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)"); |
287 _last_ext_root_scan_times_ms.print(1, "Ext Root Scanning (ms)"); |
273 if (_last_satb_filtering_times_ms.sum() > 0.0) { |
288 if (_last_satb_filtering_times_ms.sum() > 0.0) { |
274 _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)"); |
289 _last_satb_filtering_times_ms.print(1, "SATB Filtering (ms)"); |
275 } |
290 } |
|
291 if (_last_strong_code_root_mark_times_ms.sum() > 0.0) { |
|
292 _last_strong_code_root_mark_times_ms.print(1, "Code Root Marking (ms)"); |
|
293 } |
276 _last_update_rs_times_ms.print(1, "Update RS (ms)"); |
294 _last_update_rs_times_ms.print(1, "Update RS (ms)"); |
277 _last_update_rs_processed_buffers.print(2, "Processed Buffers"); |
295 _last_update_rs_processed_buffers.print(2, "Processed Buffers"); |
278 _last_scan_rs_times_ms.print(1, "Scan RS (ms)"); |
296 _last_scan_rs_times_ms.print(1, "Scan RS (ms)"); |
|
297 _last_strong_code_root_scan_times_ms.print(1, "Code Root Scanning (ms)"); |
279 _last_obj_copy_times_ms.print(1, "Object Copy (ms)"); |
298 _last_obj_copy_times_ms.print(1, "Object Copy (ms)"); |
280 } |
299 } |
281 print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms); |
300 print_stats(1, "Code Root Fixup", _cur_collection_code_root_fixup_time_ms); |
|
301 print_stats(1, "Code Root Migration", _cur_strong_code_root_migration_time_ms); |
282 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
302 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); |
283 double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms(); |
303 double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms(); |
284 print_stats(1, "Other", misc_time_ms); |
304 print_stats(1, "Other", misc_time_ms); |
285 if (_cur_verify_before_time_ms > 0.0) { |
305 if (_cur_verify_before_time_ms > 0.0) { |
286 print_stats(2, "Verify Before", _cur_verify_before_time_ms); |
306 print_stats(2, "Verify Before", _cur_verify_before_time_ms); |