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