Re: Increasing work_mem slows down query, why?

po 30. 3. 2020 v 15:09 odesílatel Silvio Moioli <moio(at)suse(dot)de> napsal:

> On 3/30/20 12:12 PM, Pavel Stehule wrote:
> > Do you have some planner variables changed - like seq_page_cost?
>
> That one was not changed but another one is - cpu_tuple_cost (to 0.5).
> Indeed bringing it back to its default does improve the query time
> significantly:
>
>
> QUERY PLAN
>
> --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> Unique (cost=36735.61..36735.63 rows=2 width=36) (actual
> time=357.825..358.036 rows=1100 loops=1)
> Output: wanted_capability.ordering, inserted_capability.id
> Buffers: shared hit=14443
> CTE wanted_capability
> -> Values Scan on "*VALUES*" (cost=0.00..13.75 rows=1100 width=68)
> (actual time=0.001..0.355 rows=1100 loops=1)
> Output: "*VALUES*".column1, "*VALUES*".column2,
> "*VALUES*".column3
> CTE missing_capability
> -> Hash Left Join (cost=18263.69..18347.78 rows=1 width=68) (actual
> time=183.826..183.826 rows=0 loops=1)
> Output: wanted_capability_2.ordering, wanted_capability_2.name,
> wanted_capability_2.version
> Hash Cond: (wanted_capability_2.name = (
> rhnpackagecapability_1.name)::text)
> Join Filter: (NOT (wanted_capability_2.version IS DISTINCT FROM
> (rhnpackagecapability_1.version)::text))
> Filter: (rhnpackagecapability_1.id IS NULL)
> Rows Removed by Filter: 1100
> Buffers: shared hit=7217
> -> CTE Scan on wanted_capability wanted_capability_2
> (cost=0.00..22.00 rows=1100 width=68) (actual time=0.000..0.729 rows=1100
> loops=1)
> Output: wanted_capability_2.ordering,
> wanted_capability_2.name, wanted_capability_2.version
> -> Hash (cost=12126.64..12126.64 rows=490964 width=79)
> (actual time=181.477..181.477 rows=490964 loops=1)
> Output: rhnpackagecapability_1.name,
> rhnpackagecapability_1.version, rhnpackagecapability_1.id
> Buckets: 524288 Batches: 1 Memory Usage: 53907kB
> Buffers: shared hit=7217
> -> Seq Scan on public.rhnpackagecapability
> rhnpackagecapability_1 (cost=0.00..12126.64 rows=490964 width=79) (actual
> time=0.009..57.663 rows=490964 loops=1)
> Output: rhnpackagecapability_1.name,
> rhnpackagecapability_1.version, rhnpackagecapability_1.id
> Buffers: shared hit=7217
> CTE inserted_capability
> -> Insert on public.rhnpackagecapability rhnpackagecapability_2
> (cost=0.00..0.04 rows=1 width=1080) (actual time=183.828..183.828 rows=0
> loops=1)
> Output: rhnpackagecapability_2.id, rhnpackagecapability_2.name,
> rhnpackagecapability_2.version
> Conflict Resolution: NOTHING
> Tuples Inserted: 0
> Conflicting Tuples: 0
> Buffers: shared hit=7217
> -> Subquery Scan on "*SELECT*" (cost=0.00..0.04 rows=1
> width=1080) (actual time=183.827..183.827 rows=0 loops=1)
> Output: "*SELECT*".nextval, "*SELECT*".name,
> "*SELECT*".version, CURRENT_TIMESTAMP, CURRENT_TIMESTAMP
> Buffers: shared hit=7217
> -> CTE Scan on missing_capability (cost=0.00..0.02
> rows=1 width=72) (actual time=183.827..183.827 rows=0 loops=1)
> Output:
> nextval('rhn_pkg_capability_id_seq'::regclass), missing_capability.name,
> missing_capability.version
> Buffers: shared hit=7217
> -> Sort (cost=18374.04..18374.04 rows=2 width=36) (actual
> time=357.825..357.862 rows=1100 loops=1)
> Output: wanted_capability.ordering, inserted_capability.id
> Sort Key: wanted_capability.ordering, inserted_capability.id
> Sort Method: quicksort Memory: 100kB
> Buffers: shared hit=14443
> -> Append (cost=0.03..18374.03 rows=2 width=36) (actual
> time=357.071..357.660 rows=1100 loops=1)
> Buffers: shared hit=14437
> -> Hash Join (cost=0.03..26.23 rows=1 width=36) (actual
> time=183.847..183.847 rows=0 loops=1)
> Output: wanted_capability.ordering,
> inserted_capability.id
> Hash Cond: (wanted_capability.name = (
> inserted_capability.name)::text)
> Join Filter: (NOT (wanted_capability.version IS
> DISTINCT FROM (inserted_capability.version)::text))
> Buffers: shared hit=7220
> -> CTE Scan on wanted_capability (cost=0.00..22.00
> rows=1100 width=68) (actual time=0.002..0.002 rows=1 loops=1)
> Output: wanted_capability.ordering,
> wanted_capability.name, wanted_capability.version
> -> Hash (cost=0.02..0.02 rows=1 width=1064) (actual
> time=183.829..183.829 rows=0 loops=1)
> Output: inserted_capability.id,
> inserted_capability.name, inserted_capability.version
> Buckets: 1024 Batches: 1 Memory Usage: 8kB
> Buffers: shared hit=7217
> -> CTE Scan on inserted_capability
> (cost=0.00..0.02 rows=1 width=1064) (actual time=183.828..183.828 rows=0
> loops=1)
> Output: inserted_capability.id,
> inserted_capability.name, inserted_capability.version
> Buffers: shared hit=7217
> -> Hash Join (cost=18263.69..18347.78 rows=1 width=10)
> (actual time=173.223..173.750 rows=1100 loops=1)
> Output: wanted_capability_1.ordering,
> rhnpackagecapability.id
> Hash Cond: (wanted_capability_1.name = (
> rhnpackagecapability.name)::text)
> Join Filter: (NOT (wanted_capability_1.version IS
> DISTINCT FROM (rhnpackagecapability.version)::text))
> Buffers: shared hit=7217
> -> CTE Scan on wanted_capability
> wanted_capability_1 (cost=0.00..22.00 rows=1100 width=68) (actual
> time=0.000..0.070 rows=1100 loops=1)
> Output: wanted_capability_1.ordering,
> wanted_capability_1.name, wanted_capability_1.version
> -> Hash (cost=12126.64..12126.64 rows=490964
> width=79) (actual time=172.220..172.220 rows=490964 loops=1)
> Output: rhnpackagecapability.id,
> rhnpackagecapability.name, rhnpackagecapability.version
> Buckets: 524288 Batches: 1 Memory Usage:
> 53922kB
> Buffers: shared hit=7217
> -> Seq Scan on public.rhnpackagecapability
> (cost=0.00..12126.64 rows=490964 width=79) (actual time=0.008..52.573
> rows=490964 loops=1)
> Output: rhnpackagecapability.id,
> rhnpackagecapability.name, rhnpackagecapability.version
> Buffers: shared hit=7217
> Planning time: 2.145 ms
> Execution time: 358.773 ms
>
>
> Is that an unreasonable value? For the sake of this discussison, I am
> targeting fairly average bare-metal SSD-backed servers with recent CPUs
> (let's say 3 year old maximum), with ample available RAM.
>

these numbers are artificial - important is stable behave, and it's hard to
say, what is correct value. But when these values are out of good range,
then some calculations can be unstable and generated plans can be strange.

There is interesting another fact, new plan uses hash from bigger table,
and then hash join is slower. This is strange.

-> Hash Join (cost=18263.69..18347.78 rows=1 width=10)
(actual time=173.223..173.750 rows=1100 loops=1)
Output: wanted_capability_1.ordering,
rhnpackagecapability.id
Hash Cond: (wanted_capability_1.name = (
rhnpackagecapability.name)::text)
Join Filter: (NOT (wanted_capability_1.version IS
DISTINCT FROM (rhnpackagecapability.version)::text))
Buffers: shared hit=7217
-> CTE Scan on wanted_capability wanted_capability_1
(cost=0.00..22.00 rows=1100 width=68) (actual time=0.000..0.070 rows=1100
loops=1)
Output: wanted_capability_1.ordering,
wanted_capability_1.name, wanted_capability_1.version
-> Hash (cost=12126.64..12126.64 rows=490964
width=79) (actual time=172.220..172.220 rows=490964 loops=1)
Output: rhnpackagecapability.id,
rhnpackagecapability.name, rhnpackagecapability.version
Buckets: 524288 Batches: 1 Memory Usage:
53922kB
Buffers: shared hit=7217
-> Seq Scan on public.rhnpackagecapability
(cost=0.00..12126.64 rows=490964 width=79) (actual time=0.008..52.573
rows=490964 loops=1)
Output: rhnpackagecapability.id,
rhnpackagecapability.name, rhnpackagecapability.version
Buffers: shared hit=7217

versus

-> Hash Join (cost=1652.75..323644.99 rows=1 width=10)
(actual time=31.846..83.234 rows=1100 loops=1)
Output: wanted_capability_1.ordering,
rhnpackagecapability.id
Hash Cond: ((rhnpackagecapability.name)::text =
wanted_capability_1.name)
Join Filter: (NOT (wanted_capability_1.version IS
DISTINCT FROM (rhnpackagecapability.version)::text))
Buffers: shared hit=7217
-> Seq Scan on public.rhnpackagecapability
(cost=0.00..252699.00 rows=490964 width=79) (actual time=0.007..29.702
rows=490964 loops=1)
Output: rhnpackagecapability.id,
rhnpackagecapability.name, rhnpackagecapability.version,
rhnpackagecapability.created, rhnpackagecapability.modified
Buffers: shared hit=7217
-> Hash (cost=1100.00..1100.00 rows=1100 width=68)
(actual time=0.257..0.257 rows=1100 loops=1)
Output: wanted_capability_1.ordering,
wanted_capability_1.name, wanted_capability_1.version
Buckets: 2048 Batches: 1 Memory Usage: 134kB
-> CTE Scan on wanted_capability
wanted_capability_1 (cost=0.00..1100.00 rows=1100 width=68) (actual
time=0.001..0.067 rows=1100 loops=1)
Output: wanted_capability_1.ordering,
wanted_capability_1.name, wanted_capability_1.version

> Thanks!
>
> Regards,
> --
> Silvio Moioli
> SUSE Manager Development Team
>
>
>