由一个go中出现的异常引出对php与go中操作sql的一些分析


最近写一个东西在用一个数据库中间件对go(xorm)中操作sql时出现一个异常:

[mysql] 2021/01/01 15:13:49 packets.go:467: busy buffer
panic: commands out of sync. Did you run multiple statements at once?

最开始各种搜索,也分析源码以为是buffer太小的原因,增大buffer后依然无法解决,后来分析相关日志发现,github.com/go-sql-driver/mysql 这个包对于查询

Mysqldb.Where("openid=?","具体值").Get(finduser)

的处理使用了预处理 SQL方式,通过查询执行sql日志发现上一个查询的后台执行时:

2021-01-01T07:10:17.192950Z        40 Connect   remote@127.0.0.1 on mydb using TCP/IP
2021-01-01T07:10:17.196651Z        40 Query     SET NAMES utf8
2021-01-01T07:10:17.198839Z        40 Prepare   SELECT `openid`,  `unionid`, `deleted_at`, `created_at`, `updated_at`, `id` FROM `tslog` WHERE (openid=?) LIMIT 1
2021-01-01T07:10:17.200948Z        40 Execute   SELECT `openid`,  `unionid`, `deleted_at`, `created_at`, `updated_at`, `id` FROM `tslog` WHERE (openid='具体值') LIMIT 1
2021-01-01T07:10:17.204922Z        40 Close stmt

所以此时异常卡在了中间件对语句对预处理sql执行后返回的处理。
原因找到本该到此为止,但想到php框架中对于执行一个sql的具体流程时什么样的,索性就查下,下面分别对laravel8的DB,Eloquent和简单的medoo的执行处理过程:

  • laravel8的DB:
    DB::select(“select * from tslog where openid=’具体值’”);

    2021-01-01T07:08:41.414498Z        39 Connect   remote@127.0.0.1 on mydb using TCP/IP
    2021-01-01T07:08:41.418254Z        39 Query     use `mydb`
    2021-01-01T07:08:41.424227Z        39 Prepare   set names 'utf8mb4' collate 'utf8mb4_unicode_ci'
    2021-01-01T07:08:41.427114Z        39 Execute   set names 'utf8mb4' collate 'utf8mb4_unicode_ci'
    2021-01-01T07:08:41.430617Z        39 Close stmt
    2021-01-01T07:08:41.430749Z        39 Prepare   set session sql_mode='ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION'
    2021-01-01T07:08:41.435796Z        39 Execute   set session sql_mode='ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION'
    2021-01-01T07:08:41.441323Z        39 Close stmt
    2021-01-01T07:08:41.441734Z        39 Prepare   select * from tslog where openid='具体值'
    2021-01-01T07:08:41.445707Z        39 Execute   select * from tslog where openid='具体值'
    2021-01-01T07:08:41.449343Z        39 Close stmt
    2021-01-01T07:08:41.455379Z        39 Quit
  • laravel8的Eloquent:
    Tslog::where(“openid”,”具体值”)->find(1);

    2021-01-01T07:07:09.201554Z        38 Connect   remote@127.0.0.1 on mydb using TCP/IP
    2021-01-01T07:07:09.216170Z        38 Query     use `mydb`
    2021-01-01T07:07:09.219893Z        38 Prepare   set names 'utf8mb4' collate 'utf8mb4_unicode_ci'
    2021-01-01T07:07:09.224192Z        38 Execute   set names 'utf8mb4' collate 'utf8mb4_unicode_ci'
    2021-01-01T07:07:09.227458Z        38 Close stmt
    2021-01-01T07:07:09.227612Z        38 Prepare   set session sql_mode='ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION'
    2021-01-01T07:07:09.230597Z        38 Execute   set session sql_mode='ONLY_FULL_GROUP_BY,STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION'
    2021-01-01T07:07:09.235626Z        38 Close stmt
    2021-01-01T07:07:09.236180Z        38 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T07:07:09.238363Z        38 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T07:07:09.238401Z        38 Execute   select * from `tslog` where `openid` = '具体值' and `tslog`.`id` = 1 limit 1
    2021-01-01T07:07:09.241515Z        38 Close stmt
    2021-01-01T07:07:09.246249Z        38 Quit
  • Medoo中:
    $db->get(‘tslog’,[‘unionid’,’id’],[“openid”=>”具体值”]);

    2021-01-01T07:11:59.492672Z        41 Connect   remote@127.0.0.1 on mydb using TCP/IP
    2021-01-01T07:11:59.495868Z        41 Query     SET SQL_MODE=ANSI_QUOTES
    2021-01-01T07:11:59.497787Z        41 Query     SET NAMES 'utf8'
    2021-01-01T07:11:59.504909Z        41 Query     SELECT "unionid","id" FROM "tslog" WHERE "openid" = '具体值' LIMIT 1
    2021-01-01T07:11:59.517974Z        41 Quit

    由此可见在laravel中对于一条简单sql的处理都会执行执行一系列的sql设置最后查询,并且设置和查询都以预处理方式进行。虽说预处理在一定程度上是优化同一sql频繁查询,但我执行并列执行同一sql,在输出的sql日志:
    /执行:
    Wxlogin::where(“openid”,”具体值”)->find(1);
    Wxlogin::where(“openid”,”具体值”)->find(1);
    两次
    日志省略前后sql
    /

    2021-01-01T08:09:39.671826Z        48 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T08:09:39.674598Z        48 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T08:09:39.674635Z        48 Execute   select * from `tslog` where `openid` = '具体值' and `tslog`.`id` = 1 limit 1
    2021-01-01T08:09:39.678185Z        48 Close stmt
    2021-01-01T08:09:39.680208Z        48 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T08:09:39.682838Z        48 Prepare   select * from `tslog` where `openid` = ? and `tslog`.`id` = ? limit 1
    2021-01-01T08:09:39.682871Z        48 Execute   select * from `tslog` where `openid` = '具体值' and `tslog`.`id` = 1 limit 1
    2021-01-01T08:09:39.686475Z        48 Close stmt

    可见每条都执行一次预处理,并未使用其优化方式。又一方面预处理在一定程度上预防sql注入,但在开始配置处的预处理应该可以忽略。
    而Medoo这个简单的数据库框架对于相关配置不是太复杂,但对于查询语句执行时未进行预处理,虽然框架中说明有一些安全的方法处理,但若是自己定义相关优化或者防注入也可以在这里注意。
    另对于中间件需要针对使用语言和框架进行相关调整,不然通常正常的sql执行可能出现莫名的异常。