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.inline.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._sum; 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, (uint32_t)ZCacheLineSize); 358 359 // Allocation aligned memory 360 const size_t size = _cpu_offset * ZCPU::count(); 361 _base = ZUtils::alloc_aligned(ZCacheLineSize, size); 362 } 363 364 const char* ZStatValue::group() const { 365 return _group; 366 } 367 368 const char* ZStatValue::name() const { 369 return _name; 370 } 371 372 uint32_t ZStatValue::id() const { 373 return _id; 374 } 375 376 // 377 // Stat iterable value 378 // 379 template <typename T> uint32_t ZStatIterableValue<T>::_count = 0; 380 template <typename T> T* ZStatIterableValue<T>::_first = NULL; 381 382 template <typename T> 383 ZStatIterableValue<T>::ZStatIterableValue(const char* group, 384 const char* name, 385 uint32_t size) : 386 ZStatValue(group, name, _count++, size), 387 _next(insert()) {} 388 389 template <typename T> 390 T* ZStatIterableValue<T>::insert() const { 391 T** current = &_first; 392 393 while (*current != NULL) { 394 // First sort by group, then by name 395 const int group_cmp = strcmp((*current)->group(), group()); 396 const int name_cmp = strcmp((*current)->name(), name()); 397 if ((group_cmp > 0) || (group_cmp == 0 && name_cmp > 0)) { 398 break; 399 } 400 401 current = &(*current)->_next; 402 } 403 404 T* const next = *current; 405 *current = (T*)this; 406 return next; 407 } 408 409 // 410 // Stat sampler 411 // 412 ZStatSampler::ZStatSampler(const char* group, const char* name, ZStatUnitPrinter printer) : 413 ZStatIterableValue<ZStatSampler>(group, name, sizeof(ZStatSamplerData)), 414 _printer(printer) {} 415 416 ZStatSamplerData* ZStatSampler::get() const { 417 return get_cpu_local<ZStatSamplerData>(ZCPU::id()); 418 } 419 420 ZStatSamplerData ZStatSampler::collect_and_reset() const { 421 ZStatSamplerData all; 422 423 const uint32_t ncpus = ZCPU::count(); 424 for (uint32_t i = 0; i < ncpus; i++) { 425 ZStatSamplerData* const cpu_data = get_cpu_local<ZStatSamplerData>(i); 426 if (cpu_data->_nsamples > 0) { 427 const uint64_t nsamples = Atomic::xchg(&cpu_data->_nsamples, (uint64_t)0); 428 const uint64_t sum = Atomic::xchg(&cpu_data->_sum, (uint64_t)0); 429 const uint64_t max = Atomic::xchg(&cpu_data->_max, (uint64_t)0); 430 all._nsamples += nsamples; 431 all._sum += sum; 432 if (all._max < max) { 433 all._max = max; 434 } 435 } 436 } 437 438 return all; 439 } 440 441 ZStatUnitPrinter ZStatSampler::printer() const { 442 return _printer; 443 } 444 445 // 446 // Stat counter 447 // 448 ZStatCounter::ZStatCounter(const char* group, const char* name, ZStatUnitPrinter printer) : 449 ZStatIterableValue<ZStatCounter>(group, name, sizeof(ZStatCounterData)), 450 _sampler(group, name, printer) {} 451 452 ZStatCounterData* ZStatCounter::get() const { 453 return get_cpu_local<ZStatCounterData>(ZCPU::id()); 454 } 455 456 void ZStatCounter::sample_and_reset() const { 457 uint64_t counter = 0; 458 459 const uint32_t ncpus = ZCPU::count(); 460 for (uint32_t i = 0; i < ncpus; i++) { 461 ZStatCounterData* const cpu_data = get_cpu_local<ZStatCounterData>(i); 462 counter += Atomic::xchg(&cpu_data->_counter, (uint64_t)0); 463 } 464 465 ZStatSample(_sampler, counter); 466 } 467 468 // 469 // Stat unsampled counter 470 // 471 ZStatUnsampledCounter::ZStatUnsampledCounter(const char* name) : 472 ZStatIterableValue<ZStatUnsampledCounter>("Unsampled", name, sizeof(ZStatCounterData)) {} 473 474 ZStatCounterData* ZStatUnsampledCounter::get() const { 475 return get_cpu_local<ZStatCounterData>(ZCPU::id()); 476 } 477 478 ZStatCounterData ZStatUnsampledCounter::collect_and_reset() const { 479 ZStatCounterData all; 480 481 const uint32_t ncpus = ZCPU::count(); 482 for (uint32_t i = 0; i < ncpus; i++) { 483 ZStatCounterData* const cpu_data = get_cpu_local<ZStatCounterData>(i); 484 all._counter += Atomic::xchg(&cpu_data->_counter, (uint64_t)0); 485 } 486 487 return all; 488 } 489 490 // 491 // Stat MMU (Minimum Mutator Utilization) 492 // 493 ZStatMMUPause::ZStatMMUPause() : 494 _start(0.0), 495 _end(0.0) {} 496 497 ZStatMMUPause::ZStatMMUPause(const Ticks& start, const Ticks& end) : 498 _start(TimeHelper::counter_to_millis(start.value())), 499 _end(TimeHelper::counter_to_millis(end.value())) {} 500 501 double ZStatMMUPause::end() const { 502 return _end; 503 } 504 505 double ZStatMMUPause::overlap(double start, double end) const { 506 const double start_max = MAX2(start, _start); 507 const double end_min = MIN2(end, _end); 508 509 if (end_min > start_max) { 510 // Overlap found 511 return end_min - start_max; 512 } 513 514 // No overlap 515 return 0.0; 516 } 517 518 size_t ZStatMMU::_next = 0; 519 size_t ZStatMMU::_npauses = 0; 520 ZStatMMUPause ZStatMMU::_pauses[200]; 521 double ZStatMMU::_mmu_2ms = 100.0; 522 double ZStatMMU::_mmu_5ms = 100.0; 523 double ZStatMMU::_mmu_10ms = 100.0; 524 double ZStatMMU::_mmu_20ms = 100.0; 525 double ZStatMMU::_mmu_50ms = 100.0; 526 double ZStatMMU::_mmu_100ms = 100.0; 527 528 const ZStatMMUPause& ZStatMMU::pause(size_t index) { 529 return _pauses[(_next - index - 1) % ARRAY_SIZE(_pauses)]; 530 } 531 532 double ZStatMMU::calculate_mmu(double time_slice) { 533 const double end = pause(0).end(); 534 const double start = end - time_slice; 535 double time_paused = 0.0; 536 537 // Find all overlapping pauses 538 for (size_t i = 0; i < _npauses; i++) { 539 const double overlap = pause(i).overlap(start, end); 540 if (overlap == 0.0) { 541 // No overlap 542 break; 543 } 544 545 time_paused += overlap; 546 } 547 548 // Calculate MMU 549 const double time_mutator = time_slice - time_paused; 550 return percent_of(time_mutator, time_slice); 551 } 552 553 void ZStatMMU::register_pause(const Ticks& start, const Ticks& end) { 554 // Add pause 555 const size_t index = _next++ % ARRAY_SIZE(_pauses); 556 _pauses[index] = ZStatMMUPause(start, end); 557 _npauses = MIN2(_npauses + 1, ARRAY_SIZE(_pauses)); 558 559 // Recalculate MMUs 560 _mmu_2ms = MIN2(_mmu_2ms, calculate_mmu(2)); 561 _mmu_5ms = MIN2(_mmu_5ms, calculate_mmu(5)); 562 _mmu_10ms = MIN2(_mmu_10ms, calculate_mmu(10)); 563 _mmu_20ms = MIN2(_mmu_20ms, calculate_mmu(20)); 564 _mmu_50ms = MIN2(_mmu_50ms, calculate_mmu(50)); 565 _mmu_100ms = MIN2(_mmu_100ms, calculate_mmu(100)); 566 } 567 568 void ZStatMMU::print() { 569 log_info(gc, mmu)("MMU: 2ms/%.1f%%, 5ms/%.1f%%, 10ms/%.1f%%, 20ms/%.1f%%, 50ms/%.1f%%, 100ms/%.1f%%", 570 _mmu_2ms, _mmu_5ms, _mmu_10ms, _mmu_20ms, _mmu_50ms, _mmu_100ms); 571 } 572 573 // 574 // Stat phases 575 // 576 ConcurrentGCTimer ZStatPhase::_timer; 577 578 ZStatPhase::ZStatPhase(const char* group, const char* name) : 579 _sampler(group, name, ZStatUnitTime) {} 580 581 void ZStatPhase::log_start(LogTargetHandle log, bool thread) const { 582 if (!log.is_enabled()) { 583 return; 584 } 585 586 if (thread) { 587 ResourceMark rm; 588 log.print("%s (%s)", name(), Thread::current()->name()); 589 } else { 590 log.print("%s", name()); 591 } 592 } 593 594 void ZStatPhase::log_end(LogTargetHandle log, const Tickspan& duration, bool thread) const { 595 if (!log.is_enabled()) { 596 return; 597 } 598 599 if (thread) { 600 ResourceMark rm; 601 log.print("%s (%s) %.3fms", name(), Thread::current()->name(), TimeHelper::counter_to_millis(duration.value())); 602 } else { 603 log.print("%s %.3fms", name(), TimeHelper::counter_to_millis(duration.value())); 604 } 605 } 606 607 ConcurrentGCTimer* ZStatPhase::timer() { 608 return &_timer; 609 } 610 611 const char* ZStatPhase::name() const { 612 return _sampler.name(); 613 } 614 615 ZStatPhaseCycle::ZStatPhaseCycle(const char* name) : 616 ZStatPhase("Collector", name) {} 617 618 void ZStatPhaseCycle::register_start(const Ticks& start) const { 619 timer()->register_gc_start(start); 620 621 ZTracer::tracer()->report_gc_start(ZCollectedHeap::heap()->gc_cause(), start); 622 623 ZCollectedHeap::heap()->print_heap_before_gc(); 624 ZCollectedHeap::heap()->trace_heap_before_gc(ZTracer::tracer()); 625 626 log_info(gc, start)("Garbage Collection (%s)", 627 GCCause::to_string(ZCollectedHeap::heap()->gc_cause())); 628 } 629 630 void ZStatPhaseCycle::register_end(const Ticks& start, const Ticks& end) const { 631 timer()->register_gc_end(end); 632 633 ZCollectedHeap::heap()->print_heap_after_gc(); 634 ZCollectedHeap::heap()->trace_heap_after_gc(ZTracer::tracer()); 635 636 ZTracer::tracer()->report_gc_end(end, timer()->time_partitions()); 637 638 const Tickspan duration = end - start; 639 ZStatSample(_sampler, duration.value()); 640 641 ZStatLoad::print(); 642 ZStatMMU::print(); 643 ZStatMark::print(); 644 ZStatRelocation::print(); 645 ZStatNMethods::print(); 646 ZStatMetaspace::print(); 647 ZStatReferences::print(); 648 ZStatHeap::print(); 649 650 log_info(gc)("Garbage Collection (%s) " ZSIZE_FMT "->" ZSIZE_FMT, 651 GCCause::to_string(ZCollectedHeap::heap()->gc_cause()), 652 ZSIZE_ARGS(ZStatHeap::used_at_mark_start()), 653 ZSIZE_ARGS(ZStatHeap::used_at_relocate_end())); 654 } 655 656 Tickspan ZStatPhasePause::_max; 657 658 ZStatPhasePause::ZStatPhasePause(const char* name) : 659 ZStatPhase("Phase", name) {} 660 661 const Tickspan& ZStatPhasePause::max() { 662 return _max; 663 } 664 665 void ZStatPhasePause::register_start(const Ticks& start) const { 666 timer()->register_gc_pause_start(name(), start); 667 668 LogTarget(Debug, gc, phases, start) log; 669 log_start(log); 670 } 671 672 void ZStatPhasePause::register_end(const Ticks& start, const Ticks& end) const { 673 timer()->register_gc_pause_end(end); 674 675 const Tickspan duration = end - start; 676 ZStatSample(_sampler, duration.value()); 677 678 // Track max pause time 679 if (_max < duration) { 680 _max = duration; 681 } 682 683 // Track minimum mutator utilization 684 ZStatMMU::register_pause(start, end); 685 686 LogTarget(Info, gc, phases) log; 687 log_end(log, duration); 688 } 689 690 ZStatPhaseConcurrent::ZStatPhaseConcurrent(const char* name) : 691 ZStatPhase("Phase", name) {} 692 693 void ZStatPhaseConcurrent::register_start(const Ticks& start) const { 694 timer()->register_gc_concurrent_start(name(), start); 695 696 LogTarget(Debug, gc, phases, start) log; 697 log_start(log); 698 } 699 700 void ZStatPhaseConcurrent::register_end(const Ticks& start, const Ticks& end) const { 701 timer()->register_gc_concurrent_end(end); 702 703 const Tickspan duration = end - start; 704 ZStatSample(_sampler, duration.value()); 705 706 LogTarget(Info, gc, phases) log; 707 log_end(log, duration); 708 } 709 710 ZStatSubPhase::ZStatSubPhase(const char* name) : 711 ZStatPhase("Subphase", name) {} 712 713 void ZStatSubPhase::register_start(const Ticks& start) const { 714 LogTarget(Debug, gc, phases, start) log; 715 log_start(log, true /* thread */); 716 } 717 718 void ZStatSubPhase::register_end(const Ticks& start, const Ticks& end) const { 719 ZTracer::tracer()->report_thread_phase(name(), start, end); 720 721 const Tickspan duration = end - start; 722 ZStatSample(_sampler, duration.value()); 723 724 LogTarget(Debug, gc, phases) log; 725 log_end(log, duration, true /* thread */); 726 } 727 728 ZStatCriticalPhase::ZStatCriticalPhase(const char* name, bool verbose) : 729 ZStatPhase("Critical", name), 730 _counter("Critical", name, ZStatUnitOpsPerSecond), 731 _verbose(verbose) {} 732 733 void ZStatCriticalPhase::register_start(const Ticks& start) const { 734 LogTarget(Debug, gc, start) log; 735 log_start(log, true /* thread */); 736 } 737 738 void ZStatCriticalPhase::register_end(const Ticks& start, const Ticks& end) const { 739 ZTracer::tracer()->report_thread_phase(name(), start, end); 740 741 const Tickspan duration = end - start; 742 ZStatSample(_sampler, duration.value()); 743 ZStatInc(_counter); 744 745 if (_verbose) { 746 LogTarget(Info, gc) log; 747 log_end(log, duration, true /* thread */); 748 } else { 749 LogTarget(Debug, gc) log; 750 log_end(log, duration, true /* thread */); 751 } 752 } 753 754 // 755 // Stat timer 756 // 757 THREAD_LOCAL uint32_t ZStatTimerDisable::_active = 0; 758 759 // 760 // Stat sample/inc 761 // 762 void ZStatSample(const ZStatSampler& sampler, uint64_t value) { 763 ZStatSamplerData* const cpu_data = sampler.get(); 764 Atomic::add(&cpu_data->_nsamples, 1u); 765 Atomic::add(&cpu_data->_sum, value); 766 767 uint64_t max = cpu_data->_max; 768 for (;;) { 769 if (max >= value) { 770 // Not max 771 break; 772 } 773 774 const uint64_t new_max = value; 775 const uint64_t prev_max = Atomic::cmpxchg(&cpu_data->_max, max, new_max); 776 if (prev_max == max) { 777 // Success 778 break; 779 } 780 781 // Retry 782 max = prev_max; 783 } 784 785 ZTracer::tracer()->report_stat_sampler(sampler, value); 786 } 787 788 void ZStatInc(const ZStatCounter& counter, uint64_t increment) { 789 ZStatCounterData* const cpu_data = counter.get(); 790 const uint64_t value = Atomic::add(&cpu_data->_counter, increment); 791 792 ZTracer::tracer()->report_stat_counter(counter, increment, value); 793 } 794 795 void ZStatInc(const ZStatUnsampledCounter& counter, uint64_t increment) { 796 ZStatCounterData* const cpu_data = counter.get(); 797 Atomic::add(&cpu_data->_counter, increment); 798 } 799 800 // 801 // Stat allocation rate 802 // 803 const ZStatUnsampledCounter ZStatAllocRate::_counter("Allocation Rate"); 804 TruncatedSeq ZStatAllocRate::_rate(ZStatAllocRate::sample_window_sec * ZStatAllocRate::sample_hz); 805 TruncatedSeq ZStatAllocRate::_rate_avg(ZStatAllocRate::sample_window_sec * ZStatAllocRate::sample_hz); 806 807 const ZStatUnsampledCounter& ZStatAllocRate::counter() { 808 return _counter; 809 } 810 811 uint64_t ZStatAllocRate::sample_and_reset() { 812 const ZStatCounterData bytes_per_sample = _counter.collect_and_reset(); 813 const uint64_t bytes_per_second = bytes_per_sample._counter * sample_hz; 814 815 _rate.add(bytes_per_second); 816 _rate_avg.add(_rate.avg()); 817 818 return bytes_per_second; 819 } 820 821 double ZStatAllocRate::avg() { 822 return _rate.avg(); 823 } 824 825 double ZStatAllocRate::avg_sd() { 826 return _rate_avg.sd(); 827 } 828 829 // 830 // Stat thread 831 // 832 ZStat::ZStat() : 833 _metronome(sample_hz) { 834 set_name("ZStat"); 835 create_and_start(); 836 } 837 838 void ZStat::sample_and_collect(ZStatSamplerHistory* history) const { 839 // Sample counters 840 for (const ZStatCounter* counter = ZStatCounter::first(); counter != NULL; counter = counter->next()) { 841 counter->sample_and_reset(); 842 } 843 844 // Collect samples 845 for (const ZStatSampler* sampler = ZStatSampler::first(); sampler != NULL; sampler = sampler->next()) { 846 ZStatSamplerHistory& sampler_history = history[sampler->id()]; 847 sampler_history.add(sampler->collect_and_reset()); 848 } 849 } 850 851 bool ZStat::should_print(LogTargetHandle log) const { 852 static uint64_t print_at = ZStatisticsInterval; 853 const uint64_t now = os::elapsedTime(); 854 855 if (now < print_at) { 856 return false; 857 } 858 859 print_at = ((now / ZStatisticsInterval) * ZStatisticsInterval) + ZStatisticsInterval; 860 861 return log.is_enabled(); 862 } 863 864 void ZStat::print(LogTargetHandle log, const ZStatSamplerHistory* history) const { 865 // Print 866 log.print("=== Garbage Collection Statistics ======================================================================================================================="); 867 log.print(" Last 10s Last 10m Last 10h Total"); 868 log.print(" Avg / Max Avg / Max Avg / Max Avg / Max"); 869 870 for (const ZStatSampler* sampler = ZStatSampler::first(); sampler != NULL; sampler = sampler->next()) { 871 const ZStatSamplerHistory& sampler_history = history[sampler->id()]; 872 const ZStatUnitPrinter printer = sampler->printer(); 873 printer(log, *sampler, sampler_history); 874 } 875 876 log.print("========================================================================================================================================================="); 877 } 878 879 void ZStat::run_service() { 880 ZStatSamplerHistory* const history = new ZStatSamplerHistory[ZStatSampler::count()]; 881 LogTarget(Info, gc, stats) log; 882 883 // Main loop 884 while (_metronome.wait_for_tick()) { 885 sample_and_collect(history); 886 if (should_print(log)) { 887 print(log, history); 888 } 889 } 890 891 delete [] history; 892 } 893 894 void ZStat::stop_service() { 895 _metronome.stop(); 896 } 897 898 // 899 // Stat table 900 // 901 class ZStatTablePrinter { 902 private: 903 static const size_t _buffer_size = 256; 904 905 const size_t _column0_width; 906 const size_t _columnN_width; 907 char _buffer[_buffer_size]; 908 909 public: 910 class ZColumn { 911 private: 912 char* const _buffer; 913 const size_t _position; 914 const size_t _width; 915 const size_t _width_next; 916 917 ZColumn next() const { 918 // Insert space between columns 919 _buffer[_position + _width] = ' '; 920 return ZColumn(_buffer, _position + _width + 1, _width_next, _width_next); 921 } 922 923 size_t print(size_t position, const char* fmt, va_list va) { 924 const int res = jio_vsnprintf(_buffer + position, _buffer_size - position, fmt, va); 925 if (res < 0) { 926 return 0; 927 } 928 929 return (size_t)res; 930 } 931 932 public: 933 ZColumn(char* buffer, size_t position, size_t width, size_t width_next) : 934 _buffer(buffer), 935 _position(position), 936 _width(width), 937 _width_next(width_next) {} 938 939 ZColumn left(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 // Fill empty space 948 memset(_buffer + _position + written, ' ', _width - written); 949 } 950 951 return next(); 952 } 953 954 ZColumn right(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) { 955 va_list va; 956 957 va_start(va, fmt); 958 const size_t written = print(_position, fmt, va); 959 va_end(va); 960 961 if (written > _width) { 962 // Line too long 963 return fill('?'); 964 } 965 966 if (written < _width) { 967 // Short line, move all to right 968 memmove(_buffer + _position + _width - written, _buffer + _position, written); 969 970 // Fill empty space 971 memset(_buffer + _position, ' ', _width - written); 972 } 973 974 return next(); 975 } 976 977 ZColumn center(const char* fmt, ...) ATTRIBUTE_PRINTF(2, 3) { 978 va_list va; 979 980 va_start(va, fmt); 981 const size_t written = print(_position, fmt, va); 982 va_end(va); 983 984 if (written > _width) { 985 // Line too long 986 return fill('?'); 987 } 988 989 if (written < _width) { 990 // Short line, move all to center 991 const size_t start_space = (_width - written) / 2; 992 const size_t end_space = _width - written - start_space; 993 memmove(_buffer + _position + start_space, _buffer + _position, written); 994 995 // Fill empty spaces 996 memset(_buffer + _position, ' ', start_space); 997 memset(_buffer + _position + start_space + written, ' ', end_space); 998 } 999 1000 return next(); 1001 } 1002 1003 ZColumn fill(char filler = ' ') { 1004 memset(_buffer + _position, filler, _width); 1005 return next(); 1006 } 1007 1008 const char* end() { 1009 _buffer[_position] = '\0'; 1010 return _buffer; 1011 } 1012 }; 1013 1014 public: 1015 ZStatTablePrinter(size_t column0_width, size_t columnN_width) : 1016 _column0_width(column0_width), 1017 _columnN_width(columnN_width) {} 1018 1019 ZColumn operator()() { 1020 return ZColumn(_buffer, 0, _column0_width, _columnN_width); 1021 } 1022 }; 1023 1024 // 1025 // Stat cycle 1026 // 1027 uint64_t ZStatCycle::_nwarmup_cycles = 0; 1028 Ticks ZStatCycle::_start_of_last; 1029 Ticks ZStatCycle::_end_of_last; 1030 NumberSeq ZStatCycle::_normalized_duration(0.3 /* alpha */); 1031 1032 void ZStatCycle::at_start() { 1033 _start_of_last = Ticks::now(); 1034 } 1035 1036 void ZStatCycle::at_end(GCCause::Cause cause, double boost_factor) { 1037 _end_of_last = Ticks::now(); 1038 1039 if (cause == GCCause::_z_warmup) { 1040 _nwarmup_cycles++; 1041 } 1042 1043 // Calculate normalized cycle duration. The measured duration is 1044 // normalized using the boost factor to avoid artificial deflation 1045 // of the duration when boost mode is enabled. 1046 const double duration = (_end_of_last - _start_of_last).seconds(); 1047 const double normalized_duration = duration * boost_factor; 1048 _normalized_duration.add(normalized_duration); 1049 } 1050 1051 bool ZStatCycle::is_warm() { 1052 return _nwarmup_cycles >= 3; 1053 } 1054 1055 uint64_t ZStatCycle::nwarmup_cycles() { 1056 return _nwarmup_cycles; 1057 } 1058 1059 bool ZStatCycle::is_normalized_duration_trustable() { 1060 // The normalized duration is considered trustable if we have 1061 // completed at least one warmup cycle 1062 return _nwarmup_cycles > 0; 1063 } 1064 1065 const AbsSeq& ZStatCycle::normalized_duration() { 1066 return _normalized_duration; 1067 } 1068 1069 double ZStatCycle::time_since_last() { 1070 if (_end_of_last.value() == 0) { 1071 // No end recorded yet, return time since VM start 1072 return os::elapsedTime(); 1073 } 1074 1075 const Ticks now = Ticks::now(); 1076 const Tickspan time_since_last = now - _end_of_last; 1077 return time_since_last.seconds(); 1078 } 1079 1080 // 1081 // Stat load 1082 // 1083 void ZStatLoad::print() { 1084 double loadavg[3] = {}; 1085 os::loadavg(loadavg, ARRAY_SIZE(loadavg)); 1086 log_info(gc, load)("Load: %.2f/%.2f/%.2f", loadavg[0], loadavg[1], loadavg[2]); 1087 } 1088 1089 // 1090 // Stat mark 1091 // 1092 size_t ZStatMark::_nstripes; 1093 size_t ZStatMark::_nproactiveflush; 1094 size_t ZStatMark::_nterminateflush; 1095 size_t ZStatMark::_ntrycomplete; 1096 size_t ZStatMark::_ncontinue; 1097 1098 void ZStatMark::set_at_mark_start(size_t nstripes) { 1099 _nstripes = nstripes; 1100 } 1101 1102 void ZStatMark::set_at_mark_end(size_t nproactiveflush, 1103 size_t nterminateflush, 1104 size_t ntrycomplete, 1105 size_t ncontinue) { 1106 _nproactiveflush = nproactiveflush; 1107 _nterminateflush = nterminateflush; 1108 _ntrycomplete = ntrycomplete; 1109 _ncontinue = ncontinue; 1110 } 1111 1112 void ZStatMark::print() { 1113 log_info(gc, marking)("Mark: " 1114 SIZE_FORMAT " stripe(s), " 1115 SIZE_FORMAT " proactive flush(es), " 1116 SIZE_FORMAT " terminate flush(es), " 1117 SIZE_FORMAT " completion(s), " 1118 SIZE_FORMAT " continuation(s) ", 1119 _nstripes, 1120 _nproactiveflush, 1121 _nterminateflush, 1122 _ntrycomplete, 1123 _ncontinue); 1124 } 1125 1126 // 1127 // Stat relocation 1128 // 1129 size_t ZStatRelocation::_relocating; 1130 bool ZStatRelocation::_success; 1131 1132 void ZStatRelocation::set_at_select_relocation_set(size_t relocating) { 1133 _relocating = relocating; 1134 } 1135 1136 void ZStatRelocation::set_at_relocate_end(bool success) { 1137 _success = success; 1138 } 1139 1140 void ZStatRelocation::print() { 1141 if (_success) { 1142 log_info(gc, reloc)("Relocation: Successful, " SIZE_FORMAT "M relocated", _relocating / M); 1143 } else { 1144 log_info(gc, reloc)("Relocation: Incomplete"); 1145 } 1146 } 1147 1148 // 1149 // Stat nmethods 1150 // 1151 void ZStatNMethods::print() { 1152 log_info(gc, nmethod)("NMethods: " SIZE_FORMAT " registered, " SIZE_FORMAT " unregistered", 1153 ZNMethodTable::registered_nmethods(), 1154 ZNMethodTable::unregistered_nmethods()); 1155 } 1156 1157 // 1158 // Stat metaspace 1159 // 1160 void ZStatMetaspace::print() { 1161 log_info(gc, metaspace)("Metaspace: " 1162 SIZE_FORMAT "M used, " SIZE_FORMAT "M capacity, " 1163 SIZE_FORMAT "M committed, " SIZE_FORMAT "M reserved", 1164 MetaspaceUtils::used_bytes() / M, 1165 MetaspaceUtils::capacity_bytes() / M, 1166 MetaspaceUtils::committed_bytes() / M, 1167 MetaspaceUtils::reserved_bytes() / M); 1168 } 1169 1170 // 1171 // Stat references 1172 // 1173 ZStatReferences::ZCount ZStatReferences::_soft; 1174 ZStatReferences::ZCount ZStatReferences::_weak; 1175 ZStatReferences::ZCount ZStatReferences::_final; 1176 ZStatReferences::ZCount ZStatReferences::_phantom; 1177 1178 void ZStatReferences::set(ZCount* count, size_t encountered, size_t discovered, size_t enqueued) { 1179 count->encountered = encountered; 1180 count->discovered = discovered; 1181 count->enqueued = enqueued; 1182 } 1183 1184 void ZStatReferences::set_soft(size_t encountered, size_t discovered, size_t enqueued) { 1185 set(&_soft, encountered, discovered, enqueued); 1186 } 1187 1188 void ZStatReferences::set_weak(size_t encountered, size_t discovered, size_t enqueued) { 1189 set(&_weak, encountered, discovered, enqueued); 1190 } 1191 1192 void ZStatReferences::set_final(size_t encountered, size_t discovered, size_t enqueued) { 1193 set(&_final, encountered, discovered, enqueued); 1194 } 1195 1196 void ZStatReferences::set_phantom(size_t encountered, size_t discovered, size_t enqueued) { 1197 set(&_phantom, encountered, discovered, enqueued); 1198 } 1199 1200 void ZStatReferences::print(const char* name, const ZStatReferences::ZCount& ref) { 1201 log_info(gc, ref)("%s: " 1202 SIZE_FORMAT " encountered, " 1203 SIZE_FORMAT " discovered, " 1204 SIZE_FORMAT " enqueued", 1205 name, 1206 ref.encountered, 1207 ref.discovered, 1208 ref.enqueued); 1209 } 1210 1211 void ZStatReferences::print() { 1212 print("Soft", _soft); 1213 print("Weak", _weak); 1214 print("Final", _final); 1215 print("Phantom", _phantom); 1216 } 1217 1218 // 1219 // Stat heap 1220 // 1221 ZStatHeap::ZAtInitialize ZStatHeap::_at_initialize; 1222 ZStatHeap::ZAtMarkStart ZStatHeap::_at_mark_start; 1223 ZStatHeap::ZAtMarkEnd ZStatHeap::_at_mark_end; 1224 ZStatHeap::ZAtRelocateStart ZStatHeap::_at_relocate_start; 1225 ZStatHeap::ZAtRelocateEnd ZStatHeap::_at_relocate_end; 1226 1227 size_t ZStatHeap::capacity_high() { 1228 return MAX4(_at_mark_start.capacity, 1229 _at_mark_end.capacity, 1230 _at_relocate_start.capacity, 1231 _at_relocate_end.capacity); 1232 } 1233 1234 size_t ZStatHeap::capacity_low() { 1235 return MIN4(_at_mark_start.capacity, 1236 _at_mark_end.capacity, 1237 _at_relocate_start.capacity, 1238 _at_relocate_end.capacity); 1239 } 1240 1241 size_t ZStatHeap::available(size_t used) { 1242 return _at_initialize.max_capacity - used; 1243 } 1244 1245 size_t ZStatHeap::reserve(size_t used) { 1246 return MIN2(_at_initialize.max_reserve, available(used)); 1247 } 1248 1249 size_t ZStatHeap::free(size_t used) { 1250 return available(used) - reserve(used); 1251 } 1252 1253 void ZStatHeap::set_at_initialize(size_t min_capacity, 1254 size_t max_capacity, 1255 size_t max_reserve) { 1256 _at_initialize.min_capacity = min_capacity; 1257 _at_initialize.max_capacity = max_capacity; 1258 _at_initialize.max_reserve = max_reserve; 1259 } 1260 1261 void ZStatHeap::set_at_mark_start(size_t soft_max_capacity, 1262 size_t capacity, 1263 size_t used) { 1264 _at_mark_start.soft_max_capacity = soft_max_capacity; 1265 _at_mark_start.capacity = capacity; 1266 _at_mark_start.reserve = reserve(used); 1267 _at_mark_start.used = used; 1268 _at_mark_start.free = free(used); 1269 } 1270 1271 void ZStatHeap::set_at_mark_end(size_t capacity, 1272 size_t allocated, 1273 size_t used) { 1274 _at_mark_end.capacity = capacity; 1275 _at_mark_end.reserve = reserve(used); 1276 _at_mark_end.allocated = allocated; 1277 _at_mark_end.used = used; 1278 _at_mark_end.free = free(used); 1279 } 1280 1281 void ZStatHeap::set_at_select_relocation_set(size_t live, 1282 size_t garbage, 1283 size_t reclaimed) { 1284 _at_mark_end.live = live; 1285 _at_mark_end.garbage = garbage; 1286 1287 _at_relocate_start.garbage = garbage - reclaimed; 1288 _at_relocate_start.reclaimed = reclaimed; 1289 } 1290 1291 void ZStatHeap::set_at_relocate_start(size_t capacity, 1292 size_t allocated, 1293 size_t used) { 1294 _at_relocate_start.capacity = capacity; 1295 _at_relocate_start.reserve = reserve(used); 1296 _at_relocate_start.allocated = allocated; 1297 _at_relocate_start.used = used; 1298 _at_relocate_start.free = free(used); 1299 } 1300 1301 void ZStatHeap::set_at_relocate_end(size_t capacity, 1302 size_t allocated, 1303 size_t reclaimed, 1304 size_t used, 1305 size_t used_high, 1306 size_t used_low) { 1307 _at_relocate_end.capacity = capacity; 1308 _at_relocate_end.capacity_high = capacity_high(); 1309 _at_relocate_end.capacity_low = capacity_low(); 1310 _at_relocate_end.reserve = reserve(used); 1311 _at_relocate_end.reserve_high = reserve(used_low); 1312 _at_relocate_end.reserve_low = reserve(used_high); 1313 _at_relocate_end.garbage = _at_mark_end.garbage - reclaimed; 1314 _at_relocate_end.allocated = allocated; 1315 _at_relocate_end.reclaimed = reclaimed; 1316 _at_relocate_end.used = used; 1317 _at_relocate_end.used_high = used_high; 1318 _at_relocate_end.used_low = used_low; 1319 _at_relocate_end.free = free(used); 1320 _at_relocate_end.free_high = free(used_low); 1321 _at_relocate_end.free_low = free(used_high); 1322 } 1323 1324 size_t ZStatHeap::max_capacity() { 1325 return _at_initialize.max_capacity; 1326 } 1327 1328 size_t ZStatHeap::used_at_mark_start() { 1329 return _at_mark_start.used; 1330 } 1331 1332 size_t ZStatHeap::used_at_relocate_end() { 1333 return _at_relocate_end.used; 1334 } 1335 1336 void ZStatHeap::print() { 1337 log_info(gc, heap)("Min Capacity: " 1338 ZSIZE_FMT, ZSIZE_ARGS(_at_initialize.min_capacity)); 1339 log_info(gc, heap)("Max Capacity: " 1340 ZSIZE_FMT, ZSIZE_ARGS(_at_initialize.max_capacity)); 1341 log_info(gc, heap)("Soft Max Capacity: " 1342 ZSIZE_FMT, ZSIZE_ARGS(_at_mark_start.soft_max_capacity)); 1343 1344 ZStatTablePrinter table(10, 18); 1345 log_info(gc, heap)("%s", table() 1346 .fill() 1347 .center("Mark Start") 1348 .center("Mark End") 1349 .center("Relocate Start") 1350 .center("Relocate End") 1351 .center("High") 1352 .center("Low") 1353 .end()); 1354 log_info(gc, heap)("%s", table() 1355 .right("Capacity:") 1356 .left(ZTABLE_ARGS(_at_mark_start.capacity)) 1357 .left(ZTABLE_ARGS(_at_mark_end.capacity)) 1358 .left(ZTABLE_ARGS(_at_relocate_start.capacity)) 1359 .left(ZTABLE_ARGS(_at_relocate_end.capacity)) 1360 .left(ZTABLE_ARGS(_at_relocate_end.capacity_high)) 1361 .left(ZTABLE_ARGS(_at_relocate_end.capacity_low)) 1362 .end()); 1363 log_info(gc, heap)("%s", table() 1364 .right("Reserve:") 1365 .left(ZTABLE_ARGS(_at_mark_start.reserve)) 1366 .left(ZTABLE_ARGS(_at_mark_end.reserve)) 1367 .left(ZTABLE_ARGS(_at_relocate_start.reserve)) 1368 .left(ZTABLE_ARGS(_at_relocate_end.reserve)) 1369 .left(ZTABLE_ARGS(_at_relocate_end.reserve_high)) 1370 .left(ZTABLE_ARGS(_at_relocate_end.reserve_low)) 1371 .end()); 1372 log_info(gc, heap)("%s", table() 1373 .right("Free:") 1374 .left(ZTABLE_ARGS(_at_mark_start.free)) 1375 .left(ZTABLE_ARGS(_at_mark_end.free)) 1376 .left(ZTABLE_ARGS(_at_relocate_start.free)) 1377 .left(ZTABLE_ARGS(_at_relocate_end.free)) 1378 .left(ZTABLE_ARGS(_at_relocate_end.free_high)) 1379 .left(ZTABLE_ARGS(_at_relocate_end.free_low)) 1380 .end()); 1381 log_info(gc, heap)("%s", table() 1382 .right("Used:") 1383 .left(ZTABLE_ARGS(_at_mark_start.used)) 1384 .left(ZTABLE_ARGS(_at_mark_end.used)) 1385 .left(ZTABLE_ARGS(_at_relocate_start.used)) 1386 .left(ZTABLE_ARGS(_at_relocate_end.used)) 1387 .left(ZTABLE_ARGS(_at_relocate_end.used_high)) 1388 .left(ZTABLE_ARGS(_at_relocate_end.used_low)) 1389 .end()); 1390 log_info(gc, heap)("%s", table() 1391 .right("Live:") 1392 .left(ZTABLE_ARGS_NA) 1393 .left(ZTABLE_ARGS(_at_mark_end.live)) 1394 .left(ZTABLE_ARGS(_at_mark_end.live /* Same as at mark end */)) 1395 .left(ZTABLE_ARGS(_at_mark_end.live /* Same as at mark end */)) 1396 .left(ZTABLE_ARGS_NA) 1397 .left(ZTABLE_ARGS_NA) 1398 .end()); 1399 log_info(gc, heap)("%s", table() 1400 .right("Allocated:") 1401 .left(ZTABLE_ARGS_NA) 1402 .left(ZTABLE_ARGS(_at_mark_end.allocated)) 1403 .left(ZTABLE_ARGS(_at_relocate_start.allocated)) 1404 .left(ZTABLE_ARGS(_at_relocate_end.allocated)) 1405 .left(ZTABLE_ARGS_NA) 1406 .left(ZTABLE_ARGS_NA) 1407 .end()); 1408 log_info(gc, heap)("%s", table() 1409 .right("Garbage:") 1410 .left(ZTABLE_ARGS_NA) 1411 .left(ZTABLE_ARGS(_at_mark_end.garbage)) 1412 .left(ZTABLE_ARGS(_at_relocate_start.garbage)) 1413 .left(ZTABLE_ARGS(_at_relocate_end.garbage)) 1414 .left(ZTABLE_ARGS_NA) 1415 .left(ZTABLE_ARGS_NA) 1416 .end()); 1417 log_info(gc, heap)("%s", table() 1418 .right("Reclaimed:") 1419 .left(ZTABLE_ARGS_NA) 1420 .left(ZTABLE_ARGS_NA) 1421 .left(ZTABLE_ARGS(_at_relocate_start.reclaimed)) 1422 .left(ZTABLE_ARGS(_at_relocate_end.reclaimed)) 1423 .left(ZTABLE_ARGS_NA) 1424 .left(ZTABLE_ARGS_NA) 1425 .end()); 1426 }