users@glassfish.java.net

Glassfish 2.1 Toplink performance degrades significantly

From: <glassfish_at_javadesktop.org>
Date: Tue, 27 Jan 2009 16:16:49 PST

Recently I switched to Glassfish 2.1 from Glassfish 2u2 and found that Toplink (JPA) performance decreased in at least 3 times for a simple query "SELECT a from Attribute a".

When I copy toplink*.jar from Glassfish 2u2 the problem vanishes.

Here's what I see in the logs (the difference exactly matches the performance decrease I see):

GLassfish 2.1 + Toplink from 2u2

[#|2009-01-28T02:06:12.324+0300|FINER|sun-appserver2.1|-persistence-unit.weaver|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|Weaver transformed class [com/sun/gtee/entity/Watch].|#]
[#|2009-01-28T02:06:12.731+0300|FINER|sun-appserver2.1|-persistence-unit.connection|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|client acquired|#]
[#|2009-01-28T02:06:12.736+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|TX binding to tx mgr, status=STATUS_ACTIVE|#]

... lots of "Register the existing object"...


[#|2009-01-28T02:06:48.867+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|TX beforeCompletion callback, status=STATUS_ACTIVE|#]
[#|2009-01-28T02:06:48.867+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|begin unit of work commit|#]
[#|2009-01-28T02:06:48.982+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|TX afterCompletion callback, status=COMMITTED|#]
[#|2009-01-28T02:06:48.982+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=19;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=77959e54-1560-4751-b975-52830a501c8c;|end unit of work commit|#]
[#|2009-01-28T02:06:49.156+0300|FINER|sun-appserver2.1|-persistence-unit.connection|_ThreadID=20;_ThreadName=Finalizer;ClassName=null;MethodName=null;_RequestID=63840d49-8fba-486b-877f-01e11944876c;|client released|#]

-- these last five are fast


SWITCHED TO TOPLINK from Glassfish 2.1

[#|2009-01-28T02:09:09.804+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;ClassName=null;MethodName=null;_RequestID=d46505fb-d76b-4487-932b-e44776d16828;|TX beforeCompletion callback, status=STATUS_ACTIVE|#]
[#|2009-01-28T02:09:09.804+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;ClassName=null;MethodName=null;_RequestID=d46505fb-d76b-4487-932b-e44776d16828;|begin unit of work commit|#]
[#|2009-01-28T02:09:21.894+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;ClassName=null;MethodName=null;_RequestID=d46505fb-d76b-4487-932b-e44776d16828;|TX afterCompletion callback, status=COMMITTED|#]
[#|2009-01-28T02:09:21.894+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=17;_ThreadName=httpSSLWorkerThread-8080-1;ClassName=null;MethodName=null;_RequestID=d46505fb-d76b-4487-932b-e44776d16828;|end unit of work commit|#]

[#|2009-01-28T02:09:32.650+0300|FINER|sun-appserver2.1|-persistence-unit.connection|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|client acquired|#]
[#|2009-01-28T02:09:32.656+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|TX binding to tx mgr, status=STATUS_ACTIVE|#]


... lots of "Register the existing object"...

[#|2009-01-28T02:09:34.332+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|TX beforeCompletion callback, status=STATUS_ACTIVE|#]
[#|2009-01-28T02:09:34.332+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|begin unit of work commit|#]
[#|2009-01-28T02:09:40.325+0300|FINER|sun-appserver2.1|-persistence-unit.connection|_ThreadID=19;_ThreadName=Finalizer;ClassName=null;MethodName=null;_RequestID=8df7777d-a620-4c01-bbd0-1668349d1883;|client released|#]
[#|2009-01-28T02:09:46.193+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|TX afterCompletion callback, status=COMMITTED|#]
[#|2009-01-28T02:09:46.194+0300|FINER|sun-appserver2.1|-persistence-unit.transaction|_ThreadID=18;_ThreadName=httpSSLWorkerThread-8080-0;ClassName=null;MethodName=null;_RequestID=42eb37c6-b68b-4be2-8b79-aa6ee6079be5;|end unit of work commit|#]
These last five are very slow. There are two 6 second delays.

I removed
oracle.toplink.essentials.session.file:/export/opt/glassfish/domains/domain1/applications/j2ee-apps/myapp/myapp-ejb_jar/-myapp in the middle of sun-appserver2.1..|-persistence
to make it a bit shorter.

The Attribute entity in question is rather simple (id, name, value), the table contains 8000 of rows.
[Message sent by forum member 'nzinoviev' (nzinoviev)]

http://forums.java.net/jive/thread.jspa?messageID=328523