TL;DR

pt-query-digest 3.0.11で、クエリーダイジェストのチェックサムが変わった
- MD5の下16桁（64ビット、BIGINT UNSIGNED）から、MD5を全部（32桁、128ビット、CHAR(32)）使い切るように
この変更に本家Anemometer が追従していないので、Anemometerと anemoeater はチェックサムによる集計結果がおかしくなる
今のところのワークアラウンドはpt-query-digestのバージョンを3.0.10とそれ以前に下げる

最近なんか変だな、とは思ってたんですよ。
この一番左端の checksum の値が、今まではそこそこ16進っぽい文字列だったのに桁数がなんかすごく変で。

しかもこれ、 checksum をクリックしてドリルダウンした先でも

フィンガープリントとサンプルが全然違ったり

サンプルを一覧で出しても全然まともにノーマライズされてない。なんじゃこりゃ。

MySQL（Anemometerは pt-query-digest の結果をMySQLの中に突っ込んでそれをグラフにするので）の中では既に値が変になっている。

mysql> SELECT checksum FROM global_query_review;
+----------------------+
| checksum             |
+----------------------+
|                    0 |
|                    5 |
|                    8 |
|                  813 |
| 18446744073709551615 |
+----------------------+
5 rows in set (0.03 sec)

じゃあpt-query-digestがおかしいのかと思って吊るしのpt-query-digestにかけるとちゃんとダイジェストごとに分類されている様子。ってかやっぱり桁数が全然違う。

$ pt-query-digest /usr/mysql/5.7.25/data/slow.log
..
# Profile
# Rank Query ID                       Response time   Calls R/Call   V/M
# ==== ============================== =============== ===== ======== =====
#    1 0x813FE962AFBBC891774B2B0B5... 3057.9484 57.5%     5 611.5897 20... SELECT t?
#    2 0xADD660F67EF8C8E84629F9AE3... 1977.1068 37.2%    18 109.8393 70... INSERT SELECT t?
#    3 0x9062D01639C2FF3E1E6D9934B...  203.5507  3.8%    12  16.9626  9.20 SELECT information_schema.tables information_schema.columns
# MISC 0xMISC                           82.8319  1.6%    11   7.5302   0.0 <6 ITEMS>

anemoeaterはAnemometerをDockerコンテナの中で動かすのを基本思想にしているので、Anemometerを動かしている Dockerイメージがおかしいのかなとか疑ってビルドしなおしてみたり、チェックサムが数字のみで構成されいてる時に “unknown checksum” になるバグを修正したパッチが悪さしているのかなとか切り分けてみたんですがどうも違う。

取り敢えず（？）コンテナの中に入り込んで、ジェネラルログを取ってみた。

                   48 Query     INSERT INTO `slow_query_log`.`global_query_review`
      (checksum, fingerprint, sample, first_seen, last_seen)
      VALUES('ADD660F67EF8C8E84629F9AE383EA2F1', 'insert into t? select ? from t?', 'INSERT INTO t1 SELECT 0 FROM t1', COALESCE('2019-01-29 10:32:15', NOW()), COALESCE('2019-01-29 10:33:13', NOW()))
      ON DUPLICATE KEY UPDATE
         first_seen = IF(
            first_seen IS NULL,
            COALESCE('2019-01-29 10:32:15', NOW()),
            LEAST(first_seen, COALESCE('2019-01-29 10:32:15', NOW()))),
         last_seen = IF(
            last_seen IS NULL,
            COALESCE('2019-01-29 10:33:13', NOW()),
            GREATEST(last_seen, COALESCE('2019-01-29 10:33:13', NOW())))

INSERTステートメントの時点ではちゃんとchecksumはそれっぽい値になっている…。
なんかふと嫌な予感がしたので、一度AnemometerのテーブルをTRUNCATEして手でINSERTステートメントを叩いてみる。

mysql> INSERT INTO `slow_query_log`.`global_query_review`
    ->       (checksum, fingerprint, sample, first_seen, last_seen)
    ->       VALUES('ADD660F67EF8C8E84629F9AE383EA2F1', 'insert into t? select ? from t?', 'INSERT INTO t1 SELECT 0 FROM t1', COALESCE('2019-01-29 10:32:15', NOW()), COALESCE('2019-01-29 10:33:13', NOW()))
    ->       ON DUPLICATE KEY UPDATE
    ->          first_seen = IF(
    ->             first_seen IS NULL,
    ->             COALESCE('2019-01-29 10:32:15', NOW()),
    ->             LEAST(first_seen, COALESCE('2019-01-29 10:32:15', NOW()))),
    ->          last_seen = IF(
    ->             last_seen IS NULL,
    ->             COALESCE('2019-01-29 10:33:13', NOW()),
    ->             GREATEST(last_seen, COALESCE('2019-01-29 10:33:13', NOW())));
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> SHOW WARNINGS;
+---------+------+--------------------------------------------------------------------------------------------+
| Level   | Code | Message                                                                                    |
+---------+------+--------------------------------------------------------------------------------------------+
| Warning | 1366 | Incorrect integer value: 'ADD660F67EF8C8E84629F9AE383EA2F1' for column 'checksum' at row 1 |
+---------+------+--------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

＿人人人人人＿
＞　大正解　＜
￣Y^Y^Y^Y^￣

mysql> SHOW CREATE TABLE global_query_review\G
*************************** 1. row ***************************
       Table: global_query_review
Create Table: CREATE TABLE `global_query_review` (
  `checksum` bigint(20) unsigned NOT NULL,
  `fingerprint` text NOT NULL,
  `sample` longtext NOT NULL,
  `first_seen` datetime DEFAULT NULL,
  `last_seen` datetime DEFAULT NULL,
  `reviewed_by` varchar(20) DEFAULT NULL,
  `reviewed_on` datetime DEFAULT NULL,
  `comments` text,
  `reviewed_status` varchar(24) DEFAULT NULL,
  PRIMARY KEY (`checksum`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

＿人人人人人人人人人人人＿
＞　bigint(20) unsigned　＜
￣Y^Y^Y^Y^Y^Y^Y^Y^￣

そうだそうだ、16進のチェックサムを数値にキャストして突っ込んでるから、チェックサムの値が全部数字だけで構成される時にキャストせずにおかしくなるバグが本家にあるんだった。

しかしちょっと前まではこれでちゃんと動いてたので、となるとpt-query-digestの方がぁゃιぃ…？

と思ったら、見つけた。

Starting from Percona Toolkit 3.0.11, the checksum function has been updated to use 32 chars in the MD5 sum. This causes the checksum field in the history table will have a different value than in the previous versions of the tool.

pt-query-digest

$ git diff diff 3.0.10 3.0.11 -- bin/pt-query-digest
diff --git a/bin/pt-query-digest b/bin/pt-query-digest
index 21310c7..35626bf 100755
--- a/bin/pt-query-digest
+++ b/bin/pt-query-digest
...
@@ -2679,7 +2679,7 @@ sub any_unix_timestamp {

sub make_checksum {
   my ( $val ) = @_;
   my $checksum = uc substr(md5_hex($val), -16);md5_hex($val);
   PTDEBUG && _d($checksum, 'checksum for', $val);
   return $checksum;
}
...
@@ -16180,7 +16188,7 @@ by pt-query-digest.
MAGIC_create_review_table:

  CREATE TABLE IF NOT EXISTS query_review (
     checksum     BIGINT UNSIGNEDCHAR(32) NOT NULL PRIMARY KEY,
     fingerprint  TEXT NOT NULL,
     sample       TEXT NOT NULL,
     first_seen   DATETIME,
...

なるほどpt-query-digestの更新に本家Anemometerが対応しきれてないのか…。

2年半くらい更新も止まってるし、Issue上げても対応してもらえるかなぁ…？

Commits · box/Anemometer

【2019/02/13 17:19】

一応Issue上げました。

pt-query-digest 3.0.11 changed `checksum` from BIGINT UNSIGNED to CHAR(32) · Issue #200 · box/Anemometer

日々の覚書

GA

2019/02/13

Anemometer（結果として anemoeater も）がpt-query-digest 3.0.11とそれ以降で変な集計結果になる話

TL;DR

0 件のコメント :

コメントを投稿