[CSHARP-1225] Performance issues with 2.0 beta driver Created: 26/Mar/15 Updated: 05/Apr/19 Resolved: 08/May/15 |
|
| Status: | Closed |
| Project: | C# Driver |
| Component/s: | None |
| Affects Version/s: | 2.0 |
| Fix Version/s: | 2.1 |
| Type: | Task | Priority: | Major - P3 |
| Reporter: | Stefan | Assignee: | Craig Wilson |
| Resolution: | Done | Votes: | 0 |
| Labels: | question | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
||||||||
| Issue Links: |
|
||||||||
| Description |
|
I am noticing high CPU usage when I put some load against my API, doing some profiling I can see that the costliest part and the bit causing the issue is the high cost of all the EvaluateSubtree calls in the SubtreeEvaluator. I am seeing these issues using the latest 2.0 beta driver. |
| Comments |
| Comment by Craig Wilson [ 08/May/15 ] | ||||||
|
Stefan, I've pushed an update (thanks Ian) to speed up partial evaluation. I couldn't find a way to speed up LINQ in general other than pre-compiling and caching. CSHARP-1267 is going to be used to track that. Therefore, I went ahead and closed this ticket. Craig | ||||||
| Comment by Githook User [ 08/May/15 ] | ||||||
|
Author: {u'username': u'craiggwilson', u'name': u'Craig Wilson', u'email': u'craiggwilson@gmail.com'}Message: | ||||||
| Comment by Craig Wilson [ 05/May/15 ] | ||||||
|
No... In fact, I'm quite sure it has nothing to do with aggregation. The second numbers above were without roundtripping with the server. In fact, it seems to also have nothing to do with partial evaluation either as the samples I measured with had no need for partial evaluation. LINQ is simply a slower animal. That's why Entity Framework offers ways of doing compiled queries (https://msdn.microsoft.com/en-us/library/vstudio/bb896297%28v=vs.100%29.aspx). It's one of the things I'm working on figuring out. I've created CSHARP-1267 to track that although I've already been working on it. | ||||||
| Comment by Stefan [ 05/May/15 ] | ||||||
|
Thanks Craig, It is good to know I was not crazy Thanks | ||||||
| Comment by Craig Wilson [ 05/May/15 ] | ||||||
|
Hi Stefan, I can absolutely reproduce what you are seeing. I wrote a simple testing application as well. While it is running the fullstack and not measure just the individual piece about taking an expression and turning it into a query, it is inline with how an application might function. My results are that there is a large difference between Linq and the other 2 methods, which are fairly close.
In addition, when not including the roundtrip with the server and solely working client side rendering the queries, the numbers are still somewhat inline with the above results.
What this tells me is that the network (even localhost) is a major factor in how fast your application runs. Deciding between builders and the expression methods are so close that it's not worth it when you aren't pushing massive amounts of data across the network. Indeed, even when using linq, if you aren't going for massive throughput, the network simply consumes the largest amount of time. However, I'm going to look at Ian's attached work and see if I can make these numbers better. But the take away is that using expressions at runtime is expensive. While it's nice for readability, it is not the most performant. If you need raw throughput, you'll likely be better staying away from expressions altogether and use a BsonDocument. None of this should be a surprise. Regardless, I'll see if we can make these numbers better. I'll start with Ian's provided work and see where that gets me. Craig | ||||||
| Comment by Stefan [ 03/May/15 ] | ||||||
|
Craig, attached a sample. Annoyingly as is usually the case the LINQ version is not running as slow as it was many days ago (my machine is not under the CPU pressure it was on Friday so this might have something to do with it), but it is still behind the builder version, although you can see the aggregate version is the slowest of all. I added some queries timing in there too or you can watch mongostat. Cheers | ||||||
| Comment by Craig Wilson [ 03/May/15 ] | ||||||
|
Could you provide the code you are using in each case? Craig | ||||||
| Comment by Stefan [ 03/May/15 ] | ||||||
|
Craig, Not sure on only supporting aggregation, running the same query I am seeing only 4,000 ops a second vs 25,000 when running the normal find query with the builder. That is a concerning decrease in performance for me. Cheers | ||||||
| Comment by Craig Wilson [ 01/May/15 ] | ||||||
|
Tremenous. Thanks Ian. | ||||||
| Comment by Ian Newson [ 01/May/15 ] | ||||||
|
Hi Craig, Attached is an example of the expression evaluator I mentioned. There's a Many thanks, | ||||||
| Comment by Craig Wilson [ 01/May/15 ] | ||||||
|
Hi Ian, Yeah, some code would be a great starting point. Email us dotnet-driver@10gen.com. Thanks, | ||||||
| Comment by Ian Newson [ 01/May/15 ] | ||||||
|
Regarding the original speed issues, I wrote a LINQ provider a few years ago and noticed definite speed issues when compiling expressions, so I ended up writing a custom expression evaluator. It attempts to resolve all parts of the expression without using compilation by using reflection alone, and falls back to .Compile for complicated or unsupported expressions, which aren't the majority of expressions I find. I can share some code if you're interested? | ||||||
| Comment by Craig Wilson [ 01/May/15 ] | ||||||
|
Yeah. Currently, we are only targeting the aggregation framework. It is a much more natural translation than find. What are your thoughts on not supporting find and only targeting the aggregation framework? | ||||||
| Comment by Stefan [ 01/May/15 ] | ||||||
|
Ah interesting when using AsQueryable() everything runs as an aggregation query? did not expect that. | ||||||
| Comment by Stefan [ 01/May/15 ] | ||||||
|
I grabbed the latest code from github and trying out that driver to see if anything has been fixed interestingly if I use the queryable provider again not that is if back collection.AsQueryable().FirstOrDefault(x => x.CustomerId == id); mongostat shows it as commands and not queries, and showing around 4k/s there, anything obvious I am not doing? | ||||||
| Comment by Stefan [ 01/May/15 ] | ||||||
|
Just a followup on this one Craig, running the following query against mongo and looking at mongostat in a 8 thread test harness and seeing around 11.000 reads a second await collection.Find(x => x.CustomerId == id).FirstOrDefaultAsync(); If I change this to use the builder I get over 25,000 reads a second, huge increase in performance so there is definitely something up here: await collection.Find(Builders<Collection>.Filter.Eq(x => x.CustomerId, id)).FirstOrDefaultAsync(); Thanks | ||||||
| Comment by Stefan [ 26/Mar/15 ] | ||||||
|
Great thanks Craig, has been hard to keep up with the new API | ||||||
| Comment by Craig Wilson [ 26/Mar/15 ] | ||||||
|
IIRC, the PartialEvaluator has always been a CPU hog. I'll take a closer look at it and see if there is anything we can do. Its purpose is to turn variables and client-side evaluatable functions into constants. That requires that a compilation and evaluation occur. Anywyas, I'll see what I can do. BTW: You don't have to lose type safety during this workaround. You can use the
| ||||||
| Comment by Stefan [ 26/Mar/15 ] | ||||||
|
Sorry Craig I copied that code from an old snip I had yesterday, I actually upgraded yesterday and yeah using the new way to use the object filter, I tried that to just see if it made any difference. Thanks | ||||||
| Comment by Craig Wilson [ 26/Mar/15 ] | ||||||
|
Stefan, what version of the driver are you using? We removed the ability to use an anonymous type as a filter in rc0 I believe. (you can still do it, it just takes a little more work). | ||||||
| Comment by Stefan [ 26/Mar/15 ] | ||||||
|
Hi Craig, The query is pretty basic, a single call to the API for this test just loads the current customer,if I run this using the LINQ version I see CPU hit 80% with evaluation being a clear hot spot.
I change this to an object search using:
I can see an over all reduction in CPU and also a fairly large increase in the requests/second I can process. Think I might need to dig into it further, just sharing my initial findings to see if anyone has experienced similar. Thanks | ||||||
| Comment by Craig Wilson [ 26/Mar/15 ] | ||||||
|
Hi Stefan, That's interesting. This is the same evaluator we've been using for years now. Have you used the 1.x series of the driver and did you see this same behavior? Perhaps some code could be shared to better let us get a handle on what types of expressions you are using. Thanks, |