Metabase connection tidb error unexpected end of stream, read 0 bytes from 7 (socket was closed by server)

[An0nymous0]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

1. Metabase v0.48.1 Latest
2. TIDB version 7.5
3. Connect to TiDB and establish an SQL query.
4. Control panel returns(unexpected end of stream, read 0 bytes from 7 (socket was closed by server))

Similar problems：https://asktug.com/t/topic/1019620

2. What did you expect to see? (Required)

3. What did you see instead (Required)

4. What is your TiDB version? (Required)

Release Version: v7.5.0
Edition: Community
Git Commit Hash: 069631e
Git Branch: heads/refs/tags/v7.5.0
UTC Build Time: 2023-11-24 08:50:14
GoVersion: go1.21.3
Race Enabled: false
Check Table Before Drop: false
Store: tikv

[YangKeao]

As a note, I failed to bootstrap metabase on TiDB 🤦 , because the limitation of multiple schema change:

2023-12-28 03:22:05,417 ERROR liquibase.changelog :: ChangeSet migrations/001_update_migrations.yaml::v46.00-011::snoe encountered an exception.
2023-12-28 03:22:05,454 ERROR metabase.core :: Metabase Initialization FAILED
liquibase.exception.CommandExecutionException: liquibase.exception.LiquibaseException: liquibase.exception.MigrationFailedException: Migration f
ailed for changeset migrations/001_update_migrations.yaml::v46.00-011::snoe:
     Reason: liquibase.exception.DatabaseException: (conn=1166016524) Multiple primary key defined [Failed SQL: (1068) ALTER TABLE query_action 
DROP PRIMARY KEY, ADD PRIMARY KEY pk_query_action (action_id)]

[An0nymous0]

:v46.00-011

Manually delete the primary key, then add pk_query_action, and execute the following statement to simulate automatic synchronization logs. Restart Metabase after that.

INSERT INTO metabase.DATABASECHANGELOG (ID, AUTHOR, FILENAME, DATEEXECUTED, ORDEREXECUTED, EXECTYPE, MD5SUM, DESCRIPTION, COMMENTS, TAG, LIQUIBASE, CONTEXTS, LABELS, DEPLOYMENT_ID) VALUES ('v46.00-010', 'snoe', 'migrations/001_update_migrations.yaml', '2023-12-25 12:31:56', 515, 'EXECUTED', '8:77ca03e5a0dbe370461295da1c77cf0f', 'addForeignKeyConstraint baseTableName=query_action, constraintName=fk_query_action_database_id, referencedTableName=metabase_database', 'Added 0.46.0 - Unify action representation', null, '4.11.0', null, null, '3478709824');

[YangKeao]

:v46.00-011

Manually delete the primary key, then add pk_query_action, and execute the following statement to simulate automatic synchronization logs. Restart Metabase after that.

INSERT INTO metabase.DATABASECHANGELOG (ID, AUTHOR, FILENAME, DATEEXECUTED, ORDEREXECUTED, EXECTYPE, MD5SUM, DESCRIPTION, COMMENTS, TAG, LIQUIBASE, CONTEXTS, LABELS, DEPLOYMENT_ID) VALUES ('v46.00-010', 'snoe', 'migrations/001_update_migrations.yaml', '2023-12-25 12:31:56', 515, 'EXECUTED', '8:77ca03e5a0dbe370461295da1c77cf0f', 'addForeignKeyConstraint baseTableName=query_action, constraintName=fk_query_action_database_id, referencedTableName=metabase_database', 'Added 0.46.0 - Unify action representation', null, '4.11.0', null, null, '3478709824');

Thanks for the tip. I successfully reproduced this problem ❤️ .

I believe this issue is caused by TiDB connection compression. A workaround is adding useCompression=false in metabase configuration:

I'll need more time to understand the detail of this compression protocol bug and fix it.

[YangKeao]

Maybe this issue is related with #49706

[2024/01/03 15:39:24.897 +08:00] [ERROR] [terror.go:324] ["encountered error"] [error="write tcp 127.0.0.1:4000->127.0.0.1:43292: write: broken pipe"] [stack="github.com/pingcap/tidb/pkg/parser/terror.Log\n\t/home/yangkeao/Project/github.com/YangKeao/tidb/master/pkg/parser/terror/terror.go:324\ngithub.com/pingcap/tidb/pkg/server.(*clientConn).Run\n\t/home/yangkeao/Project/github.com/YangKeao/tidb/master/pkg/server/conn.go:1143\ngithub.com/pingcap/tidb/pkg/server.(*Server).onConn\n\t/home/yangkeao/Project/github.com/YangKeao/tidb/master/pkg/server/server.go:701"]

[onlyacat]

looks like it is caused by an extra sequence check inside TiDB
still need further infomation

[onlyacat]

OK, finally I guess it is a problem from MariaDB jdbc ... 🤣

with environment:

1. Mariadb jdbc 2.X
2. TiDB 7.5 or later
   ,
   the error can be reproduced by the following code

import java.sql.*;

public class Main {
    public static void main(String[] args) {
        String url = "jdbc:mysql://127.0.0.1:4000/mysql?useCompression=True";
        String user = "root";
        String password = "";

        try {
            Connection c = DriverManager.getConnection(url, user, password);

            Statement s = c.createStatement();

            String sql = "/* 111111111111111111cb52dc741e5327ddbfc8411cc53663eec3a5ffdb1f30626d39cc606822 */ select version();";
            s.execute(sql);
            s.close();
            c.close();

        } catch (SQLException e) {
            e.printStackTrace();
        }

    }
}

The exact packet mariadb java connecter sends to the server looks like this:

Here If we pay attention to the header:
compress header:
91 00 00 -> compress payload length
00 -> Compress sequence number
00 00 00 -> uncompress payload length, means not compress here

sub-header:
8d 00 00 -> payload length
01 -> sequence number, actually it should be 00 here

1. TiDB behaviour

Thus inside tidb during the readOnePacket procedure, it checks the sequence of sub header and finds the difference.

https://github.com/pingcap/tidb/blob/44f33c682d238f4285205cbcfdd1dc0e5c89c4de/pkg/server/internal/packetio.go#L160C1-L166C1

2. MariaDB Java connector behaviour

As for the sequence number of 01 coming from, during the process of generating the packet header of the compress packet, MariaDB jdbc may increase the sequence of the sub header twice.

https://github.com/mariadb-corporation/mariadb-connector-j/blob/12369dfc001e48b90ea92dac8a30612bac685996/src/main/java/org/mariadb/jdbc/internal/io/output/CompressPacketOutputStream.java#L163

and

https://github.com/mariadb-corporation/mariadb-connector-j/blob/12369dfc001e48b90ea92dac8a30612bac685996/src/main/java/org/mariadb/jdbc/internal/io/output/CompressPacketOutputStream.java#L278

I guess it is not an expected behaviour, since in 3.x they rewrote the whole process and this problem disappeared.

3. MySQL 8.2 behaviour

As for MySQL, as far as I know, they don't take the sequence number inside the compress packet seriously. For MySQL 8.2, it only checks the correctness of the compress sequence number. That's the reason the mariadb jdbc 2.X can work with MySQL as normal.

https://github.com/mysql/mysql-server/blob/87307d4ddd88405117e3f1e51323836d57ab1f57/sql-common/net_serv.cc#L1477C1-L1482C51

---

Thus, I guess it is not a bad idea to keep the same behaviour as MySQL and be compatible with some special clients.
If it makes sense, a PR would come later to move the sequence check into the none compression block.

[dveeden]

@onlyacat Note that with "Decode as..." you can have Wireshark decode MySQL traffic even if it is not on port 3306. Recent versions of Wireshark can also decode compressed MySQL packets.

[dveeden]

@onlyacat Could you attach a pcap/pcapng file (make sure it doesn't contain sensitive info)?

[onlyacat]

@onlyacat Note that with "Decode as..." you can have Wireshark decode MySQL traffic even if it is not on port 3306. Recent versions of Wireshark can also decode compressed MySQL packets.

got it, thanks! 👍

[onlyacat]

@onlyacat Could you attach a pcap/pcapng file (make sure it doesn't contain sensitive info)?

No problem. I ran the code with mariadb jcon version 2.7.11 and 3.3.2 separately, naming 2X and 3X.

pcap.zip

Looks like github doesn't allow to upload pcap files. I packed them into the zip file.

[onlyacat]

Digged a little bit and guess it could be solved by the side of Mariadb j.
Raised an issue here: https://jira.mariadb.org/browse/CONJ-1145