Understand snapshot and offset behaviour in mssql source connector using CDC

[ritikanaidu-trakstar]

Hi,

I am using the Airbyte OSS version to ingest data from MSSQL server to Snowflake using CDC. The retention period is set to 10 days in SQL Server. Every 11th day, the job fails with this error -

2024-06-25 11:22:45 �[44msource�[0m > ERROR main i.a.c.i.b.s.SshWrappedSource(read):71 Exception occurred while getting the delegate read iterator, closing SSH tunnel io.airbyte.commons.exceptions.ConfigErrorException: Saved offset no longer present on the server. Please reset the connection, and then increase binlog retention and/or increase sync frequency.

To recover this, I have to reset the data and trigger a full refresh so that airbyte can get an initial snapshot again.

Looking at the events building up to this error, the lsn which the log reports missing from server - 0017bf25:0002d9d7:0004 is the lsn from the initial snapshot taken 10 days ago.

Logs from 10 days ago, snapshot offset shows that commit_lsn = 0017bf25:0002d9d7:0004

2024-06-14 12:24:17 ^[[44msource^[[0m > INFO main i.a.i.s.m.c.MssqlDebeziumStateUtil(format):185 Initial Debezium state offset constructed: {"[\"ZoomSTG\",{\"server\":\"ZoomSTG\",\"database\":\"ZoomSTG\"}]":"{\"commit_lsn\":\"0017bf25:0002d9d7:0004\",\"snapshot\":true,\"snapshot_completed\":true}"}

Latest logs where airbyte tries to locate the initial offset on the server, and fails because the lsn has been cleaned up by sql server after the retention period.

2024-06-25 11:22:45 �[44msource�[0m > INFO main i.d.c.CommonConnectorConfig(getSourceInfoStructMaker):1221 Loading the custom source info struct maker plugin: io.debezium.connector.sqlserver.SqlServerSourceInfoStructMaker
2024-06-25 11:22:45 �[44msource�[0m > INFO main i.a.i.s.m.c.MssqlDebeziumStateUtil(extractStateAttributes):240 Found previous partition offset SqlServerPartition [sourcePartition={server=ZoomSTG, database=ZoomSTG}]: {transaction_id=null, event_serial_no=0, commit_lsn=0017bf25:0002d9d7:0004, change_lsn=NULL}
2024-06-25 11:22:45 �[44msource�[0m > INFO main i.a.i.s.m.c.MssqlDebeziumStateUtil(parseSavedOffset):220 Closing offsetStorageReader and fileOffsetBackingStore
2024-06-25 11:22:45 �[44msource�[0m > INFO main o.a.k.c.s.FileOffsetBackingStore(stop):71 Stopped FileOffsetBackingStore
2024-06-25 11:22:45 �[43mdestination�[0m > 2024-06-25T11:22:45,111`�[32mINFO�[m`i.a.c.d.j.DefaultJdbcDatabase(lambda$unsafeQuery$1):132 - closing connection
2024-06-25 11:22:45 �[43mdestination�[0m > 2024-06-25T11:22:45,112`�[32mINFO�[m`i.a.i.d.s.t.SnowflakeV2TableMigrator(migrateIfNecessary):53 - Checking whether upcasing migration is necessary for tbl_bnf_suprvsr_link. Sync mode requires migration: true; existing case-sensitive table exists: false; existing uppercased table does not exist: false
2024-06-25 11:22:45 �[44msource�[0m > INFO main i.a.i.s.m.c.MssqlDebeziumStateUtil(lambda$savedOffsetStillPresentOnServer$3):268 0017bf25:0002d9d7:0004 lsn exists on server: [false]. (min server lsn: 0017bf3e:000132cc:0008 max server lsn: 0017c059:0004f2d5:0009)
2024-06-25 11:22:45 �[46mplatform�[0m > SOURCE analytics [airbyte/source-mssql:4.0.17] | Type: db-sources-cdc-cursor-invalid | Value: 1

My understanding of airbyte and debezium internals is limited. I would like to know if this is normal behaviour that airbyte tries to look for an lsn that will definitely run out its time in due course (retention period). Shouldn't it be looking for the incremental min_lsn on the server? Or should it be taking incremental (or blocking) snapshots periodically to build upon the initial snapshot taken during full refresh..? Appreciate any help in this regard, since this issue has been plaguing us for several weeks now. Thanks!

[t-willi]

Could you share your Airbyte and connector version?
I am having the same issue and cant find a solution to make incremental syncs work for longer then the retention period

[ritikanaidu-trakstar]

@t-willi We have tried 4.0.17, 4.0.32 and 4.1.1 versions of the mssql source connector. Both resulted in the same error. Also tried on airbyte 1.0, 0.63.8 and 0.52

One thing we noticed is that we do not see this error on all mssql databases. There is one particular db, which has Primary/Secondary Replication Setup, where we see this error. Syncs on another db on the same server worked well (they have only one offset written in the logs instead of the two we see here in failure scenarios).

[t-willi]

Hey, yes same issue here, with one MSSQL database, "SQL server 2016" i have two states shown in Airbyte, while with the other connection "MSSQL 2019" i have no issues. However i have a second connection to another sql 2016 server, where it is only one state, which does not properly update.
I have now recreated the connection and now the state seems to be updating correctly. What i changed was the provided schemas in the source definition. So far i always provided the table schema AND the cdc schema, now i only choose the table schema, which seems to have fixed the issue.
I will come back here once i am sure it worked.
I am on Microsoft SQL Server (MSSQL) v4.1.14.

[brian-kasen-trakstar]

@t-willi - any word on if your attempted changes resolved the issue?

[rwask]

Hi @ritikanaidu-trakstar we have an open issue internally where we are investigating this. Are you syncing from the Primary MSSQL specifically? If not can you try to use the source as the primary and see if that is able to resolve the issue?

[t-willi]

I am not sure what you mean by Primary MSSQL :) I am syncing from a SQL server 2016 "Microsoft SQL Server:13.00.6455"

[brian-kasen-trakstar]

Hi @rwask - jumping in here on behalf of @ritikanaidu-trakstar , we are syncing from the Primary MSSQL source.

[t-willi]

No. I have resorted to using cursor field via updatedAt colums instead of cdc. Have tried anything i could think of, except updating the aibyte version. I am at 0.63, and we realy don't want to upgrade. Sorry i don't have a solution.

…

On Wed, 18 Dec 2024, 21:31 Brian Kasen, ***@***.***> wrote: @t-willi <https://github.com/t-willi> - any word on if your attempted changes resolved the issue? — Reply to this email directly, view it on GitHub <#40726 (reply in thread)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AYNZ67ZQTPLKBHZ5ZEHCM5D2GHLQVAVCNFSM6AAAAABKKXSFDWVHI2DSMVQWIX3LMV43URDJONRXK43TNFXW4Q3PNVWWK3TUHMYTCNRRGAYTAOA> . You are receiving this because you were mentioned.Message ID: ***@***.***>