Death by 70,000 Facets

just sit right back and you'll hear a tale, a tale of a fateful bug. that started from a simple request, about a feature that was just a bit too snug.

okay, leaving aside my attempts at humor. this story is about a customer reporting an issue. “most of the time we have ravendb running really fast, but sometimes we have high latency requests”.

after a while, we managed to narrow it down to the following scenario:

• we have multiple concurrent requests.
• those requests contains a lazy request that has a facet query.
• the concurrent requests appears to all halt and then complete together.

in other words, it looks like we had all those requests waiting on a lock, then when it is released, all of them are free to return. this makes sense, there is a cache lock in the facet code that should behave in this manner. but when we looked at that, we could see that this didn’t really behave in the way we expected it to.

eventually we got to test this out on the client data, and that is when we were able to pin point the issue.

usually, you have facets like this:

the one of the left is when searching amazon for hd, the one on the right is when you search amazon for tv.

in ravendb, you typically express this sort of query using:

session.query<product>().search(“search”, query).tofacets(new facet { name = “brand”} );

and we expect the number of facets that you have in a query to be in the order of a few dozens.

however, the client in question has done something a bit different. i think that this is because they brought the system over from a relational database. each product in the system had a list of facets associated with it. it looked something like:

“facets”: [13124,87324,32812,65743]

obvious, this means that this product belongs to the “2,000 – 3,500” price range facet (electronics) the “red” color facet (electronics, handheld) etc…

in total, we had over 70,000 facets in the database, and that is just something that we never really expected. because we didn’t expect it, we reacted… poorly when we had to deal with it. in fact, what happened was that pattern of behavior meant that we effectively had worse than not having a cache, we would always have to do the work, and never really gain any benefit from it (there wasn’t enough sharing to actually trigger the benefits of the cache). and because we did locks on the cache to ensure that we don’t get into a giant mess… well, you can figure out how it went from there.

the fix was to actually devolve the code in to a simpler method. instead of trying to be smart and just figure out what we needed to compute for this query, we can be aggressive and load everything we needed. all the next requests will result in no wait time, because the data is already there. the code became much simpler.

oh, and we got it deployed to production and saw a 400% decrease in the average request time, and no more sudden waits when we had requests piling up.