Java heap space error in MSSQL source connector

[niveditabaliga-payroc]

Hello,
My team migrated to Airbyte at the start of this year and mid this year, we started using the CDC capability of MSSQL. After a lot of hiccups, posts on the Slack channel, reading through various posts and documents online, we were able to get CDC working and in a stable place. However, one of the jobs has started failing again on a java heap space error. The CDC _CT table had approx 91M rows at the time of investigation and the log file retention period on the DB is 3 days.

1. Attached is the log file of the failed job
   default_workspace_job_17454_attempt_1_txt.txt
2. Attached is the screenshot of the installation of abctl and Airbyte
   
3. Following is a copy of the values.yaml file

global:
edition: "community"

jobs:
resources:
limits:
cpu: 1000m
memory: 12Gi ## e.g. 500m
requests:
cpu: 500m
memory: 2Gi

env_vars:
HTTP_IDLE_TIMEOUT: 1800s

webapp:
ingress:
annotations:
kubernetes.io/ingress.class: internal
nginx.ingress.kubernetes.io/proxy-body-size: 16m
nginx.ingress.kubernetes.io/proxy-send-timeout: 1800
nginx.ingress.kubernetes.io/proxy-read-timeout: 1800

airbyte-bootloader:
resources:
limits:
cpu: 1000m
memory: 5Gi ## e.g. 500m
requests:
cpu: 500m
memory: 1Gi

worker:
enabled: true
-- Number of worker replicas
replicaCount: 1

image:
-- The repository to use for the airbyte worker image.
repository: airbyte/worker
-- the pull policy to use for the airbyte worker image
pullPolicy: IfNotPresent

-- worker resource requests and limits
-- ref: http://kubernetes.io/docs/user-guide/compute-resources/
-- We usually recommend not to specify default resources and to leave this as a conscious
-- choice for the user. This also increases chances charts run on environments with little
-- resources, such as Minikube. If you do want to specify resources, uncomment the following
-- lines, adjust them as necessary, and remove the curly braces after 'resources:'.
resources:
--! -- The resources limits for the worker container
limits:
memory: 5Gi
cpu: 500m
-- -- The requested resources for the worker container
requests:
memory: 3Gi
cpu: 250m

4. Following are some of the updates we did to various airbyte tables
   `airbyte-db-0:/$ psql airbyte -d db-airbyte -t -A -c "UPDATE actor_definition SET resource_requirements='{"jobSpecific": [{"jobType": "sync", "resourceRequirements": {"cpu_limit": "2", "cpu_request": "2", "memory_limit": "29Gi", "memory_request": "2Gi"}}]}' WHERE id = 'b5ea17b1-f170-46dc-bc31-cc744ca984c1';"

airbyte-db-0:/$ psql -U airbyte -d db-airbyte -t -A -c "UPDATE connection SET resource_requirements = '{"cpu_limit": "0.5", "cpu_request": "0.5", "memory_limit": "28Gi", "memory_request": "5Gi"}' WHERE id = '4f763461-2f5a-4535-a3fe-33d99b718a05';"`
5. Attached is a screenshot of the UI parameters

We are looking for insights into how to best debug and resolve this issue.

[marcosmarxm]

@niveditabaliga-payroc can you share what resources the cluster/server Airbyte is running has (total memory/cpu/disk)?

[scottmorgan-payroc]

32 gb ram

cpu
processor : 0-7 cpus
vendor_id : GenuineIntel
cpu family : 6
model : 85
model name : Intel(R) Xeon(R) Gold 5218R CPU @ 2.10GHz

DISK
Filesystem 1K-blocks Used Available Use% Mounted on
tmpfs 3286208 1380 3284828 1% /run
/dev/sda2 29825944 14090436 14302400 50% /
tmpfs 16431036 4 16431032 1% /dev/shm
tmpfs 5120 0 5120 0% /run/lock
/dev/sda1 973952 6228 967724 1% /boot/efi
/dev/sdb1 10217748 151572 9525556 2% /tmp
/dev/sdb2 51421852 32027548 17071136 66% /var
tmpfs 3286204 4 3286200 1% /run/user/1701003948

[marcosmarxm]

@rodireich could you help taking a look into this issue?

[scottmorgan-payroc]

Ideally when the java heap space error happens it should state allocated vs used stats plus which pod(s) name this occurred in so we would know what configuration knob to turn. In our experience we see multiple log messages indicating that the actual memory and disk resource usage is very low then suddenly we get the dreaded javaheapspace error

2024-11-05 01:19:11 destination > 2024-11-05 01:19:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:20:11 destination > 2024-11-05 01:20:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:20:11 destination > 2024-11-05 01:20:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:21:11 destination > 2024-11-05 01:21:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:21:11 destination > 2024-11-05 01:21:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:22:11 destination > 2024-11-05 01:22:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:22:11 destination > 2024-11-05 01:22:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:23:11 destination > 2024-11-05 01:23:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:23:11 destination > 2024-11-05 01:23:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:24:11 destination > 2024-11-05 01:24:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:24:11 destination > 2024-11-05 01:24:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:25:11 destination > 2024-11-05 01:25:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:25:11 destination > 2024-11-05 01:25:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:26:11 destination > 2024-11-05 01:26:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:26:11 destination > 2024-11-05 01:26:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:27:11 destination > 2024-11-05 01:27:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:27:11 destination > 2024-11-05 01:27:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:28:11 destination > 2024-11-05 01:28:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:28:11 destination > 2024-11-05 01:28:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:29:11 destination > 2024-11-05 01:29:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:29:11 destination > 2024-11-05 01:29:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:30:11 destination > 2024-11-05 01:30:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:30:11 destination > 2024-11-05 01:30:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:31:18 INFO i.a.a.BlockingShutdownAnalyticsPlugin(waitForFlush):288 - Waiting for Segment analytic client to flush enqueued messages...
2024-11-05 01:31:18 INFO i.a.a.BlockingShutdownAnalyticsPlugin(waitForFlush):300 - Segment analytic client flush complete.
2024-11-05 01:31:18 INFO i.a.a.SegmentAnalyticsClient(close):236 - Segment analytics client closed. No new events will be accepted.
2024-11-05 01:31:03 source > Terminating due to java.lang.OutOfMemoryError: Java heap space
2024-11-05 01:31:05 replication-orchestrator > readFromSource: source exception
io.airbyte.workers.internal.exception.SourceException: Source process exited with non-zero exit code 3
at io.airbyte.workers.general.BufferedReplicationWorker.readFromSource(BufferedReplicationWorker.java:364) ~[io.airbyte-airbyte-commons-worker-1.1.0.jar:?]
at io.airbyte.workers.general.BufferedReplicationWorker.lambda$runAsyncWithHeartbeatCheck$3(BufferedReplicationWorker.java:222) ~[io.airbyte-airbyte-commons-worker-1.1.0.jar:?]
at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) ~[?:?]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
2024-11-05 01:31:05 replication-orchestrator > readFromSource: done. (source.isFinished:true, fromSource.isClosed:false)
2024-11-05 01:31:09 replication-orchestrator > processMessage: done. (fromSource.isDone:true, forDest.isClosed:false)
2024-11-05 01:31:11 destination > 2024-11-05 01:31:11 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):118 - [ASYNC QUEUE INFO] Global: max: 10.15 GB, allocated: 10 MB (10.0 MB), % used: 9.621282276395386E-4 | State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-11-05 01:31:11 destination > 2024-11-05 01:31:11 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):146 - [ASYNC WORKER INFO] Pool queue size: 0, Active threads: 0
2024-11-05 01:31:12 replication-orchestrator > writeToDestination: done. (forDest.isDone:true, isDestRunning:true)
2024-11-05 01:31:12 replication-orchestrator > thread status... timeout thread: false , replication thread: true