Issue Details (XML | Word | Printable)

Key: FLM-127
Type: Improvement Improvement
Status: Closed Closed
Resolution: Fixed
Priority: Major Major
Assignee: Borys Musielak
Reporter: Borys Musielak
Votes: 0
Watchers: 0
Operations

Clone this issue
Create sub-task
If you were logged in you would be able to see more operations.
Filmaster

Hugely improve performance of filltering recommendations by tags

Created: 22/Jun/09 02:15 AM   Updated: 30/Apr/10 05:52 PM
Component/s: Optimization, Recommendations
Affects Version/s: Pending bug fixes
Fix Version/s: 1.0.5

Time Tracking:
Not Specified

Issue Links:
Blocking
 
Similar
 


 Description  « Hide
Currently recommendations filtering by tags works too slow to allow it on production.

Explain analyze outputs:
- Filtering only comedies: http://explain-analyze.info/query_plans/3499-recom-by-tags [45 sec!]
- No filtering: http://explain-analyze.info/query_plans/3500-recom-by-tags-no-tags [0.5 sec]

The actual query in: film20/recommendations/recom_helper.py, method: get_best_psi_films_queryset

 All   Comments   Work Log   Change History      Sort Order: Ascending order - Click to sort in descending order
Scott Marlowe added a comment - 25/Nov/09 10:49 PM - edited
Looking at the first query plan / explain, it looks like the row estimates are pretty far off. What does

show default_statistics_target ;

on the db show? Can someone try

alter database <dbname> set default_statistics_target=100;
analyze;

and see if the query runs any faster?

Also, what's the work_mem on that server set to? Often turning it up just a bit from the default of 1M makes a huge difference.

alter database <dbname> set work_mem='16M';

Borys Musielak added a comment - 26/Nov/09 01:08 AM
-- run the query
Total runtime: 158941.862 ms
alter database film20dev set default_statistics_target=100;
analyze;
-- run the same query
Total runtime: 16049.823 ms

Still bad but not as bad.

Borys Musielak added a comment - 26/Nov/09 01:31 AM
And the mem settings we had were:

work_mem = 1MB # min 64kB
maintenance_work_mem = 16MB # min 1MB
max_stack_depth = 2MB # min 100kB

Changed the work_mem to 16M by:

alter database film20dev set work_mem='16MB';

and re-executed the query, but the execution was no different this time:
Total runtime: 19555.234 ms

Scott Marlowe added a comment - 26/Nov/09 09:19 AM
Well, that's an improvement by a factor of ten, so we're closer. Got a new explain analyze output from the query with the new stats settings?

Borys Musielak added a comment - 26/Nov/09 08:35 PM
You're right, of cours it's a good improvement. I just have an impression that te query can be reworked so that itr runs in ~100ms, so we have lots of optimization to do :)

Here's the new analyze: http://explain-analyze.info/query_plans/4513-recom-by-tags
(it takes a bit longer as I executed it from my laptop, not the server)

Scott Marlowe added a comment - 28/Nov/09 06:19 AM
Looking at the query plan it doesn't look like it changed any, just ran faster because you had less data for it to go through. The row estimates are still WAY off. Try setting the default_statistics_target to 1000 (the max), then run analyze, then explain analyze it and see if those nested loops up top that expect 1 to 10 rows but get 1,000s to get closer. If incrementing stats target doesn't help, we may have a corner case. If it was using the proper join methods we could get this down to something in the seconds or less.

I'll check out the code base and look through the part this comes from and see what I can do with the query.

Borys Musielak added a comment - 28/Nov/09 10:37 AM
The previous example was from my local machine when I had less data.

I ran it on production now and it looks like nothing is actually changing. Even when I increased the value to 1000, it runs faster on the prod server only if the same query is run again. When I change the tag name, it runs equally slow, say: 235178.815 ms.

So, it's not the statistics.

Scott Marlowe added a comment - 28/Nov/09 05:45 PM
So, you definitely ran analyze on the database between setting the stats and running the query, right?

Borys Musielak added a comment - 28/Nov/09 06:26 PM
Yes, definitely.

Borys Musielak added a comment - 16/Dec/09 08:15 PM
Scott, I can give you access to the database dump so that you could test that on your machine. Let me know if you want to examine that issue further.

Borys Musielak added a comment - 30/Apr/10 05:52 PM
Resolved with introduction of new recommendations engine (recommendations data now stored in a separate table: core_recommendation) and a reworked query.