時間かかっているSQLのあぶり出し

【管理画面】にてある画面を開こうとするとステータスバーがグルグル回り固まっているような事象に陥ることがある。
コレの原因を調査する一貫として設定する。

以下は初期の値を確認したモノ

~~~
[root@1036oci_opedbslave etc]# mysql -h'100.0.1.36' -e'show variables like "slow_query%";'
+---------------------+-------------------------+
| Variable_name       | Value                   |
+---------------------+-------------------------+
| slow_query_log      | OFF                     |
| slow_query_log_file | /var/lib/mysql/slow.log |
+---------------------+-------------------------+
[root@1036oci_opedbslave etc]# mysql -h'100.0.1.36' -e'show variables like "long_query%";'
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
[root@1036oci_opedbslave etc]#
~~~
シェル画面１
受け取るためのファイルを作成（rootで実行する）
~~~
[opc@1036oci_opedbslave ~]$ sudo su #作業Ａ－１．suになる
[root@1035oci_opedbmaster opc]# ls -l /var/lib/mysql/slow.log #作業Ａ－２．受けファイルが無いことを確認
ls: cannot access '/var/lib/mysql/slow.log': No such file or directory	ls: cannot access '/var/lib/mysql/slow.log': No such file or directory
[root@1035oci_opedbmaster opc]# echo -n > /var/lib/mysql/slow.log #作業Ａ－３．受けファイルを作成
[root@1035oci_opedbmaster opc]# chown mysql.mysql /var/lib/mysql/slow.log #作業Ａ－４．受けファイルの所有者変更
[root@1035oci_opedbmaster opc]# chmod 644 /var/lib/mysql/slow.log #作業Ａ－５．受けファイルのパ－ミッション変更
[root@1035oci_opedbmaster opc]# ls -l /var/lib/mysql/slow.log #作業Ａ－１．受けファイルがmysqlので644になっている事を確認
-rw-r--r-- 1 mysql mysql 1 Dec 1 04:28 /var/lib/mysql/slow.log	-rw-r--r-- 1 mysql mysql 1 Dec 1 13:29 /var/lib/mysql/slow.log
[root@1035oci_opedbmaster opc]#
👆しなくても作られるがパーミッションが厳しくなる👇

[root@1120resdbmaster opc]# ll /var/lib/mysql/slow.log
-rw-rw----. 1 mysql mysql 470 Dec  4 01:25 /var/lib/mysql/slow.log
[root@1120resdbmaster opc]#
mysqlの設定を実行する（平ユーザーにて。「set global」での変数セットはマスター→レプリカへの反映がされないので、各レプリカにてセットが必要です。）

[opc@1035oci_opedbmaster ~]$ mysql -e'show variables like "long_query%";' #作業－１a．確認する
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |👈この時点では1秒
+-----------------+----------+
[opc@1035oci_opedbmaster ~]$ mysql -e'show variables like "slow_query_log%";' #作業－２a．確認する
+---------------------+-------------------------+
| Variable_name       | Value                   |
+---------------------+-------------------------+
| slow_query_log      | OFF                     |👈この時点ではOFF
| slow_query_log_file | /var/lib/mysql/slow.log |
+---------------------+-------------------------+
[opc@1035oci_opedbmaster ~]$ mysql -e'set global long_query_time=120;' #作業－１．時間を秒数でセットする
[opc@1035oci_opedbmaster ~]$ mysql -e'set global slow_query_log=1;' #作業－２．捕まえる設定をONにする
[opc@1035oci_opedbmaster ~]$ mysql -e'show variables like "long_query%";' #作業－１a．確認する
+-----------------+------------+
| Variable_name   | Value      |
+-----------------+------------+
| long_query_time | 120.000000 |👈この時点で120秒
+-----------------+------------+
[opc@1035oci_opedbmaster ~]$ mysql -e'show variables like "slow_query_log%";' #作業－２a．確認する
+---------------------+-------------------------+
| Variable_name       | Value                   |
+---------------------+-------------------------+
| slow_query_log      | ON                      |👈この時点でON
| slow_query_log_file | /var/lib/mysql/slow.log |
+---------------------+-------------------------+
[opc@1035oci_opedbmaster ~]$ tail -f /var/lib/mysql/slow.log #作業－３．動くか確認する。

/usr/sbin/mariadbd, Version: 100.5.10-MariaDB-log (MariaDB Server). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                Id Command  Argument
# Time: 231201  4:41:59
# User@Host: [opc] @  [100.0.0.100]👈100番からopcでアクセス
# Thread_id: 26422937  Schema:   QC_hit: No
# Query_time: 126.000182  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0👈秒数が126秒であることを確認
# Rows_affected: 0  Bytes_sent: 277
SET timestamp=1701405719;
SELECT NOW(),SYSDATE(), SLEEP(126) SLEPT,NOW(),SYSDATE();👈別ホストから投げたSQLがキャッチ出来てる
~~~
シェル画面２（シェル画面１とは別のホストから）

~~~
[opc@0100satellite ~]$ mysql -h'100.0.1.36' -e'SELECT NOW(),SYSDATE(), SLEEP(126) SLEPT,NOW(),SYSDATE();' #作業ー４．意図的に時間のかかるクエリを実行
+---------------------+---------------------+-------+---------------------+---------------------+
| NOW()               | SYSDATE()           | SLEPT | NOW()               | SYSDATE()           |
+---------------------+---------------------+-------+---------------------+---------------------+
| 2023-12-01 13:42:49 | 2023-12-01 13:42:49 |     0 | 2023-12-01 13:42:49 | 2023-12-01 13:44:55 |
+---------------------+---------------------+-------+---------------------+---------------------+
[opc@0100satellite ~]$
~~~
ファイルフォーマットの説明
~~~php:slow.log
# Time: 231205  4:27:05👈記録された日時＝SQLが終了した日時（SQLを開始した日時ではない。標準時刻になっているので変換が必要。）4:27:05（標準時間）→13:27:05（日本時間）
# User@Host: [whoam1] @  [100.0.0.101]👈ログイン名とfromホスト
# Thread_id: 27150103  Schema:   QC_hit: No👈Schemaには使用したデータベースが書かれている。
# Query_time: 126.000194  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0👈126秒かかった＝SQLが開始されたのは13:24:59と逆算できる。
# Rows_affected: 0  Bytes_sent: 277
SET timestamp=1701750425;
SELECT NOW(),SYSDATE(), SLEEP(126) SLEPT,NOW(),SYSDATE();👈126秒かかったSQLはコチラ。
~~~
参考にしたURL
スロークエリの確認方法：MySQL編
https://ptune.jp/tech/how-to-check-mysql-slow-query/ 👈コマンドの場合を参照
通常のクエリーログ、遅いクエリーログの保存設定
https://www.wakuwakubank.com/posts/700-mysql-query-log/
MySQLのチューニング slow logの設定方法
https://webkaru.net/mysql/mysql-tuning-slow-log/
MySQL slow_query_log はmy.cnfの[mysqld]の欄に書くのよ
https://it-afi.com/mysql/mysql-slow_query_log-%e3%81%afmy-cnf%e3%81%aemysqld%e3%81%ae%e6%ac%84%e3%81%ab%e6%9b%b8%e3%81%8f%e3%81%ae%e3%82%88/
MySQL で my.cnf のシンタックスチェックを行う方法
https://gotohayato.com/content/83/

動作確認用
上部のメニューアイコン「レス投稿エラー機能（URLは/post_error_list/）」
一回開こうとすると数分OPEサーバーのWEBが操作不能になる。

~~~
[opc@0205oci_opeweb ~]$ mysql -h'100.0.1.70' #👈bbsのメインサーバーに接続
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 2586254760
Server version: 100.5.10-MariaDB-log MariaDB Server

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> select sql_calc_found_rows * from myproject.post_error_log order by id desc limit 2; #👈時間のかかっているSQLを投げる
（省略します）
2 rows in set (1 min 28.799 sec) #🔍88秒かかっている。

MariaDB [(none)]> Bye
[opc@0205oci_opeweb ~]$
~~~
あいうえお