How to Identify a MongoDB Performance Anti Pattern in Five Minutes
Analyzing the application
By: Michael Kopp
Feb. 9, 2013 12:00 PM
The other day I was looking at a web application that was using MongoDB as its central database. We were analyzing the application for potential performance problems and inside five minutes I detected what I must consider to be a MongoDB anti pattern and had a 40% impact on response time. The funny thing: It was a Java best practice that triggered it.
Analyzing the Application
Overall Transaction Flow of the Application
As we see it's a modestly complex web application and it's using MongoDB as its datastore. Overall MongoDB contributes about 7% to the response time of the application. I noticed that about half of all transactions are actually calling MongoDB so I took a closer look.
Flow of Transactions that access MongoDB, showing 10% response time contribution of MongoDB
Those transactions that actually do call MongoDB spend about 10% of their response time in that popular document database. As a next step I wanted to know what was being executed against MongoDB.
Overview of all MongoDB commands. This shows that the JourneyCollection find and getCount contribute the most to response time
One immediately notices the first two lines, which contribute much more to the response time per transaction than all the others. What was interesting was that thegetCount on the JourneyCollection had the highest contribution time, but the developer responsible was not aware that he was even using it anywhere.
Things get interesting - the mysterious getCount call
Transactions that call JourneyCollection.getCount spend nearly half their time in MongoDB
What jumps out is that those particular transactions spend indeed over 40% of their time in MongoDB, so there was a big potential for improvement here. Another click and we looked at all MongoDB calls that were executed within the context of the same transaction as the getCount call we found so mysterious.
All MongoDB Statements that run within the same transaction context as the JourneyCollection.getCount
What struck us as interesting was that the number of executions per transaction of thefind and getCount on the JourneyCollection seemed closely connected. At this point we decided to look at the transactions themselves - we needed to understand why that particular MongoDB call was executed.
Single Transactions that execute the ominous getCount call
It's immediately clear that several different transaction types are executing that particulargetCount. What that meant for us is that the problem was likely in the core framework of that particular application rather than being specific to any one user action. Here is the interesting snippet:
The Transaction Trace shows where the getCount is executed exactly
We see that the WebService findJourneys spends all its time in the two MongoDB calls. The first is the actual find call to the Journey Collection. The MongoDB client is good at lazy loading, so the find does not actually do much yet. It only calls the server once we access the result set. We can see the round trip to MongoDB visualized in the call node at the end.
We also see the offending getCount. We see that it is executed by a method called sizewhich turns out to be com.mongodb.DBCursor.size method. This was news to our developer. Looking at several other transactions we found that this was a common pattern. Every time we search for something in the JourneyCollection the getCountwould be executed by com.mongodb.DBCursor.size. This always happens before we would really execute the send the find command to the server(which happens in the callmethod). So we used CompuwareAPM DTM's (a.k.a dynaTrace) developer integration and took a look at the offending code. Here is what we found:
An Anti-Patter triggered by a Best Practice
In addition this also demonstrates nicely why premature micro optimization, without leveraging an APM solution, in production will not lead to better performance. In some cases - like this one - it can actually lead to worse performance.
Reader Feedback: Page 1 of 1
Latest AJAXWorld RIA Stories
Subscribe to the World's Most Powerful Newsletters
Subscribe to Our Rss Feeds & Get Your SYS-CON News Live!
SYS-CON Featured Whitepapers
Most Read This Week