Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Implement PreparedStatement caching for performance #166

Closed
davidfrankson opened this issue Mar 2, 2017 · 75 comments
Closed

Implement PreparedStatement caching for performance #166

davidfrankson opened this issue Mar 2, 2017 · 75 comments
Labels
Enhancement An enhancement to the driver. Lower priority than bugs.

Comments

@davidfrankson
Copy link

To support modern versions of Hibernate, we need a JDBC 4 driver and we are looking to switch from our existing jtds driver http://jtds.sourceforge.net/ to Microsoft’s JDBC driver. Performance problems prevent us from switching.

When we run a load test simulating our toughest workload, Solarwinds DPA is recording 7 times the cpu/memory wait time, big spikes on SQL compiles / sec and an overall doubling of cpu usage overall. The performance problems occur because the MS driver does not support statement pooling and does not reuse PreparedStatements.

A older comment on your jdbcteam blog summarizes this need very well, I will copy/paste it here:

Brett.Wooldridge
December 1, 2015 at 4:47 pm
Hello JDBC Team,
I am the principal developer of HikariCP (https://github.com/brettwooldridge/HikariCP), the fastest growing connection pool for Java.
We frequently are asked to implement PreparedStatement caching within the pool, but our stance has always been and continues to be that caching belongs in the driver. On behalf of our MS SQL Server users, I would like to request the implementation of PreparedStatement caching.
A survey of the Top 5 databases (https://dzone.com/articles/10-most-popular-db-engines-sql) leaves only SQL Server out without prepared statement caching.
Ironically, SQL Server's JDBC driver has a property, disableStatementPooling, which defaults to *true. Only true is supported currently (setting to false will throw an exception).
It was literally HikariCP's stand against placing responsibility of caching in the pool that prompted PostgreSQL to implement their very excellent solution (pgjdbc/pgjdbc#308).
The PostgreSQL implementation took one developer 3 days from start to finish.
In this new Satya Nadella era, isn't this the time for Microsoft to prove that it can be just as agile as the open source databases? The 6.0 Preview is the perfect chance to introduce this long needed feature.
Regards,
Brett Wooldridge

More from Brett regarding Statement Caching and why it is needed at the driver is on the HikariCP site:
https://github.com/brettwooldridge/HikariCP

Statement Cache
Many connection pools, including Apache DBCP, Vibur, c3p0 and others offer PreparedStatement caching. HikariCP does not. Why?
At the connection pool layer PreparedStatements can only be cached per connection. If your application has 250 commonly executed queries and a pool of 20 connections you are asking your database to hold on to 5000 query execution plans -- and similarly the pool must cache this many PreparedStatements and their related graph of objects.
Most major database JDBC drivers already have a Statement cache that can be configured, including PostgreSQL, Oracle, Derby, MySQL, DB2, and many others. JDBC drivers are in a unique position to exploit database specific features, and nearly all of the caching implementations are capable of sharing execution plans across connections. This means that instead of 5000 statements in memory and associated execution plans, your 250 commonly executed queries result in exactly 250 execution plans in the database. Clever implementations do not even retain PreparedStatement objects in memory at the driver-level but instead merely attach new instances to existing plan IDs.
Using a statement cache at the pooling layer is an anti-pattern, and will negatively impact your application performance compared to driver-provided caches.

I wrote simple PreparedStatement test programs that execute a simple select PreparedStatement on AdventureWorks2014 10k times on a SQL 2016 instance. Jtds completed in 19 seconds, the ms driver in 35 seconds and there was significantly more load placed onto the SQL Server instance. You can see why in a SQL Profiler trace.

Microsoft:

image

The MS driver is constantly preparing and unpreparing a statement on every execution. I used mssql-jdbc-6.1.4.jre7-preview.

jTDS:

image

Jtds prepares things once and then reuses the PreparedStatement.

The source of those tester programs are attached if they are of value to anyone. The postgres driver implemented statement caching a couple years ago and it could be used if you want ideas on how to implement it: pgjdbc/pgjdbc#319

jdbc.zip

@v-nisidh
Copy link
Contributor

v-nisidh commented Mar 3, 2017

@davidfrankson Thanks for adding this issue with valuable data. We will keep you updated.

@v-nisidh v-nisidh added the Enhancement An enhancement to the driver. Lower priority than bugs. label Mar 3, 2017
@gordthompson
Copy link
Contributor

Here's a thought:

Perhaps the JDBC driver can offer the option to simply omit the sp_unprepare calls so that the command text from the Prepared Statement remains in the execution plan cache on the SQL Server. That seems to be what System.Data.SqlClient does by default in .NET.

When I run the C# code ...

using (var conn = new SqlConnection(connStrSqlClient))
{
    conn.Open();
    for (int i = 1; i <= 3; i++)
    {
        using (var cmd = new SqlCommand("SELECT COUNT(*) AS n FROM sys.tables WHERE @x=@y", conn))
        {
            cmd.Parameters.Add("@x", System.Data.SqlDbType.Int);
            cmd.Parameters.Add("@y", System.Data.SqlDbType.Int);
            cmd.Prepare();
            cmd.Parameters["@x"].Value = i;
            cmd.Parameters["@y"].Value = i;
            using (SqlDataReader rdr = cmd.ExecuteReader()) { }
        }
    }
}

... I see something like this in SQL Profiler:

exec sp_prepexec @p1 output,N'@x int,@y int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @x=@y',@x=1,@y=1
exec sp_prepexec @p1 output,N'@x int,@y int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @x=@y',@x=2,@y=2
exec sp_prepexec @p1 output,N'@x int,@y int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @x=@y',@x=3,@y=3

Compare with the corresponding Java code ...

try (Connection conn = DriverManager.getConnection(connUrl, myUid, myPwd)) {
    for (int i = 1; i <= 3; i++) {
        try (PreparedStatement ps = conn.prepareStatement("SELECT COUNT(*) AS n FROM sys.tables WHERE ?=?")) {
            ps.setInt(1, i);
            ps.setInt(2, i);
            try (ResultSet rs = ps.executeQuery()) { }
        }
    }
}

... for which SQL Profiler shows me

exec sp_prepexec @p1 output,N'@P0 int,@P1 int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @P0=@P1                ',1,1
exec sp_unprepare 1
exec sp_prepexec @p1 output,N'@P0 int,@P1 int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @P0=@P1                ',2,2
exec sp_unprepare 2
exec sp_prepexec @p1 output,N'@P0 int,@P1 int',N'SELECT COUNT(*) AS n FROM sys.tables WHERE @P0=@P1                ',3,3
exec sp_unprepare 3

@Arthurm1
Copy link

Arthurm1 commented Mar 6, 2017

The idea is to limit the sp_prepare/sp_prepexec statements so the SQL is not repeatedly parsed and planned.

SQL Server will keep the query in its execution plan cache even after sp_unprepare is called so there shouldn't be any performance difference between the .NET and Java examples.

I don't know why the SQL Server execution plan cache is much slower than using a driver level one like jTDS does. Maybe it's down to the large size of the cache or that it includes non-prepared statements.

The .NET trace seems strange - does the .NET driver never call sp_unprepare? Surely that just runs up resources?

@gordthompson
Copy link
Contributor

@Arthurm1

re: "SQL Server will keep the query in its execution plan cache even after sp_unprepare is called"

That's not what the documentation for sp_unprepare says:

Discards the execution plan created by the sp_prepare stored procedure.


re: "so there shouldn't be any performance difference between the .NET and Java examples"

Some rudimentary testing against a local SQL Server 2014 instance:

1) Current: current mssql-jdbc implementation

DBCC FREEPROCCACHE
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',1
exec sp_unprepare 1
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',2
exec sp_unprepare 2
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',3
exec sp_unprepare 3
...
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',10000
exec sp_unprepare 10000

11.2 seconds

2) Ideal: 1 sp_prepexec and (n-1) sp_execute calls

DBCC FREEPROCCACHE
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',1
exec sp_execute 1,2
exec sp_execute 1,3
...
exec sp_execute 1,10000
exec sp_unprepare 1

6.8 seconds: 61% of current

3) Proposed: current with exec sp_unprepare suppressed

DBCC FREEPROCCACHE
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',1
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',2
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',3
...
exec sp_prepexec @p1 output,N'@P0 int',N'SELECT * FROM test10k WHERE id=@P0        ',10000

8.0 seconds: 71% of current


re: "does the .NET driver never call sp_unprepare?"

That appears to be the case. sp_unprepare does not show up anywhere in the SQL Profiler trace.

@davidfrankson
Copy link
Author

davidfrankson commented Mar 6, 2017

The jtds driver also doesn't call sp_unprepare. I looked at the SQL proc cache and sp_unprepare does not remove the compiled plan, so I don't know if it does anything other than waste a roundtrip.

SELECT * FROM sys.dm_exec_cached_plans AS cp CROSS APPLY sys.dm_exec_sql_text(cp.plan_handle) st WHERE cp.cacheobjtype = N'Compiled Plan' AND cp.objtype IN(N'Prepared')

Making a minor fix like this would alleviate some of the wait time experienced at the client, but our main concern is the impact on the SQL hardware. Preparing all those plans consumes too much db resources.

@Arthurm1
Copy link

Arthurm1 commented Mar 6, 2017

@gordthompson
I'm surprised that just not calling sp_unprepare increases the performance so much.

Could you try an additional test using sp_executeSQL e.g.
exec sp_executeSQL N'SELECT * FROM test10k WHERE id=@P0',N'@P0 int', @p0=XXXXX
It's how jTDS runs if you turn off prepareSQL.

@davidfrankson
I think jTDS starts unpreparing old statements once more than maxStatements have been prepared.

@TobiasSQL
Copy link
Contributor

TobiasSQL commented Mar 6, 2017

Let me see if I can help clarify some things around how SQL Server does this to make sure I understand the issue.

First of all, SQL Server does do plan caching across connections without the use of prepared statements.

Example:
-- Connection #1
SELECT * FROM sys.tables

-- Connection #2
SELECT * FROM sys.tables

-- Check the procedure cache on any connection
SELECT *
FROM sys.dm_exec_cached_plans AS p
CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
WHERE s.text LIKE 'SELECT * FROM sys.tables';

Note that the output of the "usecounts" column is 2, i.e. the same compiled plan was used for both executions and SQL Server did not need to ask the query optimizer to create a new plan.

There are issues with the re-use of plans if the batch is not parameterized and SQL Server has to do auto-parameterization. sp_executesql is how the driver communicates explicit parameter definitions to the server in the non-prepared case (e.g. SELECT * FROM sys.tables WHERE name = @name vs. SELECT * FROM sys.tables WHERE name = 'Tobias').

Now WRT to prepared statements their main use-case (at least in SQL Server) is to avoid sending the full statement/batch text every execution. I.e. if you are planning to run a batch consisting of a large text many iterations you just send the text once and then the integer handle for every execution. The handles themselves are separate from the plan cache, it is simply a hash table attached to each connection, each entry basically pointing to the original text and parameter definitions.

As a rather long example:

  1. Clean up the plan cache
    DBCC FREEPROCCACHE;

  2. Add an entry to the connection's prepared statements hash table.
    EXEC sp_prepare @id OUTPUT, @params = null, @stmt = N'SELECT * FROM sys.tables'

  3. Verify no entry in the plan cache yet (this would be different with sp_prepexec which prepares and does the first execution in one roundtrip)
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

  4. Execute the prepared statement (should be handle 1 if this is your first prepare in this connection)
    EXEC sp_execute 1;

  5. Notice that there is now an item in plan cache
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

  6. Run exactly the same statement text (from any connection)
    EXEC sp_executesql N'SELECT * FROM sys.tables';

  7. Notice that the plan cache usecount is now 2.
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

  8. Clean-up the cache.
    DBCC FREEPROCCACHE;

  9. Verify no entry in the plan cache again
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

  10. Execute the prepared statement again to see that it is now added back to the plan cache (through compilation based on the prepared statement hash table), note that usecounts is back to 1.
    EXEC sp_execute 1;
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

  11. Unprepare the statement and verify that the entry is still in the plan cache to continue enabling plan re-use.
    EXEC sp_unprepare 1;
    SELECT * FROM sys.dm_exec_cached_plans AS p
    CROSS APPLY sys.dm_exec_sql_text(p.plan_handle) AS s
    WHERE s.text LIKE 'SELECT * FROM sys.tables';

In conclusion:

  • The main use case for prepared statements is executing a large batch many times in a loop only changing parameter values. I.e. optimizing the number of bytes sent to the server in each request.
  • Avoid using prepared statements other than for this use-case as they increase round-trips and application complexity (prepare, execute, unprepare).
  • If you don't do unprepare know that the connection hash tables keep growing on the server side until the connection gets closed, memory pressure will not cause SQL Server to clean-up this memory as the client app "may" need the statement in the future (as opposed to the plan cache which is a true cache).
  • Trust the default plan cache management by simply using sp_executesql. I am not saying it is perfect, but there are other ways to handle plan re-use issues rather than resorting to prepared statements (an example is plan guides)

Hope this helps :-)

Now this is a complex subject so happy to help dig in further if needed.

Thanks!
/Tobias (SQL Server database team)

@Arthurm1
Copy link

Arthurm1 commented Mar 6, 2017

@TobiasSQL
Thanks for clarifying the workings

If that's the case then I vote for switching the default PreparedStatement handling over to use just sp_executeSQL and have a property on the driver to switch back to the current sp_prepExec/sp_unprepare method for those who need it for repetitive large text SQL.

Then performance issues could be re-addressed after this has been implemented to see if a local cache is still required

@TobiasSQL
Copy link
Contributor

@Arthurm1, that makes sense to me :-)

BTW, I will add that prepared statements used to have a larger use case including plan re-use etc. But since database systems implemented proper plan caching the use case has narrowed pretty much into what I described.

@davidfrankson
Copy link
Author

@TobiasSQL Most of us aren't coding SQL Server specific stored procedure calls into our application code. We are coding to the JDBC standard and either sending the driver an adhoc SQL statement or we are using a PreparedStatement and we trust that the driver is managing the parameterized SQL in an efficient way localized to it's db.

I don't think you can just state "Avoid using PreparedStatements", I have 2107 uses of them already existing in my codebase. Using PreparedStatements is the preferred way to defend against SQL Injection
https://www.owasp.org/index.php/SQL_Injection_Prevention_Cheat_Sheet and unless we are doing some kind of dynamic SQL or working with data that has known parameter sniffing pitfalls, we use PreparedStatements by default. I'm going to assume many of us build multi-threaded webapps and a pooled connection gets reused on many requests during it's lifespan. A PreparedStatement does not need to be in a tight loop to see the benefit of a driver statement pool.

I decided to make a bigger test, I changed the AdventureWorks2014 query so that it did a join and so simple parameterization doesn't get used (and my server doesn't have forced parameterization turned on). I then tested 50k instances of adhoc sql, preparedStatements and sp_executeSQL on jtds and the MS driver:

C:\j>java -cp jtds-1.2.7.jar;. JTDSTester
222265 milliseconds for 50k Ad Hoc Statements.
90161 milliseconds for 50k PreparedStatements.
97697 milliseconds for 50k sp_executeSQL calls.

C:\j>java -cp mssql-jdbc-6.1.4.jre7-preview.jar;. MSJDBCTester
142003 milliseconds for 50k Ad Hoc Statements.
173171 milliseconds for 50k PreparedStatements.
97862 milliseconds for 50k sp_executeSQL calls.

Don't put much faith in the adhoc numbers, these result in 50k single use adhoc plans in the proc cache and the times fluctuate +/-50 seconds across runs of the same driver . This results in the server plan cache bloating with single use adhoc plans:
adhoc bloat
I just wanted to try to measure this performance difference in case someone took "Avoid using PreparedStatements" as it's ok to use adhoc SQL for everything.

Using PreparedStatements on jtds still has a measurable advantage over sp_executeSQL and saves the SQL Server from having to repeatedly parse the same SQL text. (about .06 - .16 ms per statement) but anything that saves SQL Server hardware resources has value.

sp_executeSQL calls across both drivers are the same as would be expected. sp_executeSQL does fix most of the performance issues coming from the sp_prepare/sp_unprepare approach.

@v-nisidh
Copy link
Contributor

v-nisidh commented Mar 6, 2017

@davidfrankson First we will come up with perf analysis which will give us more data and will share that in this issue.

@TobiasSQL
Copy link
Contributor

TobiasSQL commented Mar 7, 2017

Thanks @davidfrankson, very helpful! Like you say, I think your results especially show the cost of the extra round-trips to unprepare.

First, I am sorry, I don't have much experience with JDBC, I am more of a server guy here. I thought I'd help with that side but I can see how I was mistaken :-) What I do want to help with is to make sure Java developers have a great experience.

I wasn't aware that non-prepared statements in JDBC do not support parameters, that obviously changes things. Also, I for sure understand your expectation on the driver to handle this vs. you calling specific procedures for your SQL Server support.

It would be great to get your help here while the team do their perf testing.

For now these four options come to mind:

  1. Implement full statement caching in the driver per your request.
  2. Implement batching of sp_unprepare so we incur less round trips (i.e. unprepare in batches every so often).
  3. Add an option to state the intent to use the "prepared statement" once vs. many times, this would cause the driver to call sp_executesql instead of sp_prepare/sp_prepexec/sp_execute/sp_unprepare etc.
  4. Add parameterization support to Statement.

Some thoughts:
1 is a pretty big item and I am wondering if the benefits are really worth it. For 2 there is the question of the default behavior and if/how to turn the behaviors on/off but it seems like it could help a lot. 3 can obviously be done in a multitude of ways (connection string parameter, new method, ...), any thoughts? 4 would require a change in JDBC itself to make sense, not just the SQL Server driver.

What is your take? Any other options that would make sense to you?

Thanks!
/Tobias

@davidfrankson
Copy link
Author

PreparedStatements are the JDBC spec's API for parameterizing Statements. It's up to the driver to make sure they are called and managed efficiently. At this point I don't know of any other JDBC drivers that lack a statement cache.

The current performance gap is so significant that I couldn't use this driver in production. If you implement option 3 I could rerun our load test to measure the performance impact on server hardware. Re-parsing the SQL text each time will still impact performance but I should be able to get a real world measurement of the performance difference.

@gordthompson
Copy link
Contributor

@davidfrankson - If I understand the process correctly, option 3 will not require that the SQL be re-parsed each time if the lookup into the execution plan cache finds that the SQL command text is already there. (Mitigating factors: (1) We would hope that the cache lookup would be relatively inexpensive, and (2) said lookup would probably happen in any case.)

@TobiasSQL
Copy link
Contributor

TobiasSQL commented Mar 7, 2017

Thanks both @gordthompson and @davidfrankson!

I am also including @ajlam who works on our Java support for visibility.

In order to avoid you guys having to change your code I went ahead and did a simple implementation of option 2 (i.e. batching unprepares). Note that this is just a prototype to see how much/if at all this helps. @davidfrankson, if you have time to give it a spin and wouldn't mind re-running your test using my fork you can find it here: https://github.com/TobiasSQL/mssql-jdbc (I also added a jar if that is easier to consume mssql-jdbc-6.1.4.jre8_updated.zip).

Also, if you wouldn't mind sharing your test I can also run it myself to get an apples-to-apples comparison.

Thanks!
/Tobias (SQL Server database engine)

@TobiasSQL
Copy link
Contributor

FYI, I did another push to my prototype and updated the .jar above. It now uses sp_executesql for the first execution of a PreparedStatement. If you execute more it falls back to the prepare/exec/batched unprepare pattern. My guess is that this should bring the common use to similar numbers as your test of directly calling sp_executesql. This will cause a bit more work for the re-used statement pattern but that should be quickly amortized. At any rate, looking forward to see if it helps, at least as a initial step :-)

@gordthompson
Copy link
Contributor

@TobiasSQL FYI, I repeated my quick test above using your latest jar:

4) TobiasSQL prototype

DBCC FREEPROCCACHE
exec sp_executesql N'SELECT * FROM test10k WHERE id = @P0        ',N'@P0 int',1
exec sp_executesql N'SELECT * FROM test10k WHERE id = @P0        ',N'@P0 int',2
exec sp_executesql N'SELECT * FROM test10k WHERE id = @P0        ',N'@P0 int',3
...
exec sp_executesql N'SELECT * FROM test10k WHERE id = @P0        ',N'@P0 int',10000

7.6 seconds: 68% of current

(simply suppressing the exec sp_unprepare calls was 8.0 seconds: 71% of current)

@Arthurm1
Copy link

Arthurm1 commented Mar 8, 2017

@TobiasSQL
Out of interest - do you know why in SQL Server sp_prepare/sp_prepexec/sp_unprepare work on a per-connection basis when the query cache is server wide? It seems a waste of resources both on the server side and the client side especially if statement caching was implemented and a connection pool was in use.

@davidfrankson
Copy link
Author

It now uses sp_executesql for the first execution of a PreparedStatement. If you execute more it falls back to the prepare/exec/batched unprepare pattern.

Sounds like a client side equivalent to SQL's optimize for an adhoc workload setting. My simple loop tests are going to match @gordthompson tests. I have a multi-threaded version of it but I was trying to tweak it to better simulate web requests:

  1. Fetch a connection from a pool
  2. create 1 PreparedStatement
  3. execute it
  4. close the PreparedStatement
  5. return the connection to the pool

But I hit some problems running the jtds driver from the hikari connection pool. jtds doesn't support the JDBC4 isValid() method and I can only get past it by setting a testOnBorrow statement but that makes jtds have to do two roundtrips per call and I'm trying to keep a fair comparison. When I work things out I will post my tester.

@TobiasSQL
Copy link
Contributor

Thanks @davidfrankson and @gordthompson! I think @gordthompson's test as well as some I played around with strongly indicate that we should get this fix into main line sooner rather than later since it will likely improve the performance for a very common use-case and have marginal impact for the re-use of PreparedConnection case (given we start out with sp_executesql instead of sp_prepexec). I will go ahead and do some clean-up, provide a way to to turn each behavior off if needed, and send off a pull request to get things rolling on our side (BTW, it seems like this behavior should be the default if we don't run into something major when we run our full tests beds that haven't made it to GitHub yet, would love your opinions).

@davidfrankson, looking forward to understanding more once you can run and share your tests :-)

Thanks!
/Tobias

@davidfrankson
Copy link
Author

OK, so my tests try to simulate web requests. PreparedStatements are often used 1 time and then closed, but a pooled connection will be reused many times across thousands of requests and so a Statement pool gets plenty of use. I test three cases:

100,000 requests that run a PreparedStatement 10 times for 1M total requests.
1,000,000 requests that run a PreparedStatement 1 time for 1M total requests.
1,000,000 requests that run a regular Statement (calling a parameterized stored procedure) 1 time for 1M total requests.

The tester runs 10 threads concurrently and the connection pool has 10 threads and in most cases that is enough to keep 3500 +/- 500 batch requests / sec on my test server. I'm monitoring overall response time to the client and trying to ballpark SQL Server hardware usage.

Original driver:

C:\j>java -cp mssql-jdbc-6.1.4.jre7-preview.jar;HikariCP-2.6.0.jar;slf4j-api-1.7.24.jar;slf4j-nop-1.7.24.jar;. MSJDBCTesterMultithread
Starting 1000000 threads 1 Statements per thread, 10 running at a time.
Finished all threads. 279695 milliseconds for 1*1000000 = 1000000 sp_executeSQL Statements.
Starting 100000 threads 10 PreparedStatements per thread, 10 running at a time.
Finished all threads. 286891 milliseconds for 10*100000 = 1000000 PreparedStatements.
Starting 1000000 threads 1 PreparedStatements per thread, 10 running at a time.
Finished all threads. 490644 milliseconds for 1*1000000 = 1000000 PreparedStatements.

The 1m single statements is the control group. It averaged 37% cpu usage.

The original driver does well with the first test case since it prepares a statement and reuses it 10 times. It took a little longer than the single statements, but then it did prepare/unprepare 10k statements. During this test cpu averaged 23% so overall it saved 36% of the cpu costs.

Big response time slowdown with the prepare/unprepare per thread as expected. Cpu usage dropped to 19% but over a longer time and overall it used about 10% more cpu that the control.

Tobias fork:

C:\j>java -cp mssql-jdbc-6.1.4.jre8-tobias.jar;HikariCP-2.6.0.jar;slf4j-api-1.7.24.jar;slf4j-nop-1.7.24.jar;. MSJDBCTesterMultithread
Starting 1000000 threads 1 Statements per thread, 10 running at a time.
Finished all threads. 283232 milliseconds for 1*1000000 = 1000000 sp_executeSQL Statements.
Starting 100000 threads 10 PreparedStatements per thread, 10 running at a time.
Finished all threads. 274037 milliseconds for 10*100000 = 1000000 PreparedStatements.
Starting 1000000 threads 1 PreparedStatements per thread, 10 running at a time.
Finished all threads. 278267 milliseconds for 1*1000000 = 1000000 PreparedStatements.

The 1m single statements is the control group. It averaged 37% cpu usage.

The new version beat the time by a few seconds and server cpu was 23% so it is pretty close to the old performance even though 1/10 of the statements sends a sp_executeSQL instead of reusing the prepared statement.

I expected to see the performance here match the control since it should result in the same sp_executeSQL calls but cpu usage here was only 24%. The PrepreparedStatement calls coming from the driver trace as RPC:Completed and the Statement calls from my code trace as SQL:BatchCompleted. I didn't know the server parsing overhead automatically applied to all Statements and that it was so expensive.

So, yes very worthwhile performance improvements. And this looks like it solves most of the problems with PreparedStatements. It is probably possible to squeeze more efficiency out with a full PreparedStatement cache but this fixes most of it.
jdbc_multithread.zip

@TobiasSQL
Copy link
Contributor

TobiasSQL commented Mar 9, 2017

Thanks a ton @davidfrankson, super helpful!

I have cleaned-up the change and submitted the pull request. @ajlam and I will work with the rest of the team to get this in. I have updated my fork and attached a new jar (mssql-jdbc-6.1.4-TobiasSQL.zip) if you have time to test it, main functional difference is that the threshold and whether or not to run sp_executesql on first execute is now configurable through:

  • SQLServerConnection.setDefaultPreparedStatementDiscardActionThreshold
  • connection-instance.setPreparedStatementDiscardActionThreshold
  • SQLServerConnection.setDefaultPrepareStatementOnFirstCall
  • connection-instance.setPrepareStatementOnFirstCall

All defaults are that the optimizations are enabled. The other change is that if you setPrepareStatementOnFirstCall to true we go through the exact same code path as before (TDS RPC to sp_unprepare rather than language event/Statement call to sp_prepare).

@Arthurm1, sorry for missing your question from earlier. The simple answer to why prepared handles are connection based is that their namespace is attached to a specific user and connection. This way handles cannot be accidentally shared between users and you can't figure out how many or which handles may be used by other users. Also, and mainly, the cache is the fundamental way we handle performance issues related to compiling queries, i.e.it is a more general solution than a server wide cache for prepared handles. Also++, as I mentioned in my first rambling reply, the prepared handles hash table is really just the statement text and parameter definitions, it doesn't contain any plans etc., that is all managed by the plan cache. So cached plans are always server-wide if you will, including for prepared statements. The original statement texts related to prepared statements are not. Hope this makes sense :-)

Thanks!
/Tobias

@tonypet
Copy link

tonypet commented Mar 9, 2017

@TobiasSQL thank you for fixing this issue.

@davidfrankson do you know of any other outstanding performance issues related to the SQL Server JDBC driver? In your comparisons with jTDS have you found other deficiencies in our JDBC driver? I figured while we have yours and Tobias's attention we might as well try to address other known issues if we can.
Thanks

@davidfrankson
Copy link
Author

@tonypet My performance team is scheduled to do a full production simulation load test on the 22th with the new jar version. I was caught off guard by how fast @TobiasSQL fixed things. I didn't think he could fix it faster than I could test it. :-) In switching from jtds to the MS driver there were some quirks, but many of those were situations where the MS driver stuck to the spec and jtds let us get sloppy.

@tonypet
Copy link

tonypet commented Mar 10, 2017

@davidfrankson your analysis with the included traces and measurements pinpointed the problem so that made things a lot easier -- thank you for your contribution.
We will wait for your test results before we close on this issue.

@TobiasSQL
Copy link
Contributor

Same goes for @gordthompson, thanks a ton for the help both of you! Like @tonypet says, looking forward to your team's results @davidfrankson.

@rsargant
Copy link

rsargant commented Mar 22, 2017

Very happy to see this issue has been addressed !

I just wanted to add that most (all?) Java ORMs use JDBC prepared statements under the hood and do not provide the end-user any control over the lifecycle of the prepared statements. The typical pattern they follow is create a prepared statement, use it and then close it sooner rather then later. The implicit assumption is the JDBC driver will be efficient but this is precisely the lifecycle pattern that most exploits the original performance issue.

I've found it impossible to run an ORM + MS-SQL JDBC + SQL Server in production without also using a connection pool level prepared statement cache which converts a "close" issued by the ORM to a prepared statement pool return. That changes the exec sp_prepexec, exec sp_unprepare pattern to exec sp_prepexec, exec sp_execute,exec sp_execute,exec sp_execute as the ORM goes about its business.

The performance is good but it brings along all of the baggage outlined by Brett Wooldridge. A large # (made even larger by the ORM) of prepared statement objects permanently occupy the Java heap.

I'll be switching to Hikari CP as soon as this fix is available.

Truly great news !

@greg-pendlebury
Copy link

I have a question relating to the change introduced in 6.1.6(?).

We have been trialling an upgrade this week from 4.2 to 6.1.7 to get around the memory leaks in 4.2... but the performance has thus far been worse than the old driver. Not massively, but consistent and reproducible. The memory leak is gone, but the compromise seems pretty painful TBH.

Are the new changes discussed here documented anywhere? Are they off by default? I've just spent some time digging around in the pull request to find that 'enablePrepareOnFirstPreparedStatementCall=true' and 'ServerPreparedStatementDiscardThreshold=10' are probably what we want... I think. I know that 10 is something we will tweak to suit, but one of the developers will be trialling these new parameters over the weekend with load tests. I am really hoping they improve the poor performance we've seen.

We are running JBoss EAP above MS SQL. There is no choice to install HikariCP, although I wish I could if someone knows how to achieve that miracle. I have used HikariCP in Spring before and it was the first thing I reached for only to discover that JBoss does not apparently let you change. The driver is the only layer we have to improve performance and it is pretty terrible right now. I am excited at the activity in this issue though an the fact that improvements are being made.

@TobiasSQL
Copy link
Contributor

TobiasSQL commented Jun 17, 2017

@greg-pendlebury, we will be updating docs for these, defaults are false/10. However, a bunch of us have worked on actual statement caching as well which is now in the RTW branch. Everything is ON by default, you may want to give that a spin as well. This should get released fairly shortly.

Do you have any insights to share on what is getting slower (did you dig into this more and find out where more time is spent)?

@greg-pendlebury
Copy link

@TobiasSQL thank-you for confirming those parameters. Over the weekend we did have a run (using the parameters) that got the performance times a lot closer to how things worked under 4.2. We are tentatively ready to move that version through to prod, simply because it resolves the memory leak. We have been watching the discussion around performance changes and will move to that as soon as we can.

Regarding where the performance problems I could only surmise that it relates to prepared statements. The DBAs commented on the oddity of seeing none at all until we added those parameters to turn them back on again (and improved the performance back to 4.2 levels). I am somewhat resigned to agree with @rsargant's comments above in that we cannot stop the ORM libraries from using prepared statements so the fundamental clash is in what MSSQL expects regarding prepared statements and how they are actually getting used.

In our particular case we cannot change the connection pool because it is baked into JBoss though (to the best of my knowledge)

@wied03
Copy link

wied03 commented Sep 15, 2017

I'm assuming that since the metadata caching was reverted in 6.2.1, that it's still a work in progress. Is that true?

@ajlam
Copy link
Member

ajlam commented Sep 15, 2017

Hi @wied03, yes that's correct. @v-xiangs has been working on a few PRs, including #436, to address some of the issues we discovered in the original implementation. We'll try to merge this into one our future preview releases for everyone to test out.

@wied03
Copy link

wied03 commented Sep 15, 2017

@ajlam - Thanks

@gleeds
Copy link

gleeds commented Oct 10, 2017

Hi, I'd like to offer to help test preview builds of this.

For context, our application has a job queue to do data import and uses Hibernate for data access. One of our test jobs takes about 11 minutes to run on MySQL and 47 minutes on SQL Server. Several of our customers have switched from MySQL to SQL Server and seen similar performance degradation. Some have switched to jTDS, but given that it's not compatible with Hibernate 5, we don't want to recommend that as an option.

I tried testing with the code in your dev branch last night, but so far it looks like it hasn't had any noticeable effect.

@TobiasSQL
Copy link
Contributor

@gleeds , that should be easy. This is available in the dev branch so you should be able to simply use that to see what this does to your performance.

@gleeds
Copy link

gleeds commented Oct 10, 2017

@TobiasSQL That's what I was afraid of, I was really hoping that this would be the silver bullet for our SQL Server issues, but now I'm not so sure. I tried the dev branch last night in two environments, one with the default setting, and one with:

serverPreparedStatementDiscardThreshold=100;enablePrepareOnFirstPreparedStatementCall=true;disableStatementPooling=false;statementPoolingCacheSize=100;

We saw basically no difference over there 6.1.0 jar we had been using before.

I did try testing today with the old driver and C3P0's statement caching turned on and saw a ~20% improvement, so I would hope that driver level caching would be able to help at least that much.

@brettwooldridge
Copy link
Contributor

@gleeds What kind of performance are your customers seeing from the jTDS driver. While my dev branch is unfinished work, I was trying to replicate the work on did on the jTDS driver (10+ years ago).

@brettwooldridge
Copy link
Contributor

@gleeds Also, might I suggest HikariCP? Some users have reported > 2x improvement on large jobs.

@brettwooldridge
Copy link
Contributor

brettwooldridge commented Oct 10, 2017

@gleeds Finally (for tonight, it's 3:00am here in Tokyo), I'll try to revisit the dev branch this week ... I haven't had time to mess with it or rebase it in well over a month.

EDIT: Oh, I just realized you said dev. If you are brave, you can try my personal speedify branch here -- you'll have to build it (fingers crossed that it's in a buildable state).

@gleeds
Copy link

gleeds commented Oct 11, 2017

@brettwooldridge Thanks for your advice. I've been working on putting together a big matrix of testing times, but discovered right at the end of it that I was using the wrong branch of our app in some cases and wasn't getting the "apples to apples" comparison that I wanted to provide, so I'm redoing some of them now.

I've tried C3P0, Hikari, Vibur and the Hibernate built in connection pool, and found that the two fastest combinations were jTDS with the Hibernate pool, and SQL Server with Vibur with the Statement Caching option turned on. I tried the Speedify branch, and it was faster than the dev branch, but nowhere near as fast as the Vibur or jTDS native cache. Once I clean up my numbers to account for my mistake, I'll post them.

At the end of the day Statement Caching is giving me a ~25% speed improvement which is a big improvement, but it still doesn't account for why SQL Sever is 3-5x slower than MySQL in our application.

@brettwooldridge
Copy link
Contributor

I hope that the SQL Server driver can be made as fast as jTDS, though that will take some iterations.

As to SQL Server itself matching MySQL, that’s a completely separate issue from the driver, and better discussed elsewhere. But IMHO, SQL Server will probably never match MySQL in terms of raw TPS on like hardware.

The goal of this project should be the write the fastest most stable SQL Server driver available.

@tubbynl
Copy link

tubbynl commented Jan 5, 2018

How does #543 relate to this issue? As far as i can read the pull request is seems to involve fixing stuff in the Statement caching (perhaps focused on metadata only), but it suggest that some form of statement cache is implemented in 6.3

@cheenamalhotra
Copy link
Member

Closing this issue as the PS Metadata Caching is now implemented and available since driver version 6.4.
The feature is disabled by default. More details and how to enable it can be viewed here.

@luca-domenichini
Copy link

Sorry, but in your previous link there are no words about properties in jdbc connection string.

Are these properties still valid?

serverPreparedStatementDiscardThreshold=100;
enablePrepareOnFirstPreparedStatementCall=true;
disableStatementPooling=false; // this has a method also in SQLServerConnection/DataSource
statementPoolingCacheSize=100; // this has a method also in SQLServerConnection/DataSource

In the official microsoft docs, only the last two seems to have a method counterpart..

Can you clarify?

@cheenamalhotra
Copy link
Member

Yes, all the 4 connection string parameters are valid. They are however documented here. We will make sure the Prepared Statement Caching doc covers that too. Thanks for catching that!

@livingash
Copy link

DriverPropertyInfo still reports "true" as the only valid value for disableStatementPooling though passing "false" no longer caused an exception.

DriverPropertyInfo[] propertyInfo = DriverManager.getDriver(jdbcUrl).getPropertyInfo(jdbcUrl, null);

Stream.of(propertyInfo).filter(p -> p.name.equals("disableStatementPooling")).findFirst().orElse(nul = {DriverPropertyInfo@2311} 
 name = "disableStatementPooling"
 description = "Disables the statement pooling feature."
 required = false
 value = "true"
 choices = {String[1]@2318} ["true"]
  0 = "true"
DriverManager.getDriver(jdbcUrl).getMajorVersion() = 12
DriverManager.getDriver(jdbcUrl).getMinorVersion() = 2

Version tested was 12.2.0.jre8.
Same was found with 9.4.1.jre8.

Is this expected?

@Jeffery-Wasty
Copy link
Contributor

Jeffery-Wasty commented May 4, 2023

Hi @livingash,

We'll look into this but false is an expected value for input, so this might be something we need to change.

@tkyc
Copy link
Member

tkyc commented May 4, 2023

@livingash looks like valid values list wasn't updated for disableStatementPooling, we'll correct that.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Enhancement An enhancement to the driver. Lower priority than bugs.
Projects
None yet
Development

No branches or pull requests