1 /*
   2  * Copyright (c) 2013, 2018, 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.  Oracle designates this
   8  * particular file as subject to the "Classpath" exception as provided
   9  * by Oracle in the LICENSE file that accompanied this code.
  10  *
  11  * This code is distributed in the hope that it will be useful, but WITHOUT
  12  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  13  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  14  * version 2 for more details (a copy is included in the LICENSE file that
  15  * accompanied this code).
  16  *
  17  * You should have received a copy of the GNU General Public License version
  18  * 2 along with this work; if not, write to the Free Software Foundation,
  19  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  20  *
  21  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  22  * or visit www.oracle.com if you need additional information or have any
  23  * questions.
  24  */
  25 
  26 package jdk.jfr.event.runtime;
  27 
  28 import static jdk.test.lib.Asserts.assertGreaterThan;
  29 import static jdk.test.lib.Asserts.assertTrue;
  30 
  31 import java.lang.management.ManagementFactory;
  32 import java.time.Duration;
  33 import java.util.Collections;
  34 import java.util.List;
  35 import java.util.Random;
  36 import java.util.concurrent.CountDownLatch;
  37 
  38 import com.sun.management.ThreadMXBean;
  39 
  40 import jdk.jfr.Recording;
  41 import jdk.jfr.consumer.RecordedEvent;
  42 import jdk.jfr.consumer.RecordedThread;
  43 import jdk.test.lib.jfr.EventNames;
  44 import jdk.test.lib.jfr.Events;
  45 
  46 /**
  47  * @test
  48  * @key jfr
  49  *
  50  * @library /lib /
  51  *
  52  *
  53  * @run main/othervm -XX:-UseTLAB jdk.jfr.event.runtime.TestThreadAllocationEvent
  54  */
  55 
  56 /**
  57  * The test will create a few threads that will allocate memory for a short time.
  58  * During this time a number of thread_allocation events will be generated.
  59  * The test will verify:
  60  * 1. That number of allocated bytes is not decreasing for a thread.
  61  *  - This assumption is only true when not using TLABs. For this reason the
  62  *    test is run with -XX:-UseTLAB. When using TLABs, the code calculating the
  63  *    allocated bytes is using the current TLAB to do as good of an approximation
  64  *    as possible, but this introduces a race which might double count the current
  65  *    TLAB when it is full and in the middle of being switched out.
  66  * 2. That sum of allocated bytes approximately matches value in ThreadMXBean.
  67  */
  68 public class TestThreadAllocationEvent {
  69     private static final String EVENT_NAME = EventNames.ThreadAllocationStatistics;
  70     private static final String testThreadName = "testThread-";
  71     private static final long eventPeriodMillis = 50;
  72 
  73     // The value in both the JFR event and in the ThreadMXBean is documented as
  74     // an "approximation" of number of bytes allocated.
  75     // To not give any false errors, we allow an error margin of 5 mb.
  76     // The test will typically allocate over 600 mb, so 5 mb is an error of less than 1%.
  77     private static final long allowedTotalAllocatedDiff = 5000000;
  78 
  79     public static void main(String[] args) throws Throwable {
  80         Recording recording = new Recording();
  81         recording.enable(EVENT_NAME).withPeriod(Duration.ofMillis(eventPeriodMillis));
  82         recording.start();
  83 
  84         AllocatorThread[] threads = new AllocatorThread[4];
  85         CountDownLatch allocationsDoneLatch = new CountDownLatch(threads.length);
  86         for (int i = 0; i < threads.length; i++) {
  87             threads[i] = new AllocatorThread(allocationsDoneLatch, 1000 * (i + 1));
  88             threads[i].setName(testThreadName + i);
  89             threads[i].setDaemon(true);
  90             threads[i].start();
  91         }
  92 
  93         // Take regular measurements while the threads are allocating memory.
  94         // Stop measurement when all threads are ready.
  95         try {
  96             allocationsDoneLatch.await();
  97         } catch (InterruptedException e) {
  98             e.printStackTrace();
  99         }
 100         // Verify that number of allocated bytes is not decreasing.
 101         recording.stop();
 102         verifyAllocationsNotDecreasing(Events.fromRecording(recording), threads);
 103 
 104         // Now allocations are done and threads are waiting to die.
 105         // Make a new instant recording to get total number of allocated bytes.
 106         // The reason for this extra recording is to make sure we get a JFR event
 107         // after all allocations are done so we can compare the JFR value with
 108         // the value reported by ThreadMXBean.
 109         recording = new Recording();
 110         recording.enable(EVENT_NAME);
 111         recording.start();
 112         recording.stop();
 113         verifyTotalAllocated(Events.fromRecording(recording), threads);
 114     }
 115 
 116     /**
 117      * Verify that the allocated value never decreases.
 118      * We only compare our own allocator threads. The reason for that is that other threads
 119      * may start/stop at any time, and we do not know if other thread names are unique.
 120      */
 121      private static void verifyAllocationsNotDecreasing(List<RecordedEvent> events, AllocatorThread[] threads) {
 122          Collections.sort(events, (u,v) -> u.getEndTime().compareTo(v.getEndTime()));
 123          long[] prevAllocated = new long[threads.length];
 124          for (RecordedEvent event : events) {
 125              RecordedThread rt = Events.assertField(event, "thread").notNull().getValue(); // Check that we have a thread.
 126              String name = rt.getJavaName();
 127              for (int i = 0; i < threads.length; i++) {
 128                  if (name.equals(threads[i].getName())) {
 129                      long curr = Events.assertField(event, "allocated").atLeast(prevAllocated[i]).getValue();
 130                      prevAllocated[i] = curr;
 131                  }
 132              }
 133          }
 134 
 135          for (int i = 0; i < threads.length; i++) {
 136              assertGreaterThan(prevAllocated[i], 0L, "No allocations for thread " + threads[i].getName());
 137          }
 138      }
 139 
 140      /**
 141       * Verify that total allocated bytes in JFR event approximately matches the value in ThreadMXBean.
 142       */
 143     private static void verifyTotalAllocated(List<RecordedEvent> events, AllocatorThread[] threads) {
 144         boolean[] isEventFound = new boolean[threads.length];
 145         for (RecordedEvent event : events) {
 146             RecordedThread rt = Events.assertField(event, "thread").notNull().getValue();
 147             String name = rt.getJavaName();
 148             for (int i = 0; i < threads.length; ++i) {
 149                 if (name.equals(threads[i].getName())) {
 150                     System.out.println("Event:" + event);
 151                     long maxAllowed = threads[i].totalAllocated + allowedTotalAllocatedDiff;
 152                     long minAllowed = Math.max(0, threads[i].totalAllocated - allowedTotalAllocatedDiff);
 153                     Events.assertField(event, "allocated").atLeast(minAllowed).atMost(maxAllowed);
 154                     isEventFound[i] = true;
 155                 }
 156             }
 157         }
 158         for (int i = 0; i < threads.length; ++i) {
 159             assertTrue(isEventFound[i], "No event for thread id " + i);
 160         }
 161     }
 162 
 163     /**
 164      * Thread that does a number of allocations and records total number of
 165      * bytes allocated as reported by ThreadMXBean.
 166      */
 167     public static class AllocatorThread extends Thread {
 168         private volatile long totalAllocated = -1;
 169         private final int averageAllocationSize;
 170         public byte[] buffer;
 171         private final CountDownLatch allocationsDoneLatch;
 172 
 173         public AllocatorThread(CountDownLatch allocationsDoneLatch, int averageAllocationSize) {
 174             this.allocationsDoneLatch = allocationsDoneLatch;
 175             this.averageAllocationSize = averageAllocationSize;
 176         }
 177 
 178         @Override
 179         public void run() {
 180             Random rand = new Random();
 181             int allocationSizeBase = averageAllocationSize / 2;
 182             int allocationSizeRandom = averageAllocationSize;
 183             for (int batches=0; batches<100; batches++) {
 184                 for (int i=0; i<1500; i++) {
 185                     buffer = new byte[rand.nextInt(allocationSizeRandom) + allocationSizeBase];
 186                 }
 187                 try {
 188                     // No need to allocate too much data between JFR events, so do a short sleep.
 189                     Thread.sleep(eventPeriodMillis / 5);
 190                 } catch (InterruptedException e) {
 191                     e.printStackTrace();
 192                 }
 193             }
 194             totalAllocated = getThreadAllocatedBytes();
 195             allocationsDoneLatch.countDown();
 196 
 197             // Need to keep thread alive so we can get the final JFR event.
 198             // This is a daemon thread, so it will finish when the main thread finishes.
 199             while (true) {
 200                 Thread.yield();
 201             }
 202         }
 203 
 204         private long getThreadAllocatedBytes() {
 205             ThreadMXBean bean = (ThreadMXBean) ManagementFactory.getThreadMXBean();
 206             return bean.getThreadAllocatedBytes(Thread.currentThread().getId());
 207         }
 208     }
 209 
 210 }