GAE/J用バックアップ／リストアツール作成

　ここのところ多忙で、まとめサイト（cbnanashi@GAE/J）への機能追加等もなかなか出来ず申し訳ありません。

　App Engineのアプリケーションを開発するときの問題のひとつに、Datastoreのデータの取り扱いが面倒なことがあります。テストのために実サーバのデータを開発サーバに移したり、その逆を行ったりするのは、一苦労です。

　GAE/J版のバックアップ／リストアツールは以前から近日リリース予定とされていますが、なかなかリリースされません。

　そこでまとめサイトの更新を容易に行えるようにするため、まずはDatastoreのバックアップ／リストアのツールを簡単に作成してみました。当方のアプリケーションを前提としているため機能は限定的ですし、そもそも他の環境で動作するか分からないのですが、何かの役に立つかも知れませんので公開します。

　正しく動作しない場合はご連絡頂ければ改善を努力しますが、各自改造して頂ければ幸いです。

■簡単な仕組み

　App Engineのアプリケーションで動作するServletと、コマンドラインから実行するツールを組み合わせています。コマンドラインツールがServletと通信し、バックアップ／リストアを行います。

　ServletのソースファイルとJARはこちらです。

• entitybackup-web-0.1.0.zip

　コマンドラインツールのJARはこちらです。

• entitybackup.jar
• entityrestore.jar

　ソースはこちらです。

• entitybackup-tool-src-0.1.0.zip

■使い方

App Engineアプリケーション側の設定

　バックアップ／リストアのServletをApp Engineのアプリケーションに設定します。

　実サーバでは既存アプリケーションの新しいバージョンとして、バックアップ／リストアのみのアプリケーションをデプロイするのがよいでしょう。新しいApp Engineプロジェクトを作成してServletのソースファイルをコピーしてください。

　開発環境ではアプリケーションにServletを追加します。既存のアプリケーションにServletのソースファイルをコピーし、web.xmlを修正して下さい（local_db.binをコピーしてもうまく動作しないようです）。

　また、Jakarta Commonsのいくつかのコンポーネントを利用しますので、いずれの場合でも同梱されているJARをwar/WEB-INF/libに追加して下さい。

　同梱のweb.xmlではBackupServletのURLは"/backup"に、RestoreServletのURLは"/restore"にマッピングしています。

コマンドラインツールの実行

　次にバックアップ／リストア先のアプリケーションを起動し、コマンドラインからツールを実行します。バックアップは以下のように実行します。

java -jar JARのディレクトリ\entitybackup.jar ServletのURL [Kind名...]

　Kind名は複数指定できます。省略すると統計情報から取得したすべてのKindが対象となります。

　バックアップファイルはカレントディレクトリに"EntityのKind名.txt"というファイル名で作成されます。

　リストアは以下のように実行します。

java -jar JARのディレクトリ\entityrestore.jar [-d] ServletのURL [Kind名...]

　-dを指定するとDatastore上の同名のKindのEntityをすべて削除してからリストアします。-dを指定しないとキーが重複している場合のみ既存Entityを上書きします。

　Kind名は複数指定できます。省略するとカレントディレクトリの"*.txt"ファイルのKindが対象となります。

　リストアするデータはカレントディレクトリの"EntityのKind名.txt"というファイルになります。

　コマンドラインから起動するのではなくEclipseでJavaプロジェクトを作成し、ソースをコピーして実行しても結構です。

■その他

• 対応しているプロパティの種類に制限があります。以下に対応しています。
  • String、Long（int等もDatastore内ではLongとして保持）、Text、Blob、Date、Double、Key、Boolen、これらのList
  • これ以外（User、EMail、GeoPt等）は対応していません。
• DatastoreのLow-level APIを用いています。JDOや、Slim3などの他の永続化機構を用いていると正しく動作しない可能性があります。
• バックアップは高速です（当方の環境では50MBを数分）。リストアは時間が掛かります（同じく30分程度）。リストア中はメンテナンス画面を出すなどの工夫をするとよいと思います。
• 実環境へのリストア（削除、登録）にはCPU時間をかなり消費しますのでご注意下さい。
• 認証を行っていませんのでURLさえ分かれば誰でもアクセスできます。不要な時には停止／削除する、URLを変えておく等の注意をして下さい。
• Kind情報の取得元のStatisticsは反映されるまで時間が掛かるとのことです。Kindが正しく取得できない場合は引数で与えて下さい。
• 各データファイルは以下の形式です。
  • 各行はタブ区切りです。
  • あるEntityの最初の行は必ず"__key__＜tab＞キー内容"です。
    • キー内容は"KeyFactory.keyToStringの値;Kind;Name;Id"です。リストア時にはkeyToStringの値は無視されKind/Name/Idからキーが生成されます。
  • その後、Entityの各プロパティがそれぞれ一行で出力されます。
    • −行の形式は"プロパティ名＜tab＞型＜tab＞値"です。
    • バイナリはBase64エンコードになります。文字列中の改行、タブ、"\"はそれぞれ\n、\t、\\にエスケープされます。
  • 後はファイルをご覧下さい。

■ライセンス等

　Apache License, Version 2.0でお願いします。

　プログラムを使用したことによる一切の損害について責任を負いません。

　各JARにはJakarta CommonsのJARを展開してclassファイルを同梱してあります。それぞれのライセンスはMETA-INFに格納してあります。

GAE/J、5か月間のパフォーマンス推移

　cbnanashi@GAE/Jには、少しでもサイトの反応を良くするためアクセス解析等は一切入れていませんが、Googleウェブマスターツールにはサイトを登録しています。

　ウェブマスターツールの機能に「サイトのパフォーマンス」があり、サイトのアクセスに掛かった時間の統計が表示されます。5ヶ月ほどのデータが取れますので参考までに公開してみます。

　この間cbnanashi@GAE/Jの機能を多少変更していますので、それを吹き出しで追加してみました。

　1月初頭のPrecompilationの追加は、アプリケーションの起動時間には効果がありましたが、全体パフォーマンスには影響なかったようです。

　1月中旬にDatastoreアクセスをJDOからLow Level APIへ移行しました。若干ですが効果があったようです。

　2月前半に品名一覧へのサムネイル表示機能を追加し、CPU負荷とデータ転送量が大きく増加しました。特に転送量は無料quotaの50%を常に超える程度にまで増えています。しかし、その後のグラフの変化は増大傾向にあるものの緩やかですので、パフォーマンスへの影響は少なかったようです。

　2月から3月中旬に掛けてパフォーマンスが下がっていますが、その後大きく改善しています。この期間は確かになんとなく遅いと感じていましたので、使用感とも一致します。

　また、5か月間のPVは少しずつ増加傾向で1.3倍程度になっています。単純なリクエスト数は、サムネイル追加のためおそらく2倍以上になっていると思います。

　CPU負荷や転送量、リクエスト数が増えても性能が悪化しないことや、アプリケーションを変えなくても性能に影響を受けることは、クラウドならではというところでしょうか。

GAE/Jで運用中に発生する例外（と一部対処法）

　App Engineでのアプリケーション実行中に私が遭遇した不測の例外やエラーについて、原因と（一部のみですが）対策を書いてみます。

　あくまでも個人的な経験に基づくもので、多分に推測を含みますが、多少ともお役に立てば幸いです。例外の種類は随時追加したいと思います。コードの誤りや、よりよい対策などがあれば、お知らせ頂ければ幸いです。

今回記述した例外、エラーの種類

• DatastoreTimeoutException
• ApiProxy$UnknownException
• ApiProxy$CapabilityDisabledException
• GCacheException
• DeadlineExceededException
• ConcurrentModificationException
• リクエストキューのタイムアウトエラー

それぞれの例外について

　これらの例外はアプリケーションの不具合ではなく、App Engineが原因で発生すると思われます。スタックトレースの冒頭部分、推定した原因、発生する箇所、対策（あればコード例も）を示します。

　なお、当方のアプリケーション（cbnanashi@GAE/J）では、App EngineのServiceのうち、Datastore、Memcache、URL Fetch、Images、Google Accountsを使用しています。他のServiceでは別の例外が発生するかもしれません。

■DatastoreTimeoutException

• スタックトレース

com.google.appengine.api.datastore.DatastoreTimeoutException: Unknown
at com.google.appengine.api.datastore.DatastoreApiHelper.translateError(DatastoreApiHelper.java:42)
at com.google.appengine.api.datastore.DatastoreApiHelper.makeSyncCall(DatastoreApiHelper.java:60)

• 原因
  • Datastoreへのアクセスがタイムアウトした。
• 発生箇所
  • Datastoreへのアクセス。putだけでなくgetでも発生する。
• 対策
  • リトライすると成功することがあるのでリトライする。データに矛盾が発生しないよう注意が必要。リトライ対象は冪等（何度実行してもよい）にしておくとよい。
  • 同じ箇所で何度も連続してエラーが出ることがあるので、複数回リトライすると良い。ただし何回もリトライするとリクエスト30秒制限を越えそうになる。個人的には5回にしている。
  • SDK 1.3.1の自動リトライ機能追加で発生確率が大幅減。ただし発生しないわけではない（実際に1.3.1導入後の発生を数回確認）。
• コード例

int count = 0;
boolean retry;
do {
    retry = false;
    try {
        // ...
        // ここでDatastoreアクセス処理
        // ...
    } catch (RuntimeException e) {
        if (!(e instanceof DatastoreTimeoutException)) {
            // タイムアウト以外ならリトライ可能なその他の例外かどうか判定する
            if (!(e.getClass().getName().contains("ApiProxy$UnknownException") && e.getMessage().contains("datastore_v3"))) {
                throw e; // リトライ不可能
            }
            try {
                Thread.sleep(20);
            } catch (InterruptedException e2) {
                // 無視する
            }
        }
        count++;
        if (count <= MAX_RETRY_COUNT) {
            log.warn("Retry. count:" + count, e);
            retry = true;
        } else {
            log.debug("Retry count exceeded.");
            throw new IllegalStateException("Retry count exceeded.", e);
        }
    }
} while (retry);

■ApiProxy$UnknownException

• スタックトレース

com.google.apphosting.api.ApiProxy$UnknownException: An error occurred for the API request datastore_v3.Get().
at com.google.apphosting.runtime.ApiProxyImpl.doSyncCall(ApiProxyImpl.java:198)
at com.google.apphosting.runtime.ApiProxyImpl.access$000(ApiProxyImpl.java:37)

com.google.apphosting.api.ApiProxy$UnknownException: An error occurred for the API request datastore_v3.RunQuery().
at com.google.apphosting.runtime.ApiProxyImpl.doSyncCall(ApiProxyImpl.java:198)
at com.google.apphosting.runtime.ApiProxyImpl.access$000(ApiProxyImpl.java:37)

• 原因
  • 不明。App Engineから呼び出したServiceでのエラーか。
• 発生箇所
  • 主としてDatastoreアクセスで発生している。
  • ただし例外メッセージから類推すると、それ以外のService利用でも発生すると思われる。
• 対策
  • リトライすると成功することがある。
  • ただし、（個人的な印象では）すぐにリトライしても失敗するようだ。20msスリープしてからリトライしている。
• コード例
  • DatastoreTimeoutExceptionを参照。

■ApiProxy$CapabilityDisabledException

• スタックトレース

com.google.apphosting.api.ApiProxy$CapabilityDisabledException: The API call datastore_v3.BeginTransaction() is temporarily unavailable.
at com.google.apphosting.runtime.ApiProxyImpl.doSyncCall(ApiProxyImpl.java:208)
at com.google.apphosting.runtime.ApiProxyImpl.access$000(ApiProxyImpl.java:43)

• 原因
  • App Engineのメンテナンス中などでDatastoreがread-onlyになっている。
• 発生箇所
  • Datastoreへのput。
• 対策
  • catchして適切なエラー処理を行う。マニュアル（メンテナンス中の対処法）を参照。
• コード例
  • cbnanashi@GAE/Jではエラー用JSPでメッセージの切り替えのみ行っている。
  • 本来なら500 Internal Server Errorではなく503 Service Unavailableを返すのがより望ましいと思われる。

<%
    if (!(exception instanceof ApiProxy.CapabilityDisabledException)) {
        // 通常
%>      <p>内部エラーが発生しました。リロードすると正しく表示される場合があります。
        何度も発生する場合は、掲示板などでご連絡いただけると幸いです。</p>
<%
    } else {
        // Datastoreメンテナンス中
%>      <p>Google App Engineのメンテナンス中のため、レビュー投票、掲示板、参考URL送信、
        編集者機能は無効になっています。ご迷惑をお掛けしております。しばらく時間を
        置いてから再実行をお願いします。</p>
<%
    }
%>

■GCacheException

• スタックトレース

com.google.appengine.api.memcache.stdimpl.GCacheException: Policy prevented put operation
at com.google.appengine.api.memcache.stdimpl.GCache.put(GCache.java:165)

• 原因
  • メンテナンス中などMemcacheが使用できない時に値を格納しようとすると発生する。
  • マニュアル（メンテナンス中の対処法）によるとメンテナンス中のputは単に無視されるとあるが、実際には例外が出ることがあるようだ。
• 発生箇所
  • Memcacheへのput処理。
• 対策
  • 単に無視すればよいようだ。
• コード例

try {
    getCache().put(key, value);
} catch (GCacheException e) {
    // 無視する
}

■DeadlineExceededException

• スタックトレース

com.google.apphosting.api.DeadlineExceededException: This request (39031c2b39b8e37f) started at 2009/10/24 17:32:49.560 UTC and was still executing at 2009/10/24 17:33:18.038 UTC.
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(Unknown Source)

• 原因
  • リクエストが30秒以内に完了しなかった。
  • 通常は30秒以内に終了する処理でも、Datastoreのリトライや何らかのApp Engine側の理由で想定以上の時間が掛かり、発生することがある。
• 発生箇所
  • どこでも発生する可能性がある。
• 対策
  • catchできるので後始末（たとえばトランザクションのcommit/rollbackやエラーページの表示など）を行うことができる。後処理に使える時間はマニュアルによると1秒以下とのこと。
  • その時間以内にリクエストを終了しないとcatchできないErrorが発生するとのこと。
  • 根本的な対策としてはリクエストは30秒以内に終わるようにする。TaskQueueなどを利用するのも一つの方法。
• コード例
  • cbnanashi@GAE/Jではほぼ発生しないので未対策。
  • ここ数ヶ月ではリトライの繰り返しにより数回発生したことがある。

■ConcurrentModificationException

• スタックトレース

java.util.ConcurrentModificationException: too much contention on these datastore entities. please try again.
at com.google.appengine.api.datastore.DatastoreApiHelper.translateError(DatastoreApiHelper.java:36)
at com.google.appengine.api.datastore.DatastoreApiHelper.makeSyncCall(DatastoreApiHelper.java:60)

• 原因
  • Datastoreの楽観的ロックが失敗した。
  • 複数のリクエストが同じエンティティを並行して「get〜put」した場合に発生するようだ。
• 発生箇所
  • Datastoreのcommit処理。
• 対策
  • Datastoreアクセスの処理を再実行する。アプリケーションの状態に矛盾が生じないように注意が必要。
  • または単にエラーとして処理し、ユーザーに再実行してもらう。
• コード例
  • cbnanashi@GAE/Jでは、発生する可能性があるのは限定したユーザー向けの処理だけなので、現状未対策。他の例外と同様にシステムエラーとして表示している。

■リクエストキューのタイムアウトエラー

• ログに以下のワーニングログが出力される。

Request was aborted after waiting too long to attempt to service your request. 
Most likely, this indicates that you have reached your simultaneous active request 
limit. This is almost always due to excessively high latency in your app. 
Please see http://code.google.com/appengine/docs/quotas.html for more details.

• 原因
  • メッセージによれば「リクエストがQuotaに達した」とのことだが、それで発生したことは今のところないと思われる。
  • アプリケーションの起動に時間が掛かるとしばしば発生する。
  • GAEのアプリケーションへのリクエストはキューに格納される。キューのタイムアウトは10秒らしい。
  • 起動（spin up）中のアプリケーションにリクエストがキューイングされ、起動が10秒以内に終わらなかった場合に発生するようだ。
  • リクエストの処理に10秒以上掛かっていると、まれに起動中以外でも発生する。インスタンス数が適切に増えていない場合（スケールしていない場合）に発生するのかもしれない。
  • WdWeaver氏による資料「スケールアウトの真実」が参考になる。
• 発生箇所
  • アプリケーションにリクエストが渡る前。
• 対策
  • アプリケーションの起動時間を短くする。アプリケーションでの直接の対策はできない。（起動時間を短くするためのTIPSは後ほど公開したい。）
  • しかしながら、cpu_msが短くても（たとえば3,000ms程度）、起動時間（ms）が10秒を超えてしまうことがある。発生確率を下げる程度の効果しかないようだ。
  • ブラウザには、App Engineが出力する無愛想な固定エラーメッセージが表示されてしまう。