Hi, Paul
I agree with Oleg, EDB benchmarks are strange sometimes. I did the same
benchmarks several months ago. I never noticed the cache influence back
then, so I tried to reproduce your situation now (on a 5*10^6 records
although). I started to play with db cache (using `echo 3 >
/proc/sys/vm/drop_cache`), and I see difference in time execution for two
subsequent queries, but `explain` info are almost identical, e.g. `shared
hit & read`:
```
benchmark=# explain (buffers, analyze, verbose) select data from
json_tables where data @> '{"name": "AC3 Case Red"}';
QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------
Bitmap Heap Scan on public.json_tables (cost=102.74..19001.47 rows=4999
width=1257) (actual time=740.556..215956.655 rows=454546 loops=1)
Output: data
Recheck Cond: (json_tables.data @> '{"name": "AC3 Case Red"}'::jsonb)
Rows Removed by Index Recheck: 2114606
Heap Blocks: exact=31624 lossy=422922
Buffers: shared hit=1371 read=455551
-> Bitmap Index Scan on json_tables_idx (cost=0.00..101.49 rows=4999
width=0) (actual time=731.010..731.010 rows=454547 loops=1)
Index Cond: (json_tables.data @> '{"name": "AC3 Case Red"}'::jsonb)
Buffers: shared hit=1371 read=1005
Planning time: 6.352 ms
Execution time: 216075.830 ms
(11 rows)
benchmark=# explain (buffers, analyze, verbose) select data from
json_tables where data @> '{"name": "AC3 Case Red"}';
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------
Bitmap Heap Scan on public.json_tables (cost=102.74..19001.47 rows=4999
width=1257) (actual time=222.476..10692.703 rows=454546 loops=1)
Output: data
Recheck Cond: (json_tables.data @> '{"name": "AC3 Case Red"}'::jsonb)
Rows Removed by Index Recheck: 2114606
Heap Blocks: exact=31624 lossy=422922
Buffers: shared hit=1371 read=455551
-> Bitmap Index Scan on json_tables_idx (cost=0.00..101.49 rows=4999
width=0) (actual time=214.736..214.736 rows=454547 loops=1)
Index Cond: (json_tables.data @> '{"name": "AC3 Case Red"}'::jsonb)
Buffers: shared hit=1371 read=1005
Planning time: 0.089 ms
Execution time: 10767.739 ms
(11 rows)
```
But I see almost the same execution time from mongodb `explain` (216075ms
for pg and 177784ms for mongo, which isn't so much I think):
```
DBQuery.shellBatchSize = 10000000000; db.json_tables.find({"name": "AC3
Case Red"}).explain(true)
{
"queryPlanner" : {
"plannerVersion" : 1,
"namespace" : "benchmark.json_tables",
"indexFilterSet" : false,
"parsedQuery" : {
"name" : {
"$eq" : "AC3 Case Red"
}
},
"winningPlan" : {
"stage" : "FETCH",
"inputStage" : {
"stage" : "IXSCAN",
"keyPattern" : {
"name" : 1
},
"indexName" : "name_1",
"isMultiKey" : false,
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 1,
"direction" : "forward",
"indexBounds" : {
"name" : [
"[\"AC3 Case Red\", \"AC3
Case Red\"]"
]
}
}
},
"rejectedPlans" : [ ]
},
"executionStats" : {
"executionSuccess" : true,
"nReturned" : 454546,
"executionTimeMillis" : 177784,
"totalKeysExamined" : 454546,
"totalDocsExamined" : 454546,
"executionStages" : {
"stage" : "FETCH",
"nReturned" : 454546,
"executionTimeMillisEstimate" : 175590,
"works" : 454547,
"advanced" : 454546,
"needTime" : 0,
"needYield" : 0,
"saveState" : 8638,
"restoreState" : 8638,
"isEOF" : 1,
"invalidates" : 0,
"docsExamined" : 454546,
"alreadyHasObj" : 0,
"inputStage" : {
"stage" : "IXSCAN",
"nReturned" : 454546,
"executionTimeMillisEstimate" : 700,
"works" : 454547,
"advanced" : 454546,
"needTime" : 0,
"needYield" : 0,
"saveState" : 8638,
"restoreState" : 8638,
"isEOF" : 1,
"invalidates" : 0,
"keyPattern" : {
"name" : 1
},
"indexName" : "name_1",
"isMultiKey" : false,
"isUnique" : false,
"isSparse" : false,
"isPartial" : false,
"indexVersion" : 1,
"direction" : "forward",
"indexBounds" : {
"name" : [
"[\"AC3 Case Red\", \"AC3
Case Red\"]"
]
},
"keysExamined" : 454546,
"dupsTested" : 0,
"dupsDropped" : 0,
"seenInvalidated" : 0
}
},
"allPlansExecution" : [ ]
},
"serverInfo" : {
"host" : "ip-172-30-0-236",
"port" : 27017,
"version" : "3.2.4",
"gitVersion" : "e2ee9ffcf9f5a94fad76802e28cc978718bb7a30"
},
"ok" : 1
}
```
I not missed anything, am I right? Are you sure that it took much more time
for PostgreSQL?
Besides, everything is fine for queries with more small results (while the
query {"name": "AC3 Case Red"} is almost 1/10 of entire dataset):
```
=# insert into json_tables values('{"name": "test name"}'::jsonb);
=# explain (buffers, analyze, verbose) select data from json_tables where
data @> '{"name": "test name"}';
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------
Bitmap Heap Scan on public.json_tables (cost=62.75..18965.16 rows=5000
width=1257) (actual time=0.020..0.021 rows=1 loops=1)
Output: data
Recheck Cond: (json_tables.data @> '{"name": "test name"}'::jsonb)
Heap Blocks: exact=1
Buffers: shared hit=5
-> Bitmap Index Scan on json_tables_idx (cost=0.00..61.50 rows=5000
width=0) (actual time=0.011..0.011 rows=1 loops=1)
Index Cond: (json_tables.data @> '{"name": "test name"}'::jsonb)
Buffers: shared hit=4
Planning time: 1.164 ms
Execution time: 0.045 ms
(10 rows)
```
As far as I know there isn't much to do about caching. I don't know if it's
appropriate, but you can manually warm-up the cache (something like `cat
/var/lib/postgresql/9.5/main/base/*/* > /dev/null`).
On 14 March 2016 at 00:30, Oleg Bartunov <obartu...@gmail.com> wrote:
>
> On Mar 11, 2016 4:40 PM, "Paul Jones" <p...@cmicdo.com> wrote:
> >
> > I have been running the EDB benchmark that compares Postgres and MongoDB.
> > I believe EDB ran it against PG 9.4 and Mongo 2.6. I am running it
> > against PG 9.5.1 and Mongo 3.2 with WiredTiger storage using 10,000,000
> > JSON records generated by the benchmark. It looks like Mongo is winning,
> > and apparently because of its cache management.
>
> Dmitry was working on the same benchmarks. I think edb benchmark is broken
> by design. Better, use ycsb benchmarks. I hope, Dmitry will share his
> results.
>
> >
> > The first queries on both run in ~30 min. And, once PG fills its cache,
> > it whips Mongo on repeats of the *same* query (vmstat shows no disk
> > reads for PG).
> >
> > However, when different query on the same table is issued to both,
> > vmstat shows that PG has to read the *entire* table again, and it takes
> > ~30 min. Mongo does a lot of reads initially but after about 5 minutes,
> > it stops reading and completes the query, most likely because it is
> > using its cache very effectively.
> >
> > Host: Virtual Machine
> > 4 CPUs
> > 16 Gb RAM
> > 200 Gb Disk
> > RHEL 6.6
> >
> > PG: 9.5.1 compiled from source
> > shared_buffers = 7GB
> > effectve_cache_size = 12GB
> >
> > Mongo: 3.2 installed with RPM from Mongo
> >
> > In PG, I created the table by:
> >
> > CREATE TABLE json_tables
> > (
> > data JSONB
> > );
> >
> > After loading, it creates the index:
> >
> > CREATE INDEX json_tables_idx ON json_tables USING GIN (data
> jsonb_path_ops);
> >
> > After a lot of experimentation, I discovered that the benchmark was not
> > using PG's index, so I modified the four queries to be:
> >
> > SELECT data FROM json_tables WHERE data @> '{"brand": "ACME"}';
> > SELECT data FROM json_tables WHERE data @> '{"name": "Phone Service
> Basic Plan"}';
> > SELECT data FROM json_tables WHERE data @> '{"name": "AC3 Case Red"}';
> > SELECT data FROM json_tables WHERE data @> '{"type": "service"}';
> >
> > Here are two consecutive explain analyze for PG, for the same query.
> > No functional difference in the plans that I can tell, but the effect
> > of PG's cache on the second is dramatic.
> >
> > If anyone has ideas on how I can get PG to more effectively use the cache
> > for subsequent queries, I would love to hear them.
> >
> > -------
> >
> > benchmark=# explain analyze select data from json_tables where data @>
> '{"name": "AC3 Case Red"}';
> >
> > QUERY PLAN
> >
> >
> >
> -----------------------------------------------------------------------------------------------------------------------------------------
> >
> > Bitmap Heap Scan on json_tables (cost=113.50..37914.64 rows=10000
> width=1261)
> > (actual time=2157.118..1259550.327 rows=909091 loops=1)
> > Recheck Cond: (data @> '{"name": "AC3 Case Red"}'::jsonb)
> > Rows Removed by Index Recheck: 4360296
> > Heap Blocks: exact=37031 lossy=872059
> > -> Bitmap Index Scan on json_tables_idx (cost=0.00..111.00
> rows=10000 width =0) (actual time=2141.250..2141.250 rows=909091 loops=1)
> > Index Cond: (data @> '{"name": "AC3 Case Red"}'::jsonb)
> > Planning time: 291.932 ms
> > Execution time: 1259886.920 ms
> > (8 rows)
> >
> > Time: 1261191.844 ms
> >
> > benchmark=# explain analyze select data from json_tables where data @>
> '{"name": "AC3 Case Red"}';
> > QUERY PLAN
> >
> >
> ---------------------------------------------------------------------------------------------------------------------------------------
> >
> > Bitmap Heap Scan on json_tables (cost=113.50..37914.64 rows=10000
> width=1261) (actual time=779.261..29815.262 rows=909091 loops=1)
> > Recheck Cond: (data @> '{"name": "AC3 Case Red"}'::jsonb)
> > Rows Removed by Index Recheck: 4360296
> > Heap Blocks: exact=37031 lossy=872059
> > -> Bitmap Index Scan on json_tables_idx (cost=0.00..111.00
> rows=10000 width =0) (actual time=769.081..769.081 rows=909091 loops=1)
> > Index Cond: (data @> '{"name": "AC3 Case Red"}'::jsonb)
> > Planning time: 33.967 ms
> > Execution time: 29869.381 ms
> >
> > (8 rows)
> >
> > Time: 29987.122 ms
> >
> >
> > --
> > Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
> > To make changes to your subscription:
> > http://www.postgresql.org/mailpref/pgsql-general
>
