2024-02-20T17:23:38.6095253Z [ERROR] io.debezium.connector.informix.TransactionMetadataIT.transactionMetadata -- Time elapsed: 96.00 s <<< FAILURE!
2024-02-20T17:23:38.6096581Z java.lang.AssertionError: 
2024-02-20T17:23:38.6096924Z 
2024-02-20T17:23:38.6097125Z Expecting actual not to be null
2024-02-20T17:23:38.6098312Z    at io.debezium.connector.informix.TransactionMetadataIT.transactionMetadata(TransactionMetadataIT.java:102)
2024-02-20T17:23:38.6100171Z    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2024-02-20T17:23:38.6101722Z    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
2024-02-20T17:23:38.6103496Z    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2024-02-20T17:23:38.6105074Z    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
2024-02-20T17:23:38.6105855Z    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
2024-02-20T17:23:38.6106848Z    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
2024-02-20T17:23:38.6107660Z    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
2024-02-20T17:23:38.6108469Z    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
2024-02-20T17:23:38.6109344Z    at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
2024-02-20T17:23:38.6110385Z    at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
2024-02-20T17:23:38.6111040Z    at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
2024-02-20T17:23:38.6111626Z    at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
2024-02-20T17:23:38.6112319Z    at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
2024-02-20T17:23:38.6113015Z    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
2024-02-20T17:23:38.6113707Z    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
2024-02-20T17:23:38.6114496Z    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
2024-02-20T17:23:38.6115160Z    at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
2024-02-20T17:23:38.6115730Z    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
2024-02-20T17:23:38.6116347Z    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
2024-02-20T17:23:38.6116959Z    at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
2024-02-20T17:23:38.6117565Z    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
2024-02-20T17:23:38.6118508Z    at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
2024-02-20T17:23:38.6119389Z    at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
2024-02-20T17:23:38.6126976Z    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:316)
2024-02-20T17:23:38.6128408Z    at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:240)
2024-02-20T17:23:38.6129875Z    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:214)
2024-02-20T17:23:38.6131287Z    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:155)
2024-02-20T17:23:38.6132516Z    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
2024-02-20T17:23:38.6133322Z    at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
2024-02-20T17:23:38.6134039Z    at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
2024-02-20T17:23:38.6134740Z    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)

2024-02-20T17:22:02.7744275Z 2024-02-20 17:22:02,604 INFO  SchemaHistoryTopicIT||test Starting test io.debezium.connector.informix.TransactionMetadataIT#transactionMetadata [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:22:02.7746911Z 2024-02-20 17:22:02,621 INFO  TransactionMetadataIT||test EmbeddedWorkerConfig values: 
2024-02-20T17:22:02.7747956Z    access.control.allow.methods = 
2024-02-20T17:22:02.7748531Z    access.control.allow.origin = 
2024-02-20T17:22:02.7749062Z    admin.listeners = null
2024-02-20T17:22:02.7749574Z    auto.include.jmx.reporter = true
2024-02-20T17:22:02.7750416Z    bootstrap.servers = [localhost:9092]
2024-02-20T17:22:02.7751033Z    client.dns.lookup = use_all_dns_ips
2024-02-20T17:22:02.7751677Z    config.providers = []
2024-02-20T17:22:02.7752292Z    connector.client.config.override.policy = All
2024-02-20T17:22:02.7753397Z    header.converter = class org.apache.kafka.connect.storage.SimpleHeaderConverter
2024-02-20T17:22:02.7754649Z    key.converter = class org.apache.kafka.connect.json.JsonConverter
2024-02-20T17:22:02.7755495Z    listeners = [http://:8083]
2024-02-20T17:22:02.7756175Z    metric.reporters = []
2024-02-20T17:22:02.7756672Z    metrics.num.samples = 2
2024-02-20T17:22:02.7757166Z    metrics.recording.level = INFO
2024-02-20T17:22:02.7757720Z    metrics.sample.window.ms = 30000
2024-02-20T17:22:02.7758243Z    offset.flush.interval.ms = 0
2024-02-20T17:22:02.7758704Z    offset.flush.timeout.ms = 5000
2024-02-20T17:22:02.7759529Z    offset.storage.file.filename = /home/runner/work/debezium/debezium/informix/target/data/file-connector-offsets.txt
2024-02-20T17:22:02.7760754Z    offset.storage.partitions = null
2024-02-20T17:22:02.7761210Z    offset.storage.replication.factor = null
2024-02-20T17:22:02.7761573Z    offset.storage.topic = 
2024-02-20T17:22:02.7762247Z    plugin.discovery = hybrid_warn
2024-02-20T17:22:02.7762569Z    plugin.path = null
2024-02-20T17:22:02.7762942Z    response.http.headers.config = 
2024-02-20T17:22:02.7763274Z    rest.advertised.host.name = null
2024-02-20T17:22:02.7763683Z    rest.advertised.listener = null
2024-02-20T17:22:02.7764213Z    rest.advertised.port = null
2024-02-20T17:22:02.7764731Z    rest.extension.classes = []
2024-02-20T17:22:02.7765034Z    ssl.cipher.suites = null
2024-02-20T17:22:02.7765346Z    ssl.client.auth = none
2024-02-20T17:22:02.7765890Z    ssl.enabled.protocols = [TLSv1.2, TLSv1.3]
2024-02-20T17:22:02.7766590Z    ssl.endpoint.identification.algorithm = https
2024-02-20T17:22:02.7766993Z    ssl.engine.factory.class = null
2024-02-20T17:22:02.7767523Z    ssl.key.password = null
2024-02-20T17:22:02.7768063Z    ssl.keymanager.algorithm = SunX509
2024-02-20T17:22:02.7768715Z    ssl.keystore.certificate.chain = null
2024-02-20T17:22:02.7769511Z    ssl.keystore.key = null
2024-02-20T17:22:02.7770013Z    ssl.keystore.location = null
2024-02-20T17:22:02.7770582Z    ssl.keystore.password = null
2024-02-20T17:22:02.7771091Z    ssl.keystore.type = JKS
2024-02-20T17:22:02.7771438Z    ssl.protocol = TLSv1.3
2024-02-20T17:22:02.7771717Z    ssl.provider = null
2024-02-20T17:22:02.7772209Z    ssl.secure.random.implementation = null
2024-02-20T17:22:02.7772969Z    ssl.trustmanager.algorithm = PKIX
2024-02-20T17:22:02.7773334Z    ssl.truststore.certificates = null
2024-02-20T17:22:02.7773827Z    ssl.truststore.location = null
2024-02-20T17:22:02.7774374Z    ssl.truststore.password = null
2024-02-20T17:22:02.7774810Z    ssl.truststore.type = JKS
2024-02-20T17:22:02.7775252Z    task.shutdown.graceful.timeout.ms = 5000
2024-02-20T17:22:02.7775904Z    topic.creation.enable = true
2024-02-20T17:22:02.7776468Z    topic.tracking.allow.reset = true
2024-02-20T17:22:02.7777092Z    topic.tracking.enable = true
2024-02-20T17:22:02.7777719Z    value.converter = class org.apache.kafka.connect.json.JsonConverter
2024-02-20T17:22:02.7778636Z  [io.debezium.embedded.EmbeddedWorkerConfig]
2024-02-20T17:22:02.7781058Z 2024-02-20 17:22:02,622 INFO  TransactionMetadataIT||engine Loading the custom source info struct maker plugin: io.debezium.connector.informix.InformixSourceInfoStructMaker [io.debezium.config.CommonConnectorConfig]
2024-02-20T17:22:02.7785064Z 2024-02-20 17:22:02,636 INFO  TransactionMetadataIT||engine Successfully tested connection for jdbc:informix-sqli://localhost:32768/testdb:user=informix;*** with user 'informix' [io.debezium.connector.informix.InformixConnector]
2024-02-20T17:22:02.7787843Z 2024-02-20 17:22:02,636 INFO  || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2024-02-20T17:22:02.7790241Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine Starting InformixConnectorTask with configuration: [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7793052Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    connector.class = io.debezium.connector.informix.InformixConnector [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7795646Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    database.dbname = testdb [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7797573Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    database.user = informix [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7799348Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    offset.storage = org.apache.kafka.connect.storage.FileOffsetBackingStore [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7800989Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    cdc.buffersize = 2048 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7802281Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    cdc.timeout = 0 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7803891Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    offset.flush.timeout.ms = 5000 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7805611Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    errors.retry.delay.max.ms = 10000 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7807255Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    provide.transaction.metadata = true [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7808886Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    include.schema.changes = false [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7810262Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    database.port = 32768 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7812333Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    schema.history.internal.file.filename = /home/runner/work/debezium/debezium/informix/target/data/file-schema-history.txt [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7814706Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    offset.flush.interval.ms = 0 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7816972Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    topic.prefix = testdb [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7819530Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    schema.history.internal = io.debezium.storage.file.history.FileSchemaHistory [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7822421Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    offset.storage.file.filename = /home/runner/work/debezium/debezium/informix/target/data/file-connector-offsets.txt [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7824138Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    errors.max.retries = -1 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7825384Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    database.hostname = localhost [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7826697Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    database.password = ******** [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7827884Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    name = testing-connector [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7829119Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    errors.retry.delay.initial.ms = 300 [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7831087Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    value.converter = org.apache.kafka.connect.json.JsonConverter [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7833317Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    key.converter = org.apache.kafka.connect.json.JsonConverter [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7835347Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine    snapshot.mode = initial [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7837757Z 2024-02-20 17:22:02,637 INFO  TransactionMetadataIT||engine Loading the custom source info struct maker plugin: io.debezium.connector.informix.InformixSourceInfoStructMaker [io.debezium.config.CommonConnectorConfig]
2024-02-20T17:22:02.7840297Z 2024-02-20 17:22:02,638 INFO  TransactionMetadataIT||engine Loading the custom topic naming strategy plugin: io.debezium.schema.SchemaTopicNamingStrategy [io.debezium.config.CommonConnectorConfig]
2024-02-20T17:22:02.7842327Z 2024-02-20 17:22:02,680 INFO  TransactionMetadataIT||engine No previous offsets found [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:22:02.7844514Z 2024-02-20 17:22:02,681 INFO  TransactionMetadataIT||engine Requested thread factory for connector InformixConnector, id = testdb named = SignalProcessor [io.debezium.util.Threads]
2024-02-20T17:22:02.7847080Z 2024-02-20 17:22:02,681 INFO  TransactionMetadataIT||engine Requested thread factory for connector InformixConnector, id = testdb named = change-event-source-coordinator [io.debezium.util.Threads]
2024-02-20T17:22:02.7849889Z 2024-02-20 17:22:02,681 INFO  TransactionMetadataIT||engine Requested thread factory for connector InformixConnector, id = testdb named = blocking-snapshot [io.debezium.util.Threads]
2024-02-20T17:22:02.7851550Z 2024-02-20 17:22:02,681 INFO  TransactionMetadataIT||engine Creating thread debezium-informixconnector-testdb-change-event-source-coordinator [io.debezium.util.Threads]
2024-02-20T17:22:02.7852973Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot Metrics registered [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:22:02.7854185Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot Context created [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:22:02.7855585Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot No previous offset has been found [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:02.7857966Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot According to the connector configuration both schema and data will be snapshot [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:02.7859901Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot Snapshot step 1 - Preparing [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7862641Z 2024-02-20 17:22:02,681 INFO  Informix_Server|testdb|snapshot Snapshot step 2 - Determining captured tables [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7865166Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Adding table testdb.informix.tablea to the list of capture schema tables [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7867762Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Adding table testdb.informix.tableb to the list of capture schema tables [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7870284Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Created connection pool with 1 threads [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7872613Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Snapshot step 3 - Locking captured tables [testdb.informix.tablea, testdb.informix.tableb] [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7874990Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Executing schema locking [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:02.7877511Z 2024-02-20 17:22:02,683 INFO  Informix_Server|testdb|snapshot Locking table testdb.informix.tablea [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:02.7879837Z 2024-02-20 17:22:02,684 INFO  Informix_Server|testdb|snapshot Locking table testdb.informix.tableb [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:02.7882721Z 2024-02-20 17:22:02,684 INFO  Informix_Server|testdb|snapshot Snapshot step 4 - Determining snapshot offset [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7885660Z 2024-02-20 17:22:02,685 INFO  Informix_Server|testdb|snapshot Snapshot step 5 - Reading structure of captured tables [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:02.7888676Z 2024-02-20 17:22:02,685 INFO  Informix_Server|testdb|snapshot Reading structure of schema 'informix' [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:03.1745000Z 2024-02-20 17:22:03,159 INFO  Informix_Server|testdb|snapshot Snapshot step 6 - Persisting schema history [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1746991Z 2024-02-20 17:22:03,159 INFO  Informix_Server|testdb|snapshot Capturing structure of table testdb.informix.tablea [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1748878Z 2024-02-20 17:22:03,159 INFO  Informix_Server|testdb|snapshot Capturing structure of table testdb.informix.tableb [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1750681Z 2024-02-20 17:22:03,160 INFO  Informix_Server|testdb|snapshot Schema locks released. [io.debezium.connector.informix.InformixSnapshotChangeEventSource]
2024-02-20T17:22:03.1752321Z 2024-02-20 17:22:03,160 INFO  Informix_Server|testdb|snapshot Snapshot step 7 - Snapshotting data [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1754160Z 2024-02-20 17:22:03,160 INFO  Informix_Server|testdb|snapshot Creating snapshot worker pool with 1 worker thread(s) [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1756260Z 2024-02-20 17:22:03,160 INFO  Informix_Server|testdb|snapshot For table 'testdb.informix.tablea' using select statement: 'SELECT id, cola FROM informix.tablea' [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1759130Z 2024-02-20 17:22:03,160 INFO  Informix_Server|testdb|snapshot For table 'testdb.informix.tableb' using select statement: 'SELECT id, colb FROM informix.tableb' [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1761496Z 2024-02-20 17:22:03,160 INFO  || Exporting data from table 'testdb.informix.tablea' (1 of 2 tables) [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1763985Z 2024-02-20 17:22:03,161 INFO  ||    Finished exporting 1 records for table 'testdb.informix.tablea' (1 of 2 tables); total duration '00:00:00.001' [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1766359Z 2024-02-20 17:22:03,162 INFO  || Exporting data from table 'testdb.informix.tableb' (2 of 2 tables) [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1768857Z 2024-02-20 17:22:03,163 INFO  ||    Finished exporting 0 records for table 'testdb.informix.tableb' (2 of 2 tables); total duration '00:00:00.001' [io.debezium.relational.RelationalSnapshotChangeEventSource]
2024-02-20T17:22:03.1770925Z 2024-02-20 17:22:03,164 INFO  Informix_Server|testdb|snapshot Snapshot - Final stage [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
2024-02-20T17:22:03.1772794Z 2024-02-20 17:22:03,164 INFO  Informix_Server|testdb|snapshot Snapshot completed [io.debezium.pipeline.source.AbstractSnapshotChangeEventSource]
2024-02-20T17:22:03.1776522Z 2024-02-20 17:22:03,164 INFO  Informix_Server|testdb|snapshot Snapshot ended with SnapshotResult [status=COMPLETED, offset=InformixOffsetContext [sourceInfoSchema=Schema{io.debezium.connector.informix.Source:STRUCT}, sourceInfo=SourceInfo [serverName=testdb, timestamp=2024-02-20T17:22:03.160830Z, db=testdb, snapshot=FALSE, commitLsn=30068043776, changeLsn=-1, txId=-1, beginLsn=-1], snapshotCompleted=true]] [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:22:03.2029578Z 17:22:03.202 IFX >>>2024-02-20 17:22:03.202  CDC: Log Reader starting to snoop at the REQUESTED position, LSN(7,31f000), page 0.
2024-02-20T17:22:03.2031918Z 17:22:03.202 IFX >>>2024-02-20 17:22:03.202  CDC: Log Reader started.  CDC session id 477102119. SQL session id 910.
2024-02-20T17:22:03.2745034Z 2024-02-20 17:22:03,177 INFO  Informix_Server|testdb|streaming Connected metrics set to 'true' [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:22:03.2747668Z 2024-02-20 17:22:03,177 INFO  Informix_Server|testdb|streaming SignalProcessor started. Scheduling it every 5000ms [io.debezium.pipeline.signal.SignalProcessor]
2024-02-20T17:22:03.2750426Z 2024-02-20 17:22:03,177 INFO  Informix_Server|testdb|streaming Creating thread debezium-informixconnector-testdb-SignalProcessor [io.debezium.util.Threads]
2024-02-20T17:22:03.2752944Z 2024-02-20 17:22:03,178 INFO  Informix_Server|testdb|streaming Starting streaming [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:22:03.2754708Z Consumed record 1 / 1 (0 more)
2024-02-20T17:22:03.2760063Z {"sourcePartition" : {"databaseName" : "testdb"}, "sourceOffset" : {"commit_lsn" : "30068043776", "snapshot" : "true", "snapshot_completed" : "true"}, "topic" : "testdb.informix.tablea", "kafkaPartition" : null, "key" : {"id" : "1"}, "value" : {"before" : null, "after" : {"id" : "1", "cola" : "a"}, "source" : {"version" : "2.6.0-SNAPSHOT", "connector" : "informix", "name" : "testdb", "ts_ms" : "1708449723160", "snapshot" : "last", "db" : "testdb", "sequence" : null, "ts_us" : "1708449723160830", "ts_ns" : "1708449723160830000", "schema" : "informix", "table" : "tablea", "commit_lsn" : "30068043776", "change_lsn" : null, "txId" : null, "begin_lsn" : null}, "op" : "r", "ts_ms" : "1708449723161", "ts_us" : "1708449723161901", "ts_ns" : "1708449723161901218", "transaction" : null}}
2024-02-20T17:22:03.2766017Z 2024-02-20 17:22:03,187 INFO  Informix_Server|testdb|streaming Set CDCEngine's LSN to '30068043776' aka LSN(7,31f000) [io.debezium.connector.informix.InformixStreamingChangeEventSource]
2024-02-20T17:23:23.2334174Z 2024-02-20 17:23:23,195 INFO  TransactionMetadataIT||test Stopping the connector [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:23.2336599Z 2024-02-20 17:23:23,195 INFO  TransactionMetadataIT||test Stopping the engine [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:23.2339229Z 2024-02-20 17:23:23,195 INFO  TransactionMetadataIT||test Stopping the embedded engine [io.debezium.embedded.EmbeddedEngine]
2024-02-20T17:23:23.2341096Z 2024-02-20 17:23:23,195 INFO  TransactionMetadataIT||test Waiting for PT5M for connector to stop [io.debezium.embedded.EmbeddedEngine]
2024-02-20T17:23:23.4335527Z 2024-02-20 17:23:23,342 INFO  TransactionMetadataIT||engine Stopping the task and engine [io.debezium.embedded.EmbeddedEngine]
2024-02-20T17:23:23.4336973Z 2024-02-20 17:23:23,342 INFO  TransactionMetadataIT||engine Stopping down connector [io.debezium.connector.common.BaseSourceTask]
2024-02-20T17:23:38.2980594Z 17:23:38.297 IFX >>>2024-02-20 17:23:38.297  CDC: Log Reader ended.  CDC session id 477102119. SQL session id 910.
2024-02-20T17:23:38.3450256Z 2024-02-20 17:23:38,300 INFO  Informix_Server|testdb|streaming Finished streaming [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:23:38.3452538Z 2024-02-20 17:23:38,300 INFO  Informix_Server|testdb|streaming Connected metrics set to 'false' [io.debezium.pipeline.ChangeEventSourceCoordinator]
2024-02-20T17:23:38.3455024Z 2024-02-20 17:23:38,300 INFO  TransactionMetadataIT||engine SignalProcessor stopped [io.debezium.pipeline.signal.SignalProcessor]
2024-02-20T17:23:38.3456691Z 2024-02-20 17:23:38,300 INFO  TransactionMetadataIT||engine Debezium ServiceRegistry stopped. [io.debezium.service.DefaultServiceRegistry]
2024-02-20T17:23:38.3457994Z 2024-02-20 17:23:38,301 INFO  || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2024-02-20T17:23:38.3458886Z 2024-02-20 17:23:38,301 INFO  || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2024-02-20T17:23:38.3460328Z 2024-02-20 17:23:38,301 INFO  TransactionMetadataIT||engine Connector 'io.debezium.connector.informix.InformixConnector' completed normally. [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:38.4450988Z 2024-02-20 17:23:38,402 INFO  TransactionMetadataIT||test Interrupting the engine [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:38.6060328Z 2024-02-20 17:23:38,605 INFO  || Connection gracefully closed [io.debezium.jdbc.JdbcConnection]
2024-02-20T17:23:38.6062497Z 2024-02-20 17:23:38,605 INFO  TransactionMetadataIT||test Stopping the connector [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:38.6065277Z 2024-02-20 17:23:38,605 INFO  TransactionMetadataIT||test Test io.debezium.connector.informix.TransactionMetadataIT#transactionMetadata failed [io.debezium.connector.informix.TransactionMetadataIT]
2024-02-20T17:23:38.6092383Z [ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 96.00 s <<< FAILURE! -- in io.debezium.connector.informix.TransactionMetadataIT
2024-02-20T17:23:38.6095253Z [ERROR] io.debezium.connector.informix.TransactionMetadataIT.transactionMetadata -- Time elapsed: 96.00 s <<< FAILURE!