Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » EclipseLink » Eclipselink PerformanceProfiler Not Thread Safe
Eclipselink PerformanceProfiler Not Thread Safe [message #1764950] Sun, 04 June 2017 18:49 Go to next message
Nuno G. de M. is currently offline Nuno G. de M.Friend
Messages: 30
Registered: September 2012
Member
The eclipselink performance profiler appears to suffer from multiple flaws in regards to its thread safety.

Namely, if an application would be regularly asking for the PrformanceProfiler to return output of:

public Hashtable buildProfileSummaryByClass() {

Or the output of:
public Hashtable buildProfileSummaryByQuery() {

These for loops over the list of profiles is very often breaking with concurrent modificaiton exceptions as illustrated in the following snippet.

Caused by: java.util.ConcurrentModificationException
at java.util.Vector$Itr.checkForComodification(Vector.java:1184)
at java.util.Vector$Itr.next(Vector.java:1137)
at org.eclipse.persistence.tools.profiler.PerformanceProfiler.buildProfileSummaryByQuery(PerformanceProfiler.java:187)


The PerformanceProfiler seems to work fine, as long as the application does nothing more than let the default behavior of the profiler logging the metadata about the current ongoing query that has been executed.

But if the application is given some sort of timer that would be polling for the buildSummaryByQuery and using that metadata to log out it the an output LOGGER or simply doing as eclipselink does which is to log it to the session logger (typically the console), then we start being hammered by concurrecnt modification exceptions.
Mostlikely related with other queries running in parallel and having an effect on the profiler inner state.


Going to try to review the performance profiler code logically, and build a similar profiler that is in fact thread safe on all public APIs.

NOTE:
- IT would be useful to have in this performance profiler, apis to get the profiler output as string.
So that an application may log the profiler metadata with an application manager logger.

Thanks for taking a look at this issue.
Re: Eclipselink PerformanceProfiler Not Thread Safe [message #1764967 is a reply to message #1764950] Mon, 05 June 2017 08:36 Go to previous messageGo to next message
Nuno G. de M. is currently offline Nuno G. de M.Friend
Messages: 30
Registered: September 2012
Member
I have another question to add to the above.

Is the Performance profiler not becoming a complete memory leak in the system?

Based on a heap dump I have just taken, the PerformanceProfiler is accumulating thousands of Profiles over time, and each profile has potentially multiple OperatingTimings in there.
E.g. one operation timing per type of operation... parse sql, transaction commit, etc...


Over time the number of profiles sky rockets.


Once could argue, that if the performance profiler were properly implemented.
Then the number of Profiles would stop growing over time.
Why?
Because the different operations supported by the application would eventually all get a Profile into a Map.
All entities covered on all operation types.

And the PerformanceProfile would be managing its list of profiles with some sort of Map OpertionTypexClass -> Profile aggregating time of all queries.

But this seems not to be the case.

So from the looks of it we have the:

1. public void endOperationProfile(String operationName) {

That does an unconditional addProfile. Does not check for any map to pump aggregated data.
So this is memory leaker number one.

2. We have public Object profileExecutionOfQuery(DatabaseQuery query, Record row, AbstractSession session) {

This is leaker number two.
Also uncoditionally adds a new profile for each query run.


Am I missing something, or is this code completely out of this world?

If I run system tests for 5 minutes with 1.5 GB heap my system is running out of memory.
Whatever burns you first, either cncurrency issues trying to get the profiling summary killing transactions.
Or the number of profiles in the system sky rocketing and the GC log gobbing all CPU trying to free up the un-freable, because the serverssion profiler is not going anywhere.

Am I missing something from the picture, or this Performance profiler completely unusable?
How can it be written in this manner?
From what I can see, the core idea is very good, but the implementation behind this is so terrible, that the full class needs to be re-written from scrath. This is my current impression.


This performance profiler, since it is keeping the data in memory, it clarly needs an Application Scoped state that will not grow to infinity.

The class needs proper comprhensible map map of OperationTypeKey -> To Aggregated statistics of total time.
And for each Value taken out of the map, there should be a simple operation to:
Merge Timings from current operation into Aggregated timings in this app scoped map.

Then the PerformanceProfiler would be only as big as the number of different profiles you need to qualif the ClassType -> Performance.
Or OperationType (e.g ReadAll, FetchById, et) -> Performance.


Finally, for the interested consumers, the performance profile should provide adequate publich apis to return summary as String or as metadata.
Not this thing of simply assuming we all want to write the summary to the session.Writer().

Many thanks for taking a look.
In my oppinion this issue is critical - because this is an analysis tool that appears to be there, but it is really not there. You will end up analysing the side effects of using this tool rather than the performanc of your system.

[Updated on: Mon, 05 June 2017 08:58]

Report message to a moderator

Re: Eclipselink PerformanceProfiler Not Thread Safe [message #1765198 is a reply to message #1764967] Wed, 07 June 2017 12:52 Go to previous message
Nuno G. de M. is currently offline Nuno G. de M.Friend
Messages: 30
Registered: September 2012
Member
One more note, I had noticed this already but forgot to mention above:

Please reveiw the documentation:
https://www.eclipse.org/eclipselink/documentation/2.5/solutions/performance002.htm

Milliseconds are not used anywhere on the PerformanceProfiler.
The base time unit is always nano-seconds.
E.g.
System.nanoTime();
is being used.

When you look at the summaries, you have to divide the value by a million all the time... to reach ms.

Many thanks for taking a look.
Previous Topic:Transaction isolation 2
Next Topic:eclipselink 2.6.4 STUCK thead
Goto Forum:
  


Current Time: Fri Dec 15 12:13:08 GMT 2017

Powered by FUDForum. Page generated in 0.02725 seconds
.:: Contact :: Home ::.

Powered by: FUDforum 3.0.2.
Copyright ©2001-2010 FUDforum Bulletin Board Software