JVM Out of memory during task.sync-databases

Hello,

I'm running Metabase v0.43.1 on Docker using the official image, using a 1GB / 1CPU configuration and the target DB is Postgresql 14.

Every hour, during the task.sync-databases trigger, Metabase RAM usage spikes to > 2GB RAM and gets killed by the runtime, as it exceeds it limits.

I am running Metabase with those JVM options (started at 700m):
JAVA_OPTS=-Xms240m -Xmx248m -XX:-UseGCOverheadLimit

When getting killed, the JVM shows a consumption of >2GB
If I don't use -XX:UseGCOverheadLimit, I have the folowing log

Memory cgroup out of memory: Killed process 695 (java) total-vm:2027756kB, anon-rss:592580kB, file-rss:0kB, shmem-rss:0kB, UID:2000 pgtables:1468kB oom_score_adj:0

else,

# Core dump will be written. Default location: Core dumps may be processed with "/usr/x86_64-pc-linux-gnu/lib/systemd/systemd-coredump %P %u %g %s %t %c %h" (or dumping to //core.1)
#
# An error report file with more information is saved as:
# /tmp/hs_err_pid1.log
Aborting due to java.lang.OutOfMemoryError: Java heap space
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (debug.cpp:339), pid=1, tid=63
#  fatal error: OutOfMemory encountered: Java heap space
#
# JRE version: OpenJDK Runtime Environment Temurin-11.0.15+10 (11.0.15+10) (build 11.0.15+10)
# Java VM: OpenJDK 64-Bit Server VM Temurin-11.0.15+10 (11.0.15+10, mixed mode, tiered, compressed oops, serial gc, linux-amd64)

Full Log look like this:

2022-05-19 16:31:00,033 INFO task.sync-databases :: Starting sync task for Database 2.
2022-05-19 16:31:00,049 INFO sync.util :: STARTING: Sync metadata for postgres Database 2 'My DB'
2022-05-19 16:31:00,055 INFO sync.util :: STARTING: step 'sync-timezone' for postgres Database 2 'My DB'
2022-05-19 16:31:00,872 INFO sync.util :: FINISHED: step 'sync-timezone' for postgres Database 2 'My DB' (816.2 ms)
2022-05-19 16:31:00,876 INFO sync.util :: STARTING: step 'sync-tables' for postgres Database 2 'My DB'
2022-05-19 16:31:01,443 INFO sync.util :: FINISHED: step 'sync-tables' for postgres Database 2 'My DB' (566.1 ms)
2022-05-19 16:31:01,453 INFO sync.util :: STARTING: step 'sync-fields' for postgres Database 2 'My DB'
2022-05-19 16:31:02,565 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:02,584 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,003 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,004 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,005 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,005 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,020 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,021 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,021 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,022 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,052 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,053 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,053 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,066 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,067 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,068 WARN sync.describe-table :: Don't know how to map column type 'name' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,932 WARN sync.describe-table :: Don't know how to map column type 'oid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,933 WARN sync.describe-table :: Don't know how to map column type 'oid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,949 WARN sync.describe-table :: Don't know how to map column type 'oid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:03,950 WARN sync.describe-table :: Don't know how to map column type 'oid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,169 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,170 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,186 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,188 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,778 WARN sync.describe-table :: Don't know how to map column type '_int4' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,779 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,795 WARN sync.describe-table :: Don't know how to map column type '_int4' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:04,796 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,200 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,222 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:07,025 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:07,045 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,308 WARN sync.describe-table :: Don't know how to map column type '_uuid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,316 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,337 WARN sync.describe-table :: Don't know how to map column type '_uuid' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,346 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,522 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,538 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,613 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,614 WARN sync.describe-table :: Don't know how to map column type '_text' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,625 WARN sync.describe-table :: Don't know how to map column type '_varchar' to a Field base_type, falling back to :type/*.
2022-05-19 16:31:08,626 WARN sync.describe-table :: Don't know how to map column type '_text' to a Field base_type, falling back to :type/*.
# Core dump will be written. Default location: Core dumps may be processed with "/usr/x86_64-pc-linux-gnu/lib/systemd/systemd-coredump %P %u %g %s %t %c %h" (or dumping to //core.1)
#
# An error report file with more information is saved as:
# /tmp/hs_err_pid1.log
Aborting due to java.lang.OutOfMemoryError: Java heap space
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (debug.cpp:339), pid=1, tid=63
#  fatal error: OutOfMemory encountered: Java heap space
#
# JRE version: OpenJDK Runtime Environment Temurin-11.0.15+10 (11.0.15+10) (build 11.0.15+10)
# Java VM: OpenJDK 64-Bit Server VM Temurin-11.0.15+10 (11.0.15+10, mixed mode, tiered, compressed oops, serial gc, linux-amd64)
time="2022-05-19T16:31:28.026580786Z" level=info msg="ignoring event" container=4993784993c70cd2db010dfa66fd177122e7dd1da41bbd45e07a2bfbf652bdde module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
time="2022-05-19T16:31:28.032512239Z" level=info msg="shim disconnected" id=4993784993c70cd2db010dfa66fd177122e7dd1da41bbd45e07a2bfbf652bdde
time="2022-05-19T16:31:28.034912970Z" level=warning msg="cleaning up after shim disconnected" id=4993784993c70cd2db010dfa66fd177122e7dd1da41bbd45e07a2bfbf652bdde namespace=moby
time="2022-05-19T16:31:28.035025929Z" level=info msg="cleaning up dead shim"
time="2022-05-19T16:31:28.063841428Z" level=warning msg="cleanup warnings time=\"2022-05-19T16:31:28Z\" level=info msg=\"starting signal loop\" namespace=moby pid=1085\n"
Failed with reason 'Failed executing run'

Do you have any knowledge about this issue? I found out varying topics but nothing seems to be solved.

Thanks!

Hi @Antoine1
I'm guessing that you have JSON columns in your tables? How many columns, rows and average length of the JSON blobs?
We're still working on tuning the JSON unfolding:
https://github.com/metabase/metabase/issues/22636

Hi @flamber, thanks for your quick response.

Yes we use json here, for the table being scanned when it fails:

  • 0 (null), 1 up to 2 levels of nesting, Usually 1.
  • 1 JSONB column in this table
  • 14 million records (and growing, ~10k/day)
  • nullable
  • average length (result of select avg(length(value::text)) from tracking_events where value is not null;: 63

@Antoine1 With that size of a database, I would probably say that your Metabase is a little undersized.
Would probably bump it to at least 2GB.
That doesn't mean that Metabase shouldn't be more efficient during sync and scan, but running at 1GB is the same I use for my test instances.

Until we have fully fixed it, I would probably only sync daily - or disable sync temporarily:
https://github.com/metabase/metabase/issues/22636#issuecomment-1123994967

Okay thanks. I tried to keep Metabase on a 1GB machine as the ops prices climbs from 15€ to 30€/mo then.

I'll choose with your propositions, thanks a lot :slight_smile: