Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

bug: mariadb JDBC driver fails to connect #16892

Open
dantengsky opened this issue Nov 20, 2024 · 1 comment
Open

bug: mariadb JDBC driver fails to connect #16892

dantengsky opened this issue Nov 20, 2024 · 1 comment
Labels
C-bug Category: something isn't working

Comments

@dantengsky
Copy link
Member

dantengsky commented Nov 20, 2024

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


@dantengsky dantengsky added the C-bug Category: something isn't working label Nov 20, 2024
@dantengsky dantengsky mentioned this issue Nov 20, 2024
11 tasks
@dantengsky
Copy link
Member Author

dantengsky commented Nov 25, 2024

The issue on branch release/v1.2.636-rc4.2 has been resolved with PR #16893.

note that PR #16893 only fixes the issue on the release/v1.2.636-rc4.2 branch.

Before merging #16893 into the main branch, we should bump the version of opensrv to include PR #67 and use the bumped version, instead of relying on a specific commit (as PR #16893 does).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
C-bug Category: something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant