[WIP] Optimize postgresql storage get all fixes 1507 #1615

peterbe · 2018-04-26T19:41:18Z

Add documentation.
Add tests.
Add a changelog entry.
Add your name in the contributors file.
If you changed the HTTP API, update the API_VERSION constant and add an API changelog entry in the docs
If you added a new configuration setting, update the kinto.tpl file with it.

peterbe · 2018-04-26T19:42:15Z

Did some benchmarking first. See https://gist.github.com/peterbe/c4b6bb31e2b957d85d14932f5200f08a

peterbe · 2018-04-26T20:03:22Z

kinto/core/storage/postgresql/__init__.py

-        if len(retrieved) == 0:
-            return [], 0
+            if len(retrieved) == 0:
+                return [], 0


There might be some further work to do here.
This early exit allows us to being able to skip the COUNT query since the SELECT query yielded 0 results anyway.

The reason for why I didn't use the exact filter for the COUNT and the SELECT was because of this test:
https://github.com/peterbe/kinto/blob/51c7bf9ec9eb1f89d7e7d3a015429f2bc525551d/kinto/core/storage/testing.py#L1217-L1218
(there might be more like this!)
In that test it does a get_all(include_deleted=True, ...) and it expects the number of records to be different from the total count.
Isn't that strange? If you include_deleted=True why should the total count be always filter out the deleted records??

If that test is wrong, I can rewrite the two queries so that the SELECT and COUNT uses the exact same WHERE clause. Then, if we do that we can do the COUNT first (slightly faster since it's just an integer) and if it's 0 we can skip the SELECT and just return an empty list.

The variables are not named correctly in the tests, instead it could be:

records_and_tombstones, records_count = self.storage.get_all(parent_id='abc', collection_id='c', include_deleted=True) self.assertEqual(records_count, 0) self.assertEqual(len(records_and_tombstones), 2)

The returned count is the number of records, excluding tombstones. Tombstones are returned when ?_since is in querystring, they are not real records....

The parameter include_deleted is not named correctly, it should be with_tombstones. We identified the issue a while ago #710

glasserc · 2018-04-26T20:34:58Z

I see you've made some drastic changes to this query. Most are probably fine, but separating the SELECT and COUNT into separate queries damages reentrancy. Is it possible to benchmark with and without that change, to see how much it gains us to sacrifice reentrancy like this?

leplatrem

I was first tempted to think that the count reentrancy would be acceptable, but it's used to paginate in the resource code collection_get(). I wonder what consequences could there be, but maybe there are ways to be smarter there... Related #1170

leplatrem · 2018-04-27T10:44:18Z

kinto/core/storage/postgresql/__init__.py

+        select_query = """
+        SELECT {distinct} id, as_epoch(last_modified) AS last_modified, data
+          FROM records
+           WHERE {pagination_rules}


µ-nit: indentation of WHERE 😊

leplatrem · 2018-04-27T10:52:17Z

kinto/core/storage/postgresql/__init__.py

-        if len(retrieved) == 0:
-            return [], 0
+            if len(retrieved) == 0:
+                return [], 0


The variables are not named correctly in the tests, instead it could be:

records_and_tombstones, records_count = self.storage.get_all(parent_id='abc', collection_id='c', include_deleted=True) self.assertEqual(records_count, 0) self.assertEqual(len(records_and_tombstones), 2)

The returned count is the number of records, excluding tombstones. Tombstones are returned when ?_since is in querystring, they are not real records....

The parameter include_deleted is not named correctly, it should be with_tombstones. We identified the issue a while ago #710

peterbe · 2018-04-27T12:49:00Z

In #1616 (comment) I discovered something.

This PR uses a DISTINCT if '*' in parent_id. That means it will return only 1 single ID + last_modified + data combo if they're all identical, but only differ in parent_id value. That's not what the original query (which this PR replaces) did. It returned duplicate rows.
That means this PR behaves different from master and the tests didn't catch it :(

peterbe · 2018-04-27T12:59:04Z

To be clear; in my last commit, I removed the DISTINCT functionality when '*' in parent_id. It now behaves exactly like get_all in master and as a fun-fact, this changed was never caught in tests.

peterbe · 2018-04-27T13:39:25Z

@glasserc When you talked about reentrence, does that refer to the network overhead of having to send the query twice to the Postgres server. Especially if it's latency is slightly scary.

Note that the psycopg connection is kept open by the Python process. So the re-entrence doesn't have pay a "connection fee" more than once.

Or, are you referring to it as a risk of getting wrong numbers between the two queries? I.e.

time 1. (thread 1) SELECT COUNT(*) FROM records WHERE x=y  (returns 100)
time 2. (thread 2) DELETE FROM records WHERE x=y and z=z   (deletes 1 row)
time 3. (thread 1) SELECT id, last_modified FROM records WHERE x=y (returns 99 rows)

Also, in terms of benchmarking performance, see https://gist.github.com/peterbe/c4b6bb31e2b957d85d14932f5200f08a#gistcomment-2571339
That's using requests.get on my local kinto on :8888 which talks to a database on localhost. It's under no other concurrent load. This benchmark is entirely synchronous. But still, it's showing (not proving) that the HTTP GET of records (with ?_limit=10) is 30 times faster now.

peterbe · 2018-04-27T13:54:20Z

Perhaps I'm trying to prove something that isn't all that important or disputed, but I updated the HTTP GET benchmark by seeing how it behaves under concurrent load.
https://gist.github.com/peterbe/c4b6bb31e2b957d85d14932f5200f08a#gistcomment-2572108

leplatrem · 2018-04-27T14:25:15Z

kinto/core/storage/postgresql/__init__.py

            placeholders.update(**holders)
+        else:
+            safeholders['pagination_rules'] = ''


nit: superfluous since safeholders is a default dict ;)

leplatrem · 2018-04-27T14:37:17Z

CHANGELOG.rst

- Nothing changed yet.
+**Internal changes**
+
+- Refactor of ``kinto.core.storage.Storage.get_all`` method to issue two separate,


nit: it only applies to PostgreSQL ;)

And also, I think it would make sense to mention the performance gain!

leplatrem · 2018-04-27T14:38:34Z

Or, are you referring to it as a risk of getting wrong numbers between the two queries? I.e.

Yes, I'm pretty sure it's this one! Ethan has worked a lot on race conditions / TOCTOU stuff ;)

peterbe · 2018-04-27T16:14:42Z

Ethan has worked a lot on race conditions / TOCTOU stuff ;)

Ah! Yeah, it's a real concern. I stand by the fact that this is now going to get significantly an un-risk. What I mean by that is that since the select id, last_modified, data FROM records WHERE parent_id... collection_id=... ORDER BY last_modified DESC LIMIT 10 is a pure index-level read, it's always going to be fast. It doesn't even need to read the records table.

In https://gist.github.com/peterbe/c4b6bb31e2b957d85d14932f5200f08a I was able to show that I can finish the select in 1.59ms on a 183,244 records database. And what proves that it's an index-level read (apart from looking at the EXPLAIN ANALYZE) is that that number is 1.51ms for an even larger database. (Why it's not exactly the same I don't know).

Anyway, there is a real way to prevent the len(SELECT) != COUNT across the two executions. You can use REPEATABLE READ
See https://gist.github.com/peterbe/546e782b5ae51afb22ab0eed9b3ddab1
It demonstrates the race-condition (comment out line 34-35) and a solution.

I haven't attempted to use this set_session inside kinto at all. Nor have I run a benchmark to see how much it costs.

glasserc · 2018-04-27T17:07:29Z

Now that #1616 is clarified, it would be good to add a test to this PR that captures the subtle bug that the old query had when using a wildcard parent_id.

select id, last_modified, data FROM records WHERE parent_id... collection_id=... ORDER BY last_modified DESC LIMIT 10 is a pure index-level read, it's always going to be fast. It doesn't even need to read the records table.

It happens to be that way sometimes, but in general this query may not be a pure index-level read, and it may need to read the records table.

Anyway, there is a real way to prevent the len(SELECT) != COUNT across the two executions. You can use REPEATABLE READ

Another, simpler way is to use a different query. For example, the previous query doesn't have this problem. That's why I asked you to benchmark with and without that change. Even if the risk is small, it's a new risk and I would like to know what the pros and cons are.

peterbe · 2018-04-27T19:25:56Z

add a test to this PR that captures the subtle bug

Criss-cross github issue madness. #1616 (comment)

That's why I asked you to benchmark with and without that change.

So my change here comes at a danger in that you CAN end up with count != len(records) due to an unlucky edit whilst these two queries are sent.
I think we have strong benchmarks showing that the SQL is "better" and I've done bencmarks using my local localhost:8888 kinto server.

But I haven't made any benchmarks with/without the technique discussed in https://gist.github.com/peterbe/546e782b5ae51afb22ab0eed9b3ddab1
I can attempt that.

glasserc · 2018-04-27T19:34:33Z

No, I don't want you to test using REPEATABLE READ, because I think that change is outside the scope of this PR. Introducing REPEATABLE READ means having to deal with serialization failures and I don't think we're ready to do that yet.

I want you to test with/without two queries, because it's possible to write a single query that does not suffer from the race condition that you automatically have if you write two queries, and if the performance penalty for that isn't too bad, then I would prefer that.

Yes, with this PR, certain queries are faster. (It turns out that others are slower.) But you have made a lot of different changes to the queries in order to get this result. I would like to look at each change individually rather than the whole package.

peterbe · 2018-04-30T19:37:48Z

Now I understand your point @glasserc
Here's one version using the OVER () technique:

select COUNT(*) OVER (), id, as_epoch(last_modified) AS last_modified,
MD5(jsonb_pretty(data)) AS data
from records
WHERE parent_id = '/buckets/build-hub/collections/releases'
AND collection_id = 'record'
ORDER BY last_modified DESC
LIMIT 10;

Compared to these two:

select count(*)
from records
WHERE parent_id = '/buckets/build-hub/collections/releases'
AND collection_id = 'record';

select id, as_epoch(last_modified) AS last_modified,
MD5(jsonb_pretty(data)) AS data
from records
WHERE parent_id = '/buckets/build-hub/collections/releases'
AND collection_id = 'record'
ORDER BY last_modified DESC
LIMIT 10;

If I break these up and run all three 10 times and record the best possible time with my 183,240 rows database:

955.45ms
99.19ms
1.72ms

Difference is that it's roughly 10x slower to do the COUNT(*) OVER (). /me stunned!
When I attempt the same benchmark but on my larger database (775,557 rows) it blows up:

5179.24ms
758.27ms
1.70ms

To sanity check I compared it with the original query (the one still in master) and output looks the same: https://gist.github.com/peterbe/21b3e12484cc4937ec002c76f277f2cd

Lastly, the COUNT(*) OVER () is really meant for doing partitioning. For example, a count of something by weekday for example.

Also, the biggest problem with the SELECT COUNT(*) OVER (), id, ... query is that it's using the same WHERE clause for the count as it does for the LIMIT 10 records retrieval. In particular, according to the unit tests if you filter by including tombstones, the number of records isn't expected to the best same as the "total_count".

Next, anybody got a really good window function to do the same that I can use?

peterbe · 2018-04-30T20:00:16Z

By the way, I tried to write a CTE query but after a lot of trial-and-error the only thing I could come up with was one just like the original and back to square one where it takes several seconds to execute it. :(

glasserc · 2018-04-30T20:41:51Z

Great, thanks!

From your notes in #1507, the SELECT COUNT(*) is able to do a table scan, I guess probably because the vast majority of your DB is buildhub stuff. However, the combined data-and-count is probably doing an index scan so it can output results in the right order, and I bet the index scan adds some overhead. On my machine, the difference is not so drastic -- about a factor of 2x -- but maybe on your machine the table scan is being parallelized in a way that the index scan can't be.

One obvious difference between the queries you're benchmarking and the ones in your PR is that the ones in the PR have filters associated with them. Between this and the fact that your broken-down queries are doing a table scan, it might be good to see what happens if you run the query on a collection that makes up a smaller proportion of the database.

I didn't know about windowing functions. The query I came up with is much closer to the original query:

WITH collection_filtered AS (
    SELECT id, last_modified, data, deleted
      FROM records
     WHERE parent_id = '/buckets/a/collections/b'
       AND collection_id = 'record'
  ORDER BY last_modified DESC
),
total_filtered AS (
    SELECT COUNT(*) AS count_total
      FROM collection_filtered
     WHERE NOT deleted
)
 SELECT count_total,
       a.id, as_epoch(a.last_modified) AS last_modified, a.data
  FROM collection_filtered as a,
       total_filtered
 LIMIT 10;

peterbe · 2018-05-01T18:45:50Z

I took a copy of my database and deleted a bunch of random records. Now it only has 30,000 records. Half of them I changed the parent_id. Now it looks like this:

buildhub_small=# select parent_id, count(parent_id) from records group by parent_id;
                parent_id                | count
-----------------------------------------+-------
 /buckets/build-hub/collections/funny    | 14504
 /buckets/build-hub/collections/releases | 15555

Now, let's compare

WITH collection_filtered AS (
    SELECT id, last_modified, data, deleted
      FROM records
     WHERE parent_id = '/buckets/build-hub/collections/funny'
       AND collection_id = 'record'
  ORDER BY last_modified DESC
),
total_filtered AS (
    SELECT COUNT(*) AS count_total
      FROM collection_filtered
     WHERE NOT deleted
)
 SELECT count_total,
       a.id, as_epoch(a.last_modified) AS last_modified,
       a.data
  FROM collection_filtered as a,
       total_filtered
 LIMIT 10;

Against...

select count(*)
from records
WHERE parent_id = '/buckets/build-hub/collections/funny'
AND collection_id = 'record';

and

select id, as_epoch(last_modified) AS last_modified,
data
from records
WHERE parent_id = '/buckets/build-hub/collections/funny'
AND collection_id = 'record'
ORDER BY last_modified DESC
LIMIT 10;

Results:

138.09ms (the combined)
6.84ms (the count)
1.62ms (the select)

So combined is still much slower. 16x slower.

I ran each query 100 times which makes the mean ~= median on the Execution time.

glasserc · 2018-05-02T03:22:51Z

50% is still quite a large slice of your database. I bet it's still doing a table scan. (Some EXPLAIN ANALYZE output would verify it for sure.) How about if it's only 10% or 1% of the total records? How about one of the records from the buildhub docs, using the Kinto records API queries instead of ElasticSearch?

peterbe · 2018-05-02T16:24:51Z

This time, I try with a parent_id that only matches 10 items:

buildhub_small=# select parent_id, count(parent_id) from records group by parent_id;
                parent_id                 | count
------------------------------------------+-------
 /buckets/build-hub/collections/10records |    10
 /buckets/build-hub/collections/1records  |     1
 /buckets/build-hub/collections/funny     | 14497
 /buckets/build-hub/collections/releases  | 15551

Same three queries as above but instead of parent_id = '/buckets/build-hub/collections/funny' it's now parent_id = '/buckets/build-hub/collections/10records'

Results:

1.48ms
0.15ms
1.55ms

So in this case, the split up select & count is 10% slower.

peterbe · 2018-05-02T16:27:19Z

All three EXPLAIN ANALYZE are as follows:

The order is:

The COUNT query
The SELECT query
@glasserc's last suggest CTE query but with the parent_id that matches 10 records.

                                                                              QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=4.44..4.45 rows=1 width=8) (actual time=0.106..0.106 rows=1 loops=1)
   ->  Index Only Scan using idx_records_parent_id_collection_id_last_modified on records  (cost=0.41..4.43 rows=1 width=0) (actual time=0.066..0.095 rows=10 loops=1)
         Index Cond: ((parent_id = '/buckets/build-hub/collections/10records'::text) AND (collection_id = 'record'::text))
         Heap Fetches: 10
 Planning time: 0.692 ms
 Execution time: 0.190 ms
(6 rows)

                                                                                QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=8.69..8.70 rows=1 width=1064) (actual time=0.672..0.674 rows=10 loops=1)
   ->  Sort  (cost=8.69..8.70 rows=1 width=1064) (actual time=0.672..0.672 rows=10 loops=1)
         Sort Key: (as_epoch(last_modified)) DESC
         Sort Method: quicksort  Memory: 41kB
         ->  Index Scan using idx_records_parent_id_collection_id_last_modified on records  (cost=0.41..8.68 rows=1 width=1064) (actual time=0.596..0.618 rows=10 loops=1)
               Index Cond: ((parent_id = '/buckets/build-hub/collections/10records'::text) AND (collection_id = 'record'::text))
 Planning time: 0.259 ms
 Execution time: 1.971 ms
(8 rows)

                                                                              QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=8.47..8.77 rows=1 width=80) (actual time=0.064..0.086 rows=10 loops=1)
   CTE collection_filtered
     ->  Index Scan using idx_records_parent_id_collection_id_last_modified on records  (cost=0.41..8.43 rows=1 width=1065) (actual time=0.009..0.016 rows=10 loops=1)
           Index Cond: ((parent_id = '/buckets/build-hub/collections/10records'::text) AND (collection_id = 'record'::text))
   CTE total_filtered
     ->  Aggregate  (cost=0.02..0.03 rows=1 width=8) (actual time=0.032..0.032 rows=1 loops=1)
           ->  CTE Scan on collection_filtered  (cost=0.00..0.02 rows=1 width=0) (actual time=0.003..0.030 rows=10 loops=1)
                 Filter: (NOT deleted)
   ->  Nested Loop  (cost=0.00..0.30 rows=1 width=80) (actual time=0.064..0.084 rows=10 loops=1)
         ->  CTE Scan on collection_filtered a  (cost=0.00..0.02 rows=1 width=72) (actual time=0.010..0.015 rows=10 loops=1)
         ->  CTE Scan on total_filtered  (cost=0.00..0.02 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=10)
 Planning time: 0.168 ms
 Execution time: 0.142 ms
(13 rows)

All three use an index scan.

peterbe · 2018-05-03T15:10:01Z

In Buildhub we have this thing were it uses kinto_http.Client().get_records() to get every single record from the Kinto database. It does it 10,000 records at a time. I put a time measure around that beast in Python:

import time
t0=time.time()
new_records_batches = [client.get_records(
    _since=previous_run_etag,
    pages=float('inf')
)]
t1=time.time()
print(
    "TOOK",
    t1 - t0,
    "seconds to paginate fetch",
    len(new_records_batches[0]),
    "(in {} batches of 10,000)".format(int(len(new_records_batches[0]) / 10_000))
)
raise Exception

The output becomes:

TOOK 1066.8049581050873 seconds to paginate fetch 785908 (in 78 batches of 10,000)

Then I literally copied the __init__.py from this PR into my kinto inside my virtualenv and ran it again. This time the output is:

TOOK 83.82302474975586 seconds to paginate fetch 785908 (in 78 batches of 10,000)

To sanity check, I watched my /usr/local/var/log/postgres.log where I have it log every single query.

Before
After

I also saved each massive list of dicts to disk to be able to compare them:

>>> import json
>>> old =json.load(open('new_records-old.json'))
>>> new =json.load(open('new_records-new.json'))
>>> len(old)
785908
>>> len(new)
785908

However! They were not identical. If I parse them and analyzed them a bit more in detail.

If I convert each list to a dict by the 'id' I can see that there were 2 IDs in the one that the other didn't have and vice versa.

>>> old_s - new_s
{'devedition_aurora_58-0b6rc1_linux-x86_64_et', 'devedition_aurora_59-0b6_win64_bs'}
>>> old_d['devedition_aurora_58-0b6rc1_linux-x86_64_et']['last_modified']
1524241288164
>>> old_d['devedition_aurora_59-0b6_win64_bs']['last_modified']
1524240460834
>>> new_s - old_s
{'devedition_aurora_58-0b6rc1_linux-x86_64_as', 'devedition_aurora_59-0b6_win32_uk'}
>>> new_d['devedition_aurora_58-0b6rc1_linux-x86_64_as']['last_modified']
1524241288164
>>> new_d['devedition_aurora_59-0b6_win32_uk']['last_modified']
1524240460834

So the old (master) code fails to retrieve two IDs. And the new (my code) also fails to retrieve two IDs. All four records are in the database:

buildhub=# select id, as_epoch(last_modified), last_modified from records where id in ('devedition_aurora_58-0b6rc1_linux-x86_64_as', 'devedition_aurora_59-0b6_win32_uk', 'devedition_aurora_58-0b6rc1_linux-x86_64_et', 'devedition_aurora_59-0b6_win64_bs');
                     id                      |   as_epoch    |       last_modified
---------------------------------------------+---------------+----------------------------
 devedition_aurora_58-0b6rc1_linux-x86_64_as | 1524241288164 | 2018-04-20 16:21:28.163601
 devedition_aurora_58-0b6rc1_linux-x86_64_et | 1524241288164 | 2018-04-20 16:21:28.16417
 devedition_aurora_59-0b6_win32_uk           | 1524240460834 | 2018-04-20 16:07:40.833634
 devedition_aurora_59-0b6_win64_bs           | 1524240460834 | 2018-04-20 16:07:40.834225
(4 rows)

I'm not even sure where to begin debugging this! Or if now's the time to debug it at all. One culprit might be the rounding error of rounding the last_modified up to the nearest second. Note that each two pairs of last_modified is different but their as_epoch is the same. :(

End of the day, the new code works just as well as the old code but it's 13 times faster.

leplatrem · 2018-05-03T15:37:55Z

One culprit might be the rounding error of rounding the last_modified up to the nearest second. Note that each two pairs of last_modified is different but their as_epoch is the same. :(

OMG, this is dreadful... it's unrelated to this PR indeed, which has to assume that epoch timestamps are unique. Let's create a bug around that, we should at least have a DB constraint to avoid this situation

glasserc · 2018-05-04T13:34:14Z

We just talked about this in Vidyo -- for those following along at home:

Although this issue seemed like a P5 previously, maybe it's a P3 or P2. @leplatrem , @mostlygeek ?
I agree that the existing query is bad and needs to be replaced. I'm not excited about replacing it with two queries: this introduces race conditions, and for some requests, it's slower than what we have.
I think we can do better than what we have without introducing race conditions nor slowing down certain queries. I think that would be a slam dunk easy merge scenario.
If we're going to make some requests slower in exchange for making other requests faster, I think we need to have very clear and explicit reasoning about why the requests we're making slower are OK to make slower (less common, less important, etc.).

An option might be to introduce heuristics to try to figure out which kind of situation we're in -- maybe in situation A, query q1 is faster, and in situation B, query q2 is faster. (We do have some stuff like this already; see

kinto/kinto/core/permission/postgresql/__init__.py

Lines 482 to 493 in 382adcd

    
                   if len(object_id_list) == 1: 
        
                       # Optimized version for just one object ID.  This can be 
        
                       # done using an index scan on 
        
                       # idx_access_control_entries_object_id. The more 
        
                       # complicated form above confuses Postgres, which chooses 
        
                       # to do a sequential table scan rather than an index scan 
        
                       # for each entry in object_ids, even when there's only one 
        
                       # entry in object_ids. 
        
                       query = """ 
        
                       DELETE FROM access_control_entries 
        
                        WHERE object_id LIKE :obj_id_0; 
        
                       """

.) But this gets us into the business of trying to outrun the Postgres query planner and I'm not confident that our time is well spent doing that.

If I understood correctly, @peterbe said he was going to step away from this PR so (assuming it's high priority) maybe I will take a swing at coming up with a query that is better than what we have without slowing down other queries.

leplatrem · 2018-05-04T13:51:35Z

Although this issue seemed like a P5 previously, maybe it's a P3 or P2. @leplatrem , @mostlygeek ?

There are many aspects that made this issue more important recently:

It now has a proposed solution in a PR where tests pass. It's always nice to avoid letting it rot and keep conversations alive.
In buildhub, everytime a new version is deployed, a job fetches the 1 million records from Kinto. Recently there had been many new releases and the whole thing slows down.
Some users were trying to do some queries and got 504 Production service 504s (Gateway timeout) or slow mozilla-services/buildhub#350 The workaround is to use the ElasticSearch endpoint of course, but it'd be nice to avoid it

peterbe · 2018-05-04T14:29:41Z

for some requests, it's slower than what we have

I don't think that's a fair evaluation. When there were only 10 records to be matched, the sum of the SELECT + COUNT query was 10% slower. Also, it was a difference between 1.48ms vs. 0.15ms+1.55ms. That might just be noise. There is admittedly a tiny overhead of having to send two distinct queries on the open connection.

The proposed solution works for tiny queries. Paying 1.7ms for a count and a set of records is cheap. And it scales rapidly when it goes way beyond 10 matching records.

Also, in terms of priorities I think we're missing a subtle point in that if a READ query takes 15 seconds (not unrealistic at all at the moment on databases like Buildhub) that means the Postgres server is potentially distracted and resource hogging for other queries (read or write) that needs to be dealt with. Perhaps that's why we saw, in New Relic, these monster times for queries that, on paper, should be fast.

My perspective on Kinto that of a single instance that I'm familiar with. That's why I'm hesitant to speak to the risk evaluation of this in totality. Hence be now slightly withdrawn involvement.

glasserc · 2018-05-04T18:34:45Z

I don't think that's a fair evaluation. When there were only 10 records to be matched, the sum of the SELECT + COUNT query was 10% slower.

In fact, your proposed solution can be up to 100% slower because of what I wrote in #1507 (comment).

Also, in terms of priorities I think we're missing a subtle point in that if a READ query takes 15 seconds (not unrealistic at all at the moment on databases like Buildhub) that means the Postgres server is potentially distracted and resource hogging for other queries (read or write) that needs to be dealt with.

In general, yes, I agree, slow queries are bad. Note that what you are worrying about here is about CPU usage. However, your benchmarks actually measure latency.

peterbe · 2018-05-18T12:09:26Z

So can we close this now that #1622 has landed? I think so.

leplatrem · 2018-05-18T13:56:25Z

As Ethan said, #1622 was a first step and we can do better. Especially when we figure out a strategy for #1624.

optimize postgresql storage get_all, fixes Kinto#1507

51c7bf9

peterbe force-pushed the optimize-postgresql-storage-get_all-fixes-1507 branch from cb61a32 to 51c7bf9 Compare April 26, 2018 19:46

peterbe commented Apr 26, 2018

View reviewed changes

leplatrem reviewed Apr 27, 2018

View reviewed changes

peterbe mentioned this pull request Apr 27, 2018

Do we need to support get_all with a wildcard parent_id? #1616

Closed

addressing feedback and dropping DISTINCT

caf0245

peterbe added 2 commits April 27, 2018 09:55

adding myself to contributors

56c8e4e

update CHANGELOG

3a127c0

leplatrem reviewed Apr 27, 2018

View reviewed changes

review feedback

420a5d7

peterbe mentioned this pull request May 3, 2018

as_epoch is potentially too inaccurate for safe pagination #1621

Open

glasserc mentioned this pull request May 8, 2018

What should we do with Total-Records? #1624

Closed

peterbe closed this May 18, 2018

peterbe deleted the optimize-postgresql-storage-get_all-fixes-1507 branch December 6, 2018 22:20

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[WIP] Optimize postgresql storage get all fixes 1507 #1615

[WIP] Optimize postgresql storage get all fixes 1507 #1615

peterbe commented Apr 26, 2018 •

edited

peterbe commented Apr 26, 2018

peterbe Apr 26, 2018

leplatrem Apr 27, 2018

glasserc commented Apr 26, 2018

leplatrem left a comment •

edited

leplatrem Apr 27, 2018

leplatrem Apr 27, 2018

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

leplatrem Apr 27, 2018

leplatrem Apr 27, 2018

leplatrem commented Apr 27, 2018

peterbe commented Apr 27, 2018 •

edited

glasserc commented Apr 27, 2018

peterbe commented Apr 27, 2018

glasserc commented Apr 27, 2018

peterbe commented Apr 30, 2018

peterbe commented Apr 30, 2018

glasserc commented Apr 30, 2018

peterbe commented May 1, 2018 •

edited

glasserc commented May 2, 2018

peterbe commented May 2, 2018

peterbe commented May 2, 2018

peterbe commented May 3, 2018

leplatrem commented May 3, 2018

glasserc commented May 4, 2018

leplatrem commented May 4, 2018

peterbe commented May 4, 2018

glasserc commented May 4, 2018

peterbe commented May 18, 2018

leplatrem commented May 18, 2018

[WIP] Optimize postgresql storage get all fixes 1507 #1615

[WIP] Optimize postgresql storage get all fixes 1507 #1615

Conversation

peterbe commented Apr 26, 2018 • edited

peterbe commented Apr 26, 2018

peterbe Apr 26, 2018

Choose a reason for hiding this comment

leplatrem Apr 27, 2018

Choose a reason for hiding this comment

glasserc commented Apr 26, 2018

leplatrem left a comment • edited

Choose a reason for hiding this comment

leplatrem Apr 27, 2018

Choose a reason for hiding this comment

leplatrem Apr 27, 2018

Choose a reason for hiding this comment

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

peterbe commented Apr 27, 2018

leplatrem Apr 27, 2018

Choose a reason for hiding this comment

leplatrem Apr 27, 2018

Choose a reason for hiding this comment

leplatrem commented Apr 27, 2018

peterbe commented Apr 27, 2018 • edited

glasserc commented Apr 27, 2018

peterbe commented Apr 27, 2018

glasserc commented Apr 27, 2018

peterbe commented Apr 30, 2018

peterbe commented Apr 30, 2018

glasserc commented Apr 30, 2018

peterbe commented May 1, 2018 • edited

glasserc commented May 2, 2018

peterbe commented May 2, 2018

peterbe commented May 2, 2018

peterbe commented May 3, 2018

leplatrem commented May 3, 2018

glasserc commented May 4, 2018

leplatrem commented May 4, 2018

peterbe commented May 4, 2018

glasserc commented May 4, 2018

peterbe commented May 18, 2018

leplatrem commented May 18, 2018

peterbe commented Apr 26, 2018 •

edited

leplatrem left a comment •

edited

peterbe commented Apr 27, 2018 •

edited

peterbe commented May 1, 2018 •

edited