由一個go中出現的異常引出對php與go中操作sql的一些分析

Limpid發表於2021-01-01

最近寫一個東西在用一個資料庫中介軟體對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執行可能出現莫名的異常。
本作品採用《CC 協議》,轉載必須註明作者和本文連結

相關文章