Mercurial > hg > graal-jvmci-8

comparison src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp @ 2430:5c0b591e1074

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
6948149: G1: Imbalance in termination times Summary: Changed default value of WorkStealingYieldsBeforeSleep from 1000 to 5000. Added more information to G1 pause logging. Reviewed-by: jwilhelm, tonyp, jmasa
author brutisso
date Wed, 23 Mar 2011 14:12:51 +0100
parents c93aa6caa02f
children 053d84a76d3d
comparison
equal deleted inserted replaced
2429:c6580380076b 2430:5c0b591e1074
305 _par_last_obj_copy_times_ms = new double[_parallel_gc_threads]; 305 _par_last_obj_copy_times_ms = new double[_parallel_gc_threads];
306 306
307 _par_last_termination_times_ms = new double[_parallel_gc_threads]; 307 _par_last_termination_times_ms = new double[_parallel_gc_threads];
308 _par_last_termination_attempts = new double[_parallel_gc_threads]; 308 _par_last_termination_attempts = new double[_parallel_gc_threads];
309 _par_last_gc_worker_end_times_ms = new double[_parallel_gc_threads]; 309 _par_last_gc_worker_end_times_ms = new double[_parallel_gc_threads];
310 _par_last_gc_worker_times_ms = new double[_parallel_gc_threads];
310 311
311 // start conservatively 312 // start conservatively
312 _expensive_region_limit_ms = 0.5 * (double) MaxGCPauseMillis; 313 _expensive_region_limit_ms = 0.5 * (double) MaxGCPauseMillis;
313 314
314 // <NEW PREDICTION> 315 // <NEW PREDICTION>
909 _par_last_scan_rs_times_ms[i] = -1234.0; 910 _par_last_scan_rs_times_ms[i] = -1234.0;
910 _par_last_obj_copy_times_ms[i] = -1234.0; 911 _par_last_obj_copy_times_ms[i] = -1234.0;
911 _par_last_termination_times_ms[i] = -1234.0; 912 _par_last_termination_times_ms[i] = -1234.0;
912 _par_last_termination_attempts[i] = -1234.0; 913 _par_last_termination_attempts[i] = -1234.0;
913 _par_last_gc_worker_end_times_ms[i] = -1234.0; 914 _par_last_gc_worker_end_times_ms[i] = -1234.0;
915 _par_last_gc_worker_times_ms[i] = -1234.0;
914 } 916 }
915 #endif 917 #endif
916 918
917 for (int i = 0; i < _aux_num; ++i) { 919 for (int i = 0; i < _aux_num; ++i) {
918 _cur_aux_times_ms[i] = 0.0; 920 _cur_aux_times_ms[i] = 0.0;
1061 return sum; 1063 return sum;
1062 } 1064 }
1063 1065
1064 void G1CollectorPolicy::print_par_stats(int level, 1066 void G1CollectorPolicy::print_par_stats(int level,
1065 const char* str, 1067 const char* str,
1066 double* data, 1068 double* data) {
1067 bool summary) {
1068 double min = data[0], max = data[0]; 1069 double min = data[0], max = data[0];
1069 double total = 0.0; 1070 double total = 0.0;
1070 LineBuffer buf(level); 1071 LineBuffer buf(level);
1071 buf.append("[%s (ms):", str); 1072 buf.append("[%s (ms):", str);
1072 for (uint i = 0; i < ParallelGCThreads; ++i) { 1073 for (uint i = 0; i < ParallelGCThreads; ++i) {
1076 if (val > max) 1077 if (val > max)
1077 max = val; 1078 max = val;
1078 total += val; 1079 total += val;
1079 buf.append(" %3.1lf", val); 1080 buf.append(" %3.1lf", val);
1080 } 1081 }
1081 if (summary) { 1082 buf.append_and_print_cr("");
1082 buf.append_and_print_cr(""); 1083 double avg = total / (double) ParallelGCThreads;
1083 double avg = total / (double) ParallelGCThreads; 1084 buf.append_and_print_cr(" Avg: %5.1lf, Min: %5.1lf, Max: %5.1lf, Diff: %5.1lf]",
1084 buf.append(" "); 1085 avg, min, max, max - min);
1085 buf.append("Avg: %5.1lf, Min: %5.1lf, Max: %5.1lf",
1086 avg, min, max);
1087 }
1088 buf.append_and_print_cr("]");
1089 } 1086 }
1090 1087
1091 void G1CollectorPolicy::print_par_sizes(int level, 1088 void G1CollectorPolicy::print_par_sizes(int level,
1092 const char* str, 1089 const char* str,
1093 double* data, 1090 double* data) {
1094 bool summary) {
1095 double min = data[0], max = data[0]; 1091 double min = data[0], max = data[0];
1096 double total = 0.0; 1092 double total = 0.0;
1097 LineBuffer buf(level); 1093 LineBuffer buf(level);
1098 buf.append("[%s :", str); 1094 buf.append("[%s :", str);
1099 for (uint i = 0; i < ParallelGCThreads; ++i) { 1095 for (uint i = 0; i < ParallelGCThreads; ++i) {
1103 if (val > max) 1099 if (val > max)
1104 max = val; 1100 max = val;
1105 total += val; 1101 total += val;
1106 buf.append(" %d", (int) val); 1102 buf.append(" %d", (int) val);
1107 } 1103 }
1108 if (summary) { 1104 buf.append_and_print_cr("");
1109 buf.append_and_print_cr(""); 1105 double avg = total / (double) ParallelGCThreads;
1110 double avg = total / (double) ParallelGCThreads; 1106 buf.append_and_print_cr(" Sum: %d, Avg: %d, Min: %d, Max: %d, Diff: %d]",
1111 buf.append(" "); 1107 (int)total, (int)avg, (int)min, (int)max, (int)max - (int)min);
1112 buf.append("Sum: %d, Avg: %d, Min: %d, Max: %d",
1113 (int)total, (int)avg, (int)min, (int)max);
1114 }
1115 buf.append_and_print_cr("]");
1116 } 1108 }
1117 1109
1118 void G1CollectorPolicy::print_stats (int level, 1110 void G1CollectorPolicy::print_stats (int level,
1119 const char* str, 1111 const char* str,
1120 double value) { 1112 double value) {
1419 if (_last_satb_drain_processed_buffers >= 0) { 1411 if (_last_satb_drain_processed_buffers >= 0) {
1420 print_stats(2, "Processed Buffers", _last_satb_drain_processed_buffers); 1412 print_stats(2, "Processed Buffers", _last_satb_drain_processed_buffers);
1421 } 1413 }
1422 if (parallel) { 1414 if (parallel) {
1423 print_stats(1, "Parallel Time", _cur_collection_par_time_ms); 1415 print_stats(1, "Parallel Time", _cur_collection_par_time_ms);
1424 print_par_stats(2, "GC Worker Start Time", 1416 print_par_stats(2, "GC Worker Start Time", _par_last_gc_worker_start_times_ms);
1425 _par_last_gc_worker_start_times_ms, false);
1426 print_par_stats(2, "Update RS", _par_last_update_rs_times_ms); 1417 print_par_stats(2, "Update RS", _par_last_update_rs_times_ms);
1427 print_par_sizes(3, "Processed Buffers", 1418 print_par_sizes(3, "Processed Buffers", _par_last_update_rs_processed_buffers);
1428 _par_last_update_rs_processed_buffers, true); 1419 print_par_stats(2, "Ext Root Scanning", _par_last_ext_root_scan_times_ms);
1429 print_par_stats(2, "Ext Root Scanning", 1420 print_par_stats(2, "Mark Stack Scanning", _par_last_mark_stack_scan_times_ms);
1430 _par_last_ext_root_scan_times_ms);
1431 print_par_stats(2, "Mark Stack Scanning",
1432 _par_last_mark_stack_scan_times_ms);
1433 print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms); 1421 print_par_stats(2, "Scan RS", _par_last_scan_rs_times_ms);
1434 print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms); 1422 print_par_stats(2, "Object Copy", _par_last_obj_copy_times_ms);
1435 print_par_stats(2, "Termination", _par_last_termination_times_ms); 1423 print_par_stats(2, "Termination", _par_last_termination_times_ms);
1436 print_par_sizes(3, "Termination Attempts", 1424 print_par_sizes(3, "Termination Attempts", _par_last_termination_attempts);
1437 _par_last_termination_attempts, true); 1425 print_par_stats(2, "GC Worker End Time", _par_last_gc_worker_end_times_ms);
1438 print_par_stats(2, "GC Worker End Time", 1426
1439 _par_last_gc_worker_end_times_ms, false); 1427 for (int i = 0; i < _parallel_gc_threads; i++) {
1428 _par_last_gc_worker_times_ms[i] = _par_last_gc_worker_end_times_ms[i] - _par_last_gc_worker_start_times_ms[i];
1429 }
1430 print_par_stats(2, "GC Worker Times", _par_last_gc_worker_times_ms);
1431
1440 print_stats(2, "Other", parallel_other_time); 1432 print_stats(2, "Other", parallel_other_time);
1441 print_stats(1, "Clear CT", _cur_clear_ct_time_ms); 1433 print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
1442 } else { 1434 } else {
1443 print_stats(1, "Update RS", update_rs_time); 1435 print_stats(1, "Update RS", update_rs_time);
1444 print_stats(2, "Processed Buffers", 1436 print_stats(2, "Processed Buffers",