Bug 60889 - JMeter JDBC sample calls SELECT USER() when testing with MySQL JDBC due to Connection#toString call for response headers
Summary: JMeter JDBC sample calls SELECT USER() when testing with MySQL JDBC due to Co...
Status: RESOLVED FIXED
Alias: None
Product: JMeter
Classification: Unclassified
Component: Main (show other bugs)
Version: 3.1
Hardware: All All
: P2 normal (vote)
Target Milestone: ---
Assignee: JMeter issues mailing list
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-03-20 01:14 UTC by Liu XP
Modified: 2017-05-27 15:07 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Liu XP 2017-03-20 01:14:53 UTC
JMeter 3.1 JDBC sample will call SELECT USER() each time before execution SQL.
It maybe relative with commons-pool2-2.4.2.jar package. But the behaviour is not reasonable.
Comment 1 Philippe Mouawad 2017-03-20 21:08:12 UTC
(In reply to Liu XP from comment #0)
> JMeter 3.1 JDBC sample will call SELECT USER() each time before execution
> SQL.
> It maybe relative with commons-pool2-2.4.2.jar package. But the behaviour is
> not reasonable.

Hello,
What is the Database you're using ?
What make you think this request is emitted ?

Thank you
Comment 2 Philippe Mouawad 2017-03-20 21:09:54 UTC
(In reply to Philippe Mouawad from comment #1)
> (In reply to Liu XP from comment #0)
> > JMeter 3.1 JDBC sample will call SELECT USER() each time before execution
> > SQL.
> > It maybe relative with commons-pool2-2.4.2.jar package. But the behaviour is
> > not reasonable.
> 
> Hello,
> What is the Database you're using ?
> What make you think this request is emitted ?
> 
> Thank you

Hi,
It's not due to commons-pool, it could have been related to commons-dbcp.

But IMO, I think you may have a validation query in your test plan.

Regards
Comment 3 Liu XP 2017-03-21 16:32:35 UTC
Hi Philippe,

There is default validation query SELECT 1 in JDBC Connection Configuration.
And I captured both query "SELECT 1" and "SELECT USER()" by Wireshark.
I used MySQL 5.6+ to duplicate this case. And it is not relative with MySQL server version.

And You corrected my type mistook. This behaviour could have been related to commons-dbcp2.
Comment 4 Philippe Mouawad 2017-03-21 20:43:23 UTC
Hi,
Can you try setting test while idle to false ?
And report if you still see this query ?
I would expect the following behaviour:
1) test while idle to false : No query
2) test while idle == true + No Validation query => SELECT USER() is emitted
3) test while idle == true + Validation query => validation query is emitted


In case 3) are you seeing the 2 queries ?
Thanks
Comment 5 Liu XP 2017-03-22 06:33:09 UTC
Hi,

This is result. I listed Request Query & Request Quit in Wireshark.
The Query "SELECT USER()" could be found in each test case.
1) test while idle to false : No query
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Command: Ping (14)        -- test ping instead of validation query.
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: SELECT USER()        -- stubborn query.
Statement: select Name from zabbixkey;        -- test JDBC Request
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)


2) test while idle == true + No Validation query => SELECT USER() is emitted
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Command: Ping (14)        -- test ping instead of validation query.
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: SELECT USER()        -- stubborn query.
Statement: select Name from zabbixkey;        -- test JDBC Request
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)


3) test while idle == true + Validation query => validation query is emitted
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: Select 1        -- Yes, this is my validation query.
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)
Statement [truncated]: /* mysql-connector-java-5.1.40 ( Revision: 402933ef52cad9aa82624e80acbea46e3a701ce6 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: SELECT USER()        -- stubborn query.
Statement: select Name from zabbixkey;        -- test JDBC Request
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)

Thanks,
LiuXP
Comment 6 Philippe Mouawad 2017-03-28 20:38:35 UTC
Hello,
I looked into code of MySQL driver :
mysql-connector-java-5.1.41-bin

"select User()" is triggered by DatabaseMetaData#getUserName()

Query cannot be in commons-dbcp, so it should have been in driver through isValid()
Connection#isValid of MySQL Driver calls ping() not this query.

Could you check if you have this issue with 5.1.41 ?

Thanks
Comment 7 Liu XP 2017-03-29 05:35:00 UTC
Hi Philippe,

It is relative with JMeter JDBC Sampler JDBCSampler.java line 88 res.setResponseHeaders(conn.toString());
The toString method is Overrided by DBCP2 DelegatingConnect.java line 101 toString(). And it will call meta.getUserName() in MySQL JDBC function.

I comment conn.toString() line 88 and used following code to set ResponseHeaders.
It could avoid to calling "SELECT USER()" Query.

            //res.setResponseHeaders(conn.toString());
            res.setResponseHeaders("DB Pool Name: " + getDataSource() + ";\nConnect Catalog: " + conn.getCatalog());
Comment 8 Liu XP 2017-04-06 09:23:01 UTC
Hi Philippe,

This issue could be reproduced with MySQL JDBC 5.1.41. The following is my patch info. It could depress the SELECT USER() Query.
------------------------------------------------
--- a/src/protocol/jdbc/org/apache/jmeter/protocol/jdbc/sampler/JDBCSampler.java
+++ b/src/protocol/jdbc/org/apache/jmeter/protocol/jdbc/sampler/JDBCSampler.java
@@ -80,7 +80,7 @@ public class JDBCSampler extends AbstractJDBCTestElement implements Sampler, Tes
             } finally {
                 res.connectEnd();
             }
-            res.setResponseHeaders(conn.toString());
+            res.setResponseHeaders("DB Pool Name: " + getDataSource() + ";\nConnect Catalog: " + conn.getCatalog());
             res.setResponseData(execute(conn, res));
         } catch (SQLException ex) {
             final String errCode = Integer.toString(ex.getErrorCode());
------------------------------------------------

MySQL JDBC 5.1.41 Wireshark:
Statement [truncated]: /* mysql-connector-java-5.1.41 ( Revision: 83c6dc41b96809df81444362933043b20a1d49d5 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: Select 1
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)
Statement [truncated]: /* mysql-connector-java-5.1.41 ( Revision: 83c6dc41b96809df81444362933043b20a1d49d5 ) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@charac
Statement: SET NAMES utf8
Statement: SET character_set_results = NULL
Statement: SET autocommit=1
Statement: SET autocommit=0
Statement: SELECT USER()
Statement: select Name from zabbixkey;
Statement: select @@session.tx_read_only
Statement: rollback
Statement: SET autocommit=1
Command: Quit (1)


Thanks,
LiuXP
Comment 9 Philippe Mouawad 2017-04-06 15:02:18 UTC
Hello,
Thanks for this feedback.

My main concern is backward compatibility and impact of modifying this.
conn.getCatalog() could trigger also a jdbc call in other drivers and would result in the same issue.

Would it be possible for you to tell me what you get as HTTP REquest headers when using JMeter 2.13 ?

The ideal solution would be to call a method that will not trigger any call the DB Server.
Comment 10 Liu XP 2017-04-06 16:27:12 UTC
Hi,

When using JMeter 2.13, we can see following info in JDBC sampler header. The header info is not valuable.

Response headers:
com.mysql.jdbc.JDBC4Connection@4895c35b


For HTTP Response headers, it is included valuable info from server side such as Content-Encoding,Connection keep-alive,Server info,Set-Cookie and so on. I am don't know how to find JDBC Sampler reference solution from HTTP Request.
Comment 11 Philippe Mouawad 2017-04-06 16:30:31 UTC
(In reply to Liu XP from comment #10)
> Hi,
> 
> When using JMeter 2.13, we can see following info in JDBC sampler header.
> The header info is not valuable.
> 
> Response headers:
> com.mysql.jdbc.JDBC4Connection@4895c35b

Is information provided by 3.1 more valuable ? 
And With your patch ?

My opinion is that we should not put any information that impacts load on DB Server or response times. So I would tend to only put the first part of your patch.
We would not loose anything compared to 2.13 and maybe few limited information compared to 3.1


> 
> 
> For HTTP Response headers, it is included valuable info from server side
> such as Content-Encoding,Connection keep-alive,Server info,Set-Cookie and so
> on. I am don't know how to find JDBC Sampler reference solution from HTTP
> Request.

Yes because HTTP headers has a real meaning. DB response header is not a real concept
Comment 12 Liu XP 2017-04-07 03:35:05 UTC
In JMeter 3.1 response, we can see more info about the JDBC URL and DriverName.
It is good for us know detail JDBC pool info that was used by JDBC sampler in View Results Tree.

3.1 Response headers:
1190470568, URL=jdbc:mysql://10.100.17.1:3306/test?useUnicode=true&characterEncoding=utf-8, UserName=test@10.101.20.49, MySQL-AB JDBC Driver

I think JDBC pool name, JDBC URL and DriverName is valuable in response. And I agree with your opinion that we should not put any information that impacts load on DB Server or response times. And your patch suggestion is also reasonable.
Comment 13 Philippe Mouawad 2017-04-07 16:49:58 UTC
(In reply to Liu XP from comment #12)
> In JMeter 3.1 response, we can see more info about the JDBC URL and
> DriverName.
> It is good for us know detail JDBC pool info that was used by JDBC sampler
> in View Results Tree.
> 
> 3.1 Response headers:
> 1190470568,
> URL=jdbc:mysql://10.100.17.1:3306/test?useUnicode=true&characterEncoding=utf-
> 8, UserName=test@10.101.20.49, MySQL-AB JDBC Driver
> 
> I think JDBC pool name, JDBC URL and DriverName is valuable in response. 

Unfortunately giving such information requires for now calling a method on Connection which might trigger a server call.
Fixing that would require storing this info in DataSourceComponentImpl (see DataSourceComponent.java) so that it can be reused in JDBCSampler class in 
DataSourceElement.getConnection(getDataSource()); which would need to be changed.

If you want this to be integrated before 3.2 release, then please provide a PR, otherwise we'll have to wait after that.

A quick fix is to just call:
res.setResponseHeaders(getDataSource());

This would not lose information compared to 2.13 but it would compared to 3.0/3.1. And I don't know if many users use this information.




And
> I agree with your opinion that we should not put any information that
> impacts load on DB Server or response times. And your patch suggestion is
> also reasonable.
Comment 14 Philippe Mouawad 2017-04-19 20:10:01 UTC
Hi Team ,
Any thoughts on this ?

Thanks
Comment 15 Felix Schumacher 2017-04-30 10:46:54 UTC
As the info was totally unusable in older versions, I don't think, that many people are relying on this information and changing it, will have no big impact (hopefully:)

As Liu is interested in url, db driver and connection pool instance, I think we should use that. Those should -- without looking it up -- have no impact in form of database calls.
Comment 16 Philippe Mouawad 2017-04-30 10:49:03 UTC
(In reply to Felix Schumacher from comment #15)
> As the info was totally unusable in older versions, I don't think, that many
> people are relying on this information and changing it, will have no big
> impact (hopefully:)
> 
> As Liu is interested in url, db driver and connection pool instance, I think
> we should use that. Those should -- without looking it up -- have no impact
> in form of database calls.

Hi Felix, to add what Liu wants we need to make some non minor changes to pass the information from Configuration component to Request components.
Comment 17 Felix Schumacher 2017-04-30 11:01:41 UTC
My comment aimed at using the connection instance, to ask for information. This is ignoring the possibility, that that might trigger a database call.

Do you think that risk is too high?
Comment 18 Philippe Mouawad 2017-05-27 15:06:41 UTC
Author: pmouawad
Date: Sat May 27 15:06:20 2017
New Revision: 1796408

URL: http://svn.apache.org/viewvc?rev=1796408&view=rev
Log:
Bug 60889 - JMeter JDBC sample calls SELECT USER() when testing with MySQL JDBC due to Connection#toString call for response headers
Bugzilla Id: 60889

Modified:
    jmeter/trunk/src/protocol/jdbc/org/apache/jmeter/protocol/jdbc/config/DataSourceElement.java
    jmeter/trunk/src/protocol/jdbc/org/apache/jmeter/protocol/jdbc/sampler/JDBCSampler.java
    jmeter/trunk/xdocs/changes.xml