2019年8月3日土曜日

プロシージャの中身はPerconaだとスロークエリログに落ちる

プロシージャの中身のクエリはスロークエリログに落ちない の続き。

Vanilla MySQLだとプロシージャの中身がログに落ちませんが、Percona Server ではスロークエリログが拡張されていて、ログに落ちます。

log_slow_sp_statements で出力の有無を設定します。デフォルトではプロシージャの中身をスロークエリログに出力する設定になってます。

mysql> SHOW GLOBAL VARIABLES LIKE 'log_slow_sp_statements';
+------------------------+-------+
| Variable_name          | Value |
+------------------------+-------+
| log_slow_sp_statements | ON    |
+------------------------+-------+
1 row in set (0.00 sec)



試してみます。



mysql> DELIMITER //
mysql> CREATE PROCEDURE sample()
    -> BEGIN
    ->   SELECT SLEEP(10);
    -> END
    -> //
Query OK, 0 rows affected (0.02 sec)

mysql> DELIMITER ;
mysql>
mysql> SET GLOBAL slow_query_log =on;
Query OK, 0 rows affected (0.01 sec)

mysql> SET GLOBAL long_query_time = 0;
Query OK, 0 rows affected (0.00 sec)


mysql> CALL sample;
+-----------+
| SLEEP(10) |

+-----------+

Vanilla MySQL だとこうだったのが

/usr/sbin/mysqld, Version: 8.0.15 (MySQL Community Server - GPL). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 2019-04-03T06:54:09.547179Z
# User@Host: root[root] @ localhost []  Id:    30
# Query_time: 10.001274  Lock_time: 0.000376 Rows_sent: 1  Rows_examined: 0
SET timestamp=1554274439;
call test.sample();


Percona Server ではこう。
Stored_routine の項目にプロシージャの名前が記載され、プロシージャの中のSQLがログに記載されてます。

/usr/sbin/mysqld, Version: 8.0.15-6 (Percona Server (GPL), Release 6, Revision 63abd08). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 2019-08-03T12:54:22.490311Z
# User@Host: root[root] @ localhost []  Id:     9
# Schema: t  Last_errno: 0  Killed: 0
# Query_time: 10.000860  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0  Rows_affected: 0
# Bytes_sent: 57
# Stored_routine: t.sample
use t;
SET timestamp=1564836852;
SELECT SLEEP(10);



プロシージャの中身のクエリはスロークエリログに落ちない

とあるMySQLのデータベースで、性能劣化した疑いのあるプロシージャがありました。
プロシージャには複数のSELECTやINSERTが含まれています。

どのSQLが遅かったか突き止める方法はあるのでしょうか?
プロシージャに含まれている、各SQLはスロークエリログに落ちるんでしょうか?

試してみます。

テスト用に遅いプロシージャを作ります。

DELIMITER //
CREATE PROCEDURE sample()
BEGIN
  SELECT SLEEP(10);
END
//
DELIMITER ;


ログを出します。

mysql> SET GLOBAL slow_query_log = ON;
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL long_query_time = 0;
Query OK, 0 rows affected (0.00 sec)

スロークエリログにはプロシージャの中身は表示されませんでた。。。

/usr/sbin/mysqld, Version: 8.0.15 (MySQL Community Server - GPL). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 2019-04-03T06:54:09.547179Z
# User@Host: root[root] @ localhost []  Id:    30
# Query_time: 10.001274  Lock_time: 0.000376 Rows_sent: 1  Rows_examined: 0
SET timestamp=1554274439;
call test.sample();


Rows_examinedの値はどうなるんだろうか?

DELIMITER //
CREATE PROCEDURE sample2()
BEGIN
  SELECT * FROM mysql.user;
  SELECT * FROM mysql.user;
END
//
DELIMITER ;

このSELECT文は一回あたり、5行スキャンする

# Time: 2019-04-03T07:02:03.693124Z
# User@Host: root[root] @ localhost []  Id:    32
# Query_time: 0.000284  Lock_time: 0.000127 Rows_sent: 5  Rows_examined: 5
SET timestamp=1554274923;
select * from mysql.user;

ログには二回分(合計10)がちゃんと記録された。Row_examined の値は正しく合計を表していると。

# Time: 2019-04-03T07:04:31.383244Z
# User@Host: root[root] @ localhost []  Id:    36
# Query_time: 0.000693  Lock_time: 0.000000 Rows_sent: 10  Rows_examined: 10
SET timestamp=1554275071;
CALL samitani.sample2();


まとめ:

  • プロシージャの中身のどこが遅いかはスロークエリログからわからない。
    • 中のSQLを1つ1つ実行してみるしかなさそう
  • Rows_examined は合計が記録される。


つづく。。。

2019年7月31日水曜日

サーバサイドプリペアドステートメントはperformance_schemaに記録されない

あるクエリがperformance_schemaに記録されなかった。
原因を調べていて1つ記録されない条件を見つけたのでメモ。

まず、問題ないパターン。

mysql> SELECT NOW();
+---------------------+
| NOW()               |
+---------------------+
| 2019-07-30 10:40:47 |
+---------------------+
1 row in set (0.00 sec)

mysql> SELECT SQL_TEXT FROM events_statements_history;
+-------------------------------------------------------------------+
| SQL_TEXT                                                          |
+-------------------------------------------------------------------+
| NULL                                                              |

<snip>
|
| NULL                                                              |
| CALL sys.ps_truncate_all_tables(FALSE)                            |
| SELECT NOW()                                                      |
| NULL                                                              |
+-------------------------------------------------------------------+
10 rows in set (0.00 sec)



「SELECT NOW()」がしっかり、performance_schemaに記録されてますね。
しかし、サーバサイド プリペアドステートメントを使うと・・・

mysql> PREPARE stmt FROM 'SELECT "PREPARE"';
Query OK, 0 rows affected (0.00 sec)
Statement prepared

mysql> EXECUTE stmt;
+---------+
| PREPARE |
+---------+
| PREPARE |
+---------+
1 row in set (0.00 sec)

mysql> SELECT SQL_TEXT FROM events_statements_history;
+-------------------------------------------------------------------+
| SQL_TEXT                                                          |
+-------------------------------------------------------------------+
| NULL                                                              

<snip>
| NULL                                                              |
| CALL sys.ps_truncate_all_tables(FALSE)                            |
| PREPARE stmt FROM ...                                             |
| EXECUTE stmt                                                      |
+-------------------------------------------------------------------+
10 rows in set (0.00 sec)





(゚д゚)あらやだ! クエリの部分が「...」になってしまったワ。
ファンクションやプロシージャの中のSQLも記録されませんから、それと同じと思えば、違和感ないか?

子ネタでした(つづく?)

2019年7月20日土曜日

MySQL 8.0 はダウングレードできない


8.0.16でCHECK制約がサポートされました。
CHECK制約については、「yoku0825さんのブログ」や「MySQL Server teamのブログ」で詳しく解説されてます。

さて、「8.0.16でCHECK制約を設定したテーブルをCHECK制約に対応していない8.0.15で操作したらどうなるだろ?」という疑問が湧いたので試してみました。

CHECK制約を作るじゃろ?

mysql> CREATE TABLE check_constraint (pk SERIAL PRIMARY KEY, c1 int, CHECK(c1>0));
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO check_constraint VALUES(1, -10);
ERROR 3819 (HY000): Check constraint 'check_constraint_chk_1' is violated.

mysql> INSERT INTO check_constraint VALUES(1, 1);
Query OK, 1 row affected (0.01 sec)



パッケージをダウングレードするじゃろ?

$ sudo yum -y downgrade mysql-community-common-8.0.15-1.el7.x86_64 \
mysql-community-libs-compat-8.0.15-1.el7.x86_64 mysql-community-libs-8.0.15-1.el7.x86_64 \
mysql-community-server-8.0.15-1.el7.x86_64 mysql-community-client-8.0.15-1.el7.x86_64


起動する。

mysqld: Can't open file: 'mysql.ibd' (errno: 0 - )
2019-04-27T04:58:31.231293Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.15) starting as process 16650
2019-04-27T04:58:31.415389Z 1 [ERROR] [MY-013171] [InnoDB] Cannot boot server version 80015 on data directory built by version 80016. Downgrade is not supported
2019-04-27T04:58:36.522516Z 1 [ERROR] [MY-010334] [Server] Failed to initialize DD Storage Engine
2019-04-27T04:58:36.522742Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2019-04-27T04:58:36.522975Z 0 [ERROR] [MY-010119] [Server] Aborting
2019-04-27T04:58:36.523868Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.15)  MySQL Community Server - GPL.





( ゚Д゚)アライヤダ!!。起動できませんでした・・・。
8.0.16の新機能(CHECK制約)を使わなかったとしても同様でした。

ダウングレードがサポートされなくなったことは、マニュアルにもしっかりと書いてありました。
https://dev.mysql.com/doc/refman/8.0/en/downgrading.html

Downgrade from MySQL 8.0 to MySQL 5.7, or from a MySQL 8.0 release to a previous MySQL 8.0 release, is not supported.

5.7や5.6では、ダウングレードは出来ていました。

MySQLの開発ポリシーは8.0大きく変わりました。
これまでの「メジャーバージョンアップ時のみ、まとめて機能追加を行う」から「随時、機能追加を行なっていく」というポリシーに変更になりました。
ダウングレードの仕様変更は機能追加を優先した結果でしょうね?

自分の10年近い、MySQL DBA人生で、マイナーバージョンのダウングレードが必要になったケースは1回かな?
ダウングレードできなくても実際はあまり問題にならないんじゃないかと思います。

2019年7月19日金曜日

MySQL Technology Cafe #4 に参加してきた

MySQL Technology Cafe #4 に参加してきました。

State of the Dolphin - What's new in MySQL


Oracleのプリセールスのえらい人、Philipさんによる、MySQL 8の新機能のオーバビューでした。
Document Store、Build in HA / InnoDB Cluster、GISの改良、InnoDB Data Dictionary、CTE / Window Function、etc...

Mercari さんが Oracle Open World で Oracle Cloud の MySQL Analytics で話す予定だそうです!
私は、今年は参加できなそうですが、楽しみです(きっと日本でも話が聞けるでしょう)

MySQL Replication and HA at Facebook

 

Facebook の松信さんのお話!

facebookでは各リージョンにMySQLサーバは一台。読み取りはリージョン内で完結させる。書き込みはリージョンをまたぐ。書き込みは読み取りよりレイテンシが大きくなる。読み取りが多いサービスなので許容している。
書き込みもリージョン内で完結させるとすると(クロスリージョンしない) 、マスターが存在しないリージョンのアプリケーションサーバは、書き込みリクエストを受けることができなくなります。もし、マスターの存在しないリージョンで書き込みを受け付けてしまうと、クロスリージョンで書き込むことになり、書き込みをリージョン内で完結できません。片方のリージョンをアクティブに運用し、他のリージョンはスタンバイとして待機させておくことになるでしょう。

アプリケーションサーバとDBサーバの通信をリージョンをまたぐかどうかは、設計する際に話題になることが多いのですが、頭の中で整理できてなかったので、facebookの事例を聞いて整理できてよかったです。 「あのfacebookでさえ、書き込みはクロスリージョンですよ!」と言いたいと思います(笑)

以下、そこまでやるのぉ!と思ったfacebook 魔改造?たち。
Dependency Replication: スレーブでのレプリケーションの並列度を高めて、レプリケーションを速くする仕組み。トランザクション同士が並列実行できるかどうかを判断するだけでは、マスターと同じレベルの並列度は達成できない。バイナリログからレコードレベルで並列に実行して問題ないトランザクションかを判定するようにパッチを当ててる。
マスターとLBU(semi-sync スレーブ)のレイテンシは書き込みパフォーマンスに直結する。マスターとLBUの間の通信は優先度を高くするため、パケットにタグ付けしてる。
RBR COMPLETE Format: binlog_row_image=MINIMALとFULLの中間。変更前のデータは全てロギングし、変更後は変更があったカラムのみ記録する。情報量は変わらず、容量を削減できる。
あと、カジュアルに「マスターがダウンしたら、SplitBrainしないよう複数台で合意形成した上で、CHANGE MASTERして、 カタログを更新してAPの向き先を新マスターに・・・」と仰ってたのが「facebook強い」なと思いました。多くの人は、そこをどうするかで悩んでると思う(笑)


今日の話は、5月のPercona Live でも話された内容・・・ということで、
一部は tombo さんのPercona Liveのレポート にも内容が書いてあります。

2019年6月1日土曜日

MySQL 8の新機能 RESOURCE GROUP と 権限


RESOURCE GROUPはざっくり言うと、セッションごとに利用できるCPUを制限したり固定できる機能です。以前、試した記事はこちら
意図せず、CPUリソースを制限されてしまうことのないよう、RESOURCE GROUPと権限の関係を調べてみました。

結論

  • RESOURCE GROUPを作成するには、RESOURCE_GROUP_ADMIN 権限が必要
  • RESOURCE GROUPを適用するには、RESOURCE_GROUP_USER 権限が必要
    • RESOURCE_GROUP_USER 権限を持っていれば、他人のセッションのリソースグループも変更できる
    • RESOURCE_GROUP_USER権限を与えるかどうかは慎重に考えたほうがよさそう

検証

 

作成

 

mysql> CREATE RESOURCE GROUP OneCPU TYPE=USER VCPU=0;
ERROR 1227 (42000): Access denied; you need (at least one of) the RESOURCE_GROUP_ADMIN privilege(s) for this operation

 

適用

 

何も権限がない状態。 

 

mysql> SET RESOURCE GROUP OneCPU;
ERROR 1227 (42000): Access denied; you need (at least one of) the RESOURCE_GROUP_ADMIN OR RESOURCE_GROUP_USER privilege(s) for this operation
 

 

testuser に RESOURCE_GROUP_USER を与える。

mysql> GRANT RESOURCE_GROUP_USER ON *.* TO testuser@'%';
Query OK, 0 rows affected (0.01 sec)


$ mysql -utestuser -p
mysql> SET RESOURCE GROUP OneCPU;
Query OK, 0 rows affected (0.00 sec)


testuserがtestuser以外のセッションに対して、RESOURCE GROUPを適用できるかチェック。

適用する対象は(SHOW PROCESSLISTで表示される) Connection Idではなく、Thread_id で指定する必要がある点に注意。
performance_schema から確認できる。


mysql> SELECT THREAD_ID, PROCESSLIST_USER, RESOURCE_GROUP  FROM performance_schema.threads
       WHERE PROCESSLIST_ID IS NOT NULL;
+-----------+------------------+----------------+
| THREAD_ID | PROCESSLIST_USER | RESOURCE_GROUP |
+-----------+------------------+----------------+
|        43 | NULL             | SYS_default    |
|        45 | NULL             | SYS_default    |
|        50 | NULL             | SYS_default    |
|        88 | testu2           | USR_default    |
|        89 | testuser         | USR_default    |
|        90 | root             | USR_default    |
+-----------+------------------+----------------+
6 rows in set (0.00 sec)


mysql> SET RESOURCE GROUP OneCPU FOR 88;
Query OK, 0 rows affected (0.00 sec)



mysql> SET RESOURCE GROUP OneCPU FOR 90;
Query OK, 0 rows affected (0.00 sec)



RESOURCE_GROUP_USER 権限を持っていれば、誰のセッションであろうと、リソースグループを適用できる仕様みたい。

2019年5月1日水曜日

MySQLの管理者用ネットワークインタフェース(administrative network interface)を試す


MySQL 8.0.14 から DB管理者用 に追加でネットワークインタフェースを設けることができるようになりました。

このように、接続あふれを起こしているときでも、管理者用IFであれば接続できます。

$ mysql -P3306 -uroot -pPass%word123 -h db01
ERROR 1040 (HY000): Too many connections


# 3307の管理者用IFに接続
$ mysql -P3307 -uroot -pPass%word123 -h db01
mysql> 


利用するには、admin_port と admin_address を設定します。ポート番号(admin_port)だけでなく、LISTENするIPアドレス(admin_address)も指定する必要があります。

[mysqld]
admin_address=db01
admin_port=3307

admin_address を省略したり、ワイルドカードを使うことはできないようです。
ポート番号だけ、変えられれば十分なんだけどな。。。
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_admin_address
If this variable is not specified at startup, the server maintains no administrative interface.
The value cannot specify a wildcard address format (*, 0.0.0.0, or ::)
このポートにはSERVICE_CONNECTION_ADMIN権限を持っていないと接続できません。

$ mysql -P3307 -uappuser -pPassword%123 -h db01
ERROR 1227 (42000): Access denied; you need (at least one of) the SERVICE_CONNECTION_ADMIN privilege(s) for this operation



実は、この機能を利用しなくても、特権ユーザであれば、max_connections+1までコネクションを貼ることができます。

# 非特権ユーザ
$ mysql -P3306 -uappuser -pPass%word123 -h db01
ERROR 1040 (08004): Too many connections

# root なら接続できる
$ mysql -P3306 -uroot -pPass%word123 -h db01
mysql> show global variables like 'max_connections';
+-----------------+-------+
| Variable_name   | Value |
+-----------------+-------+
| max_connections | 3     |
+-----------------+-------+
1 row in set (0.01 sec)

# max_connections=3 に対して、4本目のセッションが貼れる
mysql> show processlist;
+----+-----------------+------------+------+---------+------+-------------------------------+------------------+
| Id | User            | Host       | db   | Command | Time | State                         | Info             |
+----+-----------------+------------+------+---------+------+-------------------------------+------------------+
|  5 | event_scheduler | localhost  | NULL | Daemon  |  238 | Waiting on empty queue        | NULL             |
|  9 | system user     |            | NULL | Connect |  238 | executing                     | NULL             |
| 12 | system user     |            | NULL | Query   |  238 | Slave has read all relay log; | NULL             |
| 32 | appuser         | db01:60348 | NULL | Sleep   |   71 |                               | NULL             |
| 33 | appuser         | db01:60350 | NULL | Sleep   |   69 |                               | NULL             |
| 34 | appuser         | db01:60352 | NULL | Sleep   |   67 |                               | NULL             |
| 36 | root            | db01:60356 | NULL | Query   |    0 | starting                      | show processlist |
+----+-----------------+------------+------+---------+------+-------------------------------+------------------+
7 rows in set (0.00 sec)


あくまでも、プラス1本だけなので、もう1個セッションを貼ろうとすると、拒否られる

$ mysql -P3306 -uroot -pPass%word123 -h db01
ERROR 1040 (HY000): Too many connections



トラブルシュートしていて、管理者が複数セッションを貼りたいというケースはよくあるので、admin_address/admin_port は役に立ちそうです