Bug #24706 MysqlIO serverStatus reset on checkErrorPacket
Submitted: 29 Nov 2006 22:26 Modified: 10 Jan 2007 19:39
Reporter: Mikle - Email Updates:
Status: Can't repeat Impact on me:
None 
Category:Connector / J Severity:S3 (Non-critical)
Version:3.1-nightly-20061213 OS:Any (ALL)
Assigned to: CPU Architecture:Any
Tags: java, performance, serverStatus

[29 Nov 2006 22:26] Mikle -
Description:
First of, I don't think I know what I am talking about and I am not sure if this is a bug (or unwanted behavior) or if this is the only way MySQL can function :-\

Short version
setAutocommit(...) goes to server even when when elideSetAutoCommits=true

Long version:
Driver version: 3.1.6
MysqlIO class has a method checkErrorPacket that's called from sendCommand... basically, see stack in the bottom. In this method there is a line "this.serverStatus = 0;" (line 2781). Same field is used to verify current status of autocommit set through API. Basically, what this means is that on checkErrorPacket we reset autocommit status on the IO object so even if I set elideSetAutoCommits=true autocommit status is still retrieved from the server.

On the surface this means that setAutocommit always goes to server, which is but a minor annoyance, however two minor annoyances combine into significant problem. DBCP calls setAutocommit from a synchronized block (already posted there, waiting for answer) and this creates a pretty nasty point of contention (basically, if I involve connection pool my rate drops to ~2-3 k/sec while without it I get 20-30 k easily and there is still room for improvement.

Code that uses serverStatus (same class):
protected boolean isSetNeededForAutoCommitMode(boolean autoCommitFlag) {
if (this.use41Extensions && this.connection.getElideSetAutoCommits()) {
boolean autoCommitModeOnServer = ((this.serverStatus &
SERVER_STATUS_AUTOCOMMIT) != 0);

Stack dump:
Thread [Thread-1] (Suspended)
MysqlIO.checkErrorPacket(int) line: 2788
MysqlIO.sendCommand(int, String, Buffer, boolean, String) line: 1534
MysqlIO.sqlQueryDirect(Statement, String, String, Buffer, int, Connection, int, int, boolean, String, boolean) line: 1625
Connection.execSQL(Statement, String, int, Buffer, int, int, boolean, boolean, String, boolean, byte) line: 2291
Connection.setAutoCommit(boolean) line: 496
PoolableConnection(DelegatingConnection).setAutoCommit(boolean) line: 268
PoolableConnectionFactory.passivateObject(Object) line: 355
GenericObjectPool.addObjectToPool(Object, boolean) line: 926
GenericObjectPool.returnObject(Object) line: 917
PoolableConnection.close() line: 80
PoolingDataSource$PoolGuardConnectionWrapper.close() line: 180
PropertySelectTest.test() line: 32
Starter$TestThread.run() line: 150

I hope this helps. 

How to repeat:
Set URL with elideSetAutoCommits=true
run setAutocommit(true) - this should not go to server since server status is still good (assuming the default is true)
run a query, this causes checkErrorPacket call and status reset
run setAutocommit(true). This one will go to the server even though it's pretty safe to assume autocommit status has not changed.

Suggested fix:
Not reset status or reset status on the flags other than "autocommit" (and whatever other pieces can be preserved). 
Basically instead of code
this.serverStatus = 0
 put code
this.serverStatus = serverStatus & SERVER_STATUS_AUTOCOMMIT;
[12 Dec 2006 11:05] Tonci Grgin
Hi Mikle and thanks for your report.
 - What is the MySQL server version you're using?
 - What is the JDK/JRE version you're using
Please try with new version as 3.1.6 is rather old (http://downloads.mysql.com/snapshots/mysql-connector-java-3.1/mysql-connector-java-3.1-nig...)
[14 Dec 2006 1:20] Mikle -
MySQL server 5 (MySQL-server-standard-5.0.27-0.rhel4 , 64bit build)
Java 5 (1.5.0_09)
I will try the newer driver build.
[14 Dec 2006 3:31] Mikle -
Idid test the latest nightly build (mysql-connector-java-3.1-nightly-20061213-bin.jar) and got the same results as before (both against MySQL 5 and against 4.1.20).
Both drivers performed similarly and the time difference is ~17 second when getting a connection once and reusing it vs. ~29 seconds using the pool (returning and reacquiring). I have to admit this time I did not got through the debug step to actually see the value being reset, please let me know if you need me to do this.

I hope this helps...

Code without reloading connection:
Connection conn1= ds.getConnection();
for(int i=0;i<lcount;i++){
	String sql= "select value from user_permission where user_id=? and permission_id=1";
	PreparedStatement stmt=conn1.prepareStatement(sql);
	stmt.setInt(1, UsernameGenerator.getUserId(id, lcount%400, i));
	ResultSet res=stmt.executeQuery();
	if(res.next()){
		log.debug("User found");
	}else{
		log.debug("User not found");
	}
	stmt.close();
}
conn1.close();

Code with reloading:
for(int i=0;i<lcount;i++){
	Connection conn1= ds.getConnection();
	String sql= "select value from user_permission where user_id=? and permission_id=1";
	PreparedStatement stmt=conn1.prepareStatement(sql);
	stmt.setInt(1, UsernameGenerator.getUserId(id, lcount%400, i));
	ResultSet res=stmt.executeQuery();
	if(res.next()){
		log.debug("User found");
	}else{
		log.debug("User not found");
	}
	stmt.close();
	conn1.close();
}
[14 Dec 2006 3:31] Mikle -
Sorry, accidentally closed it :-\
[14 Dec 2006 7:48] Tonci Grgin
Mikle, np. If it's ok by you, please change Version.
[16 Dec 2006 2:44] Mikle -
Version change (is this what you meant?)
[2 Jan 2007 17:51] Tonci Grgin
Hi Mikle. I agree with you on
"Basically, what this means is that on checkErrorPacket we reset autocommit status on the IO object so even if I set elideSetAutoCommits=true autocommit status is still retrieved from the server."
but we'll see what c/J team has to say.
[10 Jan 2007 19:39] Mark Matthews
The server status _needs_ to be reset on every query, that's how the protocol is designed to work (see libmysql.c -> cli_read_rows).

If the status isn't reporting correct autocommit status, then that's a bug, but I don't see how that relates to the issue reported here.

I put together a quick testcase, and tested it on 5.0.4 (the current GA release), and it performed as expected, not sending "set auto_commit=..." to the server at all (observed via breakpoints in Connection.setAutoCommit()):

public void testBug24706() throws Exception {
		Properties props = new Properties();
		props.setProperty("elideSetAutoCommits", "true");
		
		Connection c = getConnectionWithProps(props);
		c.setAutoCommit(true);
		c.createStatement().execute("SELECT 1");
		c.setAutoCommit(true);
	}

Could you try with Connector/J 5.0.x, as that is the current GA release, or alternatively if stuck on Connector/J 3.1.x, try using "useLocalSessionState=true", which is probably the optimization more along the lines of what you need?
[10 Jan 2007 19:51] Mark Matthews
Sorry, I should say I checked this with 5.0's HEAD. Try a nightly snapshot build of C/J 5.0 from http://downloads.mysql.com/snapshots.php#connector-j to see if it behaves how you expect.
[10 Jan 2007 21:04] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/17889