JDK-8247615 : Initialize the bytes left for the heap sampler
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 11,15,16
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2020-06-15
  • Updated: 2020-10-07
  • Resolved: 2020-07-17
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11 JDK 16
11.0.10-oracleFixed 16 b07Fixed
Description
Copied over from https://mail.openjdk.java.net/pipermail/serviceability-dev/2020-June/031758.html

JVMTI callback SampledObjectAlloc is currently always called for the first
allocation of a thread. This generates a lot of bias in an application that
regularly starts new threads.

I tested this with latest Java 11 and Java 15.

E.g. here is a sample that creates 100 threads and allocates one object in
each thread.

    public class AllocationProfilingBiasReproducer {
        public static void main(String[] args) throws Exception {
            for (int i = 0; i < 100; i++) {
                new Thread(new Task(), "Task " + i).start();
                Thread.sleep(1);
            }
            Thread.sleep(1000);
        }
        private static class Task implements Runnable {
            @Override
            public void run() {
                new A();
            }
        }
        private static class A {
        }
    }

I built a simple JVMTI agent that registers SampledObjectAlloc callback and
sets interval to 1 MB with SetHeapSamplingInterval. The callback simply
logs thread name and class name of allocated object.

I see the following output:

SampledObjectAlloc Ljava/lang/String; via Task 0
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 1
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 2
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 3
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 4
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 5
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 6
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 7
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 8
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 9
SampledObjectAlloc LAllocationProfilingBiasReproducer$A; via Task 10
...

This is not expected.

I set a breakpoint in my SampledObjectAlloc callback and observed the
following:

In MemAllocator::Allocation::notify_allocation_jvmti_sampler() the local
var bytes_since_last is always 0xf1f1f1f1f1f1f1f1 for first allocation of a
thread. So first allocation is always reported to my agent.

ThreadLocalAllocBuffer::_bytes_since_last_sample_point does not seem to be
explicitly initialized before accessing it for the first time. I assume
0xf1f1f1f1f1f1f1f1  is a default value provided by some Hotspot allocator.
Only after the first event fired, notify_allocation_jvmti_sampler
calls ThreadLocalAllocBuffer::set_sample_end which initializes
_bytes_since_last_sample_point to a proper value.
Comments
This down-port has now been reviewed. See: https://mail.openjdk.java.net/pipermail/jdk-updates-dev/2020-July/003566.html https://mail.openjdk.java.net/pipermail/jdk-updates-dev/2020-August/003658.html Can somebody of the 11u maintainers please approve it?
27-08-2020

Done, I didn't want to send another one so I didn't do that step. Done now :) Thanks for your help!
23-07-2020

I think you could either sign up to jdk-updates-dev (I think you're confirmed automatically) or if you don't want to, you can send it out to me (or some other folks who are subscribed) to post it on your behalf.
23-07-2020

I tried sending it but it is still up for moderation for the last 2 days I believe... Who could I ask to help?
23-07-2020

Hi [~jcbeyler], can you please post your webrev on jdk-updates-dev for review?
21-07-2020

Fix Request (11u) This fixes a sampling bias for the first allocations and ensures that the sampling rate is correct from the start. It is safe to apply as the whole code is protected behind flags and only is used when JVMTI enables the heap monitoring. We added a test that tickles this code on purpose. Finally, the patch does not apply cleanly due to slight differences with the files. This webrev provides the clean to JDK11u: http://cr.openjdk.java.net/~jcbeyler/8247615/webrev.02_11/ - That webrev compiles and tests for HeapMonitor (with the new test) pass: make run-test TEST="test/hotspot/jtreg/serviceability/jvmti/HeapMonitor" compared to what I submitted to head: http://cr.openjdk.java.net/~jcbeyler/8247615/webrev.02/ Let me know what else I can do or provide!
17-07-2020

URL: https://hg.openjdk.java.net/jdk/jdk/rev/13ec613f9373 User: jcbeyler Date: 2020-07-17 13:56:57 +0000
17-07-2020