Summary
Duplicate SQL executions observed in destination logs on Kubernetes instance compared to Docker Compose setup.
Question
Hi Community, I have a quick one (hopefully).
We’re running a self-hosted Airbyte instance with Docker Compose and are in the process of setting up a new one on Kubernetes.
I’ve noticed duplicate SQL executions in the destination logs on the Kubernetes instance, which I don’t see in the Docker Compose setup.
Is this expected behavior, so I shouldn’t worry, or is this unusual, and I should dig deeper into it?
I’ve attached some log examples.
Thanks in advance for any insights!
This topic has been created from a Slack thread to give it more visibility.
It will be on Read-Only mode here. Click here if you want
to access the original thread.
Join the conversation on Slack
["duplicate-sql-executions", "destination-logs", "kubernetes-instance", "docker-compose", "self-hosted-airbyte"]
Dennis, are both versions of the Destination connector the same?
2024-08-14 06:46:34 destination > 2024-08-14 06:46:34 INFO i.a.i.d.s.SnowflakeInternalStagingSqlOperations(uploadRecordsToStage):96 - Successfully loaded records to stage 2024/08/14/06/E5A107EB-5180-4B4E-A0D5-784F2AA82012/ with 0 re-attempt(s)
2024-08-14 06:46:34 destination > 2024-08-14 06:46:34 INFO i.a.i.b.d.t.DefaultTyperDeduper(lambda$typeAndDedupeTask$2):217 - Waiting for raw table writes to pause for IUSTA.customers
2024-08-14 06:46:34 destination > 2024-08-14 06:46:34 INFO i.a.i.b.d.t.DefaultTyperDeduper(lambda$typeAndDedupeTask$2):221 - Attempting typing and deduping for IUSTA.customers
2024-08-14 06:46:34 destination > 2024-08-14 06:46:34 INFO i.a.i.d.s.t.SnowflakeDestinationHandler(execute):134 - Executing sql 9dc9b8ac-7374-4a1b-b1c8-9c14d91676d7: BEGIN TRANSACTION;
2024-08-14 06:46:34 destination > INSERT INTO "IUSTA"."CUSTOMERS"
(...)```
Folowed by a couple of tose logs
```(...)
2024-08-14 06:46:51 destination > 2024-08-14 06:46:51 INFO i.a.c.i.d.b.BufferManager(printQueueInfo):120 - START OF QUEUE INFO
2024-08-14 06:46:51 destination > This represents an estimation of the size of the elements contain in the in memory buffer.
2024-08-14 06:46:51 destination > Global Mem Manager -- max: 742.41 MB, allocated: 10.01 MB (10.012129783630371 MB), % used: 0.013486052661370202
2024-08-14 06:46:51 destination > Queue name: customers, num records: 0, num bytes: 0 bytes, allocated bytes: 0 bytes
2024-08-14 06:46:51 destination > State Manager memory usage: Allocated: 10 MB, Used: 0 bytes, percentage Used 0.000000
2024-08-14 06:46:51 destination > END OF QUEUE INFO
2024-08-14 06:46:51 destination > 2024-08-14 06:46:51 INFO i.a.c.i.d.FlushWorkers(printWorkerInfo):137 - WORKER INFO
2024-08-14 06:46:51 destination > Pool queue size: 0, Active threads: 1
(...)```
resulting in the second SQL Execution
```(...)
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.d.s.t.SnowflakeDestinationHandler(execute):153 - Sql 9dc9b8ac-7374-4a1b-b1c8-9c14d91676d7 completed in 18486 ms
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.b.d.t.DefaultTyperDeduper(lambda$typeAndDedupeTask$2):226 - Allowing other threads to proceed for IUSTA.customers
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.r.FileBuffer(deleteFile):109 - Deleting tempFile data 07b156db-02c7-40d3-bb6f-7ffc49e94fbe11917504628681427259.csv.gz
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.GlobalMemoryManager(free):88 - Freeing 292 bytes..
2024-08-14 06:46:53 replication-orchestrator > Destination complete for customers
2024-08-14 06:46:53 replication-orchestrator > Sending update for customers - RUNNING -> COMPLETE
2024-08-14 06:46:53 replication-orchestrator > Stream Status Update Received: customers - COMPLETE
2024-08-14 06:46:53 replication-orchestrator > Updating status: customers - COMPLETE
2024-08-14 06:46:53 replication-orchestrator > starting state flush thread for connectionId bfd984e0-ac12-442e-a83c-4e1c11c6d45b
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.GlobalMemoryManager(free):88 - Freeing 12719 bytes..
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.FlushWorkers(lambda$flush$1):167 - Flush Worker (de43c) -- Worker finished flushing. Current queue size: 0
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.FlushWorkers(close):222 - Closing flush workers -- Workers shutdown status: true
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.b.BufferManager(close):90 - Buffers cleared..
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.c.i.d.s.GeneralStagingFunctions(lambda$onCloseFunction$1):121 - Cleaning up destination started for 1 streams
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.b.d.t.DefaultTyperDeduper(typeAndDedupe):244 - Typing and deduping all tables
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.b.d.t.DefaultTyperDeduper(lambda$typeAndDedupeTask$2):217 - Waiting for raw table writes to pause for IUSTA.customers
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.b.d.t.DefaultTyperDeduper(lambda$typeAndDedupeTask$2):221 - Attempting typing and deduping for IUSTA.customers
2024-08-14 06:46:53 destination > 2024-08-14 06:46:53 INFO i.a.i.d.s.t.SnowflakeDestinationHandler(execute):134 - Executing sql 937563df-3292-497a-a539-5aeee436a5f7: BEGIN TRANSACTION;
2024-08-14 06:46:53 destination > INSERT INTO "IUSTA"."CUSTOMERS"
(...)```
Hey <@U01MMSDJGC9> 
Of course, they’re not the same :face_palm:
Thank you for the hint! I’ll upgrade the connection and check if the behavior changes.