On Thu, 24 Sep 2026 18:11:09 GMT, Andrew Haley <[email protected]> wrote:
>> Please use [this >> link](https://github.com/openjdk/jdk/pull/28541/changes?w=1) to view the >> files changed. >> >> Profile counters scale very badly. >> >> The overhead for profiled code isn't too bad with one thread, but as the >> thread count increases, things go wrong very quickly. >> >> For example, here's a benchmark from the OpenJDK test suite, run at >> TieredLevel 3 with one thread, then three threads: >> >> >> Benchmark (randomized) Mode Cnt Score Error Units >> InterfaceCalls.test2ndInt5Types false avgt 4 27.468 ± 2.631 ns/op >> InterfaceCalls.test2ndInt5Types false avgt 4 240.010 ± 6.329 ns/op >> >> >> This slowdown is caused by high memory contention on the profile counters. >> Not only is this slow, but it can also lose profile counts. >> >> This patch is for C1 only. It'd be easy to randomize C1 counters as well in >> another PR, if anyone thinks it's worth doing. >> >> One other thing to note is that randomized profile counters degrade very >> badly with small decimation ratios. For example, using a ratio of 2 with >> `-XX:ProfileCaptureRatio=2` with a single thread results in >> >> >> Benchmark (randomized) Mode Cnt Score Error >> Units >> InterfaceCalls.test2ndInt5Types false avgt 4 80.147 ± 9.991 >> ns/op >> >> >> The problem is that the branch prediction rate drops away very badly, >> leading to many mispredictions. It only really makes sense to use higher >> decimation ratios, e.g. 64. >> >> --------- >> - [x] I confirm that I make this contribution in accordance with the >> [OpenJDK Interim AI Policy](https://openjdk.org/legal/ai). > > Andrew Haley has updated the pull request with a new target base due to a > merge or a rebase. The pull request now contains 215 commits: > > - Merge from master > - Better > - Crud > - Merge zarquon:/local/theRealAph-jdk into JDK-8134940 > - Cleanup > - Cleanup > - Revert "More" > > This reverts commit 3011e0fa6ef761ed7bb498a314b741b1d2f1bd90. > - Revert "Hacks to estimate profiling overhead." > > This reverts commit 4e2fdc2134a8057ad91e23642f66dc6a5728dce7. > - Hacks to estimate profiling overhead. > - More > - ... and 205 more: https://git.openjdk.org/jdk/compare/4be9a676...19eddaf2 Yes, this definitely looks better. The degradation due to inaccurate profiling at large PCRs makes sense to me. The elevated uncommon trap counts at large PCRs are still concerning, because that might imply we missed some counter update that have otherwise told us some path (branch? type?) is _not_ stone-cold? Sorry, I'll keep worrying about this one. Have you seen the evidence to the contrary in your tests? Is this just the timing-sensitive effect? The degradation on reasonable PCRs still looks like a red flag to me, I think we need to nail that one. FWIW, in my local runs: dotty -r 20 --- Patched, PCR=1 Run 1: 3775 1174 822 650 580 557 529 514 516 569 488 486 439 448 448 429 413 428 413 415 Run 2: 3838 1207 860 681 591 546 522 509 488 485 460 452 453 447 488 537 438 452 410 417 Run 3: 3921 1090 806 622 603 618 545 526 472 469 450 458 439 448 449 424 408 425 403 407 Tier1: 0.068 s, 9629 bytes, 2109 methods; Tier2: 0.014 s, 11461 bytes, 52 methods; Tier3: 4.767 s, 2728789 bytes, 17111 methods; Tier4: 48.444 s, 6539320 bytes, 6910 methods; Uncommon traps hit: 661 --- Patched, PCR=4 Run 1: 5034 1602 975 767 697 658 620 589 554 538 533 518 498 494 484 483 469 473 445 442 Run 2: 4888 1576 1131 867 733 661 605 600 549 540 531 522 512 497 502 471 464 467 440 454 Run 3: 5003 1591 939 761 712 689 630 619 559 559 532 515 505 504 488 464 466 460 440 446 Tier1: 0.061 s, 9616 bytes, 2107 methods; Tier2: 0.006 s, 4202 bytes, 35 methods; Tier3: 4.588 s, 2751919 bytes, 17074 methods; Tier4: 44.807 s, 6440172 bytes, 7025 methods; Uncommon traps hit: 683 So, tier2 method counts are still the same. I would have expected the runs at PCR=1 and PCR=4 to converge to the same steady state performance, but they don't? The initial iterations are far worse as well. And I suspect the loss at both initial and final iterations are the part of the same picture: the warmup is much slower, so cutting off the measurement at 20 iterations cuts out PCR>1 test at worse state. Final iterations more or less converge with `-r 100`: --- Patched, PCR=1 Run 1: 3960 1158 792 632 562 536 511 516 489 469 460 483 445 492 495 450 418 429 405 417 416 406 392 398 387 389 384 374 424 386 364 378 369 384 400 369 381 369 365 361 362 364 364 357 356 358 374 356 351 355 348 361 361 352 345 357 356 357 354 350 346 351 349 339 360 347 339 341 343 344 328 338 333 339 342 339 340 337 338 344 346 352 343 360 343 347 338 337 342 338 336 334 342 342 341 351 338 348 338 341 Run 2: 3958 1178 811 613 575 552 509 498 475 478 449 478 538 471 472 437 424 441 406 410 402 397 391 390 385 385 384 376 413 441 400 391 370 378 393 361 371 363 367 369 373 369 362 363 361 372 355 355 358 360 359 358 363 355 351 363 351 349 350 346 343 352 363 346 356 347 347 343 346 343 344 340 335 339 341 338 336 334 335 336 339 340 367 386 368 376 347 335 340 346 338 337 339 337 347 347 336 345 343 355 Run 3: 3881 1212 839 644 563 554 521 490 480 484 489 523 476 471 444 433 415 438 401 416 417 409 394 395 397 397 379 405 480 419 399 403 365 373 382 367 371 360 357 365 371 365 377 360 377 375 413 441 383 383 346 355 361 347 355 347 344 357 351 354 346 355 360 352 354 353 345 344 348 340 339 344 351 354 346 346 337 336 336 347 342 379 373 380 380 344 346 344 337 335 331 341 337 334 327 335 325 332 339 340 Tier1: 0.077 s, 10348 bytes, 2263 methods; Tier2: 0.013 s, 10808 bytes, 49 methods; Tier3: 5.403 s, 2901635 bytes, 18830 methods; Tier4: 61.879 s, 8703471 bytes, 8627 methods; Uncommon traps hit: 661 --- Patched, PCR=4 Run 1: 4903 1589 969 767 695 653 622 609 599 587 566 520 520 494 497 479 463 471 451 446 442 431 427 431 429 422 418 434 427 417 402 402 395 396 391 401 386 380 375 392 375 379 392 396 372 365 375 374 365 373 375 375 373 368 362 360 365 370 368 369 362 359 372 367 358 363 359 354 370 366 359 355 365 359 353 370 357 352 358 359 352 363 355 354 349 360 352 348 353 351 347 357 350 370 347 350 341 346 351 350 Run 2: 4998 1569 964 779 744 667 604 585 569 563 519 514 515 507 484 480 451 486 454 451 449 437 433 436 416 411 420 411 414 406 401 395 405 413 425 466 412 415 374 376 382 380 395 383 362 366 370 365 364 357 363 357 384 458 379 373 356 354 356 362 371 348 373 367 362 356 353 354 352 348 373 459 367 372 348 352 354 353 346 347 354 363 351 354 346 354 351 344 359 411 371 370 346 342 338 339 350 343 341 338 Run 3: 4993 1668 999 770 701 663 616 589 549 543 530 511 508 514 545 489 464 461 457 446 448 431 431 433 420 418 417 414 414 427 407 398 410 403 417 394 388 380 392 380 388 379 391 379 376 373 367 381 357 363 357 366 360 351 356 357 356 357 361 360 399 361 355 361 361 384 352 353 348 357 346 358 343 353 353 355 346 348 352 351 355 348 348 378 341 352 351 355 350 352 349 347 343 354 353 347 341 346 347 348 Tier1: 0.072 s, 10414 bytes, 2278 methods; Tier2: 0.011 s, 7285 bytes, 49 methods; Tier3: 5.209 s, 2930270 bytes, 18788 methods; Tier4: 57.123 s, 8268513 bytes, 8823 methods; Uncommon traps hit: 667 If these are true PCR costs, it looks almost as if accepting the scalability bottleneck is still more performant than trying to deal with it here. The more fundamental question: is there a workload where the overhead-vs-bottleneck tips in favor of larger PCRs? Something large-ish from Dacapo/Renaissance would be good. Maybe that _also_ means we need to obsess about the PCR>1 overheads more, so that more workloads get on the right side of that balance. Although I do not see clearly how to do it. Let me grasp at few straws here. 1. There is some discrepancy between two shapes in the new code. One (that deals with `0x70(%rdi)`) apparently goes to slow stub for updates, and another (`0xa8(%rdi)`) does inline update. Sounds like the second one is better if we linger in profiling code at lower PCRs for longer. Maybe the jump to the stub _is_ the thing that taints the performance here? 2. This one looks like a zero-check. `or`+`je` are not guaranteed to macro-fuse, IIRC? Any reason we don't do `test`+`je` here? That would macro-fuse for sure. Also probably a bit denser encoding. 0.00% 0x000079c2e040f245: mov 0x70(%rdi),%ebx 1.97% 0x000079c2e040f248: or %rbx,%rbx 0.11% 0x000079c2e040f24b: je 0x000079c2e040f419 3. Oh, I think we can save a branch if we get subtle with dealing with zero. Something like: mov (mdo-slot), %r sub %r, 1 ; set CF if %r is zero sbb %r, %r ; %r = %r - CF; so it sets %r to all 1-s iff CF==1 or %counter, %r ; mix it up: if slot was zero, we will get a counter that would definitely hit the threshold cmp $threshold, %r ; as usual... jae <slow-stub> But that destroys `%r`, so we would need to reload. Which might not be worth it at low PCRs. 4. If PCR-s are always power-of-two, is it worth `test`-ing with (hopefully small) immediate bitmasks, instead of full comparison like this? 0.00% 0x000079c2e040f251: cmp $0x40000000,%r14d 0.00% 0x000079c2e040f258: jb 0x000079c2e040f419 Right. I am only saying that minor improvements on PCR>1 path might tip the balance towards enabling it. This is what I just tried on x86: diff --git a/src/hotspot/cpu/x86/c1_LIRAssembler_x86.cpp b/src/hotspot/cpu/x86/c1_LIRAssembler_x86.cpp index 2ad184790ed..5f64a7f587f 100644 --- a/src/hotspot/cpu/x86/c1_LIRAssembler_x86.cpp +++ b/src/hotspot/cpu/x86/c1_LIRAssembler_x86.cpp @@ -1340,9 +1340,8 @@ static void increment_mdo(MacroAssembler *C1_masm, Address dst, int32_t src, Reg Label nope, do_increment; if (ProfileCaptureRatio > 1) { assert(!dst.uses(temp), "fix register allocation"); - __ movq(temp, dst); - __ orq(temp, temp); - __ jcc(Assembler::equal, do_increment); + __ cmpptr(dst, 0); + __ jccb(Assembler::equal, do_increment); auto threshold = (UCONST64(1) << 32) >> ratio_shift; __ cmpl(r_profile_rng, (uint32_t)threshold); __ jccb(Assembler::aboveEqual, nope); @@ -3101,7 +3100,7 @@ void LIR_Assembler::increment_profile_ctr(LIR_Opr step_opr, LIR_Opr dest_opr, // to make sure we don't miss its first increment. mem2reg(counter_address_opr, dest_opr, dest_opr->type(), lir_patch_none, nullptr, /*wide*/false); - __ orq(dest, dest); + __ testptr(dest, dest); __ jcc(Assembler::equal, *counter_stub->entry()); } else { __ block_comment("Counter is already non-zero"); It yields a bit more compact form, about 6 bytes denser: 0.00% 0x000070d34c40f3df: movabs $0x70d30301b7b0,%rdi ; {metadata(method data for {method} {0x00000000435a3ac0}... 0x000070d34c40f3e9: mov 0x70(%rdi),%ebx 2.16% 0x000070d34c40f3ec: test %rbx,%rbx 0.01% 0x000070d34c40f3ef: je 0x000070d34c40f5e8 0.00% 0x000070d34c40f3f5: cmp $0x40000000,%r14d 0.00% 0x000070d34c40f3fc: jb 0x000070d34c40f5e8 0x000070d34c40f402: xor %ebx,%ebx 0.01% 0x000070d34c40f404: crc32 %ebx,%r14d 0.00% 0x000070d34c40f40a: movabs $0x70d30301b7b0,%rdi ; {metadata(method data for {method} {0x00000000435a3ac0} ... 0.00% 0x000070d34c40f414: cmpq $0x0,0xa8(%rdi) 2.56% ╭ 0x000070d34c40f41c: je 0x000070d34c40f427 0.12% │ 0x000070d34c40f41e: cmp $0x40000000,%r14d 0.01% │╭ 0x000070d34c40f425: jae 0x000070d34c40f42f ↘│ 0x000070d34c40f427: addq $0x4,0xa8(%rdi) 0.49% ↘ 0x000070d34c40f42f: xor %ebx,%ebx 0.01% 0x000070d34c40f431: crc32 %ebx,%r14d But it does not help warmup. Looking at this again, I am suspicious about several more things: 1. The zero-checked pre-read hits the same counter we would contend on. Granted, this a load and not a store, but under high update traffic it would still be a coherence miss. Does that negate the benefits we get from PCR to begin with? It _looks_ from the cycles counter that load is actually hot, but it is not clear if that's a coherence or capacity miss. 2. I do indeed see the static filtering for known-not-zero counters in `increment_profile_ctr`, but not in `increment_mdo`. 3. These `cmp $0x40000000,%r14d` are real fat because our threshold mask is large. Is there something preventing us to check the _lower_ bits? E.g. instead of asking `cmp $0x40000000, %rng; jae <slow>`, ask `cmp $0x4, %rng; jbe <slow>`? Sounds like with lower PCRs, we would be able to fit the mask into 8-/16-bit immediate. I also notice that with higher PCRs, the first iterations become faster. That might indicate that the real bottleneck is going slow for counter updates? Because with any PCR>1 we do all the fast-paths, and slow-path frequency is what is changing. $ taskset -c 0-7 build/linux-x86_64-server-release/images/jdk/bin/java -XX:+UnlockExperimentalVMOptions -XX:ProfileCaptureRatio=1 -jar renaissance-gpl-0.16.1.jar dotty -r 5 2>&1 | grep completed | grep -v before # PCR=1 ====== dotty (scala) [default], iteration 0 completed (3873.434 ms) ====== ====== dotty (scala) [default], iteration 1 completed (1348.585 ms) ====== ====== dotty (scala) [default], iteration 2 completed (975.541 ms) ====== ====== dotty (scala) [default], iteration 3 completed (796.719 ms) ====== ====== dotty (scala) [default], iteration 4 completed (683.054 ms) ====== # PCR=2 ====== dotty (scala) [default], iteration 0 completed (5409.952 ms) ====== ====== dotty (scala) [default], iteration 1 completed (1870.125 ms) ====== ====== dotty (scala) [default], iteration 2 completed (1198.309 ms) ====== ====== dotty (scala) [default], iteration 3 completed (891.474 ms) ====== ====== dotty (scala) [default], iteration 4 completed (762.755 ms) ====== # PCR=4 ====== dotty (scala) [default], iteration 0 completed (5058.453 ms) ====== ====== dotty (scala) [default], iteration 1 completed (1776.732 ms) ====== ====== dotty (scala) [default], iteration 2 completed (1184.039 ms) ====== ====== dotty (scala) [default], iteration 3 completed (909.001 ms) ====== ====== dotty (scala) [default], iteration 4 completed (754.427 ms) ====== # PCR=8 ====== dotty (scala) [default], iteration 0 completed (4765.536 ms) ====== ====== dotty (scala) [default], iteration 1 completed (1718.545 ms) ====== ====== dotty (scala) [default], iteration 2 completed (1103.720 ms) ====== ====== dotty (scala) [default], iteration 3 completed (836.457 ms) ====== ====== dotty (scala) [default], iteration 4 completed (708.936 ms) ====== # PCR=16 ====== dotty (scala) [default], iteration 0 completed (4615.626 ms) ====== ====== dotty (scala) [default], iteration 1 completed (1630.216 ms) ====== ====== dotty (scala) [default], iteration 2 completed (1105.064 ms) ====== ====== dotty (scala) [default], iteration 3 completed (870.359 ms) ====== ====== dotty (scala) [default], iteration 4 completed (745.397 ms) ====== ------------- PR Comment: https://git.openjdk.org/jdk/pull/28541#issuecomment-5868088964 PR Comment: https://git.openjdk.org/jdk/pull/28541#issuecomment-5868962326 PR Comment: https://git.openjdk.org/jdk/pull/28541#issuecomment-5888594615
