-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
None
-
1
-
False
-
None
-
False
In order to make your issue reports as actionable as possible, please provide the following information, depending on the issue type.
Bug report
We have an Oracle Debezium listener which is a Java springboot application.
Last time you all applied a patch in 2.7.3 release to restart connector for ORA-600 error. After running 2.7.3 version, it worked for us long and well for 47 days without any stoppage. Then out of nowhere, after 47 days of successful run, connector just stopped with the following error and the connector stopped for ever with an exception of ORA-01013 stating user requested cancellation of current operation (DBA said that they did not stop the process nor did they find anything unusual in their logs). While reading messages normally, suddenly logs said "Already applied X database changes" followed by a ORA-01013 error as shown below
"java.sql.SQLTimeoutException","error.message":"ORA-01013: user requested cancel of current operation\nORA-06512: at \"SYS.DBMS_LOGMNR\", line 72\nORA-06512: at line 1\n","error.stack_trace":"java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation\nORA-06512: at \"SYS.DBMS_LOGMNR\", line 72\nORA-06512: at line 1\n\n\tat oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:630)\n\tat
LOGS AS SOON AS THE LAST NORMAL MESSAGE PICKED UP IN THE LOGS
Message is normally picked up last at "@timestamp":"2024-11-19T06:34:26.185Z"
{"@timestamp":"2024-11-19T06:34:27.868Z","ecs.version":"1.2.0","log.level":"INFO","message":"Already applied 11160 database changes","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.relational.history.SchemaHistoryMetrics","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"} {"@timestamp":"2024-11-19T06:34:30.171Z","ecs.version":"1.2.0","log.level":"INFO","message":"Already applied 11168 database changes","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.relational.history.SchemaHistoryMetrics","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"} {"@timestamp":"2024-11-19T06:34:31.923Z","ecs.version":"1.2.0","log.level":"INFO","message":"Already applied 11192 database changes","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.relational.history.SchemaHistoryMetrics","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"} {"@timestamp":"2024-11-19T06:34:34.573Z","ecs.version":"1.2.0","log.level":"INFO","message":"Already applied 11197 database changes","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.relational.history.SchemaHistoryMetrics","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"} {"@timestamp":"2024-11-19T06:38:41.660Z","ecs.version":"1.2.0","log.level":"INFO","message":"[AdminClient clientId=debezium-servershared-admin] Node 1039 disconnected.","process.thread.name":"kafka-admin-client-thread | debezium-servershared-admin","log.logger":"org.apache.kafka.clients.NetworkClient"} {"@timestamp":"2024-11-19T06:43:26.680Z","ecs.version":"1.2.0","log.level":"INFO","message":"[Producer clientId=producer-1] Node 1075 disconnected.","process.thread.name":"kafka-producer-network-thread | producer-1","log.logger":"org.apache.kafka.clients.NetworkClient"} {"@timestamp":"2024-11-19T06:43:41.778Z","ecs.version":"1.2.0","log.level":"INFO","message":"[AdminClient clientId=debezium-servershared-admin] Node 1040 disconnected.","process.thread.name":"kafka-admin-client-thread | debezium-servershared-admin","log.logger":"org.apache.kafka.clients.NetworkClient"} {"@timestamp":"2024-11-19T06:44:26.743Z","ecs.version":"1.2.0","log.level":"INFO","message":"[Producer clientId=producer-1] Node 1073 disconnected.","process.thread.name":"kafka-producer-network-thread | producer-1","log.logger":"org.apache.kafka.clients.NetworkClient"}{"@timestamp":"2024-11-19T06:44:53.002Z","ecs.version":"1.2.0","log.level":"ERROR","message":"Failed to start a LogMiner mining session with parameters: ","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.connector.oracle.logminer.LogMinerDatabaseStateWriter","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"}
{"@timestamp":"2024-11-19T06:44:53.002Z","ecs.version":"1.2.0","log.level":"ERROR","message":"\tSCN: [0-0], Required Start SCN: 0, Options: 2088, Status: 0 - N/A","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.connector.oracle.logminer.LogMinerDatabaseStateWriter","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0"}
{"@timestamp":"2024-11-19T06:44:53.003Z","ecs.version":"1.2.0","log.level":"ERROR","message":"Got exception when starting mining session.","process.thread.name":"debezium-oracleconnector-ed51-scan3-3881-change-event-source-coordinator","log.logger":"io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource","dbz.connectorContext":"streaming","dbz.connectorName":"ed51-scan3-3881","dbz.connectorType":"Oracle","dbz.databaseName":"MYDB","dbz.taskId":"0","error.type":"java.sql.SQLTimeoutException","error.message":"ORA-01013: user requested cancel of current operation\nORA-06512: at \"SYS.DBMS_LOGMNR\", line 72\nORA-06512: at line 1\n","error.stack_trace":"java.sql.SQLTimeoutException: ORA-01013: user requested cancel of current operation\nORA-06512: at \"SYS.DBMS_LOGMNR\", line 72\nORA-06512: at line 1\n\n\tat oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:630)\n\tat oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:564)\n\tat oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1151)\n\tat oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:771)\n\tat oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:299)\n\tat oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:498)\n\tat oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:112)\n\tat oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:1011)\n\tat oracle.jdbc.driver.OracleStatement.executeSQLStatement(OracleStatement.java:1531)\n\tat oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1311)\n\tat oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:2163)\n\tat oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:2118)\n\tat oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:328)\n\tat io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1491)\n\tat io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.startMiningSession(LogMinerStreamingChangeEventSource.java:615)\n\tat io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:238)\n\tat
What Debezium connector do you use and what version?
It is 2.7.3, but here are helpful additional library information we use in our Java Springboot application.
implementation 'io.debezium:debezium-api:2.7.3.Final'
implementation'io.debezium:debezium-embedded:2.7.3.Final'
implementation 'org.apache.kafka:connect-runtime:3.6.1'
implementation 'io.debezium:debezium-connector-oracle:2.7.3.Final'
implementation 'com.oracle.database.jdbc:ojdbc8:21.6.0.0'
implementation 'io.debezium:debezium-storage-kafka:2.7.3.Final'
What is the connector configuration?
connector:
decimalHandlingMode: string
name: <<NAME>>
class: io.debezium.connector.oracle.OracleConnector
offsetTopic: <<OFFSETTOPICNAME>>
offsetTopicNumberOfPartitions: 1
offsetTopicReplicationFactor: 1
heartbeatIntervalInMsecs: 100000
heartbeatQuery: SELECT * FROM MYTABLE WHERE ROWNUM <= 1
.with("name", wmsDbzConnectorName)
.with("connector.class", wmsDbzConnectorClass)
.with("offset.storage", "org.apache.kafka.connect.storage.KafkaOffsetBackingStore")
.with("offset.storage.topic", debeziumConnectorOffsetTopic)
.with(DistributedConfig.OFFSET_STORAGE_PARTITIONS_CONFIG, debeziumConnectorOffsetTopicPartitions)
.with(DistributedConfig.OFFSET_STORAGE_REPLICATION_FACTOR_CONFIG, debeziumConnectorOffsetTopicReplicationFactor)
.with("offset.flush.interval.ms", "60000")
.with("database.hostname", wmsDbHost)
.with("database.port", port)
.with("database.user", username)
.with("database.password", password)
.with("database.dbname", dbName)
.with("schema.include.list", schemaList)
.with("table.include.list", tableList)
.with("include.schema.changes", "false")
.with("topic.prefix", topicPrefix)
.with("database.server.name", dbserverName)
.with("snapshot.mode", snapshotMode) // It is set as initial
.with("converter.schemas.enable", "false")
.with("decimal.handling.mode", decimalHandlingMode)
.with("heartbeat.interval.ms", heartbeatInterval)
.with("heartbeat.action.query", heartbeatActionQuery)
.with("database.history.kafka.topic", dbAndSchemaHistoryTopic)
.with("database.history.consumer.group.id", dbAndSchemaHistoryTopicConsumerGroupId)
.with("schema.history.internal.kafka.topic", schemaTopic)
.with("schema.history.internal.kafka.bootstrap.servers", schemaBootstrapServers)
.with("schema.history.internal.consumer.security.protocol", schemaSecurityProtocol)
.with("schema.history.internal.consumer.ssl.keystore.type", schemaSslKeyStoreType)
.with("schema.history.internal.consumer.ssl.keystore.location", schemaSslKeystoreLocation)
.with("schema.history.internal.consumer.ssl.keystore.password", schemaSslKeystorePassword)
.with("schema.history.internal.consumer.ssl.truststore.type", schemaSslTrustStoreType)
.with("schema.history.internal.consumer.ssl.truststore.location", schemaSslTruststoreLocation)
.with("schema.history.internal.consumer.ssl.truststore.password", schemaSslTruststorePassword)
.with("schema.history.internal.consumer.ssl.endpoint.identification.algorithm", sslEndpointAlgorithm)
.with("schema.history.internal.producer.security.protocol", schemaSecurityProtocol)
.with("schema.history.internal.producer.ssl.keystore.type", schemaSslKeyStoreType)
.with("schema.history.internal.producer.ssl.keystore.location", schemaSslKeystoreLocation)
.with("schema.history.internal.producer.ssl.keystore.password", schemaSslKeystorePassword)
.with("schema.history.internal.producer.ssl.truststore.type", schemaSslTrustStoreType)
.with("schema.history.internal.producer.ssl.truststore.location", schemaSslTruststoreLocation)
.with("schema.history.internal.producer.ssl.truststore.password", schemaSslTruststorePassword)
.with("schema.history.internal.producer.ssl.endpoint.identification.algorithm", sslEndpointAlgorithm)
.with("bootstrap.servers", schemaBootstrapServers)
.with("security.protocol", schemaSecurityProtocol)
.with("ssl.keystore.location", schemaSslKeystoreLocation)
.with("ssl.keystore.password", schemaSslKeystorePassword)
.with("ssl.truststore.location", schemaSslTruststoreLocation)
.with("ssl.truststore.password", schemaSslTruststorePassword)
.with("ssl.endpoint.identification.algorithm", sslEndpointAlgorithm)
What is the captured database version and mode of deployment?
(E.g. on-premises, with a specific cloud provider, etc.)
Data base in running on a data center and is an Oracle database of version 19c.
DB Server on Dev Database runs on a 2 node RAC. The Archived log files (which Log Miner reads from) are shared to both nodes in RAC as a shared path.
What behavior do you expect?
This issue should either have not arrived OR the connector should have restarted itself, instead of manual interference from us.
What behavior do you see?
Connector is stopped after this error.
Do you see the same behaviour using the latest released Debezium version?
Haven't tried beyond 2.7.4 version yet.
Do you have the connector logs, ideally from start till finish?
I shared them with INFO level only available.
How to reproduce the issue using our tutorial deployment?
Very difficult to reproduce. Not sure how it happened and also it happened after 47 days of smooth running.
Feature request or enhancement
Maybe auto restart of the application when it stops because of this.
Meanwhile, is there any other way to temporary force application to auto restart when this error happens till we move to your patch fixing this ?
Which use case/requirement will be addressed by the proposed feature?
Oracle Debezium java Connector recovering itself after the issue.
Implementation ideas (optional)
Auto restart of Debezium Oracle java listener whenever it is stopped like this.