JVMTI callback SampledObjectAlloc always fires for first allocation in a new thread

[Jean Christophe Beyler]

Hi Markus,

I played around adding your Java code in the testing framework and I don't
get exactly the same failure as you do. Basically, I get about 5% samples
compared to the number of threads, whereas you seem to get a sample for
each element. Could you add the code you used for the agent so I can see if
you are doing something different than I am in that regard?

This doesn't change the issue, I'm just curious why you seem to be exposing
it more. I'm still digging into what would be the right solution for this.

Thanks,
Jc

On Mon, Jun 15, 2020 at 9:53 AM Jean Christophe Beyler <jcbeyler at google.com>
wrote:

> Hi Markus,
>
> I created:
> https://bugs.openjdk.java.net/browse/JDK-8247615
>
> And I'll see what needs to be done for it :)
> Jc
>
> On Fri, Jun 5, 2020 at 3:45 AM Markus Gaisbauer <
> markus.gaisbauer at gmail.com> wrote:
>
>> Hi,
>>
>> 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.
>>
>> I am looking for someone who could create a JIRA ticket for this.
>>
>> Regards,
>> Markus
>>
>
>
> --
>
> Thanks,
> Jc
>


-- 

Thanks,
Jc
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20200615/c1492116/attachment-0001.htm>