Jump to: navigation, search

Difference between revisions of "EclipseLink/Examples/JPA/Monitoring"

(New page: Monitoring EclipseLink supports a profiling and monitoring API through its [http://www.eclipse.org/eclipselink/api/2.2/org/eclipse/persistence/session...)
 
 
(5 intermediate revisions by the same user not shown)
Line 3: Line 3:
 
EclipseLink supports a profiling and monitoring API through its [http://www.eclipse.org/eclipselink/api/2.2/org/eclipse/persistence/sessions/SessionProfiler.html SessionProfiler] interface.  This interface gives events that allows a profiler or monitoring service to record performance or metrics on the EclipseLink application.
 
EclipseLink supports a profiling and monitoring API through its [http://www.eclipse.org/eclipselink/api/2.2/org/eclipse/persistence/sessions/SessionProfiler.html SessionProfiler] interface.  This interface gives events that allows a profiler or monitoring service to record performance or metrics on the EclipseLink application.
  
As of EclipseLink 2.2 a [http://www.eclipse.org/eclipselink/api/2.2/org/eclipse/persistence/tools/profiler/PerformanceMonitor.html PerformanceMonitor] is provided to collect performance an metric information.  When enabled the PerformanceMonitor will log the monitoring information at set intervals, allowing an application's performance to be analyzed.
+
As of EclipseLink 2.2 a [http://www.eclipse.org/eclipselink/api/2.2/org/eclipse/persistence/tools/profiler/PerformanceMonitor.html PerformanceMonitor] is provided to collect performance an metric information.  When enabled the PerformanceMonitor will log the monitoring information at set intervals to the session log, allowing an application's performance to be analyzed.
  
 
Previous to EclipseLink 2.2, a PerformanceProfiler was provided, but it did not make use of the complete SessionProfiler API, and was only useful for profiling a single use case, not a multi-user server.  A QueryMonitor was also provided that provided simple monitoring information on queries, but no detailed information.
 
Previous to EclipseLink 2.2, a PerformanceProfiler was provided, but it did not make use of the complete SessionProfiler API, and was only useful for profiling a single use case, not a multi-user server.  A QueryMonitor was also provided that provided simple monitoring information on queries, but no detailed information.
Line 14: Line 14:
 
</source>
 
</source>
  
==Monitoring Levels==
+
The PerformanceMonitor metrics can also be accessed through the API instead of dumping to the log.
  
 +
For example:
 +
<source lang="java">
 +
Integer cacheHits = (Integer)((PerformanceMonitor)session.getProfiler()).getOperationTimings().get(SessionProfiler.CacheHits);
 +
</source>
 +
 +
To  disable the monitor logging set the dump time to a large value.
 +
<source lang="java">
 +
Integer cacheHits = (Integer)((PerformanceMonitor)session.getProfiler()).setDumpTime(Integer.MAX_VALUE);
 +
</source>
 +
 +
===Monitoring Levels===
 +
The profile weight can be configured for the PerformanceMonitor through the API.  The default weight if the PerformanceMonitor is set is <code>ALL</code>.
 +
By default no profiler is set for a persistence unit, so no profiling or monitoring is done.
 +
The higher the level of monitoring the larger the performance overhead of the monitor.
  
 
{| border="1" cellpadding="5"
 
{| border="1" cellpadding="5"
Line 21: Line 35:
 
! Level !! Description
 
! Level !! Description
 
|-  
 
|-  
| OFF
+
| NONE
| This setting disables the generation of the log output. You may want to set logging to OFF during production to avoid the overhead of logging.
+
| No monitoring is done.
 
|-  
 
|-  
|    SEVERE
+
|    NORMAL
|    This level enables reporting of failure cases only. Usually, if the failure occurs, the application stops.
+
|    Metrics are tracked, but profiling is not done.
 
|-  
 
|-  
|    WARNING
+
|    HEAVY
|    This level enables logging of issues that have a potential to cause problems. For example, a setting that is picked by the application and not by the user.
+
|    Metrics and profiling times are tracked.
|-
+
|    INFO
+
|    This level enables the standard output. The contents of this output is very limited.  It is the default logging level if a logging level is not set.
+
|-
+
|    CONFIG
+
|    This level enables logging of such configuration details as your database login information and some metadata information. You may want to use the CONFIG log level at deployment time.
+
|-
+
|    FINE
+
|    This level enables logging of the first level of the debugging information and SQL. You may want to use this log level during debugging and testing, but not at production.
+
|-
+
|    FINER
+
|    This level enables logging of more debugging information than the FINE setting. For example, the transaction information is logged at this level. You may want to use this log level during debugging and testing, but not at production.
+
|-
+
|    FINEST
+
|    This level enables logging of more debugging information than the FINER setting, such as a very detailed information about certain features (for example, sequencing). You may want to use this log level during debugging and testing, but not at production.
+
 
|-  
 
|-  
 
|    ALL
 
|    ALL
|    This level currently logs at the same level as FINEST.
+
|    Metrics and profiling times are tracked.  
 +
|-
 
|}
 
|}
 +
 +
 +
===Example Output===
 +
The PerformanceMonitor displays three types of information, ''counters'', ''info'', and ''timers''.
 +
 +
A ''counter'' count the occurrence of an operation, such a a query, or cache hit.
 +
 +
An ''info'' records some static information, such as the time a session was connected, or the session's name.
 +
 +
A ''timer'' accumulates the total amount of time (in nano seconds) that a particular operation or query type took.
 +
 +
<pre>
 +
Performance Monitor:1279113281664
 +
Operation Value (ns)
 +
Counter:CacheHits 1,375,664
 +
Counter:CacheMisses 327
 +
Counter:ClientSessionCreates 1,204,817
 +
Counter:ConnectCalls 2
 +
Counter:DataModifyQuery 48
 +
Counter:DataModifyQuery:inventory 21
 +
Counter:DataModifyQuery:order 27
 +
Counter:DeleteObjectQuery 67,792
 +
Counter:DeleteObjectQuery:Customer 1
 +
...
 +
Counter:ReadAllQuery 1,041,767.
 +
Counter:ReadAllQuery:Item.findByCategory 733,827
 +
Counter:ReadAllQuery:Item.findByCategory:CacheHits 733,779
 +
Counter:ReadAllQuery:Item.findByCategory:CacheMisses 50
 +
...
 +
Counter:ReadObjectQuery 1,058,273
 +
Counter:ReadObjectQuery:Item:item 130,063
 +
Counter:ReadObjectQuery:Item:item:CacheHits 130,063
 +
Counter:ReadObjectQuery:Item:item:CacheMisses 1
 +
Counter:UnitOfWorkCommits 72,568
 +
Counter:UnitOfWorkCreates 471,491
 +
Counter:UnitOfWorkRollbacks 1
 +
Counter:UpdateObjectQuery 71,498
 +
Counter:UpdateObjectQuery:Customer 62,531
 +
...
 +
Info:LoginTime Wed Jul 14 08:55:41 EDT 2010
 +
Info:SessionName file:/scratch/user_domains/servers/mt-1/app.jar
 +
Timer:Caching 6,411,372,000
 +
Timer:ConnectionManagement 17,225,641,000
 +
Timer:DeleteObjectQuery 41,351,430,000
 +
Timer:DeleteObjectQuery:Customer 4,441,000
 +
Timer:DeleteObjectQuery:Customer:QueryPreparation 86,000
 +
Timer:DeleteObjectQuery:Customer:SqlGeneration 28,000
 +
Timer:DeleteObjectQuery:Customer:SqlPrepare 72,000
 +
Timer:DeleteObjectQuery:Customer:StatementExecute 2,265,000
 +
...
 +
Timer:InsertObjectQuery 69,111,086,000
 +
Timer:Logging 4,236,000
 +
Timer:Merge 1,144,400,000
 +
Timer:ObjectBuilding 31,914,397,000
 +
Timer:QueryPreparation 984,396,000
 +
Timer:ReadAllQuery 260,943,930,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory 14,790,333,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:ObjectBuilding 250,959,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:QueryPreparation 1,880,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:RowFetch 113,552,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:SqlGeneration 522,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:SqlPrepare 2,055,000
 +
Timer:ReadAllQuery:Item:Item.findByCategory:StatementExecute 107,382,000
 +
...
 +
Timer:Register 3,272,443,000
 +
Timer:RowFetch 25,340,990,000
 +
Timer:Sequencing 1,352,326,000
 +
Timer:SqlGeneration 6,646,000
 +
Timer:SqlPrepare 19,536,031,000
 +
Timer:StatementExecute 508,589,220,000
 +
Timer:TXAfterCompletion 1,854,152,000
 +
Timer:TXBeforeCompletion 169,381,843,000
 +
Timer:UnitOfWorkCommit 167,483,825,000
 +
Timer:UpdateObjectQuery 46,440,589,000
 +
Timer:UpdateObjectQuery:Customer 40,466,433,000
 +
Timer:UpdateObjectQuery:Customer:QueryPreparation 867,496,000
 +
Timer:UpdateObjectQuery:Customer:SqlGeneration 98,000
 +
Timer:UpdateObjectQuery:Customer:SqlPrepare 1,319,333,000
 +
Timer:UpdateObjectQuery:Customer:StatementExecute 32,901,366,000
 +
</pre>

Latest revision as of 13:00, 26 January 2011


EclipseLink supports a profiling and monitoring API through its SessionProfiler interface. This interface gives events that allows a profiler or monitoring service to record performance or metrics on the EclipseLink application.

As of EclipseLink 2.2 a PerformanceMonitor is provided to collect performance an metric information. When enabled the PerformanceMonitor will log the monitoring information at set intervals to the session log, allowing an application's performance to be analyzed.

Previous to EclipseLink 2.2, a PerformanceProfiler was provided, but it did not make use of the complete SessionProfiler API, and was only useful for profiling a single use case, not a multi-user server. A QueryMonitor was also provided that provided simple monitoring information on queries, but no detailed information.

The PerformanceMonitor is enabled through the "eclipselink.profiler" persistence unit property in the persistence.xml file.

Persistence unit property

<property name="eclipselink.profiler" value="PerformanceMonitor"/>

The PerformanceMonitor metrics can also be accessed through the API instead of dumping to the log.

For example:

Integer cacheHits = (Integer)((PerformanceMonitor)session.getProfiler()).getOperationTimings().get(SessionProfiler.CacheHits);

To disable the monitor logging set the dump time to a large value.

Integer cacheHits = (Integer)((PerformanceMonitor)session.getProfiler()).setDumpTime(Integer.MAX_VALUE);

Monitoring Levels

The profile weight can be configured for the PerformanceMonitor through the API. The default weight if the PerformanceMonitor is set is ALL. By default no profiler is set for a persistence unit, so no profiling or monitoring is done. The higher the level of monitoring the larger the performance overhead of the monitor.

Level Description
NONE No monitoring is done.
NORMAL Metrics are tracked, but profiling is not done.
HEAVY Metrics and profiling times are tracked.
ALL Metrics and profiling times are tracked.


Example Output

The PerformanceMonitor displays three types of information, counters, info, and timers.

A counter count the occurrence of an operation, such a a query, or cache hit.

An info records some static information, such as the time a session was connected, or the session's name.

A timer accumulates the total amount of time (in nano seconds) that a particular operation or query type took.

Performance Monitor:1279113281664
Operation	Value (ns)
Counter:CacheHits	1,375,664
Counter:CacheMisses	327
Counter:ClientSessionCreates	1,204,817
Counter:ConnectCalls	2
Counter:DataModifyQuery	48
Counter:DataModifyQuery:inventory	21
Counter:DataModifyQuery:order	27
Counter:DeleteObjectQuery	67,792
Counter:DeleteObjectQuery:Customer	1
...
Counter:ReadAllQuery	1,041,767.
Counter:ReadAllQuery:Item.findByCategory	733,827
Counter:ReadAllQuery:Item.findByCategory:CacheHits	733,779
Counter:ReadAllQuery:Item.findByCategory:CacheMisses	50
...
Counter:ReadObjectQuery	1,058,273
Counter:ReadObjectQuery:Item:item	130,063
Counter:ReadObjectQuery:Item:item:CacheHits	130,063
Counter:ReadObjectQuery:Item:item:CacheMisses	1
Counter:UnitOfWorkCommits	72,568
Counter:UnitOfWorkCreates	471,491
Counter:UnitOfWorkRollbacks	1
Counter:UpdateObjectQuery	71,498
Counter:UpdateObjectQuery:Customer	62,531
...
Info:LoginTime	Wed Jul 14 08:55:41 EDT 2010
Info:SessionName	file:/scratch/user_domains/servers/mt-1/app.jar
Timer:Caching	6,411,372,000
Timer:ConnectionManagement	17,225,641,000
Timer:DeleteObjectQuery	41,351,430,000
Timer:DeleteObjectQuery:Customer	4,441,000
Timer:DeleteObjectQuery:Customer:QueryPreparation	86,000
Timer:DeleteObjectQuery:Customer:SqlGeneration	28,000
Timer:DeleteObjectQuery:Customer:SqlPrepare	72,000
Timer:DeleteObjectQuery:Customer:StatementExecute	2,265,000
...
Timer:InsertObjectQuery	69,111,086,000
Timer:Logging	4,236,000
Timer:Merge	1,144,400,000
Timer:ObjectBuilding	31,914,397,000
Timer:QueryPreparation	984,396,000
Timer:ReadAllQuery	260,943,930,000
Timer:ReadAllQuery:Item:Item.findByCategory	14,790,333,000
Timer:ReadAllQuery:Item:Item.findByCategory:ObjectBuilding	250,959,000
Timer:ReadAllQuery:Item:Item.findByCategory:QueryPreparation	1,880,000
Timer:ReadAllQuery:Item:Item.findByCategory:RowFetch	113,552,000
Timer:ReadAllQuery:Item:Item.findByCategory:SqlGeneration	522,000
Timer:ReadAllQuery:Item:Item.findByCategory:SqlPrepare	2,055,000
Timer:ReadAllQuery:Item:Item.findByCategory:StatementExecute	107,382,000
...
Timer:Register	3,272,443,000
Timer:RowFetch	25,340,990,000
Timer:Sequencing	1,352,326,000
Timer:SqlGeneration	6,646,000
Timer:SqlPrepare	19,536,031,000
Timer:StatementExecute	508,589,220,000
Timer:TXAfterCompletion	1,854,152,000
Timer:TXBeforeCompletion	169,381,843,000
Timer:UnitOfWorkCommit	167,483,825,000
Timer:UpdateObjectQuery	46,440,589,000
Timer:UpdateObjectQuery:Customer	40,466,433,000
Timer:UpdateObjectQuery:Customer:QueryPreparation	867,496,000
Timer:UpdateObjectQuery:Customer:SqlGeneration	98,000
Timer:UpdateObjectQuery:Customer:SqlPrepare	1,319,333,000
Timer:UpdateObjectQuery:Customer:StatementExecute	32,901,366,000