1 /*
  2  * Copyright (c) 2021, 2025, 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.
  8  *
  9  * This code is distributed in the hope that it will be useful, but WITHOUT
 10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
 11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
 12  * version 2 for more details (a copy is included in the LICENSE file that
 13  * accompanied this code).
 14  *
 15  * You should have received a copy of the GNU General Public License version
 16  * 2 along with this work; if not, write to the Free Software Foundation,
 17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
 18  *
 19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
 20  * or visit www.oracle.com if you need additional information or have any
 21  * questions.
 22  */
 23 
 24 /**
 25  * @test
 26  * @summary Basic test for JFR jdk.VirtualThreadXXX events
 27  * @requires vm.continuations & vm.hasJFR
 28  * @modules jdk.jfr java.base/java.lang:+open jdk.management
 29  * @library /test/lib
 30  * @run junit/othervm/native --enable-native-access=ALL-UNNAMED JfrEvents
 31  */
 32 
 33 import java.io.IOException;
 34 import java.nio.file.Path;
 35 import java.util.List;
 36 import java.util.Map;
 37 import java.util.concurrent.Executor;
 38 import java.util.concurrent.ExecutorService;
 39 import java.util.concurrent.Executors;
 40 import java.util.concurrent.RejectedExecutionException;
 41 import java.util.concurrent.ThreadFactory;
 42 import java.util.concurrent.atomic.AtomicBoolean;
 43 import java.util.concurrent.locks.LockSupport;
 44 import java.util.stream.Collectors;
 45 import java.util.stream.IntStream;
 46 import java.util.stream.Stream;
 47 
 48 import jdk.jfr.EventType;
 49 import jdk.jfr.Recording;
 50 import jdk.jfr.consumer.RecordedEvent;
 51 import jdk.jfr.consumer.RecordingFile;
 52 
 53 import jdk.test.lib.thread.VThreadPinner;
 54 import jdk.test.lib.thread.VThreadRunner;   // ensureParallelism requires jdk.management
 55 import jdk.test.lib.thread.VThreadScheduler;
 56 import org.junit.jupiter.api.Test;
 57 import org.junit.jupiter.api.BeforeAll;
 58 import org.junit.jupiter.params.ParameterizedTest;
 59 import org.junit.jupiter.params.provider.ValueSource;
 60 import static org.junit.jupiter.api.Assertions.*;
 61 
 62 class JfrEvents {
 63 
 64     @BeforeAll
 65     static void setup() {
 66         // need at least two carriers to test pinning
 67         VThreadRunner.ensureParallelism(2);
 68     }
 69 
 70     /**
 71      * Test jdk.VirtualThreadStart and jdk.VirtualThreadEnd events.
 72      */
 73     @Test
 74     void testVirtualThreadStartAndEnd() throws Exception {
 75         try (Recording recording = new Recording()) {
 76             recording.enable("jdk.VirtualThreadStart");
 77             recording.enable("jdk.VirtualThreadEnd");
 78 
 79             // execute 100 tasks, each in their own virtual thread
 80             recording.start();
 81             try {
 82                 List<Thread> threads = IntStream.range(0, 100)
 83                         .mapToObj(_ -> Thread.startVirtualThread(() -> { }))
 84                         .toList();
 85                 for (Thread t : threads) {
 86                     t.join();
 87                 }
 88             } finally {
 89                 recording.stop();
 90             }
 91 
 92             Map<String, Integer> events = sumEvents(recording);
 93             System.err.println(events);
 94 
 95             int startCount = events.getOrDefault("jdk.VirtualThreadStart", 0);
 96             int endCount = events.getOrDefault("jdk.VirtualThreadEnd", 0);
 97             assertEquals(100, startCount);
 98             assertEquals(100, endCount);
 99         }
100     }
101 
102     /**
103      * Test jdk.VirtualThreadPark.
104      */
105     @ParameterizedTest
106     @ValueSource(longs = { 0, 30_000_000_000L, Long.MAX_VALUE })
107     void testPark(long timeout) throws Exception {
108         try (Recording recording = new Recording()) {
109             recording.enable("jdk.VirtualThreadPark");
110 
111             recording.start();
112 
113             var started = new AtomicBoolean();
114             var done = new AtomicBoolean();
115             var vthread = Thread.startVirtualThread(() -> {
116                 started.set(true);
117                 while (!done.get()) {
118                     if (timeout > 0) {
119                         LockSupport.parkNanos(timeout);
120                     } else {
121                         LockSupport.park();
122                     }
123                 }
124             });
125 
126             try {
127                 // wait for thread to start and park
128                 awaitTrue(started);
129                 await(vthread, timeout > 0 ? Thread.State.TIMED_WAITING : Thread.State.WAITING);
130             } finally {
131                 done.set(true);
132                 LockSupport.unpark(vthread);
133                 vthread.join();
134                 recording.stop();
135             }
136 
137             assertContainsParkEvent(recording, vthread, timeout);
138         }
139 
140     }
141 
142     /**
143      * Test jdk.VirtualThreadPinned event when parking while pinned.
144      */
145     @ParameterizedTest
146     @ValueSource(booleans = { true, false })
147     void testParkWhenPinned(boolean timed) throws Exception {
148         try (Recording recording = new Recording()) {
149             recording.enable("jdk.VirtualThreadPinned");
150             recording.start();
151 
152             var started = new AtomicBoolean();
153             var done = new AtomicBoolean();
154             var vthread = Thread.startVirtualThread(() -> {
155                 VThreadPinner.runPinned(() -> {
156                     started.set(true);
157                     while (!done.get()) {
158                         if (timed) {
159                             LockSupport.parkNanos(Long.MAX_VALUE);
160                         } else {
161                             LockSupport.park();
162                         }
163                     }
164                 });
165             });
166 
167             try {
168                 // wait for thread to start and park
169                 awaitTrue(started);
170                 await(vthread, timed ? Thread.State.TIMED_WAITING : Thread.State.WAITING);
171             } finally {
172                 done.set(true);
173                 LockSupport.unpark(vthread);
174                 vthread.join();
175                 recording.stop();
176             }
177 
178             assertContainsPinnedEvent(recording, vthread);
179         }
180     }
181 
182     /**
183      * Test jdk.VirtualThreadPinned event when blocking on monitor while pinned.
184      */
185     @Test
186     void testBlockWhenPinned() throws Exception {
187         try (Recording recording = new Recording()) {
188             recording.enable("jdk.VirtualThreadPinned");
189             recording.start();
190 
191             Object lock = new Object();
192 
193             var started = new AtomicBoolean();
194             var vthread = Thread.ofVirtual().unstarted(() -> {
195                 VThreadPinner.runPinned(() -> {
196                     started.set(true);
197                     synchronized (lock) { }
198                 });
199             });
200 
201             try {
202                 synchronized (lock) {
203                     vthread.start();
204                     // wait for thread to start and block
205                     awaitTrue(started);
206                     await(vthread, Thread.State.BLOCKED);
207                 }
208             } finally {
209                 vthread.join();
210                 recording.stop();
211             }
212 
213             assertContainsPinnedEvent(recording, vthread);
214         }
215     }
216 
217     /**
218      * Test jdk.VirtualThreadPinned event when waiting with Object.wait while pinned.
219      */
220     @ParameterizedTest
221     @ValueSource(booleans = { true, false })
222     void testObjectWaitWhenPinned(boolean timed) throws Exception {
223         try (Recording recording = new Recording()) {
224             recording.enable("jdk.VirtualThreadPinned");
225             recording.start();
226 
227             Object lock = new Object();
228 
229             var started = new AtomicBoolean();
230             var vthread = Thread.startVirtualThread(() -> {
231                 VThreadPinner.runPinned(() -> {
232                     started.set(true);
233                     synchronized (lock) {
234                         try {
235                             if (timed) {
236                                 lock.wait(Long.MAX_VALUE);
237                             } else {
238                                 lock.wait();
239                             }
240                         } catch (InterruptedException e) {
241                             fail();
242                         }
243                     }
244                 });
245             });
246 
247             try {
248                 // wait for thread to start and wait
249                 awaitTrue(started);
250                 await(vthread, timed ? Thread.State.TIMED_WAITING : Thread.State.WAITING);
251             } finally {
252                 synchronized (lock) {
253                     lock.notifyAll();
254                 }
255                 vthread.join();
256                 recording.stop();
257             }
258 
259             assertContainsPinnedEvent(recording, vthread);
260         }
261     }
262 
263     /**
264      * Test jdk.VirtualThreadPinned event when parking in a class initializer.
265      */
266     @Test
267     void testParkInClassInitializer() throws Exception {
268         class TestClass {
269             static {
270                 LockSupport.park();
271             }
272             static void m() {
273                 // do nothing
274             }
275         }
276 
277         try (Recording recording = new Recording()) {
278             recording.enable("jdk.VirtualThreadPinned");
279             recording.start();
280 
281             var started = new AtomicBoolean();
282             Thread vthread = Thread.startVirtualThread(() -> {
283                 started.set(true);
284                 TestClass.m();
285             });
286 
287             try {
288                 // wait for it to start and park
289                 awaitTrue(started);
290                 await(vthread, Thread.State.WAITING);
291             } finally {
292                 LockSupport.unpark(vthread);
293                 vthread.join();
294                 recording.stop();
295             }
296 
297             assertContainsPinnedEvent(recording, vthread);
298         }
299     }
300 
301     /**
302      * Test jdk.VirtualThreadPinned event when blocking on monitor in a class initializer.
303      */
304     @Test
305     void testBlockInClassInitializer() throws Exception {
306         class LockHolder {
307             static final Object lock = new Object();
308         }
309         class TestClass {
310             static {
311                 synchronized (LockHolder.lock) { }
312             }
313             static void m() {
314                 // no nothing
315             }
316         }
317 
318         try (Recording recording = new Recording()) {
319             recording.enable("jdk.VirtualThreadPinned");
320             recording.start();
321 
322             var started = new AtomicBoolean();
323             Thread vthread = Thread.ofVirtual().unstarted(() -> {
324                 started.set(true);
325                 TestClass.m();
326             });
327 
328             try {
329                 synchronized (LockHolder.lock) {
330                     vthread.start();
331                     // wait for thread to start and block
332                     awaitTrue(started);
333                     await(vthread, Thread.State.BLOCKED);
334                 }
335             } finally {
336                 vthread.join();
337                 recording.stop();
338             }
339 
340             assertContainsPinnedEvent(recording, vthread);
341         }
342     }
343 
344     /**
345      * Test jdk.VirtualThreadPinned event when waiting for a class initializer while pinned.
346      */
347     @Test
348     void testWaitingForClassInitializerWhenPinned() throws Exception {
349         class TestClass {
350             static {
351                 LockSupport.park();
352             }
353             static void m() {
354                 // do nothing
355             }
356         }
357 
358         try (Recording recording = new Recording()) {
359             recording.enable("jdk.VirtualThreadPinned");
360             recording.start();
361 
362             var started1 = new AtomicBoolean();
363             var started2 = new AtomicBoolean();
364 
365             Thread vthread1 = Thread.ofVirtual().unstarted(() -> {
366                 started1.set(true);
367                 TestClass.m();
368             });
369             Thread vthread2 = Thread.ofVirtual().unstarted(() -> {
370                 started2.set(true);
371                 VThreadPinner.runPinned(() -> {
372                     TestClass.m();
373                 });
374             });
375 
376             try {
377                 // start first virtual thread and wait for it to start + park
378                 vthread1.start();
379                 awaitTrue(started1);
380                 await(vthread1, Thread.State.WAITING);
381 
382                 // start second virtual thread and wait for it to start
383                 vthread2.start();
384                 awaitTrue(started2);
385 
386                 // give time for second virtual thread to wait in VM
387                 Thread.sleep(3000);
388 
389             } finally {
390                 LockSupport.unpark(vthread1);
391                 vthread1.join();
392                 vthread2.join();
393                 recording.stop();
394             }
395 
396             // the recording should have a pinned event for vthread2
397             assertContainsPinnedEvent(recording, vthread2);
398         }
399     }
400 
401     /**
402      * Test jdk.VirtualThreadSubmitFailed event.
403      */
404     @Test
405     void testVirtualThreadSubmitFailed() throws Exception {
406         try (Recording recording = new Recording()) {
407             recording.enable("jdk.VirtualThreadSubmitFailed");
408 
409             recording.start();
410             try (ExecutorService pool = Executors.newCachedThreadPool()) {
411                 Executor scheduler = task -> pool.execute(task);
412 
413                 // create virtual thread that uses custom scheduler
414                 ThreadFactory factory = VThreadScheduler.virtualThreadFactory(scheduler);
415 
416                 // start a thread
417                 Thread thread = factory.newThread(LockSupport::park);
418                 thread.start();
419 
420                 // wait for thread to park
421                 await(thread, Thread.State.WAITING);
422 
423                 // shutdown scheduler
424                 pool.shutdown();
425 
426                 // unpark, the submit should fail
427                 try {
428                     LockSupport.unpark(thread);
429                     fail();
430                 } catch (RejectedExecutionException expected) { }
431 
432                 // start another thread, it should fail and an event should be recorded
433                 try {
434                     factory.newThread(LockSupport::park).start();
435                     throw new RuntimeException("RejectedExecutionException expected");
436                 } catch (RejectedExecutionException expected) { }
437             } finally {
438                 recording.stop();
439             }
440 
441             List<RecordedEvent> submitFailedEvents = find(recording, "jdk.VirtualThreadSubmitFailed");
442             System.err.println(submitFailedEvents);
443             assertTrue(submitFailedEvents.size() == 2, "Expected two events");
444         }
445     }
446 
447     /**
448      * Returns the list of events in the given recording with the given name.
449      */
450     private static List<RecordedEvent> find(Recording recording, String name) throws IOException {
451         Path recordingFile = recordingFile(recording);
452         return RecordingFile.readAllEvents(recordingFile)
453                 .stream()
454                 .filter(e -> e.getEventType().getName().equals(name))
455                 .toList();
456     }
457 
458     /**
459      * Read the events from the recording and return a map of event name to count.
460      */
461     private static Map<String, Integer> sumEvents(Recording recording) throws IOException {
462         Path recordingFile = recordingFile(recording);
463         List<RecordedEvent> events = RecordingFile.readAllEvents(recordingFile);
464         return events.stream()
465                 .map(RecordedEvent::getEventType)
466                 .collect(Collectors.groupingBy(EventType::getName,
467                                                Collectors.summingInt(x -> 1)));
468     }
469 
470     /**
471      * Return the file path to the recording file.
472      */
473     private static Path recordingFile(Recording recording) throws IOException {
474         Path recordingFile = recording.getDestination();
475         if (recordingFile == null) {
476             ProcessHandle h = ProcessHandle.current();
477             recordingFile = Path.of("recording-" + recording.getId() + "-pid" + h.pid() + ".jfr");
478             recording.dump(recordingFile);
479         }
480         return recordingFile;
481     }
482 
483     /**
484      * Assert that a recording contains a jdk.VirtualThreadPinned event on the given thread.
485      */
486     private void assertContainsPinnedEvent(Recording recording, Thread thread) throws IOException {
487         List<RecordedEvent> pinnedEvents = find(recording, "jdk.VirtualThreadPinned");
488         assertTrue(pinnedEvents.size() > 0, "No jdk.VirtualThreadPinned events in recording");
489         System.err.println(pinnedEvents);
490 
491         long tid = thread.threadId();
492         assertTrue(pinnedEvents.stream()
493                         .anyMatch(e -> e.getThread().getJavaThreadId() == tid),
494                 "jdk.VirtualThreadPinned for javaThreadId = " + tid + " not found");
495     }
496 
497     /**
498      * Assert that a recording contains a jdk.VirtualThreadPark event on the given thread.
499      */
500     private void assertContainsParkEvent(Recording recording,
501                                          Thread thread,
502                                          long testTimeout) throws IOException {
503         List<RecordedEvent> allParkEvents = find(recording, "jdk.VirtualThreadPark");
504         assertTrue(allParkEvents.size() > 0, "No jdk.VirtualThreadPark events in recording");
505         System.err.println(allParkEvents);
506 
507         // park events for the given thread
508         long tid = thread.threadId();
509         List<RecordedEvent> parkEvents = allParkEvents.stream()
510                 .filter(e -> e.getThread().getJavaThreadId() == tid)
511                 .toList();
512 
513         long expectedTimeout = (testTimeout != 0) ? testTimeout : Long.MIN_VALUE;
514         boolean found = parkEvents.stream()
515                 .map(e -> e.getLong("timeout"))
516                 .allMatch(t -> t == expectedTimeout);
517         assertTrue(found, "jdk.VirtualThreadPark for javaThreadId = " + tid
518                 + ", timeout = " + expectedTimeout + " not found");
519     }
520 
521     /**
522      * Waits for the given boolean to be set to true.
523      */
524     private void awaitTrue(AtomicBoolean b) throws InterruptedException {
525         while (!b.get()) {
526             Thread.sleep(10);
527         }
528     }
529 
530     /**
531      * Waits for the given thread to reach a given state.
532      */
533     private static void await(Thread thread, Thread.State expectedState) throws InterruptedException {
534         Thread.State state = thread.getState();
535         while (state != expectedState) {
536             Thread.sleep(10);
537             state = thread.getState();
538         }
539     }
540 }