Skip to main content


Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » EclipseLink » EL-2.5.2 - Creating a single table takes 15 seconds.(Every table takes 15 seconds to create. Multiple retryQuery() calls.)
EL-2.5.2 - Creating a single table takes 15 seconds. [message #1734618] Fri, 10 June 2016 00:59 Go to next message
Erwin Hogeweg is currently offline Erwin HogewegFriend
Messages: 37
Registered: July 2009
Member
HI,

Ever since we updated from EL-2.4.2 to 2.5.2 it takes forever to create a single table. We are running EL in a Java-7 OSGi environment with Aries 1.1 and JPA 2.1 and commons-dbcp 1.4_3.

The problem appears to be that EL takes some time (...) to verify that the table doesn't already exist.

I am sure I am doing something wrong, but can't find anything about it. I mucked around with various property setting, but nothing I tried made a difference.

Does anyone have an idea what is going on here? As soon as I switch back to EL-2.4.2 and JPA 2.0.5 the system is lightning fast again.

Tested with mySQL 5.6.14 on W7 and 5.6.17 on OS X.

DB log of a single table creation and stack of 'slow' call attached.

Any suggestions are greatly appreciated.

Regards

Erwin

[EL Info]: connection: 2016-06-09 19:49:46.483--bundleresource://85.fwk471108564/_east.pu login successful
[EL Fine]: sql: 2016-06-09 19:49:46.524--Connection(1308068571)--SELECT ID FROM TABLE_ONE WHERE ID <> ID
[EL Fine]: sql: 2016-06-09 19:49:46.54--SELECT 1
[EL Fine]: sql: 2016-06-09 19:49:46.557--Connection(1166650879)--SELECT ID FROM TABLE_ONE WHERE ID <> ID
[EL Fine]: sql: 2016-06-09 19:49:46.558--SELECT 1
[EL Fine]: sql: 2016-06-09 19:49:51.58--Connection(2084829361)--SELECT ID FROM TABLE_ONE WHERE ID <> ID
[EL Fine]: sql: 2016-06-09 19:49:51.58--SELECT 1
[EL Fine]: sql: 2016-06-09 19:49:56.599--Connection(333624863)--SELECT ID FROM TABLE_ONE WHERE ID <> ID
[EL Fine]: sql: 2016-06-09 19:49:56.599--SELECT 1
[EL Fine]: sql: 2016-06-09 19:50:01.615--Connection(134797004)--SELECT ID FROM TABLE_ONE WHERE ID <> ID
[EL Fine]: sql: 2016-06-09 19:50:01.616--SELECT 1
[EL Finest]: query: 2016-06-09 19:50:01.617--Execute query DataModifyQuery(sql="CREATE TABLE TABLE_ONE (ID BIGINT NOT NULL, DELETED TINYINT(1) default 0, LASTMODIFIED DATETIME, TYPE VARCHAR(255) NOT NULL UNIQUE, VERSION BIGINT, PRIMARY KEY (ID))")
[EL Finest]: connection: 2016-06-09 19:50:01.618--Connection(1370835841)--Connection acquired from connection pool [read].
[EL Finest]: connection: 2016-06-09 19:50:01.618--reconnecting to external connection pool
[EL Fine]: sql: 2016-06-09 19:50:01.626--Connection(2051185449)--CREATE TABLE TABLE_ONE (ID BIGINT NOT NULL, DELETED TINYINT(1) default 0, LASTMODIFIED DATETIME, TYPE VARCHAR(255) NOT NULL UNIQUE, VERSION BIGINT, PRIMARY KEY (ID))
[EL Finest]: connection: 2016-06-09 19:50:01.646--Connection(1370835841)--Connection released to connection pool [read].
[EL Finest]: ddl: 2016-06-09 19:50:01.646--The table (TABLE_ONE) is created.



Daemon Thread [Thread-58] (Suspended)	
	owns: EntityManagerFactoryDelegate  (id=119)	
		waited by: Daemon Thread [CM Configuration Updater (ManagedService Update: pid=[org.apache.aries.jpa.east.pu])] (Suspended)	
	Thread.sleep(long) line: not available [native method]	
	ServerSession(AbstractSession).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 1872	
	ServerSession(DatabaseSessionImpl).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 999	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1840	
	ServerSession(AbstractSession).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 1874	
	ServerSession(DatabaseSessionImpl).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 999	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1840	
	ServerSession(AbstractSession).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 1874	
	ServerSession(DatabaseSessionImpl).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 999	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1840	
	ServerSession(AbstractSession).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 1874	
	ServerSession(DatabaseSessionImpl).retryQuery(DatabaseQuery, AbstractRecord, DatabaseException, int, AbstractSession) line: 999	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord, int) line: 1840	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery, AbstractRecord) line: 1786	
	ServerSession(AbstractSession).executeQuery(DatabaseQuery) line: 1737	
	SchemaManager.checkTableExists(TableDefinition) line: 477	
	TableCreator.createTables(DatabaseSession, SchemaManager, boolean, boolean, boolean, boolean) line: 160	
	TableCreator.createTables(DatabaseSession, SchemaManager, boolean) line: 142	
	TableCreator.createTables(DatabaseSession, SchemaManager) line: 134	
	SchemaManager.createDefaultTables(boolean) line: 1032	
	EntityManagerFactoryProvider.generateDefaultTables(SchemaManager, EntityManagerSetupImpl$TableCreationType) line: 102	
	EntityManagerSetupImpl.writeDDLToDatabase(SchemaManager, EntityManagerSetupImpl$TableCreationType) line: 3999	
	EntityManagerSetupImpl.writeDDL(String, Map, DatabaseSessionImpl, ClassLoader) line: 3927	
	EntityManagerSetupImpl.writeDDL(Map, DatabaseSessionImpl, ClassLoader) line: 3827	
	EntityManagerSetupImpl.deploy(ClassLoader, Map) line: 728	
	EntityManagerFactoryDelegate.getAbstractSession() line: 204	
	EntityManagerFactoryDelegate.createEntityManagerImpl(Map, SynchronizationType) line: 304	
	EntityManagerFactoryImpl.createEntityManagerImpl(Map, SynchronizationType) line: 336	
	EntityManagerFactoryImpl.createEntityManager() line: 302	
	GenericRepositoryImpl<E>(AbstractRepository<E>).createEntityManager() line: 153	
	GenericRepositoryImpl<E>(AbstractRepository<E>).getAll() line: 336	
	SessionRepositoryImpl.getSystemInformation() line: 383	
	SystemInitializer.initialize() line: 30	
	Activator.init() line: 45	
	Activator.access$000(Activator) line: 22	
	Activator$1.run() line: 85	
	Thread.run() line: 745

Report message to a moderator

Re: EL-2.5.2 - Creating a single table takes 15 seconds. [message #1734859 is a reply to message #1734618] Mon, 13 June 2016 14:39 Go to previous messageGo to next message
Chris Delahunt is currently offline Chris DelahuntFriend
Messages: 1389
Registered: July 2009
Senior Member
The stack trace shows that the query is getting what it thinks is a communication failure, and so it is being retried a number of times. The exact exception would be logged at the INFO level as well as a message stating it is retrying the query, but unfortunately, the SchemaManager.checkTableExists turns off logging for the call - you might want to manually run the a "SELECT ID FROM TABLE_ONE WHERE ID <> ID" through EclipseLink to have it log what is going on outside of the table creation process.

I believe the MySQLPlatform class defines SQL it uses to ping the connection as "SELECT 1" that it uses to test the connection for validation within the DatabasePlatform's wasFailureCommunicationBased method, and this must be indicating that there is a problem with the connection forcing it to retry. You can customize either the method or the SQL used to control as described here: https://www.eclipse.org/forums/index.php/t/242811/

Report message to a moderator

Re: EL-2.5.2 - Creating a single table takes 15 seconds. [message #1734888 is a reply to message #1734618] Mon, 13 June 2016 14:39 Go to previous messageGo to next message
Chris Delahunt is currently offline Chris DelahuntFriend
Messages: 1389
Registered: July 2009
Senior Member
The stack trace shows that the query is getting what it thinks is a communication failure, and so it is being retried a number of times. The exact exception would be logged at the INFO level as well as a message stating it is retrying the query, but unfortunately, the SchemaManager.checkTableExists turns off logging for the call - you might want to manually run the a "SELECT ID FROM TABLE_ONE WHERE ID <> ID" through EclipseLink to have it log what is going on outside of the table creation process.

I believe the MySQLPlatform class defines SQL it uses to ping the connection as "SELECT 1" that it uses to test the connection for validation within the DatabasePlatform's wasFailureCommunicationBased method, and this must be indicating that there is a problem with the connection forcing it to retry. You can customize either the method or the SQL used to control as described here: https://www.eclipse.org/forums/index.php/t/242811/

Report message to a moderator

Re: EL-2.5.2 - Creating a single table takes 15 seconds. [message #1734895 is a reply to message #1734618] Mon, 13 June 2016 14:39 Go to previous messageGo to next message
Chris Delahunt is currently offline Chris DelahuntFriend
Messages: 1389
Registered: July 2009
Senior Member
The stack trace shows that the query is getting what it thinks is a communication failure, and so it is being retried a number of times. The exact exception would be logged at the INFO level as well as a message stating it is retrying the query, but unfortunately, the SchemaManager.checkTableExists turns off logging for the call - you might want to manually run the a "SELECT ID FROM TABLE_ONE WHERE ID <> ID" through EclipseLink to have it log what is going on outside of the table creation process.

I believe the MySQLPlatform class defines SQL it uses to ping the connection as "SELECT 1" that it uses to test the connection for validation within the DatabasePlatform's wasFailureCommunicationBased method, and this must be indicating that there is a problem with the connection forcing it to retry. You can customize either the method or the SQL used to control as described here: https://www.eclipse.org/forums/index.php/t/242811/

Report message to a moderator

Re: EL-2.5.2 - Creating a single table takes 15 seconds. [message #1734984 is a reply to message #1734888] Tue, 14 June 2016 11:53 Go to previous messageGo to next message
Sebastien Libert is currently offline Sebastien LibertFriend
Messages: 5
Registered: June 2016
Junior Member
Hi,

Indeed, seems to be tight to connection time. Couldn't it be the famous too-slow-reverse-dns ?
http://dev.mysql.com/doc/refman/5.7/en/server-options.html#option_mysqld_skip-name-resolve



Regards

Report message to a moderator

Re: EL-2.5.2 - Creating a single table takes 15 seconds. - SOLVED [message #1735432 is a reply to message #1734888] Sun, 19 June 2016 12:33 Go to previous message
Erwin Hogeweg is currently offline Erwin HogewegFriend
Messages: 37
Registered: July 2009
Member
Thanks Chris,

You pointed me in the right directions.

This is the EclipseLink exception:
Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'OPTION SQL_SELECT_LIMIT=1' at line 1
Error Code: 1064
Call: SELECT ID FROM TABLE_ONE WHERE ID <> ID
Query: DataReadQuery(sql="SELECT ID FROM TABLE_ONE WHERE ID <> ID")


Searching for the error I came across this link:
http://stackoverflow.com/questions/15274768/how-to-resolve-incorrect-sql-syntax-error-when-using-dimension-lookup-update

Due to an error in my pom config I wasn't using the latest mysql connector. Updating from 5.1.16 to 5.1.33 solved the problem.


Regards,

Erwin

Report message to a moderator

Previous Topic:Create CriteriaQuery against DynamicEntity
Next Topic:Memory issue with PostgreSQL
Goto Forum:
  

[ Syndicate this forum (XML) ] [ RSS ]

Current Time: Thu Apr 25 16:37:15 GMT 2024

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

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

Back to the top

Sign up to our Newsletter

A fresh new issue delivered monthly