Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.
Bug 338894 - [DB][Mysql] Exception when CDO is idle for a while
Summary: [DB][Mysql] Exception when CDO is idle for a while
Status: CLOSED FIXED
Alias: None
Product: EMF
Classification: Modeling
Component: cdo.core (show other bugs)
Version: 4.0   Edit
Hardware: All All
: P2 normal (vote)
Target Milestone: ---   Edit
Assignee: Caspar D. CLA
QA Contact: Eike Stepper CLA
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-03-04 03:07 EST by Egidijus Vaisnora CLA
Modified: 2011-06-23 03:38 EDT (History)
3 users (show)

See Also:
stepper: review+


Attachments
Patch (13.02 KB, patch)
2011-03-24 01:49 EDT, Caspar D. CLA
no flags Details | Diff
Patch v2 (13.02 KB, patch)
2011-03-24 02:23 EDT, Caspar D. CLA
no flags Details | Diff
Patch v3 (13.93 KB, patch)
2011-03-24 04:21 EDT, Caspar D. CLA
no flags Details | Diff
Patch v4 (22.15 KB, patch)
2011-04-04 01:41 EDT, Eike Stepper CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Egidijus Vaisnora CLA 2011-03-04 03:07:19 EST
I left CDO server idle for a while and found stack trace in log:

com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Last packet sent to the server was 1 ms ago.
	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
	at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
	at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1074)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2985)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2871)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3414)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1936)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2536)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465)
	at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1383)
	at org.eclipse.emf.cdo.server.internal.db.DBStoreAccessor$ConnectionKeepAliveTask.run(DBStoreAccessor.java:1285)
	at java.util.TimerThread.mainLoop(Timer.java:512)
	at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.SocketException: Connection reset
	at java.net.SocketInputStream.read(SocketInputStream.java:168)
	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:113)
	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:160)
	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:188)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2428)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2882)
	... 10 more
Comment 1 Stefan Winkler CLA 2011-03-04 03:27:20 EST
Can you specify what "a while" is, roughly?

MySQL disvonnects a client after an idle time of 8 hours (default value, please check your MySQL server for your setting).

To prevent the disconnection, there is a timer facility in CDO which should prevent this by issuing a query every 4 hours (again, this is a default value that can be configured).

That said, there has been some work in the past year (I think Eike did it) to reduce the amount of single timers on the server. Maybe something got optimized away too much ;-)
Comment 2 Egidijus Vaisnora CLA 2011-03-04 04:16:00 EST
I left it for a night... However I was able to use server after I discovered stack trace, hence I cannot say that it spoil server. On another hand, maybe server was responding by taking values from the cache, without connecting to DB, I cannot tell this exactly.
Comment 3 Caspar D. CLA 2011-03-23 05:29:54 EDT
(In reply to comment #1)
> To prevent the disconnection, there is a timer facility in CDO which should
> prevent this by issuing a query every 4 hours

Er, yes. As can be seen from the stack trace, it is this keepalive
statement itself that fails.

Logical (but not the only possible) conclusion: the MySQL instance that
caused this 'incident', disconnected the client before the keepAlive
task got executed, and that means earlier than 4 hours.

> (again, this is a default value that can be configured).

How is that? At DBStoreAccessor.java:750, the task gets scheduled with
hardcoded values...
Comment 4 Caspar D. CLA 2011-03-23 05:36:19 EDT
I propose we do two things:

1. Make the keepAlive period really configurable
2. If the keepAlive statement fails, try to open a new connection.
Comment 5 Caspar D. CLA 2011-03-24 01:49:49 EDT
Created attachment 191804 [details]
Patch
Comment 6 Caspar D. CLA 2011-03-24 02:09:08 EDT
MySQL's JDBC driver offers a property 'autoReconnect' which 
can be set to 'true' to make the driver itself attempt 
to reconnect when it discovers that the connection is no longer
alive. See:

http://dev.mysql.com/doc/refman/5.0/en/connector-j-reference-configuration-properties.html

Perhaps other drivers support something similar. Neverthless, the reconnect
code that I've added to ConnectionKeepAliveTask, is still useful for JDBC
drivers that do offer such support.
Comment 7 Caspar D. CLA 2011-03-24 02:20:13 EDT
As further info: in the case of MySQL, the disconnects can be avoided
altogether by configuring the MySQL server's wait_timeout variable to some
large value. As Stefan said, the default is 28800, i.e. 8 hours.
Comment 8 Caspar D. CLA 2011-03-24 02:23:02 EDT
Created attachment 191805 [details]
Patch v2
Comment 9 Caspar D. CLA 2011-03-24 04:21:49 EDT
Created attachment 191810 [details]
Patch v3
Comment 10 Eike Stepper CLA 2011-04-04 01:41:52 EDT
Created attachment 192435 [details]
Patch v4

Renamed xyzPropertyValues() to xyzPersistentProperties()
Comment 11 Eike Stepper CLA 2011-04-04 01:42:32 EDT
Please also add a section below http://wiki.eclipse.org/CDO/Server_Configuration_Reference#Element_store
Comment 12 Caspar D. CLA 2011-04-04 05:12:13 EDT
Committed revisions 7580, 7581, 7582, 7583, 7584.

Committed in chunks to work around inexplicable refusal of SVN client
to commit in one go. Will commit from command line from now on.
Comment 13 Caspar D. CLA 2011-04-04 05:39:36 EDT
Wiki updated.
Comment 14 Eike Stepper CLA 2011-06-23 03:38:36 EDT
Available in R20110608-1407