1 /*
2 * Copyright (c) 2017, 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 com.sun.management.ThreadMXBean;
29 import jdk.jfr.Recording;
30 import jdk.jfr.consumer.RecordedEvent;
31 import jdk.jfr.consumer.RecordedThread;
32 import jdk.test.lib.Asserts;
33 import jdk.test.lib.jfr.EventNames;
34 import jdk.test.lib.jfr.Events;
35
36 import java.lang.management.ManagementFactory;
37 import java.time.Duration;
38 import java.time.Instant;
39 import java.util.Comparator;
40 import java.util.Iterator;
41 import java.util.List;
42 import java.util.concurrent.BrokenBarrierException;
43 import java.util.concurrent.CyclicBarrier;
44 import java.util.stream.Collectors;
45
46 /**
47 * @test
48 * @key jfr
49 * @requires vm.hasJFR
50 * @library /test/lib
51 * @modules jdk.jfr
52 * jdk.management
53 *
54 * @run main/othervm jdk.jfr.event.runtime.TestThreadCpuTimeEvent
55 */
56
57 /**
58 */
59 public class TestThreadCpuTimeEvent {
60
61 public static void main(String[] args) throws Throwable {
62 testSimple();
63 testCompareWithMXBean();
64 testEventAtThreadExit();
65 }
66
67 private static final long eventPeriodMillis = 50;
68 private static final String cpuConsumerThreadName = "cpuConsumer";
69
70 // The cpu consumer will run for eventPeriodMillis times this factor to ensure that we see some
71 // events even if the scheduler isn't cooperating.
72 private static final long cpuConsumerRunFactor = 10;
73
74 // The cpu consumer will run at least this number of loops, even if it takes longer than
75 // the requested period of time (in case the thread didn't get scheduled within the allotted time).
76 private static final long cpuConsumerMinCount = 1000000;
77
78 static class CpuConsumingThread extends Thread {
79
80 Duration runTime;
81 CyclicBarrier barrier;
82 volatile long counter;
83
84 CpuConsumingThread(Duration runTime, CyclicBarrier barrier, String threadName) {
85 super(threadName);
86 this.runTime = runTime;
87 this.barrier = barrier;
88 }
89
90 CpuConsumingThread(Duration runTime, CyclicBarrier barrier) {
91 this(runTime, barrier, cpuConsumerThreadName);
92 }
93
94 @Override
95 public void run() {
96 try {
97 while (true) {
98 barrier.await();
99 Instant start = Instant.now();
100 counter = 0;
101 while ((Duration.between(start, Instant.now()).compareTo(runTime) < 0) ||
102 (counter < cpuConsumerMinCount)) {
103 counter++;
104 }
105 barrier.await();
106 }
107 } catch (BrokenBarrierException e) {
108 // Another thread has been interrupted - wait for us to be interrupted as well
109 while (!interrupted()) {
110 yield();
111 }
112 } catch (InterruptedException e) {
113 // Normal way of stopping the thread
114 }
115 }
116 }
117
118 // For a given thread, check that accumulated processTime >= cpuTime >= userTime.
119 // This may not hold for a single event instance due to differences in counter resolution
120 static void verifyPerThreadInvariant(List<RecordedEvent> events, String threadName) {
121 List<RecordedEvent> filteredEvents = events.stream()
122 .filter(e -> e.getThread().getJavaName().equals(threadName))
123 .sorted(Comparator.comparing(RecordedEvent::getStartTime))
124 .collect(Collectors.toList());
125
126 int numCpus = Runtime.getRuntime().availableProcessors();
127 Iterator<RecordedEvent> i = filteredEvents.iterator();
128 while (i.hasNext()) {
129 RecordedEvent event = i.next();
130
131 Float systemLoad = (Float)event.getValue("system");
132 Float userLoad = (Float)event.getValue("user");
133
134 Asserts.assertLessThan(systemLoad + userLoad, 1.01f / numCpus); // 100% + rounding errors
135 }
136 }
137
138 static Duration getAccumulatedTime(List<RecordedEvent> events, String threadName, String fieldName) {
139 List<RecordedEvent> filteredEvents = events.stream()
140 .filter(e -> e.getThread().getJavaName().equals(threadName))
141 .sorted(Comparator.comparing(RecordedEvent::getStartTime))
142 .collect(Collectors.toList());
143
144 int numCpus = Runtime.getRuntime().availableProcessors();
145 Iterator<RecordedEvent> i = filteredEvents.iterator();
146 RecordedEvent cur = i.next();
147 Duration totalTime = Duration.ZERO;
148 while (i.hasNext()) {
149 RecordedEvent prev = cur;
150 cur = i.next();
151
152 Duration sampleTime = Duration.between(prev.getStartTime(), cur.getStartTime());
153 Float load = (Float)cur.getValue(fieldName);
154
155 // Adjust load to be thread-relative (fully loaded thread would give 100%)
156 Float totalLoadForThread = load * numCpus;
157 Duration threadTime = Duration.ofMillis((long) (sampleTime.toMillis() * totalLoadForThread));
158 totalTime = totalTime.plus(threadTime);
159 }
160
161 return totalTime;
162 }
163
164 static List<RecordedEvent> generateEvents(int minimumEventCount, CyclicBarrier barrier) throws Throwable {
165 int retryCount = 0;
166
167 while (true) {
168 Recording recording = new Recording();
169
170 // Default period is once per chunk
171 recording.enable(EventNames.ThreadCPULoad).withPeriod(Duration.ofMillis(eventPeriodMillis));
172 recording.start();
173
174 // Run a single pass
175 barrier.await();
176 barrier.await();
177
178 recording.stop();
179 List<RecordedEvent> events = Events.fromRecording(recording);
180
181 long numEvents = events.stream()
182 .filter(e -> e.getThread().getJavaName().equals(cpuConsumerThreadName))
183 .count();
184
185 // If the JFR periodicals thread is really starved, we may not get enough events.
186 // In that case, we simply retry the operation.
187 if (numEvents < minimumEventCount) {
188 System.out.println("Not enough events recorded, trying again...");
189 if (retryCount++ > 10) {
190 Asserts.fail("Retry count exceeded");
191 throw new RuntimeException();
192 }
193 } else {
194 return events;
195 }
196 }
197 }
198
199 static void testSimple() throws Throwable {
200 Duration testRunTime = Duration.ofMillis(eventPeriodMillis * cpuConsumerRunFactor);
201 CyclicBarrier barrier = new CyclicBarrier(2);
202 CpuConsumingThread thread = new CpuConsumingThread(testRunTime, barrier);
203 thread.start();
204
205 List<RecordedEvent> events = generateEvents(1, barrier);
206 verifyPerThreadInvariant(events, cpuConsumerThreadName);
207
208 thread.interrupt();
209 thread.join();
210 }
211
212 static void testCompareWithMXBean() throws Throwable {
213 Duration testRunTime = Duration.ofMillis(eventPeriodMillis * cpuConsumerRunFactor);
214 CyclicBarrier barrier = new CyclicBarrier(2);
215 CpuConsumingThread thread = new CpuConsumingThread(testRunTime, barrier);
216 thread.start();
217
218 List<RecordedEvent> beforeEvents = generateEvents(2, barrier);
219 verifyPerThreadInvariant(beforeEvents, cpuConsumerThreadName);
220
221 // Run a second single pass
222 barrier.await();
223 barrier.await();
224
225 ThreadMXBean bean = (ThreadMXBean) ManagementFactory.getThreadMXBean();
226 Duration cpuTime = Duration.ofNanos(bean.getThreadCpuTime(thread.getId()));
227 Duration userTime = Duration.ofNanos(bean.getThreadUserTime(thread.getId()));
228
229 // Check something that should hold even in the presence of unfortunate scheduling
230 Asserts.assertGreaterThanOrEqual(cpuTime.toMillis(), eventPeriodMillis);
231 Asserts.assertGreaterThanOrEqual(userTime.toMillis(), eventPeriodMillis);
232
233 Duration systemTimeBefore = getAccumulatedTime(beforeEvents, cpuConsumerThreadName, "system");
234 Duration userTimeBefore = getAccumulatedTime(beforeEvents, cpuConsumerThreadName, "user");
235 Duration cpuTimeBefore = userTimeBefore.plus(systemTimeBefore);
236
237 Asserts.assertLessThan(cpuTimeBefore, cpuTime);
238 Asserts.assertLessThan(userTimeBefore, userTime);
239 Asserts.assertGreaterThan(cpuTimeBefore, Duration.ZERO);
240
241 thread.interrupt();
242 thread.join();
243 }
244
245 static void testEventAtThreadExit() throws Throwable {
246 Recording recording = new Recording();
247
248 recording.enable(EventNames.ThreadCPULoad).withPeriod(Duration.ofHours(10));
249 recording.start();
250
251 Duration testRunTime = Duration.ofMillis(eventPeriodMillis * cpuConsumerRunFactor);
252 CyclicBarrier barrier = new CyclicBarrier(2);
253 CpuConsumingThread thread = new CpuConsumingThread(testRunTime, barrier);
254
255 // Run a single pass
256 thread.start();
257 barrier.await();
258 barrier.await();
259
260 thread.interrupt();
261 thread.join();
262
263 recording.stop();
264
265 List<RecordedEvent> events = Events.fromRecording(recording);
266 verifyPerThreadInvariant(events, cpuConsumerThreadName);
267
268 int exitingCount = 0;
269 for (RecordedEvent event : events) {
270 RecordedThread eventThread = event.getThread();
271 if (eventThread.getJavaName().equals(cpuConsumerThreadName)) {
272 exitingCount++;
273 }
274 }
275 Asserts.assertEquals(exitingCount, 1);
276 }
277 }