75 ShouldNotReachHere();
76 return NULL;
77 }
78 }
79
80 static const char* Indents[5] = {"", " ", " ", " ", " "};
81
82 void RefProcPhaseTimeBaseTracker::print_phase(ReferenceProcessorPhaseTimes::RefProcPhases phase, uint indent) {
83 double phase_time = phase_times()->phase_time_ms(phase);
84 if (phase_time != ReferenceProcessorPhaseTimes::uninitialized()) {
85 Log(gc, ref) log;
86
87 log.debug_stream()->print_cr("%s%s%s %0.3fms",
88 Indents[indent],
89 phase_enum_2_string(phase),
90 indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
91 phase_time);
92 if (phase_times()->processing_is_mt() && log.is_level(LogLevel::Trace)) {
93 outputStream* out = log.trace_stream();
94
95 out->print("%s", " ");
96 // worker_time_sec is recorded in seconds but it will be printed in milliseconds.
97 phase_times()->worker_time_sec(phase)->print_summary_on(out, true);
98 }
99 }
100 }
101
102 Ticks RefProcPhaseTimeBaseTracker::end_ticks() {
103 // If ASSERT is defined, the default value of Ticks will be -2.
104 if (_end_ticks.value() <= 0) {
105 _end_ticks.stamp();
106 }
107
108 return _end_ticks;
109 }
110
111 double RefProcPhaseTimeBaseTracker::elapsed_time() {
112 jlong end_value = end_ticks().value();
113
114 return TimeHelper::counter_to_millis(end_value - _start_ticks.value());
115 }
174 out->print_cr(" %s " SIZE_FORMAT, "Discovered:", _ref_discovered);
175 }
176
177 // Reset for next use.
178 phase_times()->reset();
179 }
180
181 RefProcEnqueueTimeLogger::RefProcEnqueueTimeLogger(ReferenceProcessorPhaseTimes* phase_times,
182 ReferenceProcessorStats& stats,
183 GCTimer* gc_timer) :
184 _stats(stats), RefProcPhaseTimeBaseTracker("Enqueue reference lists", phase_times, gc_timer) {}
185
186 RefProcEnqueueTimeLogger::~RefProcEnqueueTimeLogger() {
187 double elapsed = elapsed_time();
188
189 phase_times()->set_phase_time_ms(ReferenceProcessorPhaseTimes::RefEnqueue, elapsed);
190
191 print_phase(ReferenceProcessorPhaseTimes::RefEnqueue, 0);
192 phase_times()->reset();
193
194 log_debug(gc, ref)(" Counts: Soft: " SIZE_FORMAT " Weak: " SIZE_FORMAT
195 " Final: " SIZE_FORMAT " Phantom: " SIZE_FORMAT ,
196 _stats.soft_count(), _stats.weak_count(),
197 _stats.final_count(), _stats.phantom_count());
198 }
199
200 ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(uint max_gc_threads, bool processing_is_mt) :
201 _balance_queues_time_ms(uninitialized()), _max_gc_threads(max_gc_threads), _processing_is_mt(processing_is_mt) {
202
203 _worker_time_sec[RefPhase1] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
204 _worker_time_sec[RefPhase2] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
205 _worker_time_sec[RefPhase3] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
206 _worker_time_sec[RefEnqueue] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
207
208 _phase_time_ms[RefPhase1] = uninitialized();
209 _phase_time_ms[RefPhase2] = uninitialized();
210 _phase_time_ms[RefPhase3] = uninitialized();
211 _phase_time_ms[RefEnqueue] = uninitialized();
212 }
213
214 WorkerDataArray<double>* ReferenceProcessorPhaseTimes::worker_time_sec(RefProcPhases phase) const {
|
75 ShouldNotReachHere();
76 return NULL;
77 }
78 }
79
80 static const char* Indents[5] = {"", " ", " ", " ", " "};
81
82 void RefProcPhaseTimeBaseTracker::print_phase(ReferenceProcessorPhaseTimes::RefProcPhases phase, uint indent) {
83 double phase_time = phase_times()->phase_time_ms(phase);
84 if (phase_time != ReferenceProcessorPhaseTimes::uninitialized()) {
85 Log(gc, ref) log;
86
87 log.debug_stream()->print_cr("%s%s%s %0.3fms",
88 Indents[indent],
89 phase_enum_2_string(phase),
90 indent == 0 ? "" : ":", /* 0 indent logs don't need colon. */
91 phase_time);
92 if (phase_times()->processing_is_mt() && log.is_level(LogLevel::Trace)) {
93 outputStream* out = log.trace_stream();
94
95 out->print("%s", Indents[2]);
96 // worker_time_sec is recorded in seconds but it will be printed in milliseconds.
97 phase_times()->worker_time_sec(phase)->print_summary_on(out, true);
98 }
99 }
100 }
101
102 Ticks RefProcPhaseTimeBaseTracker::end_ticks() {
103 // If ASSERT is defined, the default value of Ticks will be -2.
104 if (_end_ticks.value() <= 0) {
105 _end_ticks.stamp();
106 }
107
108 return _end_ticks;
109 }
110
111 double RefProcPhaseTimeBaseTracker::elapsed_time() {
112 jlong end_value = end_ticks().value();
113
114 return TimeHelper::counter_to_millis(end_value - _start_ticks.value());
115 }
174 out->print_cr(" %s " SIZE_FORMAT, "Discovered:", _ref_discovered);
175 }
176
177 // Reset for next use.
178 phase_times()->reset();
179 }
180
181 RefProcEnqueueTimeLogger::RefProcEnqueueTimeLogger(ReferenceProcessorPhaseTimes* phase_times,
182 ReferenceProcessorStats& stats,
183 GCTimer* gc_timer) :
184 _stats(stats), RefProcPhaseTimeBaseTracker("Enqueue reference lists", phase_times, gc_timer) {}
185
186 RefProcEnqueueTimeLogger::~RefProcEnqueueTimeLogger() {
187 double elapsed = elapsed_time();
188
189 phase_times()->set_phase_time_ms(ReferenceProcessorPhaseTimes::RefEnqueue, elapsed);
190
191 print_phase(ReferenceProcessorPhaseTimes::RefEnqueue, 0);
192 phase_times()->reset();
193
194 log_debug(gc, ref)(" Ref Counts: Soft: " SIZE_FORMAT " Weak: " SIZE_FORMAT
195 " Final: " SIZE_FORMAT " Phantom: " SIZE_FORMAT ,
196 _stats.soft_count(), _stats.weak_count(),
197 _stats.final_count(), _stats.phantom_count());
198 }
199
200 ReferenceProcessorPhaseTimes::ReferenceProcessorPhaseTimes(uint max_gc_threads, bool processing_is_mt) :
201 _balance_queues_time_ms(uninitialized()), _max_gc_threads(max_gc_threads), _processing_is_mt(processing_is_mt) {
202
203 _worker_time_sec[RefPhase1] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
204 _worker_time_sec[RefPhase2] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
205 _worker_time_sec[RefPhase3] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
206 _worker_time_sec[RefEnqueue] = new WorkerDataArray<double>(_max_gc_threads, "Process lists (ms)");
207
208 _phase_time_ms[RefPhase1] = uninitialized();
209 _phase_time_ms[RefPhase2] = uninitialized();
210 _phase_time_ms[RefPhase3] = uninitialized();
211 _phase_time_ms[RefEnqueue] = uninitialized();
212 }
213
214 WorkerDataArray<double>* ReferenceProcessorPhaseTimes::worker_time_sec(RefProcPhases phase) const {
|