今天线上使用Mycat的业务突然反馈通过golang MySQL客户端执行SQL报异常:

Error 3344: StringIndexOutOfBoundsException: String index out of range: 237

查看Mycat日志也只有异常堆栈信息, 没有打出错误SQL和参数. 业务方很快定位到问题: 通过prepare binary协议执行一条INSERT语句时, 某个VARCHAR字段传入的数据长度超过600K而报出的错误. 通过源码调试找到了问题原因, 是mycat的一个bug, 该bug在1.6分支依然存在. 本文会详细分析该问题.

背景

业务方使用的是golang的github.com/go-sql-driver/mysql这个官方mysql客户端访问的Mycat代理服务器, 涉及到的数据表结构如下 (结构类似, 字段脱敏):

CREATE TABLE `tbl_test` (
 `id` bigint(20),
 `name` varchar(32),
 `password` varchar(32),
 `group` varchar(32),
 `data` longtext,
 `create_time` int(11),
 PRIMARY KEY (`id`)
) ENGINE=InnoDB

采用prepare binary协议执行INSERT SQL语句:

package main
import (
 "database/sql"
 "fmt"
 _ "github.com/go-sql-driver/mysql"
)
var data="abcdefg"
func main() {
 db, err := sql.Open("mysql", "test:test@tcp(127.0.0.1:8066)/test?charset=utf8")
 if err != nil {
 fmt.Printf("open error: %v\n", err)
 return
 }
 defer db.Close()
 sql := "INSERT INTO tbl_test (id,name,password,group,data,create_time) VALUES (?,?,?,?,?,?)"
 stmt, err := db.Prepare(sql)
 if err != nil {
 fmt.Printf("prepare error: %v\n", err)
 return
 }
 defer stmt.Close()
 args := []interface{}{1,"doggy","catty","animal",data,0}
 result, err := stmt.Exec(args...)
 if err != nil {
 fmt.Printf("execute error: %v\n", err)
 return
 }
 rowAffected, err := result.RowsAffected()
 if err != nil {
 fmt.Printf("get rowAffected error: %v\n", err)
 return
 }
 fmt.Printf("rowAffected: %d\n", rowAffected)
}

mycat启动端口为8066, 直连后端mysql, tbl_test没有配置分表. 当data变量长度超过600K时, 执行这段代码就会报Error 3344: StringIndexOutOfBoundsException.

MySQL prepare binary协议

由于采用了prepare binary协议执行SQL, 我们先来分析一下prepare binary执行流程. 具体内容可参考MySQL Internal Manual

prepare binary协议包含5种命令:

• COM_STMT_PREPARE
• COM_STMT_EXECUTE
• COM_STMT_CLOSE
• COM_STMT_RESET
• COM_STMT_SEND_LONG_DATA

MySQL处理一个prepare binary请求的流程如下:

• 客户端向MySQL发送COM_STMT_PREPARE命令发送SQL语句, 从而在MySQL中创建一个PrepareStmt, 客户端从响应中获取StmtId.
• 客户端向MySQL发送COM_STMT_EXECUTE命令传入参数, 并将上一步获得的StmtId一并传入, 执行PrepareStmt, 从响应中获取执行结果.
• 客户端向MySQL发送COM_STMT_RESET命令清除PrepareStmt中绑定的参数.
• 客户端向MySQL发送COM_STMT_CLOSE命令关闭PrepareStmt.

注意以上每一步都会收到MySQL的响应. 另外一个COM_STMT_SEND_LONG_DATA命令, 是用来发送某一列的参数值的. 该命令没有返回值.

问题剖析

以上是针对MySQL而言的. Mycat作为MySQL的代理中间件, 处理prepare binary的方式与上述类似, 但是因为处理COM_STMT_SEND_LONG_DATA和COM_STMT_EXECUTE命令的方式不对, 导致了这个bug. 直接上代码:

public class ExecutePacket extends MySQLPacket {
 public void read(byte[] data, String charset) throws UnsupportedEncodingException {
 ...
 // 设置参数类型和读取参数值
 byte[] nullBitMap = this.nullBitMap;
 for (int i = 0; i < parameterCount; i++) {
 BindValue bv = new BindValue();
 bv.type = pstmt.getParametersType()[i];
 if ((nullBitMap[i / 8] & (1 << (i & 7))) != 0) {
 bv.isNull = true;
 } else {
 BindValueUtil.read(mm, bv, charset);
 if(bv.isLongData) {
 bv.value = pstmt.getLongData(i);
 }
 }
 values[i] = bv;
 }
 ...
 }
}

public class BindValueUtil {
 public static final void read(MySQLMessage mm, BindValue bv, String charset) throws UnsupportedEncodingException {
 switch (bv.type & 0xff) {
 ...
 case Fields.FIELD_TYPE_VAR_STRING:
 case Fields.FIELD_TYPE_STRING:
 case Fields.FIELD_TYPE_VARCHAR:
 bv.value = mm.readStringWithLength(charset);
// if (bv.value == null) {
// bv.isNull = true;
// }
 break;
 ...
 case Fields.FIELD_TYPE_BLOB:
 bv.isLongData = true;
 break;
 }
 }
}

可以看到, 在处理VARCHAR类型时, 直接读取packet中的数据, 而当是FIELD_TYPE_BLOB类型时, 会做一个标记, 不读取packet中的数据. 这种实现方式的背后逻辑是: 对FIELD_TYPE_BLOB类型, 客户端会使用COM_STMT_SEND_LONG_DATA命令发送数据, 而在COM_STMT_EXECUTE会忽略对应列, 不再发送该列数据.

然而, Mycat的实现方式忽略了一种情况: 对于VARCHAR, TEXT等类型, 客户端同样可以用COM_STMT_SEND_LONG_DATA命令发送数据. 考虑这种情况: 客户端对VARCHAR类型的列的数据, 使用COM_STMT_SEND_LONG_DATA命令发送, 而其他类型仍使用COM_STMT_EXECUTE发送, 按照Mycat的这种实现方式, 会按照SQL中参数绑定的顺序, 处理那些本应忽略的列, 而一旦用错误的类型处理数据, 相当于协议解析错误, 就肯定会导致StringIndexOutOfBoundsException等问题了.

那么, 为什么VARCHAR字段长度超过600K会触发这个bug呢? 原来是golang mysql客户端在执行prepare binary SQL时, 如果一个字符串数据的长度超过了longDataSize的值, 就会把该数据通过COM_STMT_SEND_LONG_DATA发送. 相关代码在这个文件中, 简要给出相关内容:

// Execute Prepared Statement
// http://dev.mysql.com/doc/internals/en/com-stmt-execute.html
func (stmt *mysqlStmt) writeExecutePacket(args []driver.Value) error {
 ...
 // Determine threshold dynamically to avoid packet size shortage.
 longDataSize := mc.maxAllowedPacket / (stmt.paramCount + 1)
 if longDataSize < 64 {
 longDataSize = 64
 }
 ...
 if len(args) > 0 {
 ...
 for i, arg := range args {
 ...
 switch v := arg.(type) {
 case []byte: // 与string类似
 ...
 case string:
 paramTypes[i+i] = byte(fieldTypeString)
 paramTypes[i+i+1] = 0x00
 if len(v) < longDataSize {
 paramValues = appendLengthEncodedInteger(paramValues,
 uint64(len(v)),
 )
 paramValues = append(paramValues, v...)
 } else {
 if err := stmt.writeCommandLongData(i, []byte(v)); err != nil {
 return err
 }
 }
 ...
 }
 ...
 }
 ...
 }
 ...
}

可以看到, longDataSize := mc.maxAllowedPacket / (stmt.paramCount + 1)

其中paramCount为prepare语句中绑定的参数个数. maxAllowedPacket与MySQL系统参数max_allowed_packet有关. 这个文档给出了客户端maxAllowedPacket的设置方式. 如果不设置, 默认值是4194304, 如果设置为0, 则通过SELECT @@max_allowed_packet从MySQL获取, 如果设置值超过1<<24-1, 则设置为1<<24-1.

到此, 问题原因终于明晰了: golang mysql客户端使用了maxAllowedPacket的默认值4194304, 并且在执行prepare binary语句时, 遇到了长度超过longDataSize的数据, 执行COM_STMT_SEND_LONG_DATA发送给Mycat后, 再执行COM_STMT_EXECUTE时未发送该字段数据, 而Mycat仍在COM_STMT_EXECUTE时处理该数据, 导致协议解析错误. 至于600K触发这个bug, 执行的SQL中有6个绑定参数, 则longDataSize = 4194304 / (6 + 1) = 599186, 约等于600K.

解决方案

我们已经跟业务同学协商, 由他们优化该字段, 减小字段长度. 至于Mycat如何修复这个bug, 也非常简单: 在执行COM_STMT_SEND_LONG_DATA后, 把对应字段做一个标记, 在后续执行COM_STMT_EXECUTE遍历绑定参数时, 跳过该字段即可.

有疑问加站长微信联系(非本文作者)

• 请尽量让自己的回复能够对别人有帮助
• 支持 Markdown 格式, **粗体**、~~删除线~~、`单行代码`
• 支持 @ 本站用户;支持表情(输入 : 提示),见 Emoji cheat sheet
• 图片支持拖拽、截图粘贴等方式上传