Thread: Docker + postgreSQL : OOM killing in a large Group by operation
Hi Guys:
I have a problem with a query that grabs a bunch of rows and then does an aggreate operation, at that moment it gots killed by OOM-killer, I don't know why, the engine starts using tmpfiles as expected , and then tries to work in memory and gots killed.
I've test it in an small enviroment for more dramatic/quick results
Env:
Running on a 1GB memory Docker-container .
PostgreSQL 9.4.8 on x86_64-unknown-linux-gnu, compiled by gcc (Ubuntu 4.8.2-19ubuntu1) 4.8.2, 64-bit
Database Analyzed and the stats are up-to-date
postgresql.conf:
shared_buffers = 512MB
work_mem = 16MB
effective_cache_size = 256MB
Bad Query:
SELECT count(*)
FROM "changelog_change_transaction"
INNER JOIN "changelog_change_stats" ON ( changelog_change_stats.changelog_change_transactionid = changelog_change_transaction.changelog_change_transactionid )
LEFT OUTER JOIN "changelog_change_group" ON ( changelog_change_transaction.changelog_change_groupid = changelog_change_group.changelog_change_groupid )
WHERE ( changelog_change_group.companyid = 40 OR changelog_change_group.companyid = 1 OR changelog_change_group.companyid = 53 OR changelog_change_group.companyid IS NULL )
AND changelog_change_transaction.started_at > '2017-04-21'
GROUP BY "changelog_change_transaction"."changelog_change_transactionid", "changelog_change_transaction"."epoch", "changelog_change_transaction"
."changelog_change_groupid", "changelog_change_transaction"."started_at", "changelog_change_transaction"."duration_microseconds", "changelog_change_transaction"."changed_items", "changelog_change_transaction"."xmin"
;
Explain :
HashAggregate (cost=7845766.73..8117654.17 rows=27188744 width=152)
Group Key: changelog_change_transaction.changelog_change_transactionid, changelog_change_transaction.epoch, changelog_change_transaction.changelog_change_groupid, changelog_change_transaction.started_at, changelog_change_transaction.duration_microseconds, changelog_change_transaction.changed_items, changelog_change_transaction.xmin
-> Hash Left Join (cost=2498235.67..7301991.85 rows=27188744 width=152)
Hash Cond: (changelog_change_transaction.changelog_change_groupid = changelog_change_group.changelog_change_groupid)
Filter: ((changelog_change_group.companyid = 40) OR (changelog_change_group.companyid = 1) OR (changelog_change_group.companyid = 53) OR (changelog_change_group.companyid IS NULL))
-> Hash Join (cost=2142692.83..5176273.34 rows=27726867 width=152)
Hash Cond: (changelog_change_stats.changelog_change_transactionid = changelog_change_transaction.changelog_change_transactionid)
-> Seq Scan on changelog_change_stats (cost=0.00..689345.48 rows=33612148 width=6)
-> Hash (cost=1215858.45..1215858.45 rows=27272350 width=152)
-> Seq Scan on changelog_change_transaction (cost=0.00..1215858.45 rows=27272350 width=152)
Filter: (started_at > '2017-04-21 00:00:00-07'::timestamp with time zone)
-> Hash (cost=200291.82..200291.82 rows=8931282 width=10)
-> Seq Scan on changelog_change_group (cost=0.00..200291.82 rows=8931282 width=10)
Log execution:
2018-04-05 09:07:12.444 PDT rhost=[local] app=psql:user=postgres:db=telecom:LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp6455.19", size 9437168
......
2018-04-05 09:07:25.605 PDT rhost= app=:user=:db=:LOG: server process (PID 6455) was terminated by signal 9: Killed
2018-04-05 09:07:25.605 PDT rhost= app=:user=:db=:DETAIL: Failed process was running: SELECT count(*)
FROM "changelog_change_transaction"
INNER JOIN "changelog_change_stats" ON ( changelog_change_stats.changelog_change_transactionid = changelog_change_transaction.changelog_change_transactionid )
LEFT OUTER JOIN "changelog_change_group" ON ( changelog_change_transaction.changelog_change_groupid = changelog_change_group.changelog_change_groupid )
WHERE ( changelog_change_group.companyid = 40 OR changelog_change_group.companyid = 1 OR changelog_change_group.companyid = 53 OR changelog_change_group.companyid IS NULL )
AND changelog_change_transaction.started_at > '2017-04-21'
GROUP BY "changelog_change_transaction"."changelog_change_transactionid", "changelog_change_transaction"."epoch", "changelog_change_transaction"
."changelog_change_groupid", "changelog_change_transaction"."started_at", "changelog_change_transaction"."duration_microseconds", "changelog_change_transaction"."changed_items", "changelog_change_transaction"."xmin"
;
2018-04-05 09:07:25.605 PDT rhost= app=:user=:db=:LOG: terminating any other active server processes
2018-04-05 09:07:25.605 PDT rhost= app=:user=:db=:WARNING: terminating connection because of crash of another server process
Monitoring the /proc/*/status of the running client process ,I've noticed this :
VmData: 7944 kB
VmData: 7944 kB
VmData: 7944 kB
VmData: 29788 kB
VmData: 30696 kB
VmData: 31724 kB
...
VmData: 33776 kB
...
VmData: 37876 kB
...
VmData: 46072 kB
...
VmData: 55272 kB
VmData: 67568 kB
VmData: 76032 kB
VmData: 76484 kB
VmData: 78156 kB
...
...
VmData: 80208 kB
...
VmData: 84308 kB
VmData: 92504 kB
VmData: 198972 kB
VmData: 354620 kB
VmData: 495208 kB
...
VmData: 682364 kB
VmData: 788988 kB
VmData: 821756 kB
VmData: 887292 kB
...
VmData: 961020 kB
...
VmData: 993788 kB
...
VmData: 1001980 kB
For sure if the GROUP BY the one that causes this OOM (when I removed it, the query finish ok ) , so I've change the query-plan to avoid the HashAggregate:
telecom=# show enable_hashagg ;
enable_hashagg
----------------
off
But the explain still shows:
HashAggregate (cost=19768044.56..20039932.00 rows=27188744 width=152)
Group Key: changelog_change_transaction.changelog_change_transactionid, changelog_change_transaction.epoch, changelog_change_transaction.changelog_change_groupid, changelog_change_transaction.started_at, changelog_change_transaction.duration_microseconds, changelog_change_transaction.changed_items, changelog_change_transaction.xmin
Any help or light on this will be really appreciated!
Regards
Jorge Daniel Fernandez
Jorge Daniel <elgaita@hotmail.com> writes:
> I have a problem with a query that grabs a bunch of rows and then does an aggreate operation, at that moment it gots
killedby OOM-killer, I don't know why, the engine starts using tmpfiles as expected , and then tries to work in
memoryand gots killed.
> SELECT count(*)
> FROM "changelog_change_transaction"
> INNER JOIN "changelog_change_stats" ON ( changelog_change_stats.changelog_change_transactionid =
changelog_change_transaction.changelog_change_transactionid)
> LEFT OUTER JOIN "changelog_change_group" ON ( changelog_change_transaction.changelog_change_groupid =
changelog_change_group.changelog_change_groupid)
> WHERE ( changelog_change_group.companyid = 40 OR changelog_change_group.companyid = 1 OR
changelog_change_group.companyid= 53 OR changelog_change_group.companyid IS NULL )
> AND changelog_change_transaction.started_at > '2017-04-21'
> GROUP BY "changelog_change_transaction"."changelog_change_transactionid", "changelog_change_transaction"."epoch",
"changelog_change_transaction"
> ."changelog_change_groupid", "changelog_change_transaction"."started_at",
"changelog_change_transaction"."duration_microseconds","changelog_change_transaction"."changed_items",
"changelog_change_transaction"."xmin"
> ;
Why are you grouping on xmin?
> For sure if the GROUP BY the one that causes this OOM (when I removed it, the query finish ok ) , so I've change the
query-planto avoid the HashAggregate:
> But the explain still shows:
That's because type XID doesn't have sort support, only hash support,
so hash aggregation is the only way to do the query at all.
regards, tom lane