Insight SQL Testing で Aurora MySQL のバージョンアップ互換性確認テストを行う際に監査ログを使用する

こんにちは。インサイトテクノロジーの松尾です！

本投稿では、Insight SQL Testing で Aurora MySQL のバージョンアップ互換性確認テストを行う際に監査ログを使用する方法を紹介します！
本投稿自体はノウハウ的なものの紹介になりますので、Insight SQL Testing を使った Aurora MySQL のバージョンアップ互換性確認テストの全般的な話題については以下の投稿を参照いただければと思います。

https://qiita.com/takumats/items/980948d6d4d9cf3bec43

## はじめに

Insight SQL Testing で Aurora MySQL のバージョンアップ互換性確認テストを行う際には、一般ログ(general log)の出力を有効にし、そこで出力されたクエリの情報からSQLを抽出します。

https://support.insight-tec.com/product/testing/latest/manual/#_rds_for_mysqlamazon_auroramysql%E4%BA%92%E6%8F%9B%E3%82%A8%E3%83%87%E3%82%A3%E3%82%B7%E3%83%A7%E3%83%B3

ご存じのように監査ログでもSQLの情報が出力されます。さて、代用は可能でしょうか？

## 一般ログに出力されるクエリと監査ログに出力されるクエリの違い

なぜ Insight SQL Testing で、監査ログでなく一般ログを使うようにしているかというと、「改行を伴うクエリ」の出力について、以下のような違いがあるためです。
* 一般ログ：そのまま出力
* 監査ログ：一行にして出力

Dbeaverから以下のようなクエリを実行してみます。

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3480312/b9fad0bf-e362-5f51-b816-9822fa31b1d4.png)

一般ログと監査ログではそれぞれ以下のように出力され、監査ログの出力では、どこまでがコメントかがわからなくなります。

一般ログ：
```
2024-03-24T01:49:27.073572Z  419 Query	/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select
*
-- line comment
from
emp
LIMIT 0, 200
```

監査ログ：
```
1711243891973650,xxxxxxxxx,user1,xx.xx.xx.xx,51209,482133,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select  *  -- line comment  from  emp LIMIT 0, 200',0
```

## とはいえ、監査ログを使いたい

とはいえ、監査ログを既に取得しているような場合、一般ログを追加で出力するには追加の負荷もかかりますし、ストレージ利用もさらに増加します。こういった制約があることは許容したうえで、監査ログで出力されているクエリを利用したいということもあると思います。

そこで本投稿では、Aurora MySQL の監査ログを Insight SQL Testing の評価SQLセット(テストに使用するSQL)として取り込む方法を紹介します。

## Aurora MySQL の監査ログを評価SQLセットとして使用するには

この投稿の執筆時点(2024年3月時点)ではAurora MySQL の監査ログを評価SQLセットとして直接取り込む機能はありません。そのため、評価SQLセットをCSVファイルから作成する機能を使用します。
CSVファイルの形式と必要なカラムはあらかじめ決められており、監査ログからそのCSVファイルを作成します。

https://support.insight-tec.com/product/idt/latest/manual/#_%E3%83%9E%E3%82%A4%E3%83%8B%E3%83%B3%E3%82%B0%E3%82%B5%E3%83%BC%E3%83%81%E5%87%BA%E5%8A%9Bcsv%E5%BD%A2%E5%BC%8F

※なおマニュアルに記載のある「マイニングサーチ出力CSV形式」というのは弊社独自の用語で一般用語ではありません

処理自体は単純ですが面倒な処理なので、Pythonで簡単なスクリプトを作成しました。

https://github.com/takumats/mysql-audit-log-to-mining-search-csv

大まかな処理の流れとしては以下のようになっています。
* 前提：監査ログをテキストファイルで取得できている
* 処理
  * ログイン日時情報の作成 (CONNECTの情報、なければ、SQLの一番最初の時刻、を使用)
  * SQL情報の作成と出力

手元にログファイルがない場合は以下なども参考にしてください

https://qiita.com/takumats/items/cc0f9df02d789f896917

https://qiita.com/takumats/items/0bfa11e8909e27e09044

## スクリプトを使った処理の実施例

まず監査ログをテキストファイルで用意します。ここではCloudWatch Logsからダウンロードしたものを用意しました。書式は元のファイルと同じものです。

```
1711258401200599,aurora-mysql-instance,user1,xx.xx.xx.xx,15222,143296,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ SET autocommit=1',0
1711258401230356,aurora-mysql-instance,user1,xx.xx.xx.xx,15222,143297,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ SELECT DATABASE()',0
1711258401230433,aurora-mysql-instance,rdsadmin,localhost,15223,0,DISCONNECT,,,0
1711258401261787,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143300,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select  *  -- line comment  from  emp LIMIT 0, 200',0
1711258401313426,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143301,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select * from emp LIMIT 0, 200',0
1711258401551096,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143302,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select * from emp e where hiredate >= \'1981-05\' LIMIT 0, 200',0
1711258401738024,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143303,QUERY,demo1,'SHOW WARNINGS',0
1711258401773560,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143304,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select d.loc, count(*) from emp e inner join dept d on e.deptno = d.deptno group by d.loc LIMIT 0, 200',0
1711258402012938,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143311,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select e.empno, e.ename, s.grade salgrade from emp e inner join salgrade s on e.sal >= s.losal and e.sal < s.hisal LIMIT 0, 200',0
1711258402189359,aurora-mysql-instance,rdsadmin,localhost,15224,0,CONNECT,,,0
1711258402225458,aurora-mysql-instance,rdsadmin,localhost,15224,0,DISCONNECT,,,0
1711258402242845,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143321,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select first_value, last_value from testtable LIMIT 0, 200',0
1711258402436862,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143322,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ select version() LIMIT 0, 200',0
1711258402898311,aurora-mysql-instance,user1,xx.xx.xx.xx,15218,143323,QUERY,demo1,'/* ApplicationName=DBeaver 24.0.0 - SQLEditor <Script-7.sql> */ SELECT DATABASE()',0
```

この監査ログファイルに対して以下のように実行します。

```bash
python3 convert_myaudit_to_mscsv.py audit_log_from_cw_sorted_uniq.txt output.csv 
```

output.csvの内容
```
"Host","Database","SID","Serial","Logged In","Logged Out","DB User","SQL Start Time","SQL Start Time(Micro Sec)","SQL Text","Bind Variables","Object","Elapsed Time","Program","Client Information - Host"
"XXXXXXXXXXXXXX","demo1","87","","20240322193356","20240322193357","user1","20240322193356","367725","/* mysql-connector-j-8.2.0 (Revision: 06a1f724497fd81c6a659131fda822c9e5085b6c) */SELECT  @@session.auto_increment_increment AS auto_increment_increment, @@character_set_client AS character_set_client, @@character_set_connection AS character_set_connection, @@character_set_results AS character_set_results, @@character_set_server AS character_set_server, @@collation_server AS collation_server, @@collation_connection AS collation_connection, @@init_connect AS init_connect, @@interactive_timeout AS interactive_timeout, @@license AS license, @@lower_case_table_names AS lower_case_table_names, @@max_allowed_packet AS max_allowed_packet, @@net_write_timeout AS net_write_timeout, @@performance_schema AS performance_schema, @@query_cache_size AS query_cache_size, @@query_cache_type AS query_cache_type, @@sql_mode AS sql_mode, @@system_time_zone AS system_time_zone, @@time_zone AS time_zone, @@tx_isolation AS transaction_isolation, @@wait_timeout AS wait_timeout","","","","","xx.xx.xx.xx"
"XXXXXXXXXXXXXX","demo1","87","","20240322193356","20240322193357","user1","20240322193356","446734","SET character_set_results = NULL","","","","","xx.xx.xx.xx"
"XXXXXXXXXXXXXX","demo1","87","","20240322193356","20240322193357","user1","20240322193356","494120","SET autocommit=1","","","","","xx.xx.xx.xx"
"XXXXXXXXXXXXXX","demo1","87","","20240322193356","20240322193357","user1","20240322193356","558861","SET sql_mode='STRICT_TRANS_TABLES'","","","","","xx.xx.xx.xx"
```

できた `output.csv` を Insight SQL Testing で取り込みます。
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3480312/c6d54921-8e2c-dff8-f467-235476f6426c.png)

以下のように評価SQLセットとしてCSVを取り込むことができます。
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3480312/0a4faf84-9d36-fd2d-fb02-24ea5247c240.png)

この評価SQLセットを使ってアセスメントを実行すると、いつものようにアセスメント結果を見ることができます。
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3480312/d57b0849-9f9e-ca47-1981-6909abbc5a6e.png)

また、先述の行コメントが SQL にある場合はどうなるでしょうか？

![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3480312/7623257a-3c6b-565d-b1e8-38d06ec1f63e.png)

これは SQL として要素が足りないものとなりエラーになりました。どのように行コメントが記述されていたかによると思いますが、場合によっては、実行できてしまうけど、本来のSQLとは異なる、というケースもあるかもしれません。実際に行コメントを使っているSQLがないかは、`--`でフィルタなどをして検索して確認する必要がありそうです。

## おわりに

本投稿では、Insight SQL Testing で Aurora MySQL のバージョンアップ互換性確認テストを行う際に監査ログを使用する方法を紹介しました。監査ログを既に取得している場合に活用することで、一般ログ出力を追加することによる負荷増を避けることができます。利用にあたっては、上述のような制限があることも念頭におき、ご利用をご検討ください。

## 更新情報
* 2024/4/1: Insight Database Testingの製品名がInsight SQL Testingへ変更になったのでそれにあわせて更新しました