-
Bug
-
Resolution: Done
-
Critical
-
1.9.1.Final
-
None
-
False
-
None
-
False
What Debezium connector do you use and what version?
1.9.1.Final
What is the connector configuration?
{
"name": "src-ase1-22021",
"config":
{ "connector.class": "io.debezium.connector.oracle.OracleConnector", "key.converter": "io.confluent.connect.avro.AvroConverter", "key.converter.schema.registry.url": "XXX", "value.converter": "io.confluent.connect.avro.AvroConverter", "value.converter.schema.registry.url": "XXX", "database.url": "jdbc:oracle:thin:@//XXX", "database.user": "DSL_RO", "database.password": "ENC[AES256_GCM,data:VNMcDAZCTFu+I668,iv:jLmCjqe3U0lLsgjJo9i94SsF4m4OXO8aXbCgJ86S1do=,tag:4hltjr9WgU0opb4lX3M8mg==,type:str]", "database.dbname": "XXX", "database.server.name": "ASE1", "table.include.list": "ASEDBUSR.ABRDVRS,ASEDBUSR.ABRDVRSUNT,ASEDBUSR.ACTIVITY,ASEDBUSR.ADRESSE,ASEDBUSR.ADRESSEROLE,ASEDBUSR.ANTRFRAGENANTW,ASEDBUSR.ARBUN,ASEDBUSR.BANK,ASEDBUSR.BEZIEHUNG,ASEDBUSR.BILANZAUSGLEICH,ASEDBUSR.BUCHSTOFFV,ASEDBUSR.BUCHUNGSTOFF", "snapshot.fetch.size": "10000", "event.processing.failure.handling.mode": "fail", "tombstones.on.delete": true, "message.key.columns": "ASEDBUSR.ABRDVRS:PKEY;ASEDBUSR.ABRDVRSUNT:PKEY;ASEDBUSR.ACTIVITY:PKEY;ASEDBUSR.ADRESSE:PKEY;ASEDBUSR.ADRESSEROLE:PKEY;ASEDBUSR.ANTRFRAGENANTW:PKEY;ASEDBUSR.ARBUN:PKEY;ASEDBUSR.BANK:PKEY;ASEDBUSR.BEZIEHUNG:PKEY;ASEDBUSR.BILANZAUSGLEICH:PKEY;ASEDBUSR.BUCHSTOFFV:PKEY;ASEDBUSR.BUCHUNGSTOFF:PKEY", "log.mining.strategy": "online_catalog", "log.mining.archive.destination.name": "LOG_ARCHIVE_DEST_10", "lob.enabled": true, "time.precision.mode": "connect", "tasks.max": "1", "database.history.kafka.bootstrap.servers": "swwkafp01.suvanet.ch:9092", "database.history.kafka.topic": "ase.schema-changes.asedbusr", "database.history.consumer.security.protocol": "SASL_SSL", "database.history.producer.security.protocol": "SASL_SSL", "database.history.consumer.sasl.mechanism": "SCRAM-SHA-512", "database.history.producer.sasl.mechanism": "SCRAM-SHA-512", "database.history.consumer.sasl.jaas.config": "ENC[AES256_GCM,data:uK6nL+MtkuBv4JbkmGzOiqWqXWEdRzPTpz62KHcxqnAXrbVJAawiq5nyRb3U3Fj2jjgvzEjZT6scl2UkX8vCq+50R89Q3wsMDJge2/KbxodirWtukdROMOX3sn0S3Je9ZM+cMrEFqSelxEMBPrzel8UIeA==,iv:ITszOL5loaM3YtGtkxbG6/G+r0uh+uA//RRgy58fIrI=,tag:uoGE7++VUHRqG78WqBn1xg==,type:str]", "database.history.producer.sasl.jaas.config": "ENC[AES256_GCM,data:Y8bglxC93enSj6NV0hCeDKzuW5rlCbjx2j6XAQFXefT4RUvhGxlUNMrMTdAipxgN7vj/fdxCHgDnX1sV1160qbTY3iYZGvV5KfRPH6hWgOuvElv2NEp8SDLm/bAFW6p+LPFsfX39MSzw4oRrk1ZBer2Gfw==,iv:15kpvdmln0VfxZ2QlF+A1IUBTzudnVTWA40fHhwHASg=,tag:tp43tzl2MDhw/aldbJNzDw==,type:str]", "transforms": "unwrap", "transforms.unwrap.type": "io.debezium.transforms.ExtractNewRecordState", "transforms.unwrap.add.fields": "source.table:META_SRC_TABLENAME,source.ts_ms:META_SRC_TS,op:META_SRC_OP,source.scn:META_SRC_SCN,source.snapshot:META_SRC_SNAPSHOT", "transforms.unwrap.delete.handling.mode": "rewrite", "transforms.unwrap.drop.tombstones": false }
,
"sops": {
"kms": null,
"gcp_kms": null,
"azure_kv": null,
"hc_vault": null,
"age": null,
"lastmodified": "2022-01-31T15:45:42Z",
"mac": "ENC[AES256_GCM,data:TdQ0XOrhkGlFVFIGWVYdA2vCn3UV5x39/1vZj5F3zQHgo+w3Am2OMPQ3V9nCYUqS144q0rnO21yYz+Tnp4pUGYFYFPjulrIw3NFQN+mEMM5JBYZIQIptI4OGXN2MiTBkXTyRZbRXzoc9GdHRS1lkRvpPNMR5e0zFu3AMVf5Zxsw=,iv:5clScQVFVRcXPk059q760vGIG9BQujJMt0wfWfD+t+M=,tag:FLoPP2zGqQREJFzFlQT+mg==,type:str]",
"pgp": [
{ "created_at": "2022-01-31T15:45:11Z", "enc": "-----BEGIN PGP MESSAGE-----\n\nhQEMA243CXYlIAr3AQf/WnSBFB9VC7uuE7M7iXSY0YsVmKMWWDXU8tvIjfsYzmEr\n66QWqUmTn5ux1RLkd/NrmAn8mx6Kc3PfCtmL1HyCAV+94P2uc4y63IxAggeWDBtA\nNZdr5BRCqlmZMIkVcO2EcV6/PZTxEBPOWzpeqQa63k1ihUwYhVhIslCo66haRL1A\nDKo/QaucLeqGpCFVgzTgCl5rCKSjScD8h0RV+I1uYR2afZxNy38rgFHd1/zhGa2W\nEngmVi481C1bW98MzndfOKg9P3dLHH1OwEEF0txZyKcp5ISWip44Nzr8WTfojp1n\nzNGGbGmbMARk48gicFr8oEy50ym49brw4J5l/SnHBtJeAWx4KUEj7wD/Vls+KFty\nXdd7ojEIDMIMyFKbNUPzGmZ0iXvEeAGFuFe9M8P+ExcDD7TcbGVpSwpFyyWeIuAe\ny4DGsmPgQBxrfA4kabyrRTYdAj4HejXsU47Gb4Ml9Q==\n=X1EW\n-----END PGP MESSAGE-----\n", "fp": "F7067DB106402AABEBEF13F8C6E64E19DC477D85" }
],
"encrypted_regex": "(database.password|database.history.consumer.sasl.jaas.config|database.history.producer.sasl.jaas.config)",
"version": "3.7.1"
}
}
What is the captured database version and mode of depoyment?
Oracle 19c (non CDB)
What behaviour do you see?
At the time of the following warning /error there were several log switches going on (about 10). There were 3 errors and 1 warning for this connector at the time of the log switches.
We can see entries like this in the logs:
[2022-05-18 17:06:44,881] WARN [src-ase6-22024s1|task-0] WorkerSourceTask
{id=src-ase6-22024s1-0}
failed to poll records from SourceTask. Will retry operation. (org.apache.kafka.connect.runtime.WorkerSourceTask:306) org.apache.kafka.connect.errors.RetriableException: An exception occurred in the change event producer. This connector will be restarted. at io.debezium.pipeline.ErrorHandler.setProducerThrowable(ErrorHandler.java:46) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:199) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:59) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: java.sql.SQLException: ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494) at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446) at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252) at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37) at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:896) at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119) at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1737) at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1692) at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:300) at io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1405) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.startMiningSession(LogMinerStreamingChangeEventSource.java:532) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:185) ... 9 more Caused by: Error : 1291, Position : 0, Sql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, OriginalSql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, Error Msg = ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498) ... 24 more
[2022-05-18 17:06:44,533] ERROR [src-ase6-22024s1|task-0] Producer failure (io.debezium.pipeline.ErrorHandler:35) java.sql.SQLException: ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494) at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446) at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252) at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37) at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:896) at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119) at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1737) at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1692) at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:300) at io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1405) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.startMiningSession(LogMinerStreamingChangeEventSource.java:532) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:185) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:59) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: Error : 1291, Position : 0, Sql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, OriginalSql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, Error Msg = ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498) ... 24 more
[2022-05-18 17:06:44,533] ERROR [src-ase6-22024s1|task-0] Mining session stopped due to the {} (io.debezium.connector.oracle.logminer.LogMinerHelper:117) java.sql.SQLException: ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494) at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446) at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252) at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37) at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:896) at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119) at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1737) at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1692) at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:300) at io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1405) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.startMiningSession(LogMinerStreamingChangeEventSource.java:532) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:185) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:59) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: Error : 1291, Position : 0, Sql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, OriginalSql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, Error Msg = ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498) ... 24 more
[2022-05-18 17:06:44,532] ERROR [src-ase6-22024s1|task-0] Got exception when starting mining session. (io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource:536) java.sql.SQLException: ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494) at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446) at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054) at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623) at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252) at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213) at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37) at oracle.jdbc.driver.T4CStatement.executeForRows(T4CStatement.java:896) at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1119) at oracle.jdbc.driver.OracleStatement.executeInternal(OracleStatement.java:1737) at oracle.jdbc.driver.OracleStatement.execute(OracleStatement.java:1692) at oracle.jdbc.driver.OracleStatementWrapper.execute(OracleStatementWrapper.java:300) at io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1405) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.startMiningSession(LogMinerStreamingChangeEventSource.java:532) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:185) at io.debezium.connector.oracle.logminer.LogMinerStreamingChangeEventSource.execute(LogMinerStreamingChangeEventSource.java:59) at io.debezium.pipeline.ChangeEventSourceCoordinator.streamEvents(ChangeEventSourceCoordinator.java:174) at io.debezium.pipeline.ChangeEventSourceCoordinator.executeChangeEventSources(ChangeEventSourceCoordinator.java:141) at io.debezium.pipeline.ChangeEventSourceCoordinator.lambda$start$0(ChangeEventSourceCoordinator.java:109) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) Caused by: Error : 1291, Position : 0, Sql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, OriginalSql = BEGIN sys.dbms_logmnr.start_logmnr(startScn => '289877889220', endScn => '289877892415', OPTIONS => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG + DBMS_LOGMNR.NO_ROWID_IN_STMT);END;, Error Msg = ORA-01291: missing log file ORA-06512: at "SYS.DBMS_LOGMNR", line 72 ORA-06512: at line 1 at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498) ... 24 more
Chris Cranford meant: The only way forward that I can see is to make ORA-01291 an exception that we capture & re-run the log mining step, likely with some type of flag that if the step fails after X attempts, we hard fail the connector to deal with situations where there is a critical problem where this error is raised.