bug: mariadb JDBC driver fails to connect

[dantengsky]

Summary

mariadb JDBC driver fails to connect:

Could not connect to address=(host=127.0.0.1)(port=3307)(type=master) : unexpected end of stream, read 0 bytes from 4 (socket was closed by server)

version: main branch (commit #45a58cdadc) & release/v1.2.636-rc4.1

reproduce:

java client:

jdbc driver & connection pool libs:

        <dependency>
            <groupId>com.zaxxer</groupId>
            <artifactId>HikariCP</artifactId>
            <version>3.3.1</version>
        </dependency>
        <dependency>
            <groupId>org.mariadb.jdbc</groupId>
            <artifactId>mariadb-java-client</artifactId>
            <version>2.5.4</version>
        </dependency>

Main.java

package org.example;

import com.zaxxer.hikari.HikariConfig;
import com.zaxxer.hikari.HikariDataSource;

import java.sql.Connection;
import java.sql.PreparedStatement;
import java.sql.ResultSet;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class Main {

    public static void main(String[] args) {
        HikariConfig config = new HikariConfig();
        config.setJdbcUrl("jdbc:mysql://127.0.0.1:3307/default");
        config.setUsername("test");
        config.setPassword("test");
        config.setDriverClassName("org.mariadb.jdbc.Driver");

        config.setMaximumPoolSize(12);
        config.setMinimumIdle(1);

        config.setIdleTimeout(10000);
        config.setMaxLifetime(30000);

        System.setProperty("java.util.logging.ConsoleHandler.level", "ALL");
        System.setProperty("com.zaxxer.hikari.level", "TRACE"); //

        HikariDataSource dataSource = new HikariDataSource(config);

        int numberOfThreads = 5;
        ExecutorService executorService = Executors.newFixedThreadPool(numberOfThreads);

        int parallelTasks = numberOfThreads;
        for (int i = 0; i < parallelTasks; i++) {
            executorService.submit(() -> {
                while (true) {
                    try (Connection connection = dataSource.getConnection()) {
                        try (PreparedStatement preparedStatement = connection.prepareStatement("SELECT sleep(1)");
                             ResultSet resultSet = preparedStatement.executeQuery()) {
                            while (resultSet.next()) {
                            }
                        }
                    } catch (Exception e) {
                        e.printStackTrace();
                    }

                    try {
                        Thread.sleep(1000);
                    } catch (InterruptedException e) {
                        Thread.currentThread().interrupt();
                    }
                }
            });
        }
    }
}

java client side exceptions:

2024-11-21 00:25:02 - Driver class org.mariadb.jdbc.Driver found in Thread context class loader jdk.internal.loader.ClassLoaders$AppClassLoader@251a69d7
2024-11-21 00:25:02 - HikariPool-1 - configuration:
2024-11-21 00:25:02 - allowPoolSuspension.............false
2024-11-21 00:25:02 - autoCommit......................true
2024-11-21 00:25:02 - catalog.........................none
2024-11-21 00:25:02 - connectionInitSql...............none
2024-11-21 00:25:02 - connectionTestQuery.............none
2024-11-21 00:25:02 - connectionTimeout...............30000
2024-11-21 00:25:02 - dataSource......................none
2024-11-21 00:25:02 - dataSourceClassName.............none
2024-11-21 00:25:02 - dataSourceJNDI..................none
2024-11-21 00:25:02 - dataSourceProperties............{password=<masked>}
2024-11-21 00:25:02 - driverClassName................."org.mariadb.jdbc.Driver"
2024-11-21 00:25:02 - healthCheckProperties...........{}
2024-11-21 00:25:02 - healthCheckRegistry.............none
2024-11-21 00:25:02 - idleTimeout.....................10000
2024-11-21 00:25:02 - initializationFailTimeout.......1
2024-11-21 00:25:02 - isolateInternalQueries..........false
2024-11-21 00:25:02 - jdbcUrl.........................jdbc:mysql://127.0.0.1:3307/default
2024-11-21 00:25:02 - leakDetectionThreshold..........0
2024-11-21 00:25:02 - maxLifetime.....................30000
2024-11-21 00:25:02 - maximumPoolSize.................12
2024-11-21 00:25:02 - metricRegistry..................none
2024-11-21 00:25:02 - metricsTrackerFactory...........none
2024-11-21 00:25:02 - minimumIdle.....................1
2024-11-21 00:25:02 - password........................<masked>
2024-11-21 00:25:02 - poolName........................"HikariPool-1"
2024-11-21 00:25:02 - readOnly........................false
2024-11-21 00:25:02 - registerMbeans..................false
2024-11-21 00:25:02 - scheduledExecutor...............none
2024-11-21 00:25:02 - schema..........................none
2024-11-21 00:25:02 - threadFactory...................internal
2024-11-21 00:25:02 - transactionIsolation............default
2024-11-21 00:25:02 - username........................"test"
2024-11-21 00:25:02 - validationTimeout...............5000
2024-11-21 00:25:02 - HikariPool-1 - Starting...
2024-11-21 00:25:06 - HikariPool-1 - Failed to create/setup connection: Could not connect to address=(host=127.0.0.1)(port=3307)(type=master) : unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
2024-11-21 00:25:06 - HikariPool-1 - Cannot acquire connection from data source
java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=127.0.0.1)(port=3307)(type=master) : unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:241)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1243)
    at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:622)
    at org.mariadb.jdbc.MariaDbConnection.newConnection(MariaDbConnection.java:142)
    at org.mariadb.jdbc.Driver.connect(Driver.java:86)
    at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
    at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:353)
    at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
    at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:473)
    at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:562)
    at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
    at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
    at org.example.Main.main(Main.java:30)
Caused by: java.sql.SQLNonTransientConnectionException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.handleIoException(AbstractQueryProtocol.java:1961)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1444)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1423)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:923)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.postConnectionQueries(AbstractConnectProtocol.java:793)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.createConnection(AbstractConnectProtocol.java:549)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1238)
    ... 11 common frames omitted
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:243)
    at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:212)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1442)
    ... 16 common frames omitted
2024-11-21 00:25:06 - HikariPool-1 - Exception during pool initialization.
java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=127.0.0.1)(port=3307)(type=master) : unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:241)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1243)
    at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:622)
    at org.mariadb.jdbc.MariaDbConnection.newConnection(MariaDbConnection.java:142)
    at org.mariadb.jdbc.Driver.connect(Driver.java:86)
    at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138)
    at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:353)
    at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:201)
    at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:473)
    at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:562)
    at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
    at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
    at org.example.Main.main(Main.java:30)
Caused by: java.sql.SQLNonTransientConnectionException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.handleIoException(AbstractQueryProtocol.java:1961)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1444)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1423)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.readPipelineAdditionalData(AbstractConnectProtocol.java:923)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.postConnectionQueries(AbstractConnectProtocol.java:793)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.createConnection(AbstractConnectProtocol.java:549)
    at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1238)
    ... 11 common frames omitted
Caused by: java.io.EOFException: unexpected end of stream, read 0 bytes from 4 (socket was closed by server)
    at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:243)
    at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:212)
    at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1442)
    ... 16 common frames omitted

server (query node) exceptions:

panicked at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/unicode-segmentation-1.11.0/src/grapheme.rs:122:26:
byte index 2 is not a char boundary; it is inside '\0' (bytes 1..2) of ``
   0: backtrace::backtrace::libunwind::trace
             at /home/usr/.cargo/git/checkouts/backtrace-rs-fb1f822361417489/72265be/src/backtrace/libunwind.rs:116:5
      backtrace::backtrace::trace_unsynchronized
             at /home/usr/.cargo/git/checkouts/backtrace-rs-fb1f822361417489/72265be/src/backtrace/mod.rs:66:5
   1: backtrace::backtrace::trace
             at /home/usr/.cargo/git/checkouts/backtrace-rs-fb1f822361417489/72265be/src/backtrace/mod.rs:53:14
   2: databend_common_tracing::panic_hook::captures_frames
             at /home/usr/workspace/fuse-query/src/common/tracing/src/panic_hook.rs:67:5
   3: databend_common_tracing::panic_hook::backtrace
             at /home/usr/workspace/fuse-query/src/common/tracing/src/panic_hook.rs:75:5
   4: databend_common_tracing::panic_hook::log_panic
             at /home/usr/workspace/fuse-query/src/common/tracing/src/panic_hook.rs:48:25
   5: databend_common_tracing::panic_hook::set_panic_hook::{{closure}}
             at /home/usr/workspace/fuse-query/src/common/tracing/src/panic_hook.rs:33:9
   6: <alloc::boxed::Box<F,A> as core::ops::function::Fn<Args>>::call
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/alloc/src/boxed.rs:2078:9
      std::panicking::rust_panic_with_hook
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/panicking.rs:804:13
   7: std::panicking::begin_panic_handler::{{closure}}
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/panicking.rs:670:13
   8: std::sys::backtrace::__rust_end_short_backtrace
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/sys/backtrace.rs:171:18
   9: rust_begin_unwind
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/panicking.rs:661:5
  10: core::panicking::panic_fmt
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/panicking.rs:74:14
  11: core::str::slice_error_fail_rt
  12: core::str::slice_error_fail
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/str/mod.rs:89:5
  13: core::str::traits::<impl core::slice::index::SliceIndex<str> for core::ops::range::Range<usize>>::index
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/str/traits.rs:244:21
  14: core::str::traits::<impl core::ops::index::Index<I> for str>::index
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/str/traits.rs:62:9
  15: <unicode_segmentation::grapheme::Graphemes as core::iter::traits::iterator::Iterator>::next
             at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/unicode-segmentation-1.11.0/src/grapheme.rs:122:26
  16: core::iter::traits::iterator::Iterator::fold
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/iter/traits/iterator.rs:2587:29
  17: core::iter::traits::iterator::Iterator::count
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/iter/traits/iterator.rs:233:9
  18: databend_common_base::base::string::short_sql
             at /home/usr/workspace/fuse-query/src/common/base/src/base/string.rs:211:8
  19: databend_query::interpreters::interpreter::interpreter_plan_sql::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/interpreters/interpreter.rs:219:21
  20: databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorkerBase::do_query::{{closure}}::{{closure}}::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:378:92
  21: <async_backtrace::framed::Framed<F> as core::future::future::Future>::poll::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/framed.rs:49:27
  22: async_backtrace::frame::Frame::in_scope::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:184:17
  23: std::thread::local::LocalKey<T>::try_with
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/thread/local.rs:283:12
  24: std::thread::local::LocalKey<T>::with
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/thread/local.rs:260:9
  25: async_backtrace::frame::active_frame::with
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:81:9
  26: async_backtrace::frame::Frame::in_scope
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:180:13
  27: <async_backtrace::framed::Framed<F> as core::future::future::Future>::poll
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/framed.rs:49:9
  28: databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorkerBase::do_query::{{closure}}::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:347:5
  29: <fastrace::future::InSpan<T> as core::future::future::Future>::poll
             at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/fastrace-0.7.4/src/future.rs:124:19
  30: databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorkerBase::do_query::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:347:5
  31: <databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorker as opensrv_mysql::AsyncMysqlShim<W>>::on_query::{{closure}}::{{closure}}::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:224:18
  32: <databend_common_base::runtime::runtime_tracker::TrackingFuture<T> as core::future::future::Future>::poll
             at /home/usr/workspace/fuse-query/src/common/base/src/runtime/runtime_tracker.rs:143:9
  33: <fastrace::future::InSpan<T> as core::future::future::Future>::poll
             at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/fastrace-0.7.4/src/future.rs:124:19
  34: <databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorker as opensrv_mysql::AsyncMysqlShim<W>>::on_query::{{closure}}::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:241:10
  35: <async_backtrace::framed::Framed<F> as core::future::future::Future>::poll::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/framed.rs:49:27
  36: async_backtrace::frame::Frame::in_scope::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:184:17
  37: std::thread::local::LocalKey<T>::try_with
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/thread/local.rs:283:12
  38: std::thread::local::LocalKey<T>::with
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/std/src/thread/local.rs:260:9
  39: async_backtrace::frame::active_frame::with
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:81:9
  40: async_backtrace::frame::Frame::in_scope
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:180:13
  41: <async_backtrace::framed::Framed<F> as core::future::future::Future>::poll
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/framed.rs:49:9
  42: <databend_query::servers::mysql::mysql_interactive_worker::InteractiveWorker as opensrv_mysql::AsyncMysqlShim<W>>::on_query::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_interactive_worker.rs:187:5
  43: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/cf2df68d1f5e56803c97d91e2b1a9f1c9923c533/library/core/src/future/future.rs:123:9
  44: opensrv_mysql::AsyncMysqlIntermediary<B,R,W>::run::{{closure}}
             at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/opensrv-mysql-0.7.0/src/lib.rs:626:38
  45: opensrv_mysql::tls::plain_run_with_options::{{closure}}
             at /home/usr/.cargo/registry/src/index.crates.io-6f17d22bba15001f/opensrv-mysql-0.7.0/src/tls.rs:57:14
  46: databend_query::servers::mysql::mysql_session::MySQLConnection::run_on_stream::{{closure}}::{{closure}}
             at /home/usr/workspace/fuse-query/src/query/service/src/servers/mysql/mysql_session.rs:92:91
  47: <databend_common_base::runtime::runtime_tracker::TrackingFuture<T> as core::future::future::Future>::poll
             at /home/usr/workspace/fuse-query/src/common/base/src/runtime/runtime_tracker.rs:143:9
  48: <async_backtrace::framed::Framed<F> as core::future::future::Future>::poll::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/framed.rs:49:27
  49: async_backtrace::frame::Frame::in_scope::{{closure}}
             at /home/usr/.cargo/git/checkouts/async-backtrace-9554bf0eaadc9fb8/dea4553/backtrace/src/frame.rs:184:17