Uploaded image for project: 'Debezium'
  1. Debezium
  2. DBZ-6972

Facing issue on CDC is not working but initialized the snapshot the debezium sql server connector can't produce events and stream to kafka topic

XMLWordPrintable

    • False
    • None
    • False
    • Critical

      In order to make your issue reports as actionable as possible, please provide the following information, depending on the issue type.

      Bug report

      For bug reports, provide this information, please:

      What Debezium connector do you use and what version?

      debezium-connector-sqlserver/2.3.0.Final

      I download and push in to my docker registry

      https://repo1.maven.org/maven2/io/debezium/debezium-connector-sqlserver/2.3.0.Final/debezium-connector-sqlserver-2.3.0.Final-plugin.tar.gz

      cat <<EOF >Dockerfile
      FROM quay.io/strimzi/kafka:latest-kafka-3.5.0
      USER root:root
      RUN mkdir -p /opt/kafka/plugins/debezium
      COPY ./debezium-connector-sqlserver /opt/kafka/plugins/debezium
      USER 1001
      EOF

       

      What is the connector configuration?

      apiVersion: kafka.strimzi.io/v1beta2
      kind: KafkaConnector
      metadata:
        name: debezium-connector-sql
        labels:
          strimzi.io/cluster: debezium-connect-cluster
      spec:
        class: io.debezium.connector.sqlserver.SqlServerConnector
        tasksMax: 1
        config:
          connector.class: "io.debezium.connector.sqlserver.SqlServerConnector"
          tasks.max: 1
          database.hostname: "<hostname>"
          database.port: "1433"
          database.user: "ms-identity-manager"
          database.password: "<password>"
          database.names: "ms_identity_manager"
          topic.prefix: "create-identity"
          table.include.list: "dbo.outbox"
          schema.history.internal.kafka.bootstrap.servers: "debezium-cluster-kafka-bootstrap:9092"
          schema.history.internal.kafka.topic: "create-identity"
          database.encrypt: "false"

      What is the captured database version and mode of depoyment?

      onpremise
      sql server 14.0 version

      What behaviour do you expect?

      when i update data to the outbox table it have to reflect to the create-identity.ms_identity_manager.dbo.outbox topic. so that the connector is working means and it read the changes and produces events for the each data change operatio and stream them to kafka topic

      What behaviour do you see?

      cdc is not working i can see the data in topics which were created at the snapshot initialized if i delete the connector and create connector with different name the updated data is reflecting on the topic with duplication.

      connector is not read the changes in topic and produces events

      Do you see the same behaviour using the latest relesead Debezium version?

      I tried with Debezium beta version getting same event is not streaming

      Do you have the connector logs, ideally from start till finish?

      this is the logs for kafkaconnect

      2023-09-26 11:13:14,458 INFO [Consumer clientId=connect-cluster--offsets, groupId=connect-cluster] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [KafkaBasedLog Work Thread - connect-cluster-offsets]
      2023-09-26 11:13:15,951 INFO [Producer clientId=connect-cluster--statuses] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connect-cluster--statuses]
      2023-09-26 11:13:15,995 INFO [Consumer clientId=connect-cluster--statuses, groupId=connect-cluster] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [KafkaBasedLog Work Thread - connect-cluster-status]
      2023-09-26 11:13:16,988 INFO [Consumer clientId=connect-cluster--configs, groupId=connect-cluster] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [KafkaBasedLog Work Thread - connect-cluster-configs]
      2023-09-26 11:13:17,137 INFO [Producer clientId=connect-cluster--configs] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connect-cluster--configs]
      2023-09-26 11:13:17,214 INFO [Worker clientId=connect-1, groupId=connect-cluster] Node -1 disconnected. (org.apache.kafka.clients.NetworkClient) [DistributedHerder-connect-1-1]
      2023-09-26 11:13:21,945 INFO 172.17.0.1 - - [26/Sep/2023:11:13:21 +0000] "GET /connectors HTTP/1.1" 200 26 "" "" 7 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-41]
      2023-09-26 11:13:22,012 INFO 172.17.0.1 - - [26/Sep/2023:11:13:21 +0000] "GET /connector-plugins HTTP/1.1" 200 411 "" "" 63 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-37]
      2023-09-26 11:13:22,112 INFO 172.17.0.1 - - [26/Sep/2023:11:13:22 +0000] "GET /admin/loggers/ HTTP/1.1" 200 142 "" "" 77 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-35]
      2023-09-26 11:13:22,162 INFO 172.17.0.1 - - [26/Sep/2023:11:13:22 +0000] "GET /connectors/debezium-connector-sql/config HTTP/1.1" 200 529 "" "" 9 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-34]

      2023-09-26 11:14:04,151 INFO 172.17.0.1 - - [26/Sep/2023:11:14:04 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 2 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-37]
      2023-09-26 11:14:09,516 INFO [AdminClient clientId=connect-cluster--shared-admin] Node 0 disconnected. (org.apache.kafka.clients.NetworkClient) [kafka-admin-client-thread | connect-cluster--shared-admin]
      2023-09-26 11:15:14,168 INFO 172.17.0.1 - - [26/Sep/2023:11:15:14 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 17 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-66]
      2023-09-26 11:15:21,047 INFO 172.17.0.1 - - [26/Sep/2023:11:15:21 +0000] "GET /connector-plugins HTTP/1.1" 200 411 "" "" 5 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-35]
      2023-09-26 11:15:21,050 INFO 172.17.0.1 - - [26/Sep/2023:11:15:21 +0000] "GET /connectors HTTP/1.1" 200 26 "" "" 9 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-34]
      2023-09-26 11:15:21,053 INFO 172.17.0.1 - - [26/Sep/2023:11:15:21 +0000] "GET /admin/loggers/ HTTP/1.1" 200 142 "" "" 5 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-41

       

      ===

       

      logs for snapshot

      2023-09-26 11:07:55,708 INFO [debezium-connector-sql|task-0] Database schema history topic '(name=create-identity, numPartitions=1, replicationFactor=default, replicasAssignments=null, configs={cleanup.policy=delete, retention.ms=9223372036854775807, retention.bytes=-1})' created (io.debezium.storage.kafka.history.KafkaSchemaHistory) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:55,720 INFO [debezium-connector-sql|task-0] App info kafka.admin.client for create-identity-schemahistory unregistered (org.apache.kafka.common.utils.AppInfoParser) [kafka-admin-client-thread | create-identity-schemahistory]
      2023-09-26 11:07:55,762 INFO [debezium-connector-sql|task-0] Metrics scheduler closed (org.apache.kafka.common.metrics.Metrics) [kafka-admin-client-thread | create-identity-schemahistory]
      2023-09-26 11:07:55,763 INFO [debezium-connector-sql|task-0] Closing reporter org.apache.kafka.common.metrics.JmxReporter (org.apache.kafka.common.metrics.Metrics) [kafka-admin-client-thread | create-identity-schemahistory]
      2023-09-26 11:07:55,764 INFO [debezium-connector-sql|task-0] Metrics reporters closed (org.apache.kafka.common.metrics.Metrics) [kafka-admin-client-thread | create-identity-schemahistory]
      2023-09-26 11:07:55,982 INFO [debezium-connector-sql|task-0] No previous offsets found (io.debezium.connector.common.BaseSourceTask) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,095 INFO [debezium-connector-sql|task-0] Requested thread factory for connector SqlServerConnector, id = create-identity named = SignalProcessor (io.debezium.util.Threads) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,261 INFO [debezium-connector-sql|task-0] Requested thread factory for connector SqlServerConnector, id = create-identity named = change-event-source-coordinator (io.debezium.util.Threads) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,294 INFO [debezium-connector-sql|task-0] Creating thread debezium-sqlserverconnector-create-identity-change-event-source-coordinator (io.debezium.util.Threads) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,357 INFO [debezium-connector-sql|task-0] SignalProcessor started. Scheduling it every 5000ms (io.debezium.pipeline.signal.SignalProcessor) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,369 INFO [debezium-connector-sql|task-0] Creating thread debezium-sqlserverconnector-create-identity-SignalProcessor (io.debezium.util.Threads) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,395 INFO [debezium-connector-sql|task-0] Successfully started task (io.debezium.connector.common.BaseSourceTask) [task-thread-debezium-connector-sql-0]
      2023-09-26 11:07:56,547 INFO [debezium-connector-sql|task-0] Metrics registered (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,548 INFO [debezium-connector-sql|task-0] Context created (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,636 INFO [debezium-connector-sql|task-0] No previous offset has been found (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,650 INFO [debezium-connector-sql|task-0] According to the connector configuration both schema and data will be snapshotted (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,664 INFO [debezium-connector-sql|task-0] Snapshot step 1 - Preparing (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,840 INFO [debezium-connector-sql|task-0] Snapshot step 2 - Determining captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,937 INFO [debezium-connector-sql|task-0] Adding table ms_identity_manager.dbo.outbox to the list of capture schema tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,937 INFO [debezium-connector-sql|task-0] Adding table ms_identity_manager.dbo.Identity to the list of capture schema tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,947 INFO [debezium-connector-sql|task-0] Snapshot step 3 - Locking captured tables [ms_identity_manager.dbo.outbox] (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,947 INFO [debezium-connector-sql|task-0] Setting locking timeout to 10 s (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,957 INFO [debezium-connector-sql|task-0] Executing schema locking (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,958 INFO [debezium-connector-sql|task-0] Locking table ms_identity_manager.dbo.outbox (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:56,993 INFO [debezium-connector-sql|task-0] Snapshot step 4 - Determining snapshot offset (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,006 INFO [debezium-connector-sql|task-0] Snapshot step 5 - Reading structure of captured tables (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,029 INFO [debezium-connector-sql|task-0] Reading structure of schema 'ms_identity_manager' (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,201 INFO [debezium-connector-sql|task-0] Snapshot step 5.a - Creating connection pool (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,201 INFO [debezium-connector-sql|task-0] Created connection pool with 1 threads (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,201 INFO [debezium-connector-sql|task-0] Snapshot step 6 - Persisting schema history (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,201 INFO [debezium-connector-sql|task-0] Capturing structure of table ms_identity_manager.dbo.outbox (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,283 WARN [debezium-connector-sql|task-0] Cannot parse column default value '(getdate())' to type 'datetime'. Expression evaluation is not supported. (io.debezium.connector.sqlserver.SqlServerDefaultValueConverter) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,337 INFO [debezium-connector-sql|task-0] [Producer clientId=create-identity-schemahistory] Resetting the last seen epoch of partition create-identity-0 to 0 since the associated topicId changed from null to o_-E26vZTPyu_0hpD5KPlQ (org.apache.kafka.clients.Metadata) [kafka-producer-network-thread | create-identity-schemahistory]
      2023-09-26 11:07:57,345 INFO [debezium-connector-sql|task-0] Already applied 1 database changes (io.debezium.relational.history.SchemaHistoryMetrics) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,360 INFO [debezium-connector-sql|task-0] Schema locks released. (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,361 INFO [debezium-connector-sql|task-0] Snapshot step 7 - Snapshotting data (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,362 INFO [debezium-connector-sql|task-0] Creating snapshot worker pool with 1 worker thread(s) (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,377 INFO [debezium-connector-sql|task-0] For table 'ms_identity_manager.dbo.outbox' using select statement: 'SELECT [eventId], [eventType], [correlationId], [tenantId], [sequence], [dateTimeOccurred], [messageKey], [data], [createdOn], [eventSource], [topic] FROM [ms_identity_manager].[dbo].[outbox]' (io.debezium.relational.RelationalSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,381 INFO [debezium-connector-sql|task-0] Exporting data from table 'ms_identity_manager.dbo.outbox' (1 of 1 tables) (io.debezium.relational.RelationalSnapshotChangeEventSource) [pool-27-thread-1]
      2023-09-26 11:07:57,418 INFO [debezium-connector-sql|task-0] [Producer clientId=connector-producer-debezium-connector-sql-0] Resetting the last seen epoch of partition create-identity-0 to 0 since the associated topicId changed from null to o_-E26vZTPyu_0hpD5KPlQ (org.apache.kafka.clients.Metadata) [kafka-producer-network-thread | connector-producer-debezium-connector-sql-0]
      2023-09-26 11:07:57,434 INFO [debezium-connector-sql|task-0]      Finished exporting 7 records for table 'ms_identity_manager.dbo.outbox' (1 of 1 tables); total duration '00:00:00.053' (io.debezium.relational.RelationalSnapshotChangeEventSource) [pool-27-thread-1]
      2023-09-26 11:07:57,444 INFO [debezium-connector-sql|task-0] Snapshot - Final stage (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,444 INFO [debezium-connector-sql|task-0] Snapshot completed (io.debezium.pipeline.source.AbstractSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,445 INFO [debezium-connector-sql|task-0] Removing locking timeout (io.debezium.connector.sqlserver.SqlServerSnapshotChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,472 INFO [debezium-connector-sql|task-0] Snapshot ended with SnapshotResult [status=COMPLETED, offset=SqlServerOffsetContext [sourceInfoSchema=Schema{io.debezium.connector.sqlserver.Source:STRUCT}, sourceInfo=SourceInfo [serverName=create-identity, changeLsn=NULL, commitLsn=0000002e:000014c0:0071, eventSerialNo=null, snapshot=FALSE, sourceTime=2023-09-26T11:07:57.367667700Z], snapshotCompleted=true, eventSerialNo=1]] (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,479 INFO [debezium-connector-sql|task-0] Connected metrics set to 'true' (io.debezium.pipeline.ChangeEventSourceCoordinator) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,480 INFO [debezium-connector-sql|task-0] Starting streaming (io.debezium.connector.sqlserver.SqlServerChangeEventSourceCoordinator) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,483 INFO [debezium-connector-sql|task-0] Last position recorded in offsets is 0000002e:000014c0:0071(NULL)[1] (io.debezium.connector.sqlserver.SqlServerStreamingChangeEventSource) [debezium-sqlserverconnector-create-identity-change-event-source-coordinator]
      2023-09-26 11:07:57,954 WARN [debezium-connector-sql|task-0] [Producer clientId=connector-producer-debezium-connector-sql-0] Error while fetching metadata with correlation id 5 : {create-identity.ms_identity_manager.dbo.outbox=LEADER_NOT_AVAILABLE} (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connector-producer-debezium-connector-sql-0]
      2023-09-26 11:07:58,126 WARN [debezium-connector-sql|task-0] [Producer clientId=connector-producer-debezium-connector-sql-0] Error while fetching metadata with correlation id 6 : {create-identity.ms_identity_manager.dbo.outbox=LEADER_NOT_AVAILABLE} (org.apache.kafka.clients.NetworkClient) [kafka-producer-network-thread | connector-producer-debezium-connector-sql-0]
      2023-09-26 11:07:58,127 INFO [debezium-connector-sql|task-0] [Producer clientId=connector-producer-debezium-connector-sql-0] Resetting the last seen epoch of partition create-identity-0 to 0 since the associated topicId changed from null to o_-E26vZTPyu_0hpD5KPlQ (org.apache.kafka.clients.Metadata) [kafka-producer-network-thread | connector-producer-debezium-connector-sql-0]
      2023-09-26 11:07:58,233 INFO [debezium-connector-sql|task-0] [Producer clientId=connector-producer-debezium-connector-sql-0] Resetting the last seen epoch of partition create-identity.ms_identity_manager.dbo.outbox-0 to 0 since the associated topicId changed from null to T-tdrGzGRsy0y0mhLSbStw (org.apache.kafka.clients.Metadata) [kafka-producer-network-thread | connector-producer-debezium-connector-sql-0]
      2023-09-26 11:08:04,184 INFO 172.17.0.1 - - [26/Sep/2023:11:08:04 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 29 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-40]
      2023-09-26 11:08:04,188 INFO 172.17.0.1 - - [26/Sep/2023:11:08:04 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 27 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-34]
      2023-09-26 11:08:14,162 INFO 172.17.0.1 - - [26/Sep/2023:11:08:14 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 11 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-39]
      2023-09-26 11:08:14,187 INFO 172.17.0.1 - - [26/Sep/2023:11:08:14 +0000] "GET / HTTP/1.1" 200 91 "-" "kube-probe/1.23" 36 (org.apache.kafka.connect.runtime.rest.RestServer) [qtp2122252822-35]

       

      ===

       

       

      How to reproduce the issue using our tutorial deployment?

      <Your answer>

      Feature request or enhancement

      For feature requests or enhancements, provide this information, please:

      Which use case/requirement will be addressed by the proposed feature?

      <Your answer>

      Implementation ideas (optional)

      <Your answer>

              Unassigned Unassigned
              gopi-prasanth-softobiz Gopi Prasanth (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: