Thread: Out of Memory
I have this situation:
Machine:
VPS with CentOS 6.6 x86_64
64GB of RAM
2GB of swap (unused)
Ulimit settings:
postgres soft nproc 2047
postgres hard nproc 16384
postgres soft nofile 1024
postgres hard nofile 65536
postgres hard stack 10240
PostgreSQL 9.4.0 from official repositories. Postgresql.conf is:
listen_addresses = '*'
port = 5432
max_connections = 20
shared_buffers = 16GB
effective_cache_size = 48GB
work_mem = 419430kB
maintenance_work_mem = 2GB
checkpoint_segments = 128
checkpoint_completion_target = 0.9
wal_buffers = 16MB
default_statistics_target = 500
When I launch a query (the principal field is JSONb), the database return this:
ERROR: out of memory
DETAIL: Failed on request of size 110558.
This is the query:
SELECT CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id ->'comment')->>'id'
ELSE NULL
END AS comment_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->'from'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id ->'comment')->'from'->>'id'
ELSE NULL
END AS user_id,
field_id ->> '_id' post_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id ->'comment'->>'created_timestamp')::timestamp without time zone
WHEN '[' THEN (jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone
ELSE NULL
END AS comment_create_date,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN cast(to_char((field_id ->'comment'->>'created_time')::timestamp without time zone,'YYYYMMDD') as numeric)
WHEN '[' THEN cast(to_char((jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone,'YYYYMMDD') as numeric)
ELSE NULL
END AS comment_created_day,
field_id ->> 'pageId' page_id,
CASE substring(field_id->>'feedtype',1,1)
WHEN 'f' THEN 2
WHEN 'b' THEN 1
ELSE 3
END AS owner_type,
'WALL' comment_type,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN to_char((field_id ->'comment'->>'created_time')::timestamp without time zone,'HH24')::numeric
WHEN '[' THEN to_char((jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone,'HH24')::numeric
ELSE NULL
END AS comment_time_slot,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id ->'comment'->>'like_count')::numeric
WHEN '[' THEN (jsonb_array_elements(field_id ->'comment')->>'like_count')::numeric
ELSE NULL
END AS like_count,
1 as sn_id,
17 AS group_id
FROM stage.fbcomment
WHERE field_id ->> 'pageId' in (SELECT stage.eng_page.identifier::text
FROM stage.eng_group_page,
stage.eng_page
where stage.eng_group_page.page_id=stage.eng_page._id
AND stage.eng_group_page.group_id=17
)
;
And this is the query plan:
QUERY PLAN
---------------------------------------------------------------------------------------------------
Nested Loop (cost=49.52..57597.31 rows=6729600 width=989)
-> HashAggregate (cost=41.38..42.02 rows=64 width=12)
Group Key: (eng_page.identifier)::text
-> Hash Join (cost=32.54..41.22 rows=64 width=12)
Hash Cond: (eng_group_page.page_id = eng_page._id)
-> Bitmap Heap Scan on eng_group_page (cost=4.77..12.57 rows=64 width=5)
Recheck Cond: (group_id = 17::numeric)
-> Bitmap Index Scan on pk_eng_group_page (cost=0.00..4.76 rows=64 width=0)
Index Cond: (group_id = 17::numeric)
-> Hash (cost=17.34..17.34 rows=834 width=17)
-> Seq Scan on eng_page (cost=0.00..17.34 rows=834 width=17)
-> Bitmap Heap Scan on fbcomment (cost=8.14..103.95 rows=673 width=989)
Recheck Cond: ((field_id ->> 'pageId'::text) = (eng_page.identifier)::text)
-> Bitmap Index Scan on fbcomment_idx (cost=0.00..7.97 rows=673 width=0)
Index Cond: ((field_id ->> 'pageId'::text) = (eng_page.identifier)::text)
(15 rows)
Any hint for resolving the problem is appreciated
Cheers,
Enrico
Machine:
VPS with CentOS 6.6 x86_64
64GB of RAM
2GB of swap (unused)
Ulimit settings:
postgres soft nproc 2047
postgres hard nproc 16384
postgres soft nofile 1024
postgres hard nofile 65536
postgres hard stack 10240
PostgreSQL 9.4.0 from official repositories. Postgresql.conf is:
listen_addresses = '*'
port = 5432
max_connections = 20
shared_buffers = 16GB
effective_cache_size = 48GB
work_mem = 419430kB
maintenance_work_mem = 2GB
checkpoint_segments = 128
checkpoint_completion_target = 0.9
wal_buffers = 16MB
default_statistics_target = 500
When I launch a query (the principal field is JSONb), the database return this:
ERROR: out of memory
DETAIL: Failed on request of size 110558.
This is the query:
SELECT CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id ->'comment')->>'id'
ELSE NULL
END AS comment_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->'from'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id ->'comment')->'from'->>'id'
ELSE NULL
END AS user_id,
field_id ->> '_id' post_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id ->'comment'->>'created_timestamp')::timestamp without time zone
WHEN '[' THEN (jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone
ELSE NULL
END AS comment_create_date,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN cast(to_char((field_id ->'comment'->>'created_time')::timestamp without time zone,'YYYYMMDD') as numeric)
WHEN '[' THEN cast(to_char((jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone,'YYYYMMDD') as numeric)
ELSE NULL
END AS comment_created_day,
field_id ->> 'pageId' page_id,
CASE substring(field_id->>'feedtype',1,1)
WHEN 'f' THEN 2
WHEN 'b' THEN 1
ELSE 3
END AS owner_type,
'WALL' comment_type,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN to_char((field_id ->'comment'->>'created_time')::timestamp without time zone,'HH24')::numeric
WHEN '[' THEN to_char((jsonb_array_elements(field_id ->'comment')->>'created_time')::timestamp without time zone,'HH24')::numeric
ELSE NULL
END AS comment_time_slot,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id ->'comment'->>'like_count')::numeric
WHEN '[' THEN (jsonb_array_elements(field_id ->'comment')->>'like_count')::numeric
ELSE NULL
END AS like_count,
1 as sn_id,
17 AS group_id
FROM stage.fbcomment
WHERE field_id ->> 'pageId' in (SELECT stage.eng_page.identifier::text
FROM stage.eng_group_page,
stage.eng_page
where stage.eng_group_page.page_id=stage.eng_page._id
AND stage.eng_group_page.group_id=17
)
;
And this is the query plan:
QUERY PLAN
---------------------------------------------------------------------------------------------------
Nested Loop (cost=49.52..57597.31 rows=6729600 width=989)
-> HashAggregate (cost=41.38..42.02 rows=64 width=12)
Group Key: (eng_page.identifier)::text
-> Hash Join (cost=32.54..41.22 rows=64 width=12)
Hash Cond: (eng_group_page.page_id = eng_page._id)
-> Bitmap Heap Scan on eng_group_page (cost=4.77..12.57 rows=64 width=5)
Recheck Cond: (group_id = 17::numeric)
-> Bitmap Index Scan on pk_eng_group_page (cost=0.00..4.76 rows=64 width=0)
Index Cond: (group_id = 17::numeric)
-> Hash (cost=17.34..17.34 rows=834 width=17)
-> Seq Scan on eng_page (cost=0.00..17.34 rows=834 width=17)
-> Bitmap Heap Scan on fbcomment (cost=8.14..103.95 rows=673 width=989)
Recheck Cond: ((field_id ->> 'pageId'::text) = (eng_page.identifier)::text)
-> Bitmap Index Scan on fbcomment_idx (cost=0.00..7.97 rows=673 width=0)
Index Cond: ((field_id ->> 'pageId'::text) = (eng_page.identifier)::text)
(15 rows)
The query goes wrong also a subset of data extracted from the subquery. With this subset (5 values with generate 336500 records), vmstat is this:
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 64467148 16888 996464 0 0 5 1 75 40 5 1 94 0 0
2 0 0 64365252 16888 996464 0 0 0 0 734 167 13 2 82 0 2
1 0 0 63471488 16888 996464 0 0 0 1 1102 176 21 4 75 0 0
1 0 0 62257732 16888 996464 0 0 0 12 1070 160 21 4 74 0 2
1 0 0 60939172 16888 996464 0 0 0 0 1072 158 21 4 75 0 0
1 0 0 59627188 16888 996464 0 0 0 6 1071 161 21 4 75 0 0
1 0 0 58324692 16888 996464 0 0 0 0 1069 152 21 4 75 0 0
1 0 0 57002732 16888 996464 0 0 0 0 1049 133 21 4 75 0 0
1 0 0 55671200 16888 996464 0 0 0 1 1076 152 21 4 75 0 0
1 0 0 54316064 16896 996460 0 0 0 4 1056 140 21 4 75 0 0
1 0 0 52939020 16896 996464 0 0 0 0 1052 140 22 3 75 0 0
1 0 0 51558644 16896 996464 0 0 0 5 1069 156 21 4 75 0 0
1 0 0 50188544 16896 996464 0 0 0 0 1069 156 21 4 75 0 0
0 0 0 64464804 16896 996476 0 0 0 0 557 269 6 7 88 0 0
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 64467148 16888 996464 0 0 5 1 75 40 5 1 94 0 0
2 0 0 64365252 16888 996464 0 0 0 0 734 167 13 2 82 0 2
1 0 0 63471488 16888 996464 0 0 0 1 1102 176 21 4 75 0 0
1 0 0 62257732 16888 996464 0 0 0 12 1070 160 21 4 74 0 2
1 0 0 60939172 16888 996464 0 0 0 0 1072 158 21 4 75 0 0
1 0 0 59627188 16888 996464 0 0 0 6 1071 161 21 4 75 0 0
1 0 0 58324692 16888 996464 0 0 0 0 1069 152 21 4 75 0 0
1 0 0 57002732 16888 996464 0 0 0 0 1049 133 21 4 75 0 0
1 0 0 55671200 16888 996464 0 0 0 1 1076 152 21 4 75 0 0
1 0 0 54316064 16896 996460 0 0 0 4 1056 140 21 4 75 0 0
1 0 0 52939020 16896 996464 0 0 0 0 1052 140 22 3 75 0 0
1 0 0 51558644 16896 996464 0 0 0 5 1069 156 21 4 75 0 0
1 0 0 50188544 16896 996464 0 0 0 0 1069 156 21 4 75 0 0
0 0 0 64464804 16896 996476 0 0 0 0 557 269 6 7 88 0 0
Any hint for resolving the problem is appreciated
Cheers,
Enrico
On 1/15/2015 3:17 PM, Enrico Bianchi wrote: > When I launch a query (the principal field is JSONb), the database > return this: > > ERROR: out of memory > DETAIL: Failed on request of size 110558. it looks like your query is trying to return 7 million rows, although you didn't do EXPLAIN ANALYZE, so your query plan statistics are all estimates. without knowing your schema and table contents its hard to say more. -- john r pierce 37N 122W somewhere on the middle of the left coast
Enrico Bianchi <enrico.bianchi@ymail.com> writes:
> When I launch a query (the principal field is JSONb), the database
> return this:
> ERROR: out of memory
> DETAIL: Failed on request of size 110558.
That error should be associated with a memory usage map getting dumped to
postmaster stderr, where hopefully your logging setup will catch it.
Can we see the map?
Even better would be a self-contained test case. Maybe you can generate
some artificial data that produces the problem?
regards, tom lane
On 01/16/2015 02:18 AM, Tom Lane wrote:
> Can we see the map?
This is the log when executing the query with a subset of data:
< 2015-01-16 08:47:43.517 GMT >DEBUG: StartTransactionCommand
< 2015-01-16 08:47:43.517 GMT >DEBUG: StartTransaction
< 2015-01-16 08:47:43.517 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.121 GMT >DEBUG: StartTransaction
< 2015-01-16 08:47:51.121 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.121 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:47:51.121 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.121 GMT >DEBUG: received inquiry for database 0
< 2015-01-16 08:47:51.121 GMT >DEBUG: writing stats file
"pg_stat_tmp/global.stat"
< 2015-01-16 08:47:51.121 GMT >DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
< 2015-01-16 08:47:51.132 GMT >DEBUG: InitPostgres
< 2015-01-16 08:47:51.133 GMT >DEBUG: my backend ID is 6
< 2015-01-16 08:47:51.133 GMT >DEBUG: StartTransaction
< 2015-01-16 08:47:51.133 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.134 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:47:51.134 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.134 GMT >DEBUG: autovacuum: processing database
"postgres"
< 2015-01-16 08:47:51.135 GMT >DEBUG: received inquiry for database 13003
< 2015-01-16 08:47:51.135 GMT >DEBUG: writing stats file
"pg_stat_tmp/global.stat"
< 2015-01-16 08:47:51.137 GMT >DEBUG: writing stats file
"pg_stat_tmp/db_13003.stat"
< 2015-01-16 08:47:51.145 GMT >DEBUG: StartTransaction
< 2015-01-16 08:47:51.145 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.145 GMT >DEBUG: pg_statistic: vac: 23 (threshold
130), anl: 42 (threshold 90)
< 2015-01-16 08:47:51.145 GMT >DEBUG: pg_type: vac: 0 (threshold 118),
anl: 0 (threshold 84)
< 2015-01-16 08:47:51.145 GMT >DEBUG: pg_authid: vac: 3 (threshold 50),
anl: 5 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_attribute: vac: 0 (threshold
512), anl: 0 (threshold 281)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_proc: vac: 0 (threshold 587),
anl: 0 (threshold 318)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_index: vac: 0 (threshold 73),
anl: 0 (threshold 61)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_operator: vac: 0 (threshold
203), anl: 0 (threshold 126)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_opclass: vac: 0 (threshold
76), anl: 0 (threshold 63)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_am: vac: 0 (threshold 51),
anl: 0 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_amop: vac: 0 (threshold 137),
anl: 0 (threshold 94)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_amproc: vac: 0 (threshold
119), anl: 0 (threshold 84)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_database: vac: 0 (threshold
50), anl: 1 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_aggregate: vac: 0 (threshold
77), anl: 0 (threshold 63)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_rewrite: vac: 0 (threshold
72), anl: 0 (threshold 61)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_cast: vac: 0 (threshold 90),
anl: 0 (threshold 70)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_namespace: vac: 0 (threshold
51), anl: 0 (threshold 51)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_db_role_setting: vac: 0
(threshold 50), anl: 1 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_tablespace: vac: 0 (threshold
50), anl: 4 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_shdepend: vac: 57 (threshold
69), anl: 24 (threshold 59)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_shdescription: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_class: vac: 0 (threshold 109),
anl: 0 (threshold 80)
< 2015-01-16 08:47:51.146 GMT >DEBUG: pg_toast_2619: vac: 0 (threshold
52), anl: 0 (threshold 51)
< 2015-01-16 08:47:51.147 GMT >DEBUG: pg_toast_2618: vac: 0 (threshold
87), anl: 0 (threshold 69)
< 2015-01-16 08:47:51.147 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:47:51.147 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:47:51.147 GMT >DEBUG: shmem_exit(0): 1
before_shmem_exit callbacks to make
< 2015-01-16 08:47:51.147 GMT >DEBUG: shmem_exit(0): 7 on_shmem_exit
callbacks to make
< 2015-01-16 08:47:51.147 GMT >DEBUG: proc_exit(0): 2 callbacks to make
< 2015-01-16 08:47:51.147 GMT >DEBUG: exit(0)
< 2015-01-16 08:47:51.147 GMT >DEBUG: shmem_exit(-1): 0
before_shmem_exit callbacks to make
< 2015-01-16 08:47:51.147 GMT >DEBUG: shmem_exit(-1): 0 on_shmem_exit
callbacks to make
< 2015-01-16 08:47:51.147 GMT >DEBUG: proc_exit(-1): 0 callbacks to make
< 2015-01-16 08:47:51.149 GMT >DEBUG: reaping dead processes
< 2015-01-16 08:47:51.149 GMT >DEBUG: server process (PID 1451) exited
with exit code 0
< 2015-01-16 08:48:21.149 GMT >DEBUG: StartTransaction
< 2015-01-16 08:48:21.149 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.149 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:48:21.149 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.150 GMT >DEBUG: received inquiry for database 0
< 2015-01-16 08:48:21.150 GMT >DEBUG: writing stats file
"pg_stat_tmp/global.stat"
< 2015-01-16 08:48:21.150 GMT >DEBUG: writing stats file
"pg_stat_tmp/db_0.stat"
< 2015-01-16 08:48:21.161 GMT >DEBUG: InitPostgres
< 2015-01-16 08:48:21.161 GMT >DEBUG: my backend ID is 6
< 2015-01-16 08:48:21.161 GMT >DEBUG: StartTransaction
< 2015-01-16 08:48:21.162 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.164 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:48:21.164 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.164 GMT >DEBUG: autovacuum: processing database
"ecce"
< 2015-01-16 08:48:21.164 GMT >DEBUG: received inquiry for database 16390
< 2015-01-16 08:48:21.164 GMT >DEBUG: writing stats file
"pg_stat_tmp/global.stat"
< 2015-01-16 08:48:21.166 GMT >DEBUG: writing stats file
"pg_stat_tmp/db_16390.stat"
< 2015-01-16 08:48:21.175 GMT >DEBUG: StartTransaction
< 2015-01-16 08:48:21.175 GMT >DEBUG: name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_statistic: vac: 140 (threshold
169), anl: 9089 (threshold 110)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_type: vac: 122 (threshold
154), anl: 67 (threshold 102)
< 2015-01-16 08:48:21.175 GMT >DEBUG: eng_function: vac: 0 (threshold
71), anl: 0 (threshold 61)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_authid: vac: 3 (threshold 50),
anl: 5 (threshold 50)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_attribute: vac: 329 (threshold
833), anl: 72 (threshold 442)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_proc: vac: 54 (threshold 587),
anl: 101 (threshold 318)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_attrdef: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_constraint: vac: 25 (threshold
67), anl: 10 (threshold 58)
< 2015-01-16 08:48:21.175 GMT >DEBUG: pg_index: vac: 2 (threshold 95),
anl: 49 (threshold 72)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_operator: vac: 0 (threshold
203), anl: 0 (threshold 126)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_opclass: vac: 0 (threshold
76), anl: 0 (threshold 63)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_am: vac: 0 (threshold 51),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_amop: vac: 0 (threshold 137),
anl: 0 (threshold 94)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_amproc: vac: 0 (threshold
119), anl: 0 (threshold 84)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_language: vac: 0 (threshold
51), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_database: vac: 0 (threshold
50), anl: 1 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_aggregate: vac: 0 (threshold
77), anl: 0 (threshold 63)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_rewrite: vac: 0 (threshold
72), anl: 0 (threshold 61)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_trigger: vac: 28 (threshold
66), anl: 28 (threshold 58)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_event_trigger: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_description: vac: 1 (threshold
787), anl: 37 (threshold 419)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_cast: vac: 0 (threshold 90),
anl: 0 (threshold 70)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_namespace: vac: 6 (threshold
51), anl: 8 (threshold 51)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_depend: vac: 634 (threshold
1529), anl: 167 (threshold 790)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_db_role_setting: vac: 0
(threshold 50), anl: 1 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_tablespace: vac: 0 (threshold
50), anl: 4 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_shdepend: vac: 57 (threshold
78), anl: 24 (threshold 64)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_shdescription: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_ts_config: vac: 0 (threshold
53), anl: 0 (threshold 52)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_ts_config_map: vac: 0
(threshold 111), anl: 0 (threshold 80)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_ts_dict: vac: 0 (threshold
53), anl: 0 (threshold 52)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_ts_parser: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.176 GMT >DEBUG: pg_ts_template: vac: 0 (threshold
51), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: pg_extension: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: pg_collation: vac: 0 (threshold
224), anl: 0 (threshold 137)
< 2015-01-16 08:48:21.177 GMT >DEBUG: pg_class: vac: 103 (threshold
155), anl: 42 (threshold 103)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_comment_group17: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: ft_activities: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: eng_group: vac: 0 (threshold 69),
anl: 0 (threshold 59)
< 2015-01-16 08:48:21.177 GMT >DEBUG: pg_inherits: vac: 23 (threshold
51), anl: 5 (threshold 51)
< 2015-01-16 08:48:21.177 GMT >DEBUG: eng_group_page: vac: 0 (threshold
296), anl: 0 (threshold 173)
< 2015-01-16 08:48:21.177 GMT >DEBUG: fbcomment_test: vac: 0 (threshold
26972), anl: 0 (threshold 13511)
< 2015-01-16 08:48:21.177 GMT >DEBUG: eng_group_function: vac: 0
(threshold 545), anl: 0 (threshold 298)
< 2015-01-16 08:48:21.177 GMT >DEBUG: eng_module: vac: 0 (threshold
50), anl: 12 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_rule_type: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_sn: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_time_slot: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_comment_group60: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_user_gender: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_object_type: vac: 0 (threshold
50), anl: 14 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_post_type: vac: 0 (threshold
50), anl: 5 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_group: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.177 GMT >DEBUG: lk_page: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group71: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_post: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: ft_rule_page: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: ft_trend_page: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_rules: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: cfg_wk_data_insert: vac: 37
(threshold 52), anl: 22 (threshold 51)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_gnip_urls: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_hashtags: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group121: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: eng_sn: vac: 0 (threshold 50),
anl: 48 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: cfg_data_table_list: vac: 7
(threshold 50), anl: 9 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group130: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: twuser: vac: 0 (threshold 35574),
anl: 0 (threshold 17812)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_user: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_album: vac: 0 (threshold 50),
anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group150: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_matching_rules: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_user_mentions: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_languages: vac: 0 (threshold
57), anl: 0 (threshold 54)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group160: vac: 0
(threshold 50), anl: 32 (threshold 50)
< 2015-01-16 08:48:21.178 GMT >DEBUG: fbalbum: vac: 0 (threshold 386),
anl: 0 (threshold 218)
< 2015-01-16 08:48:21.178 GMT >DEBUG: talend_stats: vac: 1 (threshold
203), anl: 87 (threshold 126)
< 2015-01-16 08:48:21.178 GMT >DEBUG: lk_comment_group8: vac: 0
(threshold 109), anl: 0 (threshold 79)
< 2015-01-16 08:48:21.179 GMT >DEBUG: lk_comment_group16: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.179 GMT >DEBUG: lk_comment_group79: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.179 GMT >DEBUG: lk_comment_group110: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.179 GMT >DEBUG: eng_rt_tw_rule_group: vac: 0
(threshold 648), anl: 0 (threshold 349)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fbuser: vac: 0 (threshold 92503),
anl: 0 (threshold 46276)
< 2015-01-16 08:48:21.179 GMT >DEBUG: talend_flowmeter: vac: 0
(threshold 50), anl: 36 (threshold 50)
< 2015-01-16 08:48:21.179 GMT >DEBUG: lk_owner_type: vac: 8 (threshold
50), anl: 9 (threshold 50)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fbfeed: vac: 0 (threshold 42234),
anl: 0 (threshold 21142)
< 2015-01-16 08:48:21.179 GMT >DEBUG: eng_page: vac: 0 (threshold 217),
anl: 0 (threshold 133)
< 2015-01-16 08:48:21.179 GMT >DEBUG: talend_log: vac: 0 (threshold
67), anl: 20 (threshold 58)
< 2015-01-16 08:48:21.179 GMT >DEBUG: cfg_wk_download_page: vac: 0
(threshold 183), anl: 0 (threshold 116)
< 2015-01-16 08:48:21.179 GMT >DEBUG: lk_application: vac: 0 (threshold
72), anl: 0 (threshold 61)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fblike: vac: 0 (threshold 7473),
anl: 0 (threshold 3762)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fbalbumlike: vac: 0 (threshold
210), anl: 0 (threshold 130)
< 2015-01-16 08:48:21.179 GMT >DEBUG: cfg_io_parameter: vac: 1
(threshold 52), anl: 10 (threshold 51)
< 2015-01-16 08:48:21.179 GMT >DEBUG: cfg_table_list: vac: 9 (threshold
52), anl: 19 (threshold 51)
< 2015-01-16 08:48:21.179 GMT >DEBUG: twtweet: vac: 0 (threshold 8568),
anl: 0 (threshold 4309)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fbalbumcomment: vac: 0 (threshold
189), anl: 0 (threshold 120)
< 2015-01-16 08:48:21.179 GMT >DEBUG: fbcomment: vac: 0 (threshold
26968), anl: 0 (threshold 13509)
< 2015-01-16 08:48:21.180 GMT >DEBUG: tmp_fbuser: vac: 0 (threshold
100049), anl: 0 (threshold 50049)
< 2015-01-16 08:48:21.180 GMT >DEBUG: fbdmconversation: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: x: vac: 0 (threshold 50), anl: 1
(threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: lk_album_comment: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341306: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341528: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_2619: vac: 60 (threshold
69), anl: 3634 (threshold 60)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_1255: vac: 37 (threshold
50), anl: 32 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_2618: vac: 0 (threshold
87), anl: 0 (threshold 69)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341324: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_295391: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_17106: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_17118: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341333: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_302509: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341573: vac: 0
(threshold 50), anl: 70442 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_514066: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_340155: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_340186: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_34499: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_340241: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_17157: vac: 0 (threshold
16745), anl: 83474 (threshold 8397)
< 2015-01-16 08:48:21.180 GMT >DEBUG: pg_toast_341346: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340358: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340460: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340532: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340491: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340571: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17100: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340589: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341132: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341386: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17133: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340607: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341395: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_51098: vac: 0 (threshold
50), anl: 114 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_34578: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340633: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341405: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340729: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_340672: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341414: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17079: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341315: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341355: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341377: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17181: vac: 0 (threshold
50), anl: 246440 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17067: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17139: vac: 0 (threshold
50), anl: 26505 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341472: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17169: vac: 0 (threshold
50), anl: 165994 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17124: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17073: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17094: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_341225: vac: 0
(threshold 50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.181 GMT >DEBUG: pg_toast_17175: vac: 0 (threshold
50), anl: 341014 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17151: vac: 0 (threshold
50), anl: 13530 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17187: vac: 0 (threshold
50), anl: 18216 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17145: vac: 0 (threshold
50), anl: 4460 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17088: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17199: vac: 0 (threshold
50), anl: 15464 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17163: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: pg_toast_17205: vac: 0 (threshold
50), anl: 0 (threshold 50)
< 2015-01-16 08:48:21.182 GMT >DEBUG: CommitTransaction
< 2015-01-16 08:48:21.182 GMT >DEBUG: name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
< 2015-01-16 08:48:21.183 GMT >DEBUG: shmem_exit(0): 1
before_shmem_exit callbacks to make
< 2015-01-16 08:48:21.183 GMT >DEBUG: shmem_exit(0): 7 on_shmem_exit
callbacks to make
< 2015-01-16 08:48:21.183 GMT >DEBUG: proc_exit(0): 2 callbacks to make
< 2015-01-16 08:48:21.183 GMT >DEBUG: exit(0)
< 2015-01-16 08:48:21.183 GMT >DEBUG: shmem_exit(-1): 0
before_shmem_exit callbacks to make
< 2015-01-16 08:48:21.183 GMT >DEBUG: shmem_exit(-1): 0 on_shmem_exit
callbacks to make
< 2015-01-16 08:48:21.183 GMT >DEBUG: proc_exit(-1): 0 callbacks to make
< 2015-01-16 08:48:21.185 GMT >DEBUG: reaping dead processes
< 2015-01-16 08:48:21.185 GMT >DEBUG: server process (PID 1452) exited
with exit code 0
TopMemoryContext: 63584 total in 8 blocks; 6592 free (11 chunks); 56992
used
TopTransactionContext: 8192 total in 1 blocks; 7312 free (1 chunks);
880 used
Record information cache: 24576 total in 2 blocks; 15984 free (5
chunks); 8592 used
Type information cache: 24240 total in 2 blocks; 3744 free (0
chunks); 20496 used
TableSpace cache: 8192 total in 1 blocks; 3216 free (0 chunks); 4976
used
Operator lookup cache: 24576 total in 2 blocks; 11888 free (5
chunks); 12688 used
MessageContext: 131072 total in 5 blocks; 4608 free (3 chunks);
126464 used
Operator class cache: 8192 total in 1 blocks; 1680 free (0 chunks);
6512 used
smgr relation table: 24576 total in 2 blocks; 9808 free (4 chunks);
14768 used
TransactionAbortContext: 32768 total in 1 blocks; 32736 free (0
chunks); 32 used
Portal hash: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 used
PortalMemory: 8192 total in 1 blocks; 7888 free (0 chunks); 304 used
PortalHeapMemory: 1024 total in 1 blocks; 800 free (0 chunks); 224
used
ExecutorState: 4315656 total in 17 blocks; 63248 free (22
chunks); 4252408 used
TIDBitmap: 253952 total in 5 blocks; 42976 free (16 chunks);
210976 used
printtup: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used
BTree Array Context: 1024 total in 1 blocks; 696 free (0
chunks); 328 used
ExprContext: 15936275496 total in 28236 blocks; 7158480 free (6
chunks); 15929117016 used
Relcache by OID: 24576 total in 2 blocks; 13872 free (3 chunks);
10704 used
CacheMemoryContext: 1064336 total in 8 blocks; 475200 free (0
chunks); 589136 used
pg_toast_17157_index: 1024 total in 1 blocks; 16 free (0 chunks);
1008 used
pg_toast_2619_index: 1024 total in 1 blocks; 16 free (0 chunks);
1008 used
fbcomment_idx: 3072 total in 2 blocks; 1704 free (0 chunks); 1368 used
pk_eng_page: 1024 total in 1 blocks; 152 free (0 chunks); 872 used
pk_eng_group_page: 1024 total in 1 blocks; 16 free (0 chunks); 1008
used
pg_index_indrelid_index: 1024 total in 1 blocks; 152 free (0
chunks); 872 used
pg_db_role_setting_databaseid_rol_index: 1024 total in 1 blocks; 16
free (0 chunks); 1008 used
pg_user_mapping_user_server_index: 1024 total in 1 blocks; 64 free
(0 chunks); 960 used
pg_user_mapping_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_type_oid_index: 1024 total in 1 blocks; 152 free (0 chunks); 872
used
pg_type_typname_nsp_index: 1024 total in 1 blocks; 16 free (0
chunks); 1008 used
pg_ts_template_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_ts_template_tmplname_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_ts_parser_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_ts_parser_prsname_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_ts_dict_oid_index: 1024 total in 1 blocks; 200 free (0 chunks);
824 used
pg_ts_dict_dictname_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_ts_config_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_ts_config_cfgname_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_ts_config_map_index: 3072 total in 2 blocks; 1784 free (2
chunks); 1288 used
pg_tablespace_oid_index: 1024 total in 1 blocks; 152 free (0
chunks); 872 used
pg_statistic_relid_att_inh_index: 3072 total in 2 blocks; 1736 free
(2 chunks); 1336 used
pg_class_relname_nsp_index: 1024 total in 1 blocks; 16 free (0
chunks); 1008 used
pg_range_rngtypid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_proc_oid_index: 1024 total in 1 blocks; 152 free (0 chunks); 872
used
pg_proc_proname_args_nsp_index: 3072 total in 2 blocks; 1736 free
(2 chunks); 1336 used
pg_opfamily_oid_index: 1024 total in 1 blocks; 200 free (0 chunks);
824 used
pg_opfamily_am_name_nsp_index: 3072 total in 2 blocks; 1784 free (2
chunks); 1288 used
pg_operator_oid_index: 1024 total in 1 blocks; 152 free (0 chunks);
872 used
pg_operator_oprname_l_r_n_index: 3072 total in 2 blocks; 1736 free
(2 chunks); 1336 used
pg_namespace_oid_index: 1024 total in 1 blocks; 152 free (0
chunks); 872 used
pg_namespace_nspname_index: 1024 total in 1 blocks; 152 free (0
chunks); 872 used
pg_language_oid_index: 1024 total in 1 blocks; 200 free (0 chunks);
824 used
pg_language_name_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_foreign_table_relid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_foreign_server_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_foreign_server_name_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_foreign_data_wrapper_oid_index: 1024 total in 1 blocks; 200 free
(0 chunks); 824 used
pg_foreign_data_wrapper_name_index: 1024 total in 1 blocks; 200
free (0 chunks); 824 used
pg_event_trigger_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_event_trigger_evtname_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_enum_typid_label_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_enum_oid_index: 1024 total in 1 blocks; 200 free (0 chunks); 824
used
pg_default_acl_role_nsp_obj_index: 3072 total in 2 blocks; 1784
free (2 chunks); 1288 used
pg_conversion_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_constraint_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_conversion_name_nsp_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_conversion_default_index: 3072 total in 2 blocks; 1784 free (2
chunks); 1288 used
pg_collation_oid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_collation_name_enc_nsp_index: 3072 total in 2 blocks; 1784 free
(2 chunks); 1288 used
pg_opclass_am_name_nsp_index: 3072 total in 2 blocks; 1736 free (2
chunks); 1336 used
pg_cast_source_target_index: 1024 total in 1 blocks; 16 free (0
chunks); 1008 used
pg_auth_members_role_member_index: 1024 total in 1 blocks; 64 free
(0 chunks); 960 used
pg_attribute_relid_attnam_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_amop_fam_strat_index: 3072 total in 2 blocks; 1736 free (2
chunks); 1336 used
pg_amop_opr_fam_index: 3072 total in 2 blocks; 1736 free (2
chunks); 1336 used
pg_aggregate_fnoid_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_auth_members_member_role_index: 1024 total in 1 blocks; 64 free
(0 chunks); 960 used
pg_authid_oid_index: 1024 total in 1 blocks; 200 free (0 chunks);
824 used
pg_authid_rolname_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_database_oid_index: 1024 total in 1 blocks; 152 free (0 chunks);
872 used
pg_database_datname_index: 1024 total in 1 blocks; 200 free (0
chunks); 824 used
pg_trigger_tgrelid_tgname_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_rewrite_rel_rulename_index: 1024 total in 1 blocks; 64 free (0
chunks); 960 used
pg_amproc_fam_proc_index: 3072 total in 2 blocks; 1736 free (2
chunks); 1336 used
pg_opclass_oid_index: 1024 total in 1 blocks; 152 free (0 chunks);
872 used
pg_index_indexrelid_index: 1024 total in 1 blocks; 152 free (0
chunks); 872 used
pg_attribute_relid_attnum_index: 1024 total in 1 blocks; 16 free (0
chunks); 1008 used
pg_class_oid_index: 1024 total in 1 blocks; 152 free (0 chunks);
872 used
MdSmgr: 8192 total in 1 blocks; 6688 free (0 chunks); 1504 used
ident parser context: 0 total in 0 blocks; 0 free (0 chunks); 0 used
hba parser context: 7168 total in 3 blocks; 3184 free (2 chunks);
3984 used
LOCALLOCK hash: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 used
Timezones: 83472 total in 2 blocks; 3744 free (0 chunks); 79728 used
ErrorContext: 8192 total in 1 blocks; 8160 free (4 chunks); 32 used
< 2015-01-16 08:48:42.816 GMT >ERROR: out of memory
< 2015-01-16 08:48:42.816 GMT >DETAIL: Failed on request of size 524288.
< 2015-01-16 08:48:42.816 GMT >STATEMENT: SELECT CASE
substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id
->'comment')->>'id'
ELSE NULL
END AS comment_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN field_id ->'comment'->'from'->>'id'
WHEN '[' THEN jsonb_array_elements(field_id
->'comment')->'from'->>'id'
ELSE NULL
END AS user_id,
field_id ->> '_id' post_id,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id
->'comment'->>'created_timestamp')::timestamp without time zone
WHEN '[' THEN (jsonb_array_elements(field_id
->'comment')->>'created_time')::timestamp without time zone
ELSE NULL
END AS comment_create_date,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN cast(to_char((field_id
->'comment'->>'created_time')::timestamp without time zone,'YYYYMMDD')
as numeric)
WHEN '[' THEN
cast(to_char((jsonb_array_elements(field_id
->'comment')->>'created_time')::timestamp without time zone,'YYYYMMDD')
as numeric)
ELSE NULL
END AS comment_created_day,
field_id ->> 'pageId' page_id,
CASE substring(field_id->>'feedtype',1,1)
WHEN 'f' THEN 2
WHEN 'b' THEN 1
ELSE 3
END AS owner_type,
'WALL' comment_type,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN to_char((field_id
->'comment'->>'created_time')::timestamp without time zone,'HH24')::numeric
WHEN '[' THEN to_char((jsonb_array_elements(field_id
->'comment')->>'created_time')::timestamp without time
zone,'HH24')::numeric
ELSE NULL
END AS comment_time_slot,
CASE substring((field_id ->'comment')::text,1,1)
WHEN '{' THEN (field_id
->'comment'->>'like_count')::numeric
WHEN '[' THEN (jsonb_array_elements(field_id
->'comment')->>'like_count')::numeric
ELSE NULL
END AS like_count,
1 as sn_id,
17 AS group_id
FROM ecce_stage.fbcomment
WHERE field_id ->> 'pageId' in ('110686168966251',
'124858950920112',
'164913773543444', '190178617688826', '142553345763418')
;
> Maybe you can generate some artificial data that produces the problem?
I've asked permission for these data
Enrico
On 01/16/2015 01:19 AM, John R Pierce wrote: > you didn't do EXPLAIN ANALYZE, so your query plan statistics are all > estimates. I know, but the EXPLAIN ANALYZE has the same problem of the query Enrico
On 01/16/2015 09:58 AM, Enrico Bianchi wrote: > I've asked permission for these data I've obtained the permission, here is available a subset of data large enough to replicate the problem (note: you can simply run the query without the where clause): https://drive.google.com/file/d/0ByfjZX4TabhocUg2MFJ6a21qS2M/view?usp=sharing Enrico
On 01/16/2015 11:22 AM, Enrico Bianchi wrote: > https://drive.google.com/file/d/0ByfjZX4TabhocUg2MFJ6a21qS2M/view?usp=sharing > Note: due an error in dump script, if you are in Linux/Unix environment, use this command for uncompressing the file: bzip2 -d -c comment_test.dump.bz2 |sed -e '12d' > comment_test.dump Enrico
>> https://drive.google.com/file/d/0ByfjZX4TabhocUg2MFJ6a21qS2M/view?usp=sharing > Note: due an error in dump script, if you are in Linux/Unix environment, use this command for uncompressing the file: > > bzip2 -d -c comment_test.dump.bz2 |sed -e '12d' > comment_test.dump Hi, I've played a bit with this. Here's what I see. Let me give a bit of info: enrico=# \d stage.fbcomment Table "stage.fbcomment" Column | Type | Modifiers ----------+-------+----------- field_id | jsonb | Indexes: "comment_test_idx" btree ((field_id ->> 'pageId'::text)) enrico=# select pg_total_relation_size('stage.fbcomment'); pg_total_relation_size ------------------------ 83755008 (1 row) enrico=# select count(*) from stage.fbcomment; count ------- 23431 (1 row) enrico=# select sum(jsonb_array_length(field_id ->'comment')) from stage.fbcomment; sum -------- 541454 (1 row) -> to keep in mind: there are 23k rows, but if you unnest the 'comment' array there are 541k rows. The following two queries are just fine. I see the postgres worker reaching a "RES" size of 108MB for both. nrico=# explain analyze enrico-# SELECT substring((field_id ->'comment')::text,1,1) enrico-# FROM stage.fbcomment; QUERY PLAN ------------------------------------------------------------------------------------------------------------------- Seq Scan on fbcomment (cost=0.00..3012.62 rows=23431 width=828) (actual time=0.147..2749.940 rows=23431 loops=1) Planning time: 0.046 ms Execution time: 2756.881 ms (3 rows) Time: 2757.398 ms enrico=# enrico=# explain analyze enrico-# SELECT jsonb_array_elements(field_id ->'comment')->>'id' enrico-# FROM stage.fbcomment; QUERY PLAN ---------------------------------------------------------------------------------------------------------------------- Seq Scan on fbcomment (cost=0.00..14552.39 rows=2343100 width=828) (actual time=0.067..885.041 rows=541454 loops=1) Planning time: 0.053 ms Execution time: 978.161 ms (3 rows) Time: 978.705 ms Interestingly, if you combine these, it quickly blows up! The following query with a limit 1000 already has a RES of well over 1GB. With larger limits it quickly thrashes my machine. enrico=# explain analyze SELECT substring((field_id ->'comment')::text,1,1), jsonb_array_elements(field_id ->'comment')->>'id' FROM stage.fbcomment limit 1000; QUERY PLAN --------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..6.31 rows=1000 width=828) (actual time=0.200..2419.749 rows=1000 loops=1) -> Seq Scan on fbcomment (cost=0.00..14786.70 rows=2343100 width=828) (actual time=0.198..2418.931 rows=1000 loops=1) Planning time: 0.059 ms Execution time: 2659.065 ms (4 rows) Time: 2659.708 ms I think this triggers some code path that is not really optimal for memory usage for some reason. I don't know if there is something interesting to fix here or not. I guess other people will quickly see what happens here? In any case the solution for you might be to unnest the comments in this table and split the '{' vs '[' before doing your processing. I.e. create the intermediate table with the 541454 comments and then throw your queries against that table. This should also use way less processing time than the hack with the '[' vs '{' cases. Bye, Chris.
Chris Mair <chris@1006.org> writes:
> ...
> Interestingly, if you combine these, it quickly blows up! The following query with a limit 1000 already
> has a RES of well over 1GB. With larger limits it quickly thrashes my machine.
> enrico=# explain analyze
> SELECT substring((field_id ->'comment')::text,1,1),
> jsonb_array_elements(field_id ->'comment')->>'id'
> FROM stage.fbcomment limit 1000;
Yeah. The key point here is that jsonb_array_elements() returns a set,
that is one tuple per array element. We've semi-deprecated use of
set-returning functions in SELECT output lists, and one of the reasons
is that memory management in the presence of set-returning functions
is a mess: we can't clear the SELECT's expression-evaluation context
until the SRF is done returning rows. Some of the rows in this dataset
contain 'comment' arrays with over 1000 elements; that means that the
"substring()" expression gets executed over 1000 times without any
opportunity to reclaim memory. And that expression will leak a pretty
fair amount of memory when dealing with a large field_id value.
Multiply that by the fact that the original query does this half a
dozen times, and you have a fairly large peak memory consumption.
The space does get reclaimed after each original table row, but that's
no comfort if you ran out before that.
It would probably be possible to go through the JSONB code and reduce
(though not eliminate) its appetite for memory in this sort of situation
--- for instance, freeing detoasted input arguments would help a lot.
But that's not likely to happen overnight. In any case, you're right
that this is a very inefficiently expressed query; refactoring things
so that the jsonb_array_elements() call is done just once in a subquery
would probably help a great deal.
regards, tom lane