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

Misleading error message on lost database connection

    Details

      Description

      When something happens with connection during `snapshot` phase `Debezium` swallows initial db error. The chain of embedded try/catches and error wrapping makes you think that something bad happens while acquiring / releasing table locks:

      [2020-03-31 22:02:58,180] INFO Step 9: - 860000 of 1967916 rows scanned from table 'db_cxp_perf_01.cases' after 00:02:09.91 (io.debezium.connector.mysql.SnapshotReader)
      [2020-03-31 22:02:58,415] TRACE Polling for events (io.debezium.connector.mysql.MySqlConnectorTask)
      [2020-03-31 22:02:58,456] INFO Step 9: committing transaction (io.debezium.connector.mysql.SnapshotReader)
      [2020-03-31 22:02:58,457] TRACE Executing statement UNLOCK TABLES (io.debezium.jdbc.JdbcConnection)
      [2020-03-31 22:02:58,457] ERROR Removing of table locks not completed successfully (io.debezium.connector.mysql.SnapshotReader)
      java.sql.SQLException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
      	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
      	at com.mysql.cj.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.java:1429)
      	at com.mysql.cj.jdbc.ConnectionImpl.isReadOnly(ConnectionImpl.java:1408)
      	at com.mysql.cj.jdbc.StatementImpl.executeInternal(StatementImpl.java:696)
      	at com.mysql.cj.jdbc.StatementImpl.execute(StatementImpl.java:666)
      	at io.debezium.jdbc.JdbcConnection.executeWithoutCommitting(JdbcConnection.java:1202)
      	at io.debezium.connector.mysql.SnapshotReader.execute(SnapshotReader.java:835)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      [2020-03-31 22:02:58,459] ERROR Execption while rollback is executed (io.debezium.connector.mysql.SnapshotReader)
      java.sql.SQLException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
      	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
      	at com.mysql.cj.jdbc.ConnectionImpl.rollbackNoChecks(ConnectionImpl.java:1961)
      	at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1855)
      	at io.debezium.connector.mysql.SnapshotReader.execute(SnapshotReader.java:841)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      [2020-03-31 22:02:58,459] ERROR Failed due to error: Aborting snapshot due to error when last running 'UNLOCK TABLES': Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries. (io.debezium.connector.mysql.SnapshotReader)
      org.apache.kafka.connect.errors.ConnectException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries. Error code: 0; SQLSTATE: S1000.
      	at io.debezium.connector.mysql.AbstractReader.wrap(AbstractReader.java:230)
      	at io.debezium.connector.mysql.AbstractReader.failed(AbstractReader.java:207)
      	at io.debezium.connector.mysql.SnapshotReader.execute(SnapshotReader.java:847)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      Caused by: java.sql.SQLException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
      	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
      	at com.mysql.cj.jdbc.ConnectionImpl.commit(ConnectionImpl.java:813)
      	at io.debezium.connector.mysql.SnapshotReader.execute(SnapshotReader.java:748)
      	... 3 more
      [2020-03-31 22:02:58,460] TRACE Closing database connection (io.debezium.jdbc.JdbcConnection)
      [2020-03-31 22:02:58,462] WARN Failed to close the connection properly (io.debezium.connector.mysql.SnapshotReader)
      java.sql.SQLException: Streaming result set com.mysql.cj.protocol.a.result.ResultsetRowsStreaming@4dd484b3 is still active. No statements may be issued when any streaming result sets are open and in use on a given connection. Ensure that you have called .close() on any active streaming result sets before attempting more queries.
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:129)
      	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97)
      	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
      	at com.mysql.cj.jdbc.ConnectionImpl.rollbackNoChecks(ConnectionImpl.java:1961)
      	at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1855)
      	at com.mysql.cj.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:1720)
      	at com.mysql.cj.jdbc.ConnectionImpl.close(ConnectionImpl.java:720)
      	at io.debezium.jdbc.JdbcConnection.close(JdbcConnection.java:850)
      	at io.debezium.connector.mysql.SnapshotReader.execute(SnapshotReader.java:851)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      	at java.lang.Thread.run(Thread.java:748)
      

      In my case DB is AWS Aurora.

        Gliffy Diagrams

          Attachments

            Activity

              People

              • Assignee:
                ccranfor Chris Cranford
                Reporter:
                mikekamornikov Mike Kamornikov
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: