JEP 349: JFR Event Streaming (sandbox preview)

Erik Gahlin erik.gahlin at oracle.com
Mon May 20 18:09:05 UTC 2019


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