1 /*
2 * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation.
8 *
9 * This code is distributed in the hope that it will be useful, but WITHOUT
10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
12 * version 2 for more details (a copy is included in the LICENSE file that
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 */
23
24 #include "precompiled.hpp"
25 #include "gc/z/zCollectedHeap.hpp"
26 #include "gc/z/zCPU.hpp"
27 #include "gc/z/zHeap.inline.hpp"
28 #include "gc/z/zLargePages.inline.hpp"
29 #include "gc/z/zNMethodTable.hpp"
30 #include "gc/z/zNUMA.hpp"
31 #include "gc/z/zStat.hpp"
32 #include "gc/z/zTracer.inline.hpp"
33 #include "gc/z/zUtils.hpp"
34 #include "runtime/atomic.hpp"
35 #include "runtime/os.hpp"
36 #include "runtime/timer.hpp"
37 #include "utilities/align.hpp"
38 #include "utilities/compilerWarnings.hpp"
39 #include "utilities/debug.hpp"
40 #include "utilities/ticks.inline.hpp"
41
42 //
43 // Stat sampler/counter data
44 //
45 struct ZStatSamplerData {
46 uint64_t _nsamples;
47 uint64_t _sum;
48 uint64_t _max;
49
50 ZStatSamplerData() :
51 _nsamples(0),
52 _sum(0),
53 _max(0) {}
54
55 void add(const ZStatSamplerData& new_sample) {
56 _nsamples += new_sample._nsamples;
57 _sum += new_sample._nsamples;
58 _max = MAX2(_max, new_sample._max);
59 }
60 };
61
62 struct ZStatCounterData {
63 uint64_t _counter;
64
65 ZStatCounterData() :
66 _counter(0) {}
67 };
68
69 //
70 // Stat sampler history
71 //
72 template <size_t size>
73 class ZStatSamplerHistoryInterval VALUE_OBJ_CLASS_SPEC {
74 private:
75 size_t _next;
76 ZStatSamplerData _samples[size];
77 ZStatSamplerData _accumulated;
78 ZStatSamplerData _total;
79
80 public:
81 ZStatSamplerHistoryInterval() :
82 _next(0),
83 _samples(),
84 _total(),
85 _accumulated() {}
86
87 bool add(const ZStatSamplerData& new_sample) {
88 // Insert sample
89 const ZStatSamplerData old_sample = _samples[_next];
90 _samples[_next] = new_sample;
91
92 // Adjust accumulated
93 _accumulated._nsamples += new_sample._nsamples;
94 _accumulated._sum += new_sample._sum;
95 _accumulated._max = MAX2(_accumulated._max, new_sample._max);
96
97 // Adjust total
98 _total._nsamples -= old_sample._nsamples;
99 _total._sum -= old_sample._sum;
100 _total._nsamples += new_sample._nsamples;
101 _total._sum += new_sample._sum;
102 if (_total._max < new_sample._max) {
103 // Found new max
104 _total._max = new_sample._max;
105 } else if (_total._max == old_sample._max) {
106 // Removed old max, reset and find new max
107 _total._max = 0;
108 for (size_t i = 0; i < size; i++) {
109 if (_total._max < _samples[i]._max) {
110 _total._max = _samples[i]._max;
111 }
112 }
113 }
114
115 // Adjust next
116 if (++_next == size) {
117 _next = 0;
118
119 // Clear accumulated
120 const ZStatSamplerData zero;
121 _accumulated = zero;
122
123 // Became full
124 return true;
125 }
126
127 // Not yet full
128 return false;
129 }
130
131 const ZStatSamplerData& total() const {
132 return _total;
133 }
134
135 const ZStatSamplerData& accumulated() const {
136 return _accumulated;
137 }
138 };
139
140 class ZStatSamplerHistory : public CHeapObj<mtGC> {
141 private:
142 ZStatSamplerHistoryInterval<10> _10seconds;
143 ZStatSamplerHistoryInterval<60> _10minutes;
144 ZStatSamplerHistoryInterval<60> _10hours;
145 ZStatSamplerData _total;
146
147 uint64_t avg(uint64_t sum, uint64_t nsamples) const {
148 return (nsamples > 0) ? sum / nsamples : 0;
149 }
150
151 public:
152 ZStatSamplerHistory() :
153 _10seconds(),
154 _10minutes(),
155 _10hours(),
156 _total() {}
157
158 void add(const ZStatSamplerData& new_sample) {
159 if (_10seconds.add(new_sample)) {
160 if (_10minutes.add(_10seconds.total())) {
161 if (_10hours.add(_10minutes.total())) {
162 _total.add(_10hours.total());
163 }
164 }
165 }
166 }
167
168 uint64_t avg_10_seconds() const {
169 const uint64_t sum = _10seconds.total()._sum;
170 const uint64_t nsamples = _10seconds.total()._nsamples;
171 return avg(sum, nsamples);
172 }
173
174 uint64_t avg_10_minutes() const {
175 const uint64_t sum = _10seconds.accumulated()._sum +
176 _10minutes.total()._sum;
177 const uint64_t nsamples = _10seconds.accumulated()._nsamples +
178 _10minutes.total()._nsamples;
179 return avg(sum, nsamples);
180 }
181
182 uint64_t avg_10_hours() const {
183 const uint64_t sum = _10seconds.accumulated()._sum +
184 _10minutes.accumulated()._sum +
185 _10hours.total()._sum;
186 const uint64_t nsamples = _10seconds.accumulated()._nsamples +
187 _10minutes.accumulated()._nsamples +
188 _10hours.total()._nsamples;
189 return avg(sum, nsamples);
190 }
191
192 uint64_t avg_total() const {
193 const uint64_t sum = _10seconds.accumulated()._sum +
194 _10minutes.accumulated()._sum +
195 _10hours.accumulated()._sum +
196 _total._sum;
197 const uint64_t nsamples = _10seconds.accumulated()._nsamples +
198 _10minutes.accumulated()._nsamples +
199 _10hours.accumulated()._nsamples +
200 _total._nsamples;
201 return avg(sum, nsamples);
202 }
203
204 uint64_t max_10_seconds() const {
205 return _10seconds.total()._max;
206 }
207
208 uint64_t max_10_minutes() const {
209 return MAX2(_10seconds.accumulated()._max,
210 _10minutes.total()._max);
211 }
212
213 uint64_t max_10_hours() const {
214 return MAX3(_10seconds.accumulated()._max,
215 _10minutes.accumulated()._max,
216 _10hours.total()._max);
217 }
218
219 uint64_t max_total() const {
220 return MAX4(_10seconds.accumulated()._max,
221 _10minutes.accumulated()._max,
222 _10hours.accumulated()._max,
223 _total._max);
224 }
225 };
226
227 //
228 // Stat unit printers
229 //
230 void ZStatUnitTime(LogTargetHandle log, const ZStatSampler& sampler, const ZStatSamplerHistory& history) {
231 log.print(" %10s: %-40s "
232 "%9.3f / %-9.3f "
233 "%9.3f / %-9.3f "
234 "%9.3f / %-9.3f "
235 "%9.3f / %-9.3f ms",
236 sampler.group(),
237 sampler.name(),
238 TimeHelper::counter_to_millis(history.avg_10_seconds()),
239 TimeHelper::counter_to_millis(history.max_10_seconds()),
240 TimeHelper::counter_to_millis(history.avg_10_minutes()),
241 TimeHelper::counter_to_millis(history.max_10_minutes()),
242 TimeHelper::counter_to_millis(history.avg_10_hours()),
243 TimeHelper::counter_to_millis(history.max_10_hours()),
244 TimeHelper::counter_to_millis(history.avg_total()),
245 TimeHelper::counter_to_millis(history.max_total()));
246 }
247
248 void ZStatUnitBytes(LogTargetHandle log, const ZStatSampler& sampler, const ZStatSamplerHistory& history) {
249 log.print(" %10s: %-40s "
250 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
251 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
252 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
253 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " MB",
254 sampler.group(),
255 sampler.name(),
256 history.avg_10_seconds() / M,
257 history.max_10_seconds() / M,
258 history.avg_10_minutes() / M,
259 history.max_10_minutes() / M,
260 history.avg_10_hours() / M,
261 history.max_10_hours() / M,
262 history.avg_total() / M,
263 history.max_total() / M);
264 }
265
266 void ZStatUnitThreads(LogTargetHandle log, const ZStatSampler& sampler, const ZStatSamplerHistory& history) {
267 log.print(" %10s: %-40s "
268 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
269 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
270 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
271 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " threads",
272 sampler.group(),
273 sampler.name(),
274 history.avg_10_seconds(),
275 history.max_10_seconds(),
276 history.avg_10_minutes(),
277 history.max_10_minutes(),
278 history.avg_10_hours(),
279 history.max_10_hours(),
280 history.avg_total(),
281 history.max_total());
282 }
283
284 void ZStatUnitBytesPerSecond(LogTargetHandle log, const ZStatSampler& sampler, const ZStatSamplerHistory& history) {
285 log.print(" %10s: %-40s "
286 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
287 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
288 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
289 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " MB/s",
290 sampler.group(),
291 sampler.name(),
292 history.avg_10_seconds() / M,
293 history.max_10_seconds() / M,
294 history.avg_10_minutes() / M,
295 history.max_10_minutes() / M,
296 history.avg_10_hours() / M,
297 history.max_10_hours() / M,
298 history.avg_total() / M,
299 history.max_total() / M);
300 }
301
302 void ZStatUnitOpsPerSecond(LogTargetHandle log, const ZStatSampler& sampler, const ZStatSamplerHistory& history) {
303 log.print(" %10s: %-40s "
304 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
305 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
306 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " "
307 UINT64_FORMAT_W(9) " / " UINT64_FORMAT_W(-9) " ops/s",
308 sampler.group(),
309 sampler.name(),
310 history.avg_10_seconds(),
311 history.max_10_seconds(),
312 history.avg_10_minutes(),
313 history.max_10_minutes(),
314 history.avg_10_hours(),
315 history.max_10_hours(),
316 history.avg_total(),
317 history.max_total());
318 }
319
320 //
321 // Stat value
322 //
323 uintptr_t ZStatValue::_base = 0;
324 uint32_t ZStatValue::_cpu_offset = 0;
325
326 ZStatValue::ZStatValue(const char* group,
327 const char* name,
328 uint32_t id,
329 uint32_t size) :
330 _group(group),
331 _name(name),
332 _id(id),
333 _offset(_cpu_offset) {
334 assert(_base == 0, "Already initialized");
335 _cpu_offset += size;
336 }
337
338 template <typename T>
339 T* ZStatValue::get_cpu_local(uint32_t cpu) const {
340 assert(_base != 0, "Not initialized");
341 const uintptr_t cpu_base = _base + (_cpu_offset * cpu);
342 const uintptr_t value_addr = cpu_base + _offset;
343 return (T*)value_addr;
344 }
345
346 void ZStatValue::initialize() {
347 // Finalize and align CPU offset
348 _cpu_offset = align_up(_cpu_offset, DEFAULT_CACHE_LINE_SIZE);
349
350 // Allocation aligned memory
351 const size_t size = _cpu_offset * ZCPU::count();
352 _base = ZUtils::alloc_aligned(DEFAULT_CACHE_LINE_SIZE, size);
353 memset((void*)_base, 0, size);
354 }
355
356 const char* ZStatValue::group() const {
357 return _group;
358 }
359
360 const char* ZStatValue::name() const {
361 return _name;
362 }
363
364 uint32_t ZStatValue::id() const {
365 return _id;
366 }
367
368 //
369 // Stat iterable value
370 //
371 template <typename T> uint32_t ZStatIterableValue<T>::_count = 0;
372 template <typename T> T* ZStatIterableValue<T>::_first = NULL;
373
374 template <typename T>
375 ZStatIterableValue<T>::ZStatIterableValue(const char* group,
376 const char* name,
377 uint32_t size) :
378 ZStatValue(group, name, _count++, size),
379 _next(insert()) {}
380
381 template <typename T>
382 T* ZStatIterableValue<T>::insert() const {
383 T** current = &_first;
384
385 while (*current != NULL) {
386 // First sort by group, then by name
387 const int group_cmp = strcmp((*current)->group(), group());
388 const int name_cmp = strcmp((*current)->name(), name());
389 if ((group_cmp > 0) || (group_cmp == 0 && name_cmp > 0)) {
390 break;
391 }
392
393 current = &(*current)->_next;
394 }
395
396 T* const next = *current;
397 *current = (T*)this;
398 return next;
399 }
400
401 //
402 // Stat sampler
403 //
404 ZStatSampler::ZStatSampler(const char* group, const char* name, ZStatUnitPrinter printer) :
405 ZStatIterableValue(group, name, sizeof(ZStatSamplerData)),
406 _printer(printer) {}
407
408 ZStatSamplerData* ZStatSampler::get() const {
409 return get_cpu_local<ZStatSamplerData>(ZCPU::id());
410 }
411
412 ZStatSamplerData ZStatSampler::collect_and_reset() const {
413 ZStatSamplerData all;
414
415 const uint32_t ncpus = ZCPU::count();
416 for (uint32_t i = 0; i < ncpus; i++) {
417 ZStatSamplerData* const cpu_data = get_cpu_local<ZStatSamplerData>(i);
418 if (cpu_data->_nsamples > 0) {
419 const uint64_t nsamples = Atomic::xchg((uint64_t)0, &cpu_data->_nsamples);
420 const uint64_t sum = Atomic::xchg((uint64_t)0, &cpu_data->_sum);
421 const uint64_t max = Atomic::xchg((uint64_t)0, &cpu_data->_max);
422 all._nsamples += nsamples;
423 all._sum += sum;
424 if (all._max < max) {
425 all._max = max;
426 }
427 }
428 }
429
430 return all;
431 }
432
433 ZStatUnitPrinter ZStatSampler::printer() const {
434 return _printer;
435 }
436
437 //
438 // Stat counter
439 //
440 ZStatCounter::ZStatCounter(const char* group, const char* name, ZStatUnitPrinter printer) :
441 ZStatIterableValue(group, name, sizeof(ZStatCounterData)),
442 _sampler(group, name, printer) {}
443
444 ZStatCounterData* ZStatCounter::get() const {
445 return get_cpu_local<ZStatCounterData>(ZCPU::id());
446 }
447
448 void ZStatCounter::sample_and_reset() const {
449 uint64_t counter = 0;
450
451 const uint32_t ncpus = ZCPU::count();
452 for (uint32_t i = 0; i < ncpus; i++) {
453 ZStatCounterData* const cpu_data = get_cpu_local<ZStatCounterData>(i);
454 counter += Atomic::xchg((uint64_t)0, &cpu_data->_counter);
455 }
456
457 ZStatSample(_sampler, counter);
458 }
459
460 //
461 // Stat unsampled counter
462 //
463 ZStatUnsampledCounter::ZStatUnsampledCounter(const char* name) :
464 ZStatIterableValue("Unsampled", name, sizeof(ZStatCounterData)) {}
465
466 ZStatCounterData* ZStatUnsampledCounter::get() const {
467 return get_cpu_local<ZStatCounterData>(ZCPU::id());
468 }
469
470 ZStatCounterData ZStatUnsampledCounter::collect_and_reset() const {
471 ZStatCounterData all;
472
473 const uint32_t ncpus = ZCPU::count();
474 for (uint32_t i = 0; i < ncpus; i++) {
475 ZStatCounterData* const cpu_data = get_cpu_local<ZStatCounterData>(i);
476 all._counter += Atomic::xchg((uint64_t)0, &cpu_data->_counter);
477 }
478
479 return all;
480 }
481
482 //
483 // Stat MMU (Mimimum Mutator Utilization)
484 //
485 ZStatMMUPause::ZStatMMUPause() :
486 _start(0.0),
487 _end(0.0) {}
488
489 ZStatMMUPause::ZStatMMUPause(const Ticks& start, const Ticks& end) :
490 _start(TimeHelper::counter_to_millis(start.value())),
491 _end(TimeHelper::counter_to_millis(end.value())) {}
492
493 double ZStatMMUPause::end() const {
494 return _end;
495 }
496
497 double ZStatMMUPause::overlap(double start, double end) const {
498 const double start_max = MAX2(start, _start);
499 const double end_min = MIN2(end, _end);
500
501 if (end_min > start_max) {
502 // Overlap found
503 return end_min - start_max;
504 }
505
506 // No overlap
507 return 0.0;
508 }
509
510 size_t ZStatMMU::_next = 0;
511 size_t ZStatMMU::_npauses = 0;
512 ZStatMMUPause ZStatMMU::_pauses[200];
513 double ZStatMMU::_mmu_2ms = 100.0;
514 double ZStatMMU::_mmu_5ms = 100.0;
515 double ZStatMMU::_mmu_10ms = 100.0;
516 double ZStatMMU::_mmu_20ms = 100.0;
517 double ZStatMMU::_mmu_50ms = 100.0;
518 double ZStatMMU::_mmu_100ms = 100.0;
519
520 const ZStatMMUPause& ZStatMMU::pause(size_t index) {
521 return _pauses[(_next - index - 1) % ARRAY_SIZE(_pauses)];
522 }
523
524 double ZStatMMU::calculate_mmu(double time_slice) {
525 const double end = pause(0).end();
526 const double start = end - time_slice;
527 double time_paused = 0.0;
528
529 // Find all overlapping pauses
530 for (size_t i = 0; i < _npauses; i++) {
531 const double overlap = pause(i).overlap(start, end);
532 if (overlap == 0.0) {
533 // No overlap
534 break;
535 }
536
537 time_paused += overlap;
538 }
539
540 // Calculate MMU
541 const double time_mutator = time_slice - time_paused;
542 return percent_of(time_mutator, time_slice);
543 }
544
545 void ZStatMMU::register_pause(const Ticks& start, const Ticks& end) {
546 // Add pause
547 const size_t index = _next++ % ARRAY_SIZE(_pauses);
548 _pauses[index] = ZStatMMUPause(start, end);
549 _npauses = MIN2(_npauses + 1, ARRAY_SIZE(_pauses));
550
551 // Recalculate MMUs
552 _mmu_2ms = MIN2(_mmu_2ms, calculate_mmu(2));
553 _mmu_5ms = MIN2(_mmu_5ms, calculate_mmu(5));
554 _mmu_10ms = MIN2(_mmu_10ms, calculate_mmu(10));
555 _mmu_20ms = MIN2(_mmu_20ms, calculate_mmu(20));
556 _mmu_50ms = MIN2(_mmu_50ms, calculate_mmu(50));
557 _mmu_100ms = MIN2(_mmu_100ms, calculate_mmu(100));
558 }
559
560 void ZStatMMU::print() {
561 log_info(gc, mmu)(
562 "MMU: 2ms/%.1f%%, 5ms/%.1f%%, 10ms/%.1f%%, 20ms/%.1f%%, 50ms/%.1f%%, 100ms/%.1f%%",
563 _mmu_2ms, _mmu_5ms, _mmu_10ms, _mmu_20ms, _mmu_50ms, _mmu_100ms);
564 }
565
566 //
567 // Stat phases
568 //
569 ConcurrentGCTimer ZStatPhase::_timer;
570
571 ZStatPhase::ZStatPhase(const char* group, const char* name) :
572 _sampler(group, name, ZStatUnitTime) {}
573
574 void ZStatPhase::log_start(LogTargetHandle log, bool thread) const {
575 if (!log.is_enabled()) {
576 return;
577 }
578
579 if (thread) {
580 ResourceMark rm;
581 log.print("%s (%s)", name(), Thread::current()->name());
582 } else {
583 log.print("%s", name());
584 }
585 }
586
587 void ZStatPhase::log_end(LogTargetHandle log, const Tickspan& duration, bool thread) const {
588 if (!log.is_enabled()) {
589 return;
590 }
591
592 if (thread) {
593 ResourceMark rm;
594 log.print("%s (%s) %.3fms", name(), Thread::current()->name(), TimeHelper::counter_to_millis(duration.value()));
595 } else {
596 log.print("%s %.3fms", name(), TimeHelper::counter_to_millis(duration.value()));
597 }
598 }
599
600 ConcurrentGCTimer* ZStatPhase::timer() {
601 return &_timer;
602 }
603
604 const char* ZStatPhase::name() const {
605 return _sampler.name();
606 }
607
608 ZStatPhaseCycle::ZStatPhaseCycle(const char* name) :
609 ZStatPhase("Collector", name) {}
610
611 void ZStatPhaseCycle::register_start(const Ticks& start) const {
612 timer()->register_gc_start(start);
613
614 ZTracer::tracer()->report_gc_start(ZCollectedHeap::heap()->gc_cause(), start);
615
616 ZCollectedHeap::heap()->print_heap_before_gc();
617 ZCollectedHeap::heap()->trace_heap_before_gc(ZTracer::tracer());
618
619 log_info(gc, start)("Garbage Collection (%s)",
620 GCCause::to_string(ZCollectedHeap::heap()->gc_cause()));
621 }
622
623 #define ZUSED_FMT SIZE_FORMAT "M(%.0lf%%)"
624 #define ZUSED_ARGS(size, max_capacity) ((size) / M), (percent_of<size_t>(size, max_capacity))
625
626 void ZStatPhaseCycle::register_end(const Ticks& start, const Ticks& end) const {
627 timer()->register_gc_end(end);
628
629 ZCollectedHeap::heap()->print_heap_after_gc();
630 ZCollectedHeap::heap()->trace_heap_after_gc(ZTracer::tracer());
631
632 ZTracer::tracer()->report_gc_end(end, timer()->time_partitions());
633
634 const Tickspan duration = end - start;
635 ZStatSample(_sampler, duration.value());
636
637 ZStatLoad::print();
638 ZStatMMU::print();
639 ZStatMark::print();
640 ZStatRelocation::print();
641 ZStatNMethods::print();
642 ZStatReferences::print();
643 ZStatHeap::print();
644
645 log_info(gc)("Garbage Collection (%s) " ZUSED_FMT "->" ZUSED_FMT,
646 GCCause::to_string(ZCollectedHeap::heap()->gc_cause()),
647 ZUSED_ARGS(ZStatHeap::used_at_mark_start(), ZStatHeap::max_capacity()),
648 ZUSED_ARGS(ZStatHeap::used_at_relocate_end(), ZStatHeap::max_capacity()));
649 }
650
651 Tickspan ZStatPhasePause::_max;
652
653 ZStatPhasePause::ZStatPhasePause(const char* name) :
654 ZStatPhase("Phase", name) {}
655
656 const Tickspan& ZStatPhasePause::max() {
657 return _max;
658 }
659
660 void ZStatPhasePause::register_start(const Ticks& start) const {
661 timer()->register_gc_pause_start(name(), start);
662
663 LogTarget(Debug, gc, phases, start) log;
664 log_start(log);
665 }
666
667 void ZStatPhasePause::register_end(const Ticks& start, const Ticks& end) const {
668 timer()->register_gc_pause_end(end);
669
670 const Tickspan duration = end - start;
671 ZStatSample(_sampler, duration.value());
672
673 // Track max pause time
674 if (_max < duration) {
675 _max = duration;
676 }
677
678 // Track minimum mutator utilization
679 ZStatMMU::register_pause(start, end);
680
681 LogTarget(Info, gc, phases) log;
682 log_end(log, duration);
683 }
684
685 ZStatPhaseConcurrent::ZStatPhaseConcurrent(const char* name) :
686 ZStatPhase("Phase", name) {}
687
688 void ZStatPhaseConcurrent::register_start(const Ticks& start) const {
689 timer()->register_gc_concurrent_start(name(), start);
690
691 LogTarget(Debug, gc, phases, start) log;
692 log_start(log);
693 }
694
695 void ZStatPhaseConcurrent::register_end(const Ticks& start, const Ticks& end) const {
696 timer()->register_gc_concurrent_end(end);
697
698 const Tickspan duration = end - start;
699 ZStatSample(_sampler, duration.value());
700
701 LogTarget(Info, gc, phases) log;
702 log_end(log, duration);
703 }
704
705 ZStatSubPhase::ZStatSubPhase(const char* name) :
706 ZStatPhase("Subphase", name) {}
707
708 void ZStatSubPhase::register_start(const Ticks& start) const {
709 LogTarget(Debug, gc, phases, start) log;
710 log_start(log, true /* thread */);
711 }
712
713 void ZStatSubPhase::register_end(const Ticks& start, const Ticks& end) const {
714 ZTracer::tracer()->report_thread_phase(*this, start, end);
715
716 const Tickspan duration = end - start;
717 ZStatSample(_sampler, duration.value());
718
719 LogTarget(Debug, gc, phases) log;
720 log_end(log, duration, true /* thread */);
721 }
722
723 ZStatCriticalPhase::ZStatCriticalPhase(const char* name, bool verbose) :
724 ZStatPhase("Critical", name),
725 _counter("Critical", name, ZStatUnitOpsPerSecond),
726 _verbose(verbose) {}
727
728 void ZStatCriticalPhase::register_start(const Ticks& start) const {
729 LogTarget(Debug, gc, start) log;
730 log_start(log, true /* thread */);
731 }
732
733 void ZStatCriticalPhase::register_end(const Ticks& start, const Ticks& end) const {
734 ZTracer::tracer()->report_thread_phase(*this, start, end);
735
736 const Tickspan duration = end - start;
737 ZStatSample(_sampler, duration.value());
738 ZStatInc(_counter);
739
740 if (_verbose) {
741 LogTarget(Info, gc) log;
742 log_end(log, duration, true /* thread */);
743 } else {
744 LogTarget(Debug, gc) log;
745 log_end(log, duration, true /* thread */);
746 }
747 }
748
749 //
750 // Stat sample/inc
751 //
752 void ZStatSample(const ZStatSampler& sampler, uint64_t value, bool trace) {
753 ZStatSamplerData* const cpu_data = sampler.get();
754 Atomic::add(1u, &cpu_data->_nsamples);
755 Atomic::add(value, &cpu_data->_sum);
756
757 uint64_t max = cpu_data->_max;
758 for (;;) {
759 if (max >= value) {
760 // Not max
761 break;
762 }
763
764 const uint64_t new_max = value;
765 const uint64_t prev_max = Atomic::cmpxchg(new_max, &cpu_data->_max, max);
766 if (prev_max == max) {
767 // Success
768 break;
769 }
770
771 // Retry
772 max = prev_max;
773 }
774
775 if (trace) {
776 ZTracer::tracer()->report_stat_sampler(sampler, value);
777 }
778 }
779
780 void ZStatInc(const ZStatCounter& counter, uint64_t increment, bool trace) {
781 ZStatCounterData* const cpu_data = counter.get();
782 const uint64_t value = Atomic::add(increment, &cpu_data->_counter);
783
784 if (trace) {
785 ZTracer::tracer()->report_stat_counter(counter, increment, value);
786 }
787 }
788
789 void ZStatInc(const ZStatUnsampledCounter& counter, uint64_t increment) {
790 ZStatCounterData* const cpu_data = counter.get();
791 Atomic::add(increment, &cpu_data->_counter);
792 }
793
794 //
795 // Stat allocation rate
796 //
797 const ZStatUnsampledCounter ZStatAllocRate::_counter("Allocation Rate");
798 TruncatedSeq ZStatAllocRate::_rate(ZStatAllocRate::sample_window_sec * ZStatAllocRate::sample_hz);
799 TruncatedSeq ZStatAllocRate::_rate_avg(ZStatAllocRate::sample_window_sec * ZStatAllocRate::sample_hz);
800
801 const ZStatUnsampledCounter& ZStatAllocRate::counter() {
802 return _counter;
803 }
804
805 uint64_t ZStatAllocRate::sample_and_reset() {
806 const ZStatCounterData bytes_per_sample = _counter.collect_and_reset();
807 const uint64_t bytes_per_second = bytes_per_sample._counter * sample_hz;
808
809 _rate.add(bytes_per_second);
810 _rate_avg.add(_rate.avg());
811
812 return bytes_per_second;
813 }
814
815 double ZStatAllocRate::avg() {
816 return _rate.avg();
817 }
818
819 double ZStatAllocRate::avg_sd() {
820 return _rate_avg.sd();
821 }
822
823 //
824 // Stat thread
825 //
826 ZStat::ZStat() :
827 _metronome(sample_hz) {
828 set_name("ZStat");
829 create_and_start();
830 }
831
832 void ZStat::sample_and_collect(ZStatSamplerHistory* history) const {
833 // Sample counters
834 for (const ZStatCounter* counter = ZStatCounter::first(); counter != NULL; counter = counter->next()) {
835 counter->sample_and_reset();
836 }
837
838 // Collect samples
839 for (const ZStatSampler* sampler = ZStatSampler::first(); sampler != NULL; sampler = sampler->next()) {
840 ZStatSamplerHistory& sampler_history = history[sampler->id()];
841 sampler_history.add(sampler->collect_and_reset());
842 }
843 }
844
845 bool ZStat::should_print(LogTargetHandle log) const {
846 return log.is_enabled() && (_metronome.nticks() % ZStatisticsInterval == 0);
847 }
848
849 void ZStat::print(LogTargetHandle log, const ZStatSamplerHistory* history) const {
850 // Print
851 log.print("=== Garbage Collection Statistics =======================================================================================================================");
852 log.print(" Last 10s Last 10m Last 10h Total");
853 log.print(" Avg / Max Avg / Max Avg / Max Avg / Max");
854
855 for (const ZStatSampler* sampler = ZStatSampler::first(); sampler != NULL; sampler = sampler->next()) {
856 const ZStatSamplerHistory& sampler_history = history[sampler->id()];
857 const ZStatUnitPrinter printer = sampler->printer();
858 printer(log, *sampler, sampler_history);
859 }
860
861 log.print("=========================================================================================================================================================");
862 }
863
864 void ZStat::run_service() {
865 ZStatSamplerHistory* const history = new ZStatSamplerHistory[ZStatSampler::count()];
866 LogTarget(Info, gc, stats) log;
867
868 // Main loop
869 while (_metronome.wait_for_tick()) {
870 sample_and_collect(history);
871 if (should_print(log)) {
872 print(log, history);
873 }
874 }
875
876 delete [] history;
877 }
878
879 void ZStat::stop_service() {
880 _metronome.stop();
881 }
882
883 //
884 // Stat table
885 //
886 class ZStatTablePrinter {
887 private:
888 static const size_t _buffer_size = 256;
889
890 const size_t _column0_width;
891 const size_t _columnN_width;
892 char _buffer[_buffer_size];
893
894 public:
895 class ZColumn {
896 private:
897 char* const _buffer;
898 const size_t _position;
899 const size_t _width;
900 const size_t _width_next;
901
902 ZColumn next() const {
903 // Insert space between columns
904 _buffer[_position + _width] = ' ';
905 return ZColumn(_buffer, _position + _width + 1, _width_next, _width_next);
906 }
907
908 size_t print(size_t position, const char* fmt, va_list va) {
909 const int res = jio_vsnprintf(_buffer + position, _buffer_size - position, fmt, va);
910 if (res < 0) {
911 return 0;
912 }
913
914 return (size_t)res;
915 }
916
917 public:
918 ZColumn(char* buffer, size_t position, size_t width, size_t width_next) :
919 _buffer(buffer),
920 _position(position),
921 _width(width),
922 _width_next(width_next) {}
923
924 ZColumn left(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) {
925 va_list va;
926
927 va_start(va, fmt);
928 const size_t written = print(_position, fmt, va);
929 va_end(va);
930
931 if (written < _width) {
932 // Fill empty space
933 memset(_buffer + _position + written, ' ', _width - written);
934 }
935
936 return next();
937 }
938
939 ZColumn right(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) {
940 va_list va;
941
942 va_start(va, fmt);
943 const size_t written = print(_position, fmt, va);
944 va_end(va);
945
946 if (written > _width) {
947 // Line too long
948 return fill('?');
949 }
950
951 if (written < _width) {
952 // Short line, move all to right
953 memmove(_buffer + _position + _width - written, _buffer + _position, written);
954
955 // Fill empty space
956 memset(_buffer + _position, ' ', _width - written);
957 }
958
959 return next();
960 }
961
962 ZColumn center(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) {
963 va_list va;
964
965 va_start(va, fmt);
966 const size_t written = print(_position, fmt, va);
967 va_end(va);
968
969 if (written > _width) {
970 // Line too long
971 return fill('?');
972 }
973
974 if (written < _width) {
975 // Short line, move all to center
976 const size_t start_space = (_width - written) / 2;
977 const size_t end_space = _width - written - start_space;
978 memmove(_buffer + _position + start_space, _buffer + _position, written);
979
980 // Fill empty spaces
981 memset(_buffer + _position, ' ', start_space);
982 memset(_buffer + _position + start_space + written, ' ', end_space);
983 }
984
985 return next();
986 }
987
988 ZColumn fill(char filler = ' ') {
989 memset(_buffer + _position, filler, _width);
990 return next();
991 }
992
993 const char* end() {
994 _buffer[_position] = '\0';
995 return _buffer;
996 }
997 };
998
999 public:
1000 ZStatTablePrinter(size_t column0_width, size_t columnN_width) :
1001 _column0_width(column0_width),
1002 _columnN_width(columnN_width) {}
1003
1004 ZColumn operator()() {
1005 return ZColumn(_buffer, 0, _column0_width, _columnN_width);
1006 }
1007 };
1008
1009 //
1010 // Stat cycle
1011 //
1012 uint64_t ZStatCycle::_ncycles = 0;
1013 Ticks ZStatCycle::_start_of_last;
1014 Ticks ZStatCycle::_end_of_last;
1015 NumberSeq ZStatCycle::_duration(0.3 /* alpha */);
1016
1017 void ZStatCycle::at_start() {
1018 _start_of_last = Ticks::now();
1019 }
1020
1021 void ZStatCycle::at_end(double boost_factor) {
1022 _end_of_last = Ticks::now();
1023 _ncycles++;
1024
1025 // Calculate cycle duration. The cycle duration is normalize using the
1026 // boost factor to avoid artificially deflate the duration when boost
1027 // mode is enabled.
1028 const double duration = TicksToTimeHelper::seconds(_end_of_last - _start_of_last);
1029 const double normalized_duration = duration * boost_factor;
1030 _duration.add(normalized_duration);
1031 }
1032
1033 uint64_t ZStatCycle::ncycles() {
1034 return _ncycles;
1035 }
1036
1037 const AbsSeq& ZStatCycle::duration() {
1038 return _duration;
1039 }
1040
1041 double ZStatCycle::time_since_last() {
1042 if (_ncycles == 0) {
1043 // Return time since VM start-up
1044 return os::elapsedTime();
1045 }
1046
1047 const Ticks now = Ticks::now();
1048 const Tickspan time_since_last = now - _end_of_last;
1049 return TicksToTimeHelper::seconds(time_since_last);
1050 }
1051
1052 //
1053 // Stat load
1054 //
1055 void ZStatLoad::print() {
1056 double loadavg[3] = {};
1057 os::loadavg(loadavg, ARRAY_SIZE(loadavg));
1058 log_info(gc, load)("Load: %.2f/%.2f/%.2f", loadavg[0], loadavg[1], loadavg[2]);
1059 }
1060
1061 //
1062 // Stat mark
1063 //
1064 size_t ZStatMark::_nstripes;
1065 size_t ZStatMark::_nproactiveflush;
1066 size_t ZStatMark::_nterminateflush;
1067 size_t ZStatMark::_ntrycomplete;
1068 size_t ZStatMark::_ncontinue;
1069
1070 void ZStatMark::set_at_mark_start(size_t nstripes) {
1071 _nstripes = nstripes;
1072 }
1073
1074 void ZStatMark::set_at_mark_end(size_t nproactiveflush,
1075 size_t nterminateflush,
1076 size_t ntrycomplete,
1077 size_t ncontinue) {
1078 _nproactiveflush = nproactiveflush;
1079 _nterminateflush = nterminateflush;
1080 _ntrycomplete = ntrycomplete;
1081 _ncontinue = ncontinue;
1082 }
1083
1084 void ZStatMark::print() {
1085 log_info(gc, marking)("Mark: "
1086 SIZE_FORMAT " stripe(s), "
1087 SIZE_FORMAT " proactive flush(es), "
1088 SIZE_FORMAT " terminate flush(es), "
1089 SIZE_FORMAT " completion(s), "
1090 SIZE_FORMAT " continuation(s) ",
1091 _nstripes,
1092 _nproactiveflush,
1093 _nterminateflush,
1094 _ntrycomplete,
1095 _ncontinue);
1096 }
1097
1098 //
1099 // Stat relocation
1100 //
1101 size_t ZStatRelocation::_relocating;
1102 bool ZStatRelocation::_success;
1103
1104 void ZStatRelocation::set_at_select_relocation_set(size_t relocating) {
1105 _relocating = relocating;
1106 }
1107
1108 void ZStatRelocation::set_at_relocate_end(bool success) {
1109 _success = success;
1110 }
1111
1112 void ZStatRelocation::print() {
1113 if (_success) {
1114 log_info(gc, reloc)("Relocation: Successful, " SIZE_FORMAT "M relocated", _relocating / M);
1115 } else {
1116 log_info(gc, reloc)("Relocation: Incomplete");
1117 }
1118 }
1119
1120 //
1121 // Stat nmethods
1122 //
1123 void ZStatNMethods::print() {
1124 log_info(gc, nmethod)("NMethods: " SIZE_FORMAT " registered, " SIZE_FORMAT " unregistered",
1125 ZNMethodTable::registered_nmethods(),
1126 ZNMethodTable::unregistered_nmethods());
1127 }
1128
1129 //
1130 // Stat references
1131 //
1132 ZStatReferences::ZCount ZStatReferences::_soft;
1133 ZStatReferences::ZCount ZStatReferences::_weak;
1134 ZStatReferences::ZCount ZStatReferences::_final;
1135 ZStatReferences::ZCount ZStatReferences::_phantom;
1136
1137 void ZStatReferences::set(ZCount* count, size_t encountered, size_t dropped, size_t enqueued) {
1138 count->encountered = encountered;
1139 count->discovered = dropped + enqueued;
1140 count->dropped = dropped;
1141 count->enqueued = enqueued;
1142 }
1143
1144 void ZStatReferences::set_soft(size_t encountered, size_t dropped, size_t enqueued) {
1145 set(&_soft, encountered, dropped, enqueued);
1146 }
1147
1148 void ZStatReferences::set_weak(size_t encountered, size_t dropped, size_t enqueued) {
1149 set(&_weak, encountered, dropped, enqueued);
1150 }
1151
1152 void ZStatReferences::set_final(size_t encountered, size_t dropped, size_t enqueued) {
1153 set(&_final, encountered, dropped, enqueued);
1154 }
1155
1156 void ZStatReferences::set_phantom(size_t encountered, size_t dropped, size_t enqueued) {
1157 set(&_phantom, encountered, dropped, enqueued);
1158 }
1159
1160 void ZStatReferences::print(const char* name, const ZStatReferences::ZCount& ref) {
1161 log_info(gc, ref)("%s: "
1162 SIZE_FORMAT " encountered, "
1163 SIZE_FORMAT " discovered, "
1164 SIZE_FORMAT " dropped, "
1165 SIZE_FORMAT " enqueued",
1166 name,
1167 ref.encountered,
1168 ref.discovered,
1169 ref.dropped,
1170 ref.enqueued);
1171 }
1172
1173 void ZStatReferences::print() {
1174 print("Soft", _soft);
1175 print("Weak", _weak);
1176 print("Final", _final);
1177 print("Phantom", _phantom);
1178 }
1179
1180 //
1181 // Stat heap
1182 //
1183 ZStatHeap::ZAtInitialize ZStatHeap::_at_initialize;
1184 ZStatHeap::ZAtMarkStart ZStatHeap::_at_mark_start;
1185 ZStatHeap::ZAtMarkEnd ZStatHeap::_at_mark_end;
1186 ZStatHeap::ZAtRelocateStart ZStatHeap::_at_relocate_start;
1187 ZStatHeap::ZAtRelocateEnd ZStatHeap::_at_relocate_end;
1188
1189 #define ZSIZE_NA "%9s", "-"
1190 #define ZSIZE_ARGS(size) SIZE_FORMAT_W(8) "M (%.0lf%%)", \
1191 ((size) / M), (percent_of<size_t>(size, _at_initialize.max_capacity))
1192
1193 size_t ZStatHeap::available(size_t used) {
1194 return _at_initialize.max_capacity - used;
1195 }
1196
1197 size_t ZStatHeap::reserve(size_t used) {
1198 return MIN2(_at_initialize.max_reserve, available(used));
1199 }
1200
1201 size_t ZStatHeap::free(size_t used) {
1202 return available(used) - reserve(used);
1203 }
1204
1205 void ZStatHeap::set_at_initialize(size_t max_capacity,
1206 size_t max_reserve) {
1207 _at_initialize.max_capacity = max_capacity;
1208 _at_initialize.max_reserve = max_reserve;
1209 }
1210
1211 void ZStatHeap::set_at_mark_start(size_t capacity,
1212 size_t used) {
1213 _at_mark_start.capacity = capacity;
1214 _at_mark_start.reserve = reserve(used);
1215 _at_mark_start.used = used;
1216 _at_mark_start.free = free(used);
1217 }
1218
1219 void ZStatHeap::set_at_mark_end(size_t capacity,
1220 size_t allocated,
1221 size_t used) {
1222 _at_mark_end.capacity = capacity;
1223 _at_mark_end.reserve = reserve(used);
1224 _at_mark_end.allocated = allocated;
1225 _at_mark_end.used = used;
1226 _at_mark_end.free = free(used);
1227 }
1228
1229 void ZStatHeap::set_at_select_relocation_set(size_t live,
1230 size_t garbage,
1231 size_t reclaimed) {
1232 _at_mark_end.live = live;
1233 _at_mark_end.garbage = garbage;
1234
1235 _at_relocate_start.garbage = garbage - reclaimed;
1236 _at_relocate_start.reclaimed = reclaimed;
1237 }
1238
1239 void ZStatHeap::set_at_relocate_start(size_t capacity,
1240 size_t allocated,
1241 size_t used) {
1242 _at_relocate_start.capacity = capacity;
1243 _at_relocate_start.reserve = reserve(used);
1244 _at_relocate_start.allocated = allocated;
1245 _at_relocate_start.used = used;
1246 _at_relocate_start.free = free(used);
1247 }
1248
1249 void ZStatHeap::set_at_relocate_end(size_t capacity,
1250 size_t allocated,
1251 size_t reclaimed,
1252 size_t used,
1253 size_t used_high,
1254 size_t used_low) {
1255 _at_relocate_end.capacity = capacity;
1256 _at_relocate_end.capacity_high = capacity;
1257 _at_relocate_end.capacity_low = _at_mark_start.capacity;
1258 _at_relocate_end.reserve = reserve(used);
1259 _at_relocate_end.reserve_high = reserve(used_high);
1260 _at_relocate_end.reserve_low = reserve(used_low);
1261 _at_relocate_end.garbage = _at_mark_end.garbage - reclaimed;
1262 _at_relocate_end.allocated = allocated;
1263 _at_relocate_end.reclaimed = reclaimed;
1264 _at_relocate_end.used = used;
1265 _at_relocate_end.used_high = used_high;
1266 _at_relocate_end.used_low = used_low;
1267 _at_relocate_end.free = free(used);
1268 _at_relocate_end.free_high = free(used_low);
1269 _at_relocate_end.free_low = free(used_high);
1270 }
1271
1272 size_t ZStatHeap::max_capacity() {
1273 return _at_initialize.max_capacity;
1274 }
1275
1276 size_t ZStatHeap::used_at_mark_start() {
1277 return _at_mark_start.used;
1278 }
1279
1280 size_t ZStatHeap::used_at_relocate_end() {
1281 return _at_relocate_end.used;
1282 }
1283
1284 void ZStatHeap::print() {
1285 ZStatTablePrinter table(10, 18);
1286 log_info(gc, heap)("%s", table()
1287 .fill()
1288 .center("Mark Start")
1289 .center("Mark End")
1290 .center("Relocate Start")
1291 .center("Relocate End")
1292 .center("High")
1293 .center("Low")
1294 .end());
1295 log_info(gc, heap)("%s", table()
1296 .right("Capacity:")
1297 .left(ZSIZE_ARGS(_at_mark_start.capacity))
1298 .left(ZSIZE_ARGS(_at_mark_end.capacity))
1299 .left(ZSIZE_ARGS(_at_relocate_start.capacity))
1300 .left(ZSIZE_ARGS(_at_relocate_end.capacity))
1301 .left(ZSIZE_ARGS(_at_relocate_end.capacity_high))
1302 .left(ZSIZE_ARGS(_at_relocate_end.capacity_low))
1303 .end());
1304 log_info(gc, heap)("%s", table()
1305 .right("Reserve:")
1306 .left(ZSIZE_ARGS(_at_mark_start.reserve))
1307 .left(ZSIZE_ARGS(_at_mark_end.reserve))
1308 .left(ZSIZE_ARGS(_at_relocate_start.reserve))
1309 .left(ZSIZE_ARGS(_at_relocate_end.reserve))
1310 .left(ZSIZE_ARGS(_at_relocate_end.reserve_high))
1311 .left(ZSIZE_ARGS(_at_relocate_end.reserve_low))
1312 .end());
1313 log_info(gc, heap)("%s", table()
1314 .right("Free:")
1315 .left(ZSIZE_ARGS(_at_mark_start.free))
1316 .left(ZSIZE_ARGS(_at_mark_end.free))
1317 .left(ZSIZE_ARGS(_at_relocate_start.free))
1318 .left(ZSIZE_ARGS(_at_relocate_end.free))
1319 .left(ZSIZE_ARGS(_at_relocate_end.free_high))
1320 .left(ZSIZE_ARGS(_at_relocate_end.free_low))
1321 .end());
1322 log_info(gc, heap)("%s", table()
1323 .right("Used:")
1324 .left(ZSIZE_ARGS(_at_mark_start.used))
1325 .left(ZSIZE_ARGS(_at_mark_end.used))
1326 .left(ZSIZE_ARGS(_at_relocate_start.used))
1327 .left(ZSIZE_ARGS(_at_relocate_end.used))
1328 .left(ZSIZE_ARGS(_at_relocate_end.used_high))
1329 .left(ZSIZE_ARGS(_at_relocate_end.used_low))
1330 .end());
1331 log_info(gc, heap)("%s", table()
1332 .right("Live:")
1333 .left(ZSIZE_NA)
1334 .left(ZSIZE_ARGS(_at_mark_end.live))
1335 .left(ZSIZE_ARGS(_at_mark_end.live /* Same as at mark end */))
1336 .left(ZSIZE_ARGS(_at_mark_end.live /* Same as at mark end */))
1337 .left(ZSIZE_NA)
1338 .left(ZSIZE_NA)
1339 .end());
1340 log_info(gc, heap)("%s", table()
1341 .right("Allocated:")
1342 .left(ZSIZE_NA)
1343 .left(ZSIZE_ARGS(_at_mark_end.allocated))
1344 .left(ZSIZE_ARGS(_at_relocate_start.allocated))
1345 .left(ZSIZE_ARGS(_at_relocate_end.allocated))
1346 .left(ZSIZE_NA)
1347 .left(ZSIZE_NA)
1348 .end());
1349 log_info(gc, heap)("%s", table()
1350 .right("Garbage:")
1351 .left(ZSIZE_NA)
1352 .left(ZSIZE_ARGS(_at_mark_end.garbage))
1353 .left(ZSIZE_ARGS(_at_relocate_start.garbage))
1354 .left(ZSIZE_ARGS(_at_relocate_end.garbage))
1355 .left(ZSIZE_NA)
1356 .left(ZSIZE_NA)
1357 .end());
1358 log_info(gc, heap)("%s", table()
1359 .right("Reclaimed:")
1360 .left(ZSIZE_NA)
1361 .left(ZSIZE_NA)
1362 .left(ZSIZE_ARGS(_at_relocate_start.reclaimed))
1363 .left(ZSIZE_ARGS(_at_relocate_end.reclaimed))
1364 .left(ZSIZE_NA)
1365 .left(ZSIZE_NA)
1366 .end());
1367 }