JEP 349: JFR Event Streaming (sandbox preview)
Erik Gahlin
erik.gahlin at oracle.com
Tue May 21 18:20:06 UTC 2019
I will add a Files.exist check file before opening a DirectoryStream.
This race should really only happen during shutdown, so I will change so
it will cancel the thread, perhaps by throwing an exception.
Erik
> 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