Improve performance of SQL binding #304

Closed
cowwoc opened this Issue Nov 29, 2012 · 21 comments

Projects

None yet

3 participants

@cowwoc
Contributor
cowwoc commented Nov 29, 2012

I put together a simple test that looks up a record by id, and iterate over this many times. What I noticed is that over time, the sql binding overhead is actually greater than the database lookup. Specifically, generating the SQL query string takes more time than executing it.

@timowest timowest added a commit that referenced this issue Nov 29, 2012
@timowest timowest #304 added PerformanceTest 3155232
@timowest
Member

I now also added a simple test case for a select-from-where query with 1.000.000 iterations.

Here are the numbers for the serialization

non-normalized 3777 ms
default 5172 ms

The normalization pass after the serialization needs to be optimized as well as the template handling for operations.

Everything else is quite direct model serialization.

@timowest timowest added a commit that referenced this issue Nov 30, 2012
@timowest timowest #304 added new performance test 230b475
@timowest
Member

Now I got some more numbers for a new test with 1.000.000 iterations

raw JDBC 1306 ms
Querydsl query 12535 ms
Serialization only 5315 ms
Serialization only (no normalization) 3160 ms

I still think that the absolute numbers are quite good, but you are right about the serialization performance.

@timowest timowest added a commit that referenced this issue Nov 30, 2012
@timowest timowest #304 updated tests e755ca7
@cowwoc
Contributor
cowwoc commented Nov 30, 2012

I still think that the absolute numbers are quite good

Really? The above numbers seem to indicate querydsl-sql causes queries to take 10x longer than normal. Ouch :)

What does "serialization" mean in the context of querydsl? Why do you believe these numbers are quite good? Perhaps I am misunderstanding something.

@timowest
Member

Really? The above numbers seem to indicate querydsl-sql causes queries to take 10x longer than normal. Ouch :)

With absolute numbers I mean absolute numbers, not a relative number, I thought that would be clear.

Also please reread "The above numbers seem to indicate querydsl-sql causes queries to take 10x longer than normal"`. You can't generalize it like this. I hope you realize that.

I has an overhead of ~ 900% for this case, which is an by id lookup against an in memory database.

What does "serialization" mean in the context of querydsl? Why do you believe these numbers are quite good? Perhaps I am misunderstanding something.

Serialization means converting the Querydsl query model into a SQL String.

12535ms for 1.000.000 queries means 0.012535 ms per query. I do believe this isn't bad.

Also comparing Querydsl queries to prepared queries that are probably going to be mapped to map lookups in H2 since they are by id queries is maybe not very meaningful. So It's a bit like comparing the Querydsl query serialization to a hashmap lookup.

Does this overhead cause problems in any of your projects? Also do you see other improvement points than the two I mentioned?

@cowwoc
Contributor
cowwoc commented Nov 30, 2012

With absolute numbers I mean absolute numbers, not a relative number, I thought that would be clear.

Sorry for that. Sometimes I read what I want to read instead of what's actually written :)

You are right, we shouldn't compare serialization to an in-memory database (which is equivalent to a HashMap lookup). To be fair, my original testcase uses a disk-based database and shows that 80% of the time was used by querydsl, 20% by the database.

Why does this matter? Server scalability. The database is the bottleneck in most projects I'm aware of.

I'm confident you will be able to improve performance. The expectation is for disk look-ups to be an order of magnitude slower than in-memory computation. The fact that we're seeing the opposite leads to believe there will be some low-hanging fruit to fix this.

@timowest
Member

I updated the benchmark to be more realistic, and more close to your original one. There are now 1 million rows in the table and 1 million iterations.

I added also a different query which selects by name.

Here are the results

jdbc by id 3320
jdbc by name 5520
querydsl by id 16865
querydsl by name 17469
default serialization  5513
non-normalized serialization 3050

For example in the by id case the querydsl by id result could be interpreted as

20% JDBC
33% serialization
47% something else

This is close to your results.

I also used H2 with disk persistence, but I think it does the query evaluation in memory. I am not sure though.

Next I will continue with some profiling.

@timowest
Member
timowest commented Dec 1, 2012

Base on profiling results the following methods to be checked for possible optimizations

com.mysema.query.sql.SQLSerializer.visit(com.mysema.query.types.Path, Void)
com.mysema.query.types.ValidatingVisitor.visit(com.mysema.query.types.Path, Void)
com.mysema.query.types.PathImpl.equals(Object)
com.mysema.query.types.path.BeanPath.getMetadata()
com.mysema.query.support.CollectionAnyVisitor.visit(com.mysema.query.types.Path, com.mysema.query.support.Context)
com.mysema.query.support.SerializerBase.append(String)
com.mysema.query.types.path.StringPath.getMetadata()
com.mysema.query.sql.SQLTemplates.requiresQuotes(String)
com.mysema.query.sql.Configuration.getType(com.mysema.query.types.Path, Class)
com.mysema.query.types.path.BeanPath.accept(com.mysema.query.types.Visitor, Object)
com.mysema.query.sql.SQLTemplates.quoteIdentifier(String)
com.mysema.query.support.SerializerBase.handle(com.mysema.query.types.Expression)
com.mysema.commons.lang.Assert.notNull(Object, String)
com.mysema.query.types.ValidatingVisitor.visit(com.mysema.query.types.Path, Object)
com.mysema.query.support.Normalization.normalize(String)
com.mysema.query.types.path.StringPath.accept(com.mysema.query.types.Visitor, Object)
com.mysema.query.support.SerializerBase.visitOperation(Class, com.mysema.query.types.Operator, java.util.List)
@timowest timowest added a commit that referenced this issue Dec 2, 2012
@timowest timowest #304 fixed quoting 0e31ccc
@timowest timowest added a commit that referenced this issue Dec 2, 2012
@timowest timowest #304 removed assert usage 58e3f62
@timowest timowest added a commit that referenced this issue Dec 2, 2012
@timowest timowest #304 updated performance test 51d4d58
@timowest
Member
timowest commented Dec 2, 2012

Here is an update with the latest results

jdbc by id 3711
jdbc by name 5841
qdsl by id 11918
qdsl by id 10263 (iterated)
qdsl by id 9309 (no validation)
qdsl by name 12325
qdsl by name 12513 (iterated)
qdsl by name 11650 (no validation)
ser1 1620
ser2 1399 (non normalized)

So the "qdsl by id" times can be split into roughly

3711 JDBC
1620 serialization
2609 validation (can be turned off)
3978 misc

11918 total

If you have some time, please take a look at the methods listed in the hot spots and see if you spot some obvious performance improvements that could be done.

@cowwoc
Contributor
cowwoc commented Dec 2, 2012

What does "validation" do and how can it be disabled?

@timowest
Member
timowest commented Dec 2, 2012

Validation checks that you refer to paths that have been defined in your query.

You can disable it like this

SQLQuery query = new SQLQueryImpl(conn, conf, new DefaultQueryMetadata().noValidate());

I will check later how validation could still be improved.

@timowest
Member

Here is the current state

jdbc by id 3302
jdbc by name 5715
qdsl by id 8451
qdsl by id 7702 (iterated)
qdsl by id 7522 (no validation)
qdsl by id 9708 (two cols)
qdsl by name 9794
qdsl by name 9803 (iterated)
qdsl by name 9487 (no validation)
ser1 1258
ser2 1070 (non normalized)
@timowest
Member

Here is a snapshot of a Visual VM profiling session

profile

For some reason the JDBC part inside Querydsl is slower than with H2 directly, but most of the time is spent in the JDBC part.

@cowwoc
Contributor
cowwoc commented Dec 12, 2012

This discrepancy makes me believe we're not measuring correctly.

You should probably take a look at http://stackoverflow.com/a/513259/14731 and http://code.google.com/p/caliper/.

@timowest timowest added a commit that referenced this issue Dec 13, 2012
@timowest timowest #304 added warmup phase a6e0282
@timowest
Member

Here are the newest results with 50.000 warmup iterations. I didn't tune the JVM/Compiler settings

jdbc by id 2318
jdbc by name 3175
qdsl by id 7649
qdsl by id (iterated) 7644
qdsl by id (no validation) 7421
qdsl by id (two cols) 9319
qdsl by name 10322
qdsl by name (iterated) 9895
qdsl by name (no validation) 11743
ser1 2426
ser2 (non normalized) 1122

The profiling showed again more locking overhead in the Querydsl version.

I expect that for some reason the direct JDBC usage can be optimized better than JDBC usage inside Querydsl. I am no opimization expert, so there might still be something to do.

@ssaarela
Contributor

Could serialized strings be cached under the hood and re-used for structurally similar queries? Most queries in an app or another are pretty static or have only little structural variance. If equals and hashCode could be optimized better than string concatenation, caching would help. As query serialization contains some find'n'replace of SQLTemplate parameters (right?) in addition to string appending, I would assume that correctly implemented caching should really help.

And for optimization freaks you could even offer something like custom cache key for queries: Query.setCacheKey(QUERY1) - "beware that using same key for different queries fails miserably - use at your own risk!"

Maybe query cache usage could be optional? Something like Configuration.setQueryCache(new EhQueryCache())? Or maybe on a Query-basis via Query.setCacheKey(Object) - "for absolutely safe usage, use Query itself as a cache key: qry.setCacheKey(qry)!"

Or maybe something like Query.prepare().xxx() fluent pattern that would return a pre-serialized version of the query:

final PreparedListQuery pqry = queryFactory
.from(x)
.where(x.name.eq(stringParam), x.age.eq(intParam))
.prepare()
.list(qType);

...

List results = pqry.executeWith("Name matcher", 50);

Then anyone could implement their own query caches for static queries at least.

Another matter is StringBuilder usage in SerializerBase. The default initial capacity for StringBuilder is 16, which is hardly enough even for the most simplest of queries: even "select * from mytable" requires reallocation of the internal char table. I would recommend using much higher initial capacity there. It's hard to say what would be good initial capacity... but to me 30 char limit of names in Oracle feels way too short for descriptive names, so if we have 30 char table name and a few descriptive column names.. maybe 512 could be a good starting point.

@cowwoc
Contributor
cowwoc commented Dec 13, 2012

I don't like the idea of manual cache configuration (anyway, we've yet to establish that manual intervention is necessary).

Also, as much as I agree that StringBuilder should use a more reasonable constructor value, the profiler seems to indicate the overhead is negligible (not anywhere close to being a top offender).

I'm having problems with the profiler (bugs in the version of the IDE I'm using) but I believe the top offenders are regex operations. You'd have to dig into the code to figure out whether many of these operations are necessary for simple queries like query by name/id and if not, whether there is a quick way to skip them.

@timowest
Member

Could serialized strings be cached under the hood and re-used for structurally similar queries?

Query string caching might help, but the equals/hashCode identity of the Query can't be used for it, and it would potentially need to go through the structure of multiple queries in a hashmap to find the right one, so this might not be faster.

I'm having problems with the profiler (bugs in the version of the IDE I'm using) but I believe the top offenders are regex operations.

Yes, before, but most of them have been optimized now. Let me know if there are still regex related hotspots.

You'd have to dig into the code to figure out whether many of these operations are necessary for simple queries like query by name/id and if not, whether there is a quick way to skip them.

Serialization of operations can still be optimized and will be, the rest is already quite streamlined.

@ssaarela
Contributor

I like the idea of PreparedQuery very much. Having "PeparedQuery" would allow highly optimal client code. Most queries are quite static with only a few parameters. Ability to have these pre-build and serialized would not only cut the cost of serialization but also the cost of building the query model. Having something like ParameterExpression and setters similar to StoreClause to indicate parameters of the query would even allow parameter type/count validation when setting them. However, in cases where performance is critical I would personally gladly settle for untyped index-based (Object[]) setting of parameters as that is the most efficient way - and have JDBC/DB validate parameter count and types.

"Caching" simple and static queries would be trivial: as fields of the class. Building cache keys for dynamic queries in application code should also be easy: most often the structure of the query depends on given parameter - whether some filter-parameter exists or not and for collection parameters also the size of the collection. So something like

public List findProducts(String name, Set categories, Integer maxPrice)

would have simple and efficient cache key:

Arrays.asList(name != null, (categories == null ? null : categories.size()), maxPrice != null)

Prepared*Querys should probably be modeled as it's own class... new PreparedListQuery(qry)...

@timowest
Member

Please open a new ticket for the PreparedQuery idea. It is a bit out of scope here.

I'd like to keep this ticket focused on the optimization of ad hoc queries.

@timowest timowest added a commit that referenced this issue Dec 14, 2012
@timowest timowest #304 improved Template handling 54be3d7
@timowest timowest added a commit that referenced this issue Dec 14, 2012
@timowest timowest #304 add new test case 382cc49
@timowest timowest added a commit that referenced this issue Dec 15, 2012
@timowest timowest #304 add gc before timings f63834d
@timowest timowest added a commit that referenced this issue Dec 15, 2012
@timowest timowest #304 optimize Templates e7de0a0
@timowest timowest added a commit that referenced this issue Dec 16, 2012
@timowest timowest #304 optmize metadata validation 51d9f99
@timowest timowest added a commit that referenced this issue Dec 16, 2012
@timowest timowest #304 remove types from Operator 9f0d281
@timowest
Member

Here are the latest results. This time with JDK 7

There is still some locking overhead in H2

- - jdbc by id 2228
- - jdbc by name 2978
- - qdsl by id 5963
- - qdsl by id (iterated) 6135
- - qdsl by id (result set access) 5787
- - qdsl by id (no validation) 5789
- - qdsl by id (two cols) 7195
- - qdsl by name 8412
- - qdsl by name (iterated) 8202
- - qdsl by name (no validation) 7782
- - ser1 1100
- - ser2 (non normalized) 972

The validation overhead for simple queries is now also quite minimal.

@timowest timowest added a commit that referenced this issue Dec 16, 2012
@timowest timowest #304 optimize CollectionUtils 253e6a5
@timowest
Member

Released in 3.0.0.BETA1

@timowest timowest closed this Jan 13, 2013
@timowest timowest added this to the 3.0.0 milestone Apr 14, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment