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