JEP 349: JFR Event Streaming (sandbox preview)

Chihiro Ito chihiro.ito at oracle.com
Mon May 20 18:46:22 UTC 2019


Hi Erik,

Thank you for your prompt reply.
I did the debugging referring to your advice. As you say, this exception 
is likely caused by the timing of the Streaming thread and the process 
of deleting the file.

My environment is Oracle Linux 7.5 with kernel 4.1. 12 -112.16. 4. el 7 
uke.x 86 _ 64.

Regards,
Chihiro

On 2019/05/21 3:09, Erik Gahlin wrote:
> What I think happens is that the JVM is shutting down (removing the 
> repository), before the streaming thread has started to read any files.
>
> Erik
>
>> Hi Chihiro,
>>
>> Thanks for reporting this!
>>
>> The fix looks like a reasonable workaround, but I'm a bit puzzled 
>> that this can happen.
>>
>> This is how RecordingStream.startAsync() looks like.
>>
>>   PlatformRecording pr = 
>> PrivateAccess.getInstance().getPlatformRecording(recording);
>>   long startNanos = pr.start();
>>   stream.startAsync(startNanos);
>>
>> and PlatformRecording.start() should not return before 
>> RepositoryChunk::newChunk has been called and a repository is 
>> created, if it doesn't already exists.
>>
>> What operating system are you using?
>>
>> Thanks
>> Erik
>>
>>
>>> Hi Erik,
>>>
>>> I tried JFR Streaming with the following code [1], but occasionally 
>>> an exception occurred [2].
>>> This is because the repository has not yet been created when JFR 
>>> Streaming reads the JFR file.
>>> I made a patch as attached.
>>>
>>> How do I handle bug reports? Should I raise the issue as usual?
>>>
>>>
>>> [1]
>>> public static void premain(String args, Instrumentation inst) {
>>>  RecordingStream r = new RecordingStream();
>>>  r.startAsync();
>>>  Runtime.getRuntime().addShutdownHook(new Thread() {
>>>   public void run() {
>>>    r.close();
>>>   }
>>>  });
>>> }
>>>
>>> public static void main(String... args) throws Exception {
>>>  TimeUnit.SECONDS.sleep(2);
>>>  System.out.println("Completed");
>>> }
>>>
>>> [2]
>>> java.nio.file.NoSuchFileException: /tmp/2019_05_20_00_30_44_445
>>>     at 
>>> java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
>>>     at 
>>> java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
>>>     at 
>>> java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116)
>>>     at 
>>> java.base/sun.nio.fs.UnixFileSystemProvider.newDirectoryStream(UnixFileSystemProvider.java:432)
>>>     at java.base/java.nio.file.Files.newDirectoryStream(Files.java:542)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventSetLocation.updateEventSets(EventSetLocation.java:129)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventSetLocation.acquire(EventSetLocation.java:108)
>>>     at jdk.jfr/jdk.jfr.consumer.EventSet.next(EventSet.java:210)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventRunner.process(EventRunner.java:132)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventRunner.execute(EventRunner.java:105)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventRunner.lambda$run$0(EventRunner.java:89)
>>>     at jdk.jfr/jdk.jfr.consumer.EventRunner$1.run(EventRunner.java:96)
>>>     at jdk.jfr/jdk.jfr.consumer.EventRunner$1.run(EventRunner.java:93)
>>>     at 
>>> java.base/java.security.AccessController.doPrivileged(AccessController.java:391)
>>>     at 
>>> jdk.jfr/jdk.jfr.consumer.EventRunner.doPriviliged(EventRunner.java:93)
>>>     at jdk.jfr/jdk.jfr.consumer.EventRunner.run(EventRunner.java:89)
>>>     at java.base/java.lang.Thread.run(Thread.java:830)
>>>
>>> Regards,
>>> Chihiro
>>>
>>>
>>>
>>> On 2019/05/18 1:27, Erik Gahlin wrote:
>>>> Hi folks,
>>>>
>>>> We have created a sandbox for JEP 349: JFR Event Streaming[1] for 
>>>> people who
>>>> like to try the feature out. It is work in progress, but plan is to 
>>>> integrate it
>>>> in the next couple of months, but not for JDK 13.
>>>>
>>>> A build can be created like this:
>>>>
>>>>  $ hg clone -b JEP-349-branch -r 53dccc90a5be 
>>>> http://hg.openjdk.java.net/jdk/sandbox jep-349
>>>>  $ cd jep-349
>>>>  $ bash configure
>>>>  $ make images
>>>>  $ ./build/*/images/jdk/bin/java -version
>>>>
>>>> See [2] and [3] for more information on how to use the sandbox 
>>>> repository and
>>>> build the JDK.
>>>>
>>>> For testing purposes, and to illustrate how the Event Streaming API 
>>>> can be
>>>> used, there exists a Java agent[4] that aggregates event data and 
>>>> print the
>>>> results on standard out.
>>>>
>>>> Example,
>>>> http://cr.openjdk.java.net/~egahlin/health-report-agent/health-report-example.txt 
>>>>
>>>> =================== HEALTH REPORT === 2019-05-16 23:57:50 
>>>> ====================
>>>> | GC: G1Old/G1New         Phys. memory: 28669 MB    Alloc Rate: 8 
>>>> MB/s       |
>>>> | OC Count    : 28        Initial Heap: 448 MB      Total Alloc: 
>>>> 190 MB      |
>>>> | OC Pause Avg: 40.1 ms   Used Heap   : 19 MB       Thread Count: 
>>>> 20.0       |
>>>> | OC Pause Max: 48.8 ms   Commit. Heap: 47 MB       Class Count : 
>>>> 3894.0     |
>>>> | YC Count    : 8         CPU Machine   :  20.12 % Safepoints: 
>>>> 335          |
>>>> | YC Pause Avg: 5.7 ms    CPU JVM User  :  10.28 %  Max Safepoint: 
>>>> 46.4 ms   |
>>>> | YC Pause Max: 22.4 ms   CPU JVM System:   1.07 %  Max Comp. Time: 
>>>> 728.3 ms |
>>>> |--- Top Allocation Methods ------------------------------- 
>>>> -----------------|
>>>> | DataBufferInt.<init>(int) 11.27 % |
>>>> | Component.size() 9.01 % |
>>>> | BufferedContext.validate(...) 6.21 % |
>>>> | Path2D$Double.<init>(...) 5.87 % |
>>>> | SunGraphics2D.clone() 5.85 % |
>>>> |--- Hot Methods 
>>>> ------------------------------------------------------------|
>>>> | DRenderer._endRendering(int, 
>>>> int)                                  51.11 % |
>>>> | DRenderer.copyAARow(...) 6.67 % |
>>>> | Arrays.fill(...) 4.44 % |
>>>> | StringConcatFactory.doStringConcat(...) 2.22 % |
>>>> | MarlinTileGenerator.getAlphaNoRLE(...) 2.22 % |
>>>> ============================================================================== 
>>>>
>>>>
>>>> The agent can be started like this:
>>>>
>>>>  $ java -javaagent:health-report.jar MyApp
>>>>
>>>> The interval at which events are flushed can be changed with the 
>>>> interval
>>>> option. The default interval is 1 second. For example, to flush
>>>> every ten second, use -javaagent:health-report.jar=interval=10
>>>>
>>>> For quick experimentation, the agent can also be run as a Java 
>>>> program that
>>>> allocate objects in a loop.
>>>>
>>>>  $ java Main.java
>>>>
>>>> Two new classes, EventStream[5] and RecordingStream[6], have been 
>>>> added to the
>>>> jdk.jfr.consumer package. A EventFilter class may be added later 
>>>> for more
>>>> advanced filtering.
>>>>
>>>> The JVM implementation is close to finished, but there is work on 
>>>> the consumer
>>>> side left. There is also an effort to reduce allocation on the client.
>>>>
>>>> To get started without using the agent, the CPU load can be printed
>>>> like this:
>>>>
>>>>   Configuration c = Configuration.getConfiguration("default");
>>>>   try (RecordingStream r = new RecordingStream(c)) {
>>>>     r.onEvent("jdk.CPULoad",  event -> {
>>>>       float percentage = 100 * event.getFloat("machineTotal");
>>>>       System.out.printf("CPU: %.2f %% \n\n", percentage);
>>>>     });
>>>>     r.start();
>>>>   }
>>>>
>>>> Feedback is very much welcomed!
>>>>
>>>> Thanks
>>>> Erik and Markus
>>>>
>>>> Outages, known issues and limitations
>>>> -------------------------------------
>>>>
>>>> - Only start/open one RecordingStream at a time
>>>> Implementation has not been tested with two RecordingStreams 
>>>> simultaneously.
>>>>
>>>> - Exception handling
>>>> Behavior is undefined if an exception is thrown in a handler.
>>>>
>>>> - Parser level filtering disabled
>>>> Purpose of parser level filtering is to be able to use predefined
>>>> configurations, for example default.jfc, but only pay the overhead 
>>>> in the
>>>> parser of the events that the stream is listening to. Now all 
>>>> events are
>>>> parsed. Workaround is to only enable the events of interest.
>>>>
>>>> - Chunk files not removed
>>>> Chunk files may be left behind in the disk repository when the JVM 
>>>> exits.
>>>>
>>>> - EventStream::openFile(...)
>>>> Not possible to open a file as an event stream.
>>>>
>>>> - EventStream:::openRepository(...)
>>>> Not possible to open a (remote) directory as an event stream.
>>>>
>>>> - EventStream.setReuse(...) (cursor mode)
>>>> Method has not been added / implemented.
>>>>
>>>> - EventStream.setParallel(...)
>>>> Method has not been added / implemented as it will make most sense if
>>>> EventStream::openFile exists.
>>>>
>>>> - EventStream.setOrdered(...)
>>>> Method has not been added. Need to figure out how to handle events 
>>>> that arrives
>>>> way out of order. For example,
>>>>
>>>>  MyEvent event = new MyEvent();
>>>>  event.begin();
>>>>  event.end(); // end timestamp taken here
>>>>  Thread.sleep(1000_000);
>>>>  event.commit();
>>>>
>>>> Currently a best effort is made to deliver events in order.
>>>>
>>>>  [1] https://openjdk.java.net/jeps/349
>>>>  [2] http://cr.openjdk.java.net/~chegar/docs/sandbox.html
>>>>  [3] http://hg.openjdk.java.net/jdk/jdk/raw-file/tip/doc/building.html
>>>>  [4] http://cr.openjdk.java.net/~egahlin/health-report-agent/
>>>>  [5] 
>>>> http://cr.openjdk.java.net/~egahlin/jep-349-preview/docs/jdk/jfr/consumer/RecordingStream.html
>>>>  [6] 
>>>> http://cr.openjdk.java.net/~egahlin/jep-349-preview/docs/jdk/jfr/consumer/EventStream.html 
>>>>
>>>>
>>>
>>
>
>



More information about the hotspot-jfr-dev mailing list