Amazon Auroraのデータを高速に『巻き戻す』Backtrack機能がリリースされました！

スタートプラン

大栗です。

個人的にAuroraのアップデートをずっと追っているのですが、アナウンスされてからリリースがされておらずずっと気になっていたBacktrackという即座に過去の状態にもどる機能がリリースされたのでレポートします。

Backtrackとは？

そもそもはre:Invent 2016のBreakout Sessionで『オンライン ポイントインタイム リストア』としてアナウンスされていました。

これはDBクラスタを過去の状態に巻き戻す機能となります。通常のポイントインタイムリカバリ(PiTR)と異なり既存のAuroraクラスタに対して、高速に特定の過去の時点に戻す事が特徴です。

以下の図のように、Auroraの特徴であるLog Structured Storageを活用しています。Auroraのストレージでは全データにLSN（Log Sequence Number）が付いており、それを任意の時点まで戻すことで実現しています。

ユースケースとしては、誤ってWhere句無しでDelete文を発行（つまり全件削除）してしまったり、テーブルをDropしてしまった時にBacktrackを使うことで高速に以前の状態に巻き戻ります。PITRでも同様の事ができますが、既存のバックアップから別のクラスタ/インスタンスとしてリストアを行うため時間がかかってしまいます。

また、データの変更がいつ発生したのか調査するためにDBクラスタを戻したり進めたりすることができます。

Backtrackには『ターゲットウィンドウ』と『実際のウィンドウ』があります。『ターゲットウィンドウ』はBacktrakの変更レコードを保存する期間で、『実際のウィンドウ』は変更レコードは実際にたまっている期間です。

Backtrackで戻る時刻はAuroraクラスタの一貫性のある時刻に戻ります。Backtrackの時刻を指定するとAuroraは自動的に最も近い一貫性のある時刻へ巻戻ります。この方法では指定した時刻と正確に一致しない場合がありますが、正確な時刻はdescribe-db-cluster-backtracksコマンドで確認できます。

BacktrackはAuroraが提供されている全リージョンで利用可能です。

注意点

Backtrackにはいくつかの注意点があります

  • Backtrackは機能を有効にして作成したDBクラスタのみで使用できます。クラスタの新規作成、スナップショットの復元、クラスタのクローンをすると起きに機能を有効化できます。機能が無効のクラスタを有効に変更することはできません。
  • Backtrackのウィンドウは72時間までです。
  • Backtrackはクラスタ全体が対象です。例えば一つのテーブルだけを選択して戻すことはできません。
  • Backtrackはbinlogをサポートしていません。Backtrackを有効にするにはクロスリージョンレプリケーションを無効にする必要があります。
  • データベースのクローンが作成される前にクローンを巻き戻すことはできません。ただし、元データベースをクローン作成時刻まで巻き戻すことができます。
  • BacktrackによりDBインスタンスを短時間中断します。Backtrack操作の前にアプリケーションを停止して新規の読み書きがないことの確認が必要です。Backtrack中にAuroraを一時停止してコネクションを全てクローズし未コミットの読み書きを破棄します。その後Backtrその後の完了を待ちます。
  • 現在BacktrackはAurora MySQL 5.6のみでサポートされています。Aurora MySQL5.7ではサポートされていません。
  • 現在Backtrackを有効にしたAurora MySQL 5.6クラスタのスナップショットをAurora MySQL 5.7へ復元できません。

やってみる

実際にBacktrackを試してみます。

以下の前提で環境を構築します。

  • リージョン：東京
  • Aurora：MySQL 5.6互換
  • インスタンスタイプ：db.t2.medium

Auroraの起動

Auroraは今までと同様に起動します。そして[詳細設定] の設定でバックトラックという項目が増えています。

ここでバックトラックを有効にするを選択すると以下のようになります。ここでBacktrackが可能な範囲を記述します。ここでは6時間を設定しました。これ以外は今まで通りAuroraを起動します。

Auroraを起動すると以下の様にインスタンスの詳細にBacktrackの項目が増えています。中段が今までのPITRについての情報で、右の段がBacktrackの情報です。ターゲットウィンドウと実際にウィンドウが表示されます。

動作を確認する

Backtrackの動作を確認します。

まず例として以下のようなテーブルを作成します。

1
2
3
4
5
SQL> CREATE TABLE test1 (
col1 int NOT NULL AUTO_INCREMENT,
col2 VARCHAR(256),
col3 datetime,
PRIMARY KEY (col1));

そして、以下のような1秒ごとにデータを挿入するスクリプトを作成しました。

test1.sh
1
2
3
4
5
6
7
8
#! /bin/bash
 
while true
do
  echo $(date "+%Y-%m-%d %T")
  (echo "insert into test1 (col2, col3) values ('$(date "+%Y-%m-%d %T.%N")', now());" | mysql -u awsuser -pmypassword -h backtrack-test-cluster.cluster-abcdefghijk1.ap-northeast-1.rds.amazonaws.com mydb) &
  sleep 1
done

以下のように実行して1時間くらい放置します。（時刻はUTCで出力されています）

1
2
3
4
5
6
7
8
9
$ ./test1.sh
2018-05-10 08:22:32
2018-05-10 08:22:33
2018-05-10 08:22:34
2018-05-10 08:22:35
2018-05-10 08:22:36
・
・
・

さて、ここでBacktrackを実行します。インスタンスを選択してインスタンスの操作からDB クラスターのバックトラックを選択します。

として復元可能な範囲の任意の時刻を設定するとBacktrackが実行できます。

ここでは実際にかかる操作の時間を確認するために、別の画面でAWS CLIで実行してみます。backtrack-db-clusterコマンドで2018-05-10T18:30:00+09:00に戻るように実行します。時刻が分かるように前後に時刻を出力しています（時刻はJSTで出力されています）。

1
2
3
4
5
6
7
8
9
10
$ date "+%Y-%m-%d %H:%M:%S" ; aws rds backtrack-db-cluster --db-cluster-identifier backtrack-test-cluster --backtrack-to "2018-05-10T18:30:00+09:00" ; date "+%Y-%m-%d %H:%M:%S"
2018-05-10 18:59:46
{
    "Status": "PENDING",
    "DBClusterIdentifier": "backtrack-test-cluster",
    "BacktrackIdentifier": "1234abcd-1234-12ab-34cd-123456789012",
    "BacktrackRequestCreationTime": "2018-05-10T09:59:50.851Z",
    "BacktrackTo": "2018-05-10T09:30:00Z"
}
2018-05-10 18:59:50

describe-db-cluster-backtracksコマンドでBacktrackの状況を確認すると以下のようになります。ステータスがAPPLYINGなので適用中ということです。

1
2
3
4
5
6
7
8
9
10
11
12
13
$ aws rds describe-db-cluster-backtracks --db-cluster-identifier backtrack-test-cluster
{
    "DBClusterBacktracks": [
        {
            "Status": "APPLYING",
            "BacktrackedFrom": "2018-05-10T09:59:54.784Z",
            "DBClusterIdentifier": "backtrack-test-cluster",
            "BacktrackIdentifier": "1234abcd-1234-12ab-34cd-123456789012",
            "BacktrackRequestCreationTime": "2018-05-10T09:59:50.851Z",
            "BacktrackTo": "2018-05-10T09:30:00Z"
        }
    ]
}

ここでAuroraに1秒ごとにデータを挿入していた画面を確認します。すると、2018-05-10 10:00:17(UTC)と2018-05-10 10:00:18(UTC)の2秒間だけアクセスができていません。Backtrackのコマンドを2018-05-10 18:59:50(JST)に実行したので30秒程度で実行されています。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
2018-05-10 09:59:40
2018-05-10 09:59:41
2018-05-10 09:59:42
2018-05-10 09:59:43
2018-05-10 09:59:44
2018-05-10 09:59:45
2018-05-10 09:59:46
2018-05-10 09:59:47
2018-05-10 09:59:48
2018-05-10 09:59:49
2018-05-10 09:59:50
2018-05-10 09:59:51
2018-05-10 09:59:52
2018-05-10 09:59:53
2018-05-10 09:59:54
2018-05-10 09:59:55
2018-05-10 09:59:56
2018-05-10 09:59:57
2018-05-10 09:59:58
2018-05-10 09:59:59
2018-05-10 10:00:00
2018-05-10 10:00:01
2018-05-10 10:00:02
2018-05-10 10:00:03
2018-05-10 10:00:04
2018-05-10 10:00:05
2018-05-10 10:00:06
2018-05-10 10:00:07
2018-05-10 10:00:08
2018-05-10 10:00:09
2018-05-10 10:00:10
2018-05-10 10:00:11
2018-05-10 10:00:12
2018-05-10 10:00:13
2018-05-10 10:00:14
2018-05-10 10:00:15
2018-05-10 10:00:16
2018-05-10 10:00:17
ERROR 2003 (HY000): Can't connect to MySQL server on 'backtrack-test-cluster.cluster-abcdefghijk1.ap-northeast-1.rds.amazonaws.com' (111)
2018-05-10 10:00:18
ERROR 2003 (HY000): Can't connect to MySQL server on 'backtrack-test-cluster.cluster-abcdefghijk1.ap-northeast-1.rds.amazonaws.com' (111)
2018-05-10 10:00:19
2018-05-10 10:00:20
2018-05-10 10:00:21
2018-05-10 10:00:22
2018-05-10 10:00:23
2018-05-10 10:00:24
2018-05-10 10:00:25

Backtrackの状態を確認すると、以下のようにステータスがCOMPLETEDと完了になっています。

1
2
3
4
5
6
7
8
9
10
11
12
13
$ aws rds describe-db-cluster-backtracks --db-cluster-identifier backtrack-test-cluster
{
    "DBClusterBacktracks": [
        {
            "Status": "COMPLETED",
            "BacktrackedFrom": "2018-05-10T10:00:18.759Z",
            "DBClusterIdentifier": "backtrack-test-cluster",
            "BacktrackIdentifier": "1234abcd-1234-12ab-34cd-123456789012",
            "BacktrackRequestCreationTime": "2018-05-10T09:59:50.851Z",
            "BacktrackTo": "2018-05-10T09:30:00Z"
        }
    ]
}

ここで気になるデータを確認します。Backtrackでは2018-05-10T18:30:00+09:00を指定しました。綺麗に2018-05-10T18:30:00+09:00に戻り、直前の| 4037 | 2018-05-10 09:29:59.535494549 | 2018-05-10 09:29:59 |までのデータの後に、操作後のレコードが挿入されています。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
mysql> select * from test1 order by col1 desc limit 25;
+------+-------------------------------+---------------------+
| col1 | col2                          | col3                |
+------+-------------------------------+---------------------+
| 4052 | 2018-05-10 10:00:33.760096665 | 2018-05-10 10:00:33 |
| 4051 | 2018-05-10 10:00:32.756508967 | 2018-05-10 10:00:32 |
| 4050 | 2018-05-10 10:00:31.752326214 | 2018-05-10 10:00:31 |
| 4049 | 2018-05-10 10:00:30.748302513 | 2018-05-10 10:00:30 |
| 4048 | 2018-05-10 10:00:29.744090912 | 2018-05-10 10:00:29 |
| 4047 | 2018-05-10 10:00:28.740261280 | 2018-05-10 10:00:28 |
| 4046 | 2018-05-10 10:00:27.736103320 | 2018-05-10 10:00:27 |
| 4045 | 2018-05-10 10:00:26.732077506 | 2018-05-10 10:00:26 |
| 4044 | 2018-05-10 10:00:25.728073088 | 2018-05-10 10:00:25 |
| 4043 | 2018-05-10 10:00:24.724169937 | 2018-05-10 10:00:24 |
| 4042 | 2018-05-10 10:00:23.719975706 | 2018-05-10 10:00:23 |
| 4041 | 2018-05-10 10:00:22.715743215 | 2018-05-10 10:00:22 |
| 4040 | 2018-05-10 10:00:21.711749481 | 2018-05-10 10:00:21 |
| 4039 | 2018-05-10 10:00:20.707727291 | 2018-05-10 10:00:20 |
| 4038 | 2018-05-10 10:00:19.703870734 | 2018-05-10 10:00:19 |
| 4037 | 2018-05-10 09:29:59.535494549 | 2018-05-10 09:29:59 |
| 4036 | 2018-05-10 09:29:58.531299470 | 2018-05-10 09:29:58 |
| 4035 | 2018-05-10 09:29:57.527505435 | 2018-05-10 09:29:57 |
| 4034 | 2018-05-10 09:29:56.523597580 | 2018-05-10 09:29:56 |
| 4033 | 2018-05-10 09:29:55.519864174 | 2018-05-10 09:29:55 |
| 4032 | 2018-05-10 09:29:54.515956589 | 2018-05-10 09:29:54 |
| 4031 | 2018-05-10 09:29:53.511821917 | 2018-05-10 09:29:53 |
| 4030 | 2018-05-10 09:29:52.507819972 | 2018-05-10 09:29:52 |
| 4029 | 2018-05-10 09:29:51.504080405 | 2018-05-10 09:29:51 |
| 4028 | 2018-05-10 09:29:50.499816234 | 2018-05-10 09:29:50 |
+------+-------------------------------+---------------------+
25 rows in set (0.04 sec)

Backtrackでは、範囲内であれば進めることもできるので試してみます。今度は2018-05-10T18:50:00+09:00と20分進めてみます。

1
2
3
4
5
6
7
8
9
$ date "+%Y-%m-%d %H:%M:%S" ; aws rds backtrack-db-cluster --db-cluster-identifier backtrack-test-cluster --backtrack-to "2018-05-10T18:50:00+09:00" ; date "+%Y-%m-%d %H:%M:%S"
2018-05-10 20:10:27
{
    "Status": "PENDING",
    "DBClusterIdentifier": "backtrack-test-cluster",
    "BacktrackIdentifier": "abcd1234-1234-ab12-cd34-123456789012",
    "BacktrackRequestCreationTime": "2018-05-10T11:10:28.420Z",
    "BacktrackTo": "2018-05-10T09:50:00Z"
}

少し経つとステータスがCOMPLETEDになります。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
$ aws rds describe-db-cluster-backtracks --db-cluster-identifier backtrack-test-cluster
{
    "DBClusterBacktracks": [
        {
            "Status": "COMPLETED",
            "BacktrackedFrom": "2018-05-10T11:11:20.819Z",
            "DBClusterIdentifier": "backtrack-test-cluster",
            "BacktrackIdentifier": "abcd1234-1234-ab12-cd34-123456789012",
            "BacktrackRequestCreationTime": "2018-05-10T11:10:28.420Z",
            "BacktrackTo": "2018-05-10T09:50:00Z"
        },
        {
            "Status": "COMPLETED",
            "BacktrackedFrom": "2018-05-10T10:00:18.759Z",
            "DBClusterIdentifier": "backtrack-test-cluster",
            "BacktrackIdentifier": "1234abcd-1234-12ab-34cd-123456789012",
            "BacktrackRequestCreationTime": "2018-05-10T09:59:50.851Z",
            "BacktrackTo": "2018-05-10T09:30:00Z"
        }
    ]
}

データを確認してみます。以下のように2018-05-10T18:50:00+09:00以前のデータとなっており、全体のBacktrack操作以降に挿入したデータも消えています。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
mysql> select * from test1 order by col1 desc limit 25;
+------+-------------------------------+---------------------+
| col1 | col2                          | col3                |
+------+-------------------------------+---------------------+
| 5232 | 2018-05-10 09:49:59.242953475 | 2018-05-10 09:49:59 |
| 5231 | 2018-05-10 09:49:58.238612939 | 2018-05-10 09:49:58 |
| 5230 | 2018-05-10 09:49:57.234466798 | 2018-05-10 09:49:57 |
| 5229 | 2018-05-10 09:49:56.230314246 | 2018-05-10 09:49:56 |
| 5228 | 2018-05-10 09:49:55.226782455 | 2018-05-10 09:49:55 |
| 5227 | 2018-05-10 09:49:54.222649048 | 2018-05-10 09:49:54 |
| 5226 | 2018-05-10 09:49:53.218815194 | 2018-05-10 09:49:53 |
| 5225 | 2018-05-10 09:49:52.214942643 | 2018-05-10 09:49:52 |
| 5224 | 2018-05-10 09:49:51.210936054 | 2018-05-10 09:49:51 |
| 5223 | 2018-05-10 09:49:50.206865313 | 2018-05-10 09:49:50 |
| 5222 | 2018-05-10 09:49:49.202863464 | 2018-05-10 09:49:49 |
| 5221 | 2018-05-10 09:49:48.198998730 | 2018-05-10 09:49:48 |
| 5220 | 2018-05-10 09:49:47.195010167 | 2018-05-10 09:49:47 |
| 5219 | 2018-05-10 09:49:46.191071258 | 2018-05-10 09:49:46 |
| 5218 | 2018-05-10 09:49:45.187034525 | 2018-05-10 09:49:45 |
| 5217 | 2018-05-10 09:49:44.183095239 | 2018-05-10 09:49:44 |
| 5216 | 2018-05-10 09:49:43.179329970 | 2018-05-10 09:49:43 |
| 5215 | 2018-05-10 09:49:42.175474601 | 2018-05-10 09:49:42 |
| 5214 | 2018-05-10 09:49:41.171338924 | 2018-05-10 09:49:41 |
| 5213 | 2018-05-10 09:49:40.167399286 | 2018-05-10 09:49:40 |
| 5212 | 2018-05-10 09:49:39.163373416 | 2018-05-10 09:49:39 |
| 5211 | 2018-05-10 09:49:38.159373548 | 2018-05-10 09:49:38 |
| 5210 | 2018-05-10 09:49:37.155499048 | 2018-05-10 09:49:37 |
| 5209 | 2018-05-10 09:49:36.151460766 | 2018-05-10 09:49:36 |
| 5208 | 2018-05-10 09:49:35.147423840 | 2018-05-10 09:49:35 |
+------+-------------------------------+---------------------+
25 rows in set (0.01 sec)

当然、前回のBacktrack操作をした2018-05-10T18:30:00+09:00前後にもデータの欠損はありません。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
mysql> select * from test1 where col3 between '2018-05-10 09:29:50' and '2018-05-10 09:30:10' order by col1 desc limit 25;
+------+-------------------------------+---------------------+
| col1 | col2                          | col3                |
+------+-------------------------------+---------------------+
| 4048 | 2018-05-10 09:30:10.578183551 | 2018-05-10 09:30:10 |
| 4047 | 2018-05-10 09:30:09.574343300 | 2018-05-10 09:30:09 |
| 4046 | 2018-05-10 09:30:08.570463667 | 2018-05-10 09:30:08 |
| 4045 | 2018-05-10 09:30:07.566448216 | 2018-05-10 09:30:07 |
| 4044 | 2018-05-10 09:30:06.562809844 | 2018-05-10 09:30:06 |
| 4043 | 2018-05-10 09:30:05.558684909 | 2018-05-10 09:30:05 |
| 4042 | 2018-05-10 09:30:04.554946551 | 2018-05-10 09:30:04 |
| 4041 | 2018-05-10 09:30:03.551229772 | 2018-05-10 09:30:03 |
| 4040 | 2018-05-10 09:30:02.547174116 | 2018-05-10 09:30:02 |
| 4039 | 2018-05-10 09:30:01.543216309 | 2018-05-10 09:30:01 |
| 4038 | 2018-05-10 09:30:00.539268343 | 2018-05-10 09:30:00 |
| 4037 | 2018-05-10 09:29:59.535494549 | 2018-05-10 09:29:59 |
| 4036 | 2018-05-10 09:29:58.531299470 | 2018-05-10 09:29:58 |
| 4035 | 2018-05-10 09:29:57.527505435 | 2018-05-10 09:29:57 |
| 4034 | 2018-05-10 09:29:56.523597580 | 2018-05-10 09:29:56 |
| 4033 | 2018-05-10 09:29:55.519864174 | 2018-05-10 09:29:55 |
| 4032 | 2018-05-10 09:29:54.515956589 | 2018-05-10 09:29:54 |
| 4031 | 2018-05-10 09:29:53.511821917 | 2018-05-10 09:29:53 |
| 4030 | 2018-05-10 09:29:52.507819972 | 2018-05-10 09:29:52 |
| 4029 | 2018-05-10 09:29:51.504080405 | 2018-05-10 09:29:51 |
| 4028 | 2018-05-10 09:29:50.499816234 | 2018-05-10 09:29:50 |
+------+-------------------------------+---------------------+
21 rows in set (0.06 sec)

このように、DBの状態を巻き戻したり進めたりすることができました。

さいごに

re:Invent 2016のアナウンスからずっと期待していた機能がようやくリリースされました。もしかしてずっと出ないのではと不安になるくらいの機能であったのでリリースされて大変嬉しいです。

この機能により、DBのメンテナンスミスなどからの復旧を高速に行なったり、ある特定時刻のデータの状況を調査可能になりました。システムの運用では何が起こるか分からないので、転ばぬ先の杖としてBacktrackを有効にしておくべきだと思います。

スタートプラン