BUG #14078: Excessive memory growth during nested loop in select

From: psuderevsky(at)gmail(dot)com
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #14078: Excessive memory growth during nested loop in select
Date: 2016-04-08 16:37:36
Message-ID: 20160408163736.15196.33214@wrigleys.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

The following bug has been logged on the website:

Bug reference: 14078
Logged by: Pavel Suderevsky
Email address: psuderevsky(at)gmail(dot)com
PostgreSQL version: 9.5.2
Operating system: Ubuntu 14.04.04 LTS; CentOS 7.2.1511
Description:

Repoduced on:
1. 9.5.1 + Ubuntu 14.04.4 LTS
2. 9.5.1 + CentOS 7.2.1511
2. 9.5.2 + CentOS 7.2.1511
3. 9.4.5 + CentOS 7.2.1511

Memory setting:

> platform_db=# select name, setting from pg_settings where name like
> '%shared%' or name like '%mem%';
> name | setting
> ----------------------------+--------------------
> autovacuum_work_mem | -1
> dynamic_shared_memory_type | posix
> maintenance_work_mem | 131072
> shared_buffers | 786432
> work_mem | 131072
> (6 rows)

DDL:

> platform_db=# \d n_statuses
> Table "platform_db.n_statuses"
> Column | Type | Modifiers
>
>
>
-----------------------+-------------------------+---------------------------------
> n_id | integer | not null
> s_id | integer | not null
> msg | character varying(1024) | default NULL::character
> varying
> ns_timestamp | bigint | not null
> Indexes:
> "n_statuses_n_id_FK" btree (n_id)
> "n_statuses_n_id_TIMESTAMP_IDX" btree (n_id, ns_timestamp)
> "n_statuses_TIMESTAMP_IDX" btree (ns_timestamp)
>
> platform_db=# \d ns_VALUES
> Table "platform_db.ns_VALUES"
> Column | Type | Modifiers
> ----------------------+---------+-----------
> n_id | integer | not null
> s_id | integer | not null
> nv_timestamp | bigint | not null
> Indexes:
> "ns_VALUES_n_id_FK" btree (n_id)
> "ns_VALUES_n_id_TIMESTAMP_IDX" btree (n_id, nv_timestamp)

SQL query:

> platform_db=# select nsv.n_id, nsv.s_id, ns.msg, ns.ns_timestamp,
ns.s_id,
> nsv.nv_timestamp FROM n_statuses ns INNER JOIN ns_VALUES nsv USING
> (ne_id) where ns.n_id = 1147;

Counts:

> platform_db=# SELECT count(*) FROM n_statuses ns where n_id = 1147;
> count
> -------
> 6819
> (1 row)
> platform_db=# SELECT count(*) FROM ns_VALUES nsv where n_id = 1147;
> count
> -------
> 6814
> (1 row)
> platform_db=# SELECT count(*) FROM n_statuses ns INNER JOIN ns_VALUES nsv
> ON ns.n_id = nsv.n_id where ns.n_id = 1147;
> count
> ----------
> 46423776
> (1 row)

Sizes:

> platform_db=# select
> pg_size_pretty(pg_relation_size('n_statuses'));
> pg_size_pretty
> ----------------
> 11 MB
> platform_db=# select
> pg_size_pretty(pg_relation_size('ns_VALUES'));
> pg_size_pretty
> ----------------
> 11 MB

Query plan:

> Nested Loop (cost=477.14..570040.76 rows=45261752 width=53) (actual
> time=3.223..252614.947 rows=46382904 loops=1)
> -> Bitmap Heap Scan on n_statuses ns (cost=241.60..2336.38 rows=6862
> width=37) (actual time=1.724..21.248 rows=6813 loops=1)
> Recheck Cond: (node_id = 1147)
> Heap Blocks: exact=1397
> -> Bitmap Index Scan on "n_statuses_NODE_ID_FK"
> (cost=0.00..239.89 rows=6862 width=0) (actual time=1.472..1.472
rows=6813
> loops=1)
> Index Cond: (node_id = 1147)
> -> Materialize (cost=235.54..1948.97 rows=6596 width=16) (actual
> time=0.002..12.092 rows=6808 loops=6813)
> -> Bitmap Heap Scan on ns_VALUES nsv (cost=235.54..1915.99
> rows=6596 width=16) (actual time=1.471..17.282 rows=6808 loops=1)
> Recheck Cond: (node_id = 1147)
> Heap Blocks: exact=1357
> -> Bitmap Index Scan on "ns_VALUES_NODE_ID_FK"
> (cost=0.00..233.89 rows=6596 width=0) (actual time=1.238..1.238
rows=6808
> loops=1)
> Index Cond: (node_id = 1147)
> Planning time: 0.210 ms
> Execution time: 334897.948 ms

Observing amount of memory consumed by psql process with pmap utility (for
i in `seq 125`; do pmap 30469 | grep total && sleep 3 ; done):
Initial memory allocated for psql process:

> total 105724K

Before query is completed:

> total 8906492K

'Free' command provided similar statistics:
Initial:

> total used free shared buffers
> cached
> Mem: 16049 6908 9140 2953 158 5684
> -/+ buffers/cache: 1065 14984
> Swap: 0 0 0

Before query is completed:

> total used free shared buffers
cached
> Mem: 16049 15333 716 2953 159 5657
> -/+ buffers/cache: 9516 6532
> Swap: 0 0 0

So about 8Gb of linux virtual memory has been allocated for join of two
tables with sizes of 11MB.
The question is why so high amount of virtual memory is consumed, isn't it
a memory leak.

By the way, when I perform this query like 'create temp table as
<this_query> it consuming 2.6Gb of disk space and while creating it uses
some extra space that is released when table is created. On ubuntu that
extra space was about 300Mb and on CentOS it was about 1.3GB. I can presume
it is related to pages flushing techniques, but can't be sure. Also no
virtual memory was consumed by this operation.
Also when I was performing 'explain analyze select...' no virtual memory
have been consumed.

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Jeff Janes 2016-04-08 18:00:04 Re: released savepoint blocking further statements
Previous Message jacksonemmerich 2016-04-08 15:52:03 BUG #14077: Error with pgadim v1.22.1 and ubuntu 15.10 + postgres 9.2