フツーな日常

■低可用性データセンターとかどうか

年末にid:halfrack ｾﾝｾｲとかと話をしていたネタ。

現行のデータセンターはどこも高可用性のために利用するものだが、逆に低可用性だけど非常に安価なデータセンターとかはどうだろう。

目標の可用性は98%ぐらい。この程度の可用性だと1年で1週間程度は落ちていることになるので、通常のサービス提供には使えない。故障しない程度の空調と二重化まではしていないファシリティでハードウェアを置かせてくれるサービスとしての位置付け。

ターゲットとしては都内の高めのオフィスの一角で占有しているサーバの行き先や、Hadoopなんかのリソースは食うけど単価をとにかく安く上げたいサーバを大量に詰め込む先として。

ぽっと出の事業者がやると単なる劣悪なサービスになりそうだけど、見切りの出来る事業者が本当に割り切って作ればいい線行かないかな、などと妄想した

ツイートする

Permalink | コメント(0) | トラックバック(0)

■isuconに行って平凡な記録を残してきた

もう先週のことになりますが、去る8月27日にid:pekeqさんに誘われてisuconに行って平凡な記録を残してきました。

参加者はpekeqさんとrshさんと無職で暇な奴ということで私

準備編

rshさんがノリノリで高速なKVSを実装するということになった。memcachedはsocketで接続して読み書きするが、この独自KVSはshmでデータを保持する。仕組み上ホストを跨いだデータの共有が出来ないが同一ホスト内での単純なKVSとしてはこれ以上に高速な仕組みはなかなか無いだろうという見込み。

アプリはperlで記述されているとのことなので、XSで読み書きできるところまでを当日までに実装してgithubに置いておくことに。これでレギュレーションで指定された外部で公開されているアプリの利用ということになるだろうということになった。

実際、rshさんの事前の計測では同一ホストで動くmemcachedよりはXS経由でも10倍程度高速なものが完成した。急造品であるため異なるデータサイズへの対応がmemcachedよりも柔軟ではないことや、原理的にホスト間でのデータ同期が問題になるが、そこはフロントのプロキシで分離することでなんとかしようということになった。

おおまかな作業分担は、私がフロントのプロキシ、rshさんが例のKVS、pekeqさんがSQLとそれ以外。

当日編

当日は奇跡的に全員遅刻もせず会場入り

pekeqさんがisuconということでhttp://www.nhk.or.jp/kids/program/miitsuketa.html:NHKの幼児向け番組]のイスのキャラ「コッシー」のおもちゃを持ち込む。「これなら投げつけても大丈夫なはずだ…」お子さんが入る家庭でないとそのネタは分からないよ!

前半戦

競技の開始と同時に各人がざっと構成を把握。

私の担当部分はApacheのmod_proxyを使った単純な構成と判明。設定の書き方もApacheとしてはかなり整理された記述で移植が楽そうであると判断した。

アプリの本体はコードを読んだ人間が口々に「こんなに短かいのか…」と呟くほどあっさりした記述。現代的なperlによるアプリケーション記法に慣れていないためのカルチャーギャップに動揺が走る。

この初期状態での測定結果は800qps程度

全員が担当パートをざっと把握したところで軽く意識合わせ。私はnginxに変更のうえ、スタティックな画像やcssなどをリバースプロキシに置くところまで作業することに。

私の担当パートであるリバースプロキシについてもApacheでの設定が簡素であったのでnginxへの移植はすぐに終った。MySQLの各種パラメータが初期状態のままであったため、更新のディスク反映を遅延させたり、クエリキャッシュを有効にしたり、バッファの量を増やしたり、トランザクションログを大きめにするといった基本的な変更を実施。

この時点で再度ベンチマークを流してみたところ1200qps程度まで上昇。隣りのチームがいきなり20000qpsを越える値を叩き出して、余裕の昼食に出たため衝撃が走る。

SQLはアプリに直書きされているものを全て列挙しても両手で数えられるほど、ほとんどは単純なキーによる検索のみであると即断できる程度のものだった。一つだけ明らかに遅くなりそうなSQLはpekeqさんは目視で発見。

記事とコメントがそれぞれ違うテーブルで保持されているのだが、このSQLは最近コメントが付いた順で記事の最新数件のタイトルを取得するというもの。コメントがつくたびに記事が上に上がってくる、スレッドフロート型の掲示板を想像するといいだろうか。

記事と対応するコメントを内部結合し、記事のidで集約、そのうち付けられた最新のコメントをMAX()で出しその降順で出力するというものだった。

これはすぐに非正規化による高速化が可能であると結論されたので、最新のコメント日付と記事のidを保持するだけのテーブルを作ってコメントが付けられると同時にそちらにも書くようにした。同じ記事への書き込みによって日付のみが更新される場合もあるのでMySQLの拡張構文'insert on duplicate key update'を使うことで簡単に書けた。

ここまでのチューニング結果を測定してみたところ21000qpsほど。一瞬ではあったが暫定2位に踊り出た

後半戦

前半は比較的順調だったのだが、後半はいろいろと酷かった。

例のキャッシュシステムの機構を色々な場所に入れてキャッシュをしてみるが一向に速くならない。データベースもリバースプロキシも最初の段階で当初想定していた変更を出し切ってしまっていたのであとは微妙なパラメータを変更する程度。

変更する都度、主催側が用意したベンチマークを走らせるのだが1分間という測定時間内に完全に作業を止めてまでそちらに専念しなかったこともあって、測定中に他のパートが設定変更したことによるfailや結果への影響が排除できなかったためどの変更がどれだけ効果があったのか(あるいは無かったのか)が判然としないまま、暗中模索が続いてしまった。

SQLの変更については別テーブル方式から記事テーブル自体にコメント時刻を持たせ、それを更新する方式に変更した。ただし、パフォーマンスはさほど変化せず。

最後にはアプリケーションがレンダリングした結果自体をキャッシュに入れることで高速に返すよう改修を実施していたのだが、それもベンチマーク側での内容チェックを抜けることが出来ず最後にはロールバックして終了。

会場のメインモニターには各チームの途中結果が表示されていたのだが、それを見る限りfujiwara組とシーサーが頭ひとつ抜けた80000qps越え。それ以降チューニングに成功したチームが70000qpsから30000qpsぐらいで第二集団を形成するといった具合。我々は第二集団の最後尾ぐらい

結果

正式には開催側から発表があると思いますが、最終結果は7位でテストが完走したチームの中では下から数えた方が速い程度

懇親会

1位と2位のチームに終了後に話を聞く機会があったのですが、1位のfujiwara組がかなりアグレッシブなキャッシュ戦略と絶妙なチューニングによって高性能とテスト完走のいずれも勝ち取ったのに対して、2位のいんふらえんじにあーは比較的正攻法のコードの最適化を重視した結果手堅い結果を残したようだった。もちろんSELinuxは有効状態で(ｷﾘｯ

最終結果ではfailだったが、シーサーもかなり高速な暫定結果を残しており恐らく手法としてはfujiwara組と近いものであったのではないかと推測される。

反省

いや、もう反省点だらけの結果であった。

ベンチマークは主催側で用意されているからと測定ツールは用意しなかったのだが、やはり1分間かかる測定できっちりと意味のある結果を測定できなかったため色々と裏目に出てしまった。仮に自前の測定ツールを作ったところで例のkeepaliveや内容チェックの罠を再現しないまま適当なテストをしてしまい逆にあさっての方向へ改修をしてしまう可能性もあった。事実、ウォームアップ用のスクリプトを使って簡易的にレスポンスを測っているときにはどんどん結果が良くなっていたので気を良くしてコスい変更をいろいろとしてしまった。そして、それが裏目裏目に出た結果、自己最高記録さえも上回れない最終結果となってしまった。

作業のやり方という点では、普段一緒に仕事をしているわけではない3名だったため、作業の進め方も意識を合わせられなかった。ホワイトボードとはいわなくとも、紙のノート1冊でも有ればそれにタスクリストを作ってチェックしながら進めることができただろう。

skypeチャットなりIRCなりで各人の作業を小まめに共有していれば、ベンチマーク中の作業中断ももっとスムーズにできただろう。

測定の1分間を毎時05分からと決めて、次の測定までに行なう変更を明確にするといったチェックポイントを作ったほうが効率的だっただろう。

あとは、アプリケーションのボトルネック調査を適当にしてしまったこと。10倍速いキャッシュもキャッシュがネックになっている局面に正しく投入しないと効果が無いということだ。今回の測定内容からするとキャッシュを効果的に入れることがかなり難しく、それを突破できたかが勝敗の別れ目になった感がある。Livedoor社内での事前実施で好成績を残した方の手法はコンテンツの性質に応じて適切な粒度でキャッシュをし、その有効期間を管理するというものだった。

後知恵ではあるが、リバースプロキシでのSSIもmemcachedの利用も競技中に検討しないではなかったのだが、アプリへ手を入れる工数を考えると採用に踏み切れなかった。この辺は普段からperlで手を動かしている人との差が顕著に出てしまったと考える

最後に

isuconという非常に刺激的な場を提供くださったLivedoorの皆様には大変感謝しております。機材や場所といったリソースはもちろん、競技用のコードの準備といった人的リソースは多大なものであったと想像致します。

ツイートする

Permalink | コメント(0) | トラックバック(0)

■[android]U300でセルスタンバイでやたらと電力を食う問題について追う(1)

どういう問題かは宮川さんが書かれている通りです。

無線部分の細かい制御を読むのはちょっと無理だと思うのだけど、せっかくAndroidでソースがあるのだからと読める範囲で追いかけてみました。

とっかかりを掴むまで

• CM7のコードを取ってくる
• "セルスタンバイ"という文字列を検索
  • リソースファイルが見付かる
  • ./packages/apps/Settings/res/values-ja/strings.xml
  • "power_cell"がリソース名であるようだ
• "power_cell"でgrep
  • ./packages/apps/Settings/src/com/android/settings/fuelgauge/PowerUsageSummary.javaで使われている
  • というかここだけ
  • ファイル名からすると電力消費に関係する箇所のようだ

ここをとっかりとして読み進める。

呼び出し元

    private void processMiscUsage() {
        final int which = mStatsType;
        long uSecTime = SystemClock.elapsedRealtime() * 1000;
        final long uSecNow = mStats.computeBatteryRealtime(uSecTime, which);
        final long timeSinceUnplugged = uSecNow;
        if (DEBUG) {
            Log.i(TAG, "Uptime since last unplugged = " + (timeSinceUnplugged / 1000));
        }

        addPhoneUsage(uSecNow);
        addScreenUsage(uSecNow);
        addWiFiUsage(uSecNow);
        addBluetoothUsage(uSecNow);
        addIdleUsage(uSecNow); // Not including cellular idle power
        addRadioUsage(uSecNow);
    }

バッテリ駆動に切り替わってからの経過時間のマイクロ秒(といっても1000倍しているだけ)を渡して、電話、画面、WiFi、Bluetoothなどなどコンポーネント毎の利用電力を出している。

で、以下が実際にpower_cellというリソース名が使われている部分。無線コンポーネントに関係する電力消費を算出しているメソッド

    private void addRadioUsage(long uSecNow) {
        double power = 0;
        final int BINS = BatteryStats.NUM_SIGNAL_STRENGTH_BINS;
        long signalTimeMs = 0;
        for (int i = 0; i < BINS; i++) {
            long strengthTimeMs = mStats.getPhoneSignalStrengthTime(i, uSecNow, mStatsType) / 1000;
            power += strengthTimeMs / 1000
                    * mPowerProfile.getAveragePower(PowerProfile.POWER_RADIO_ON, i);
            signalTimeMs += strengthTimeMs;
        }
        long scanningTimeMs = mStats.getPhoneSignalScanningTime(uSecNow, mStatsType) / 1000;
        power += scanningTimeMs / 1000 * mPowerProfile.getAveragePower(
                PowerProfile.POWER_RADIO_SCANNING);
        BatterySipper bs =
                addEntry(getString(R.string.power_cell), DrainType.CELL, signalTimeMs,
                R.drawable.ic_settings_cell_standby, power);
        if (signalTimeMs != 0) {
            bs.noCoveragePercent = mStats.getPhoneSignalStrengthTime(0, uSecNow, mStatsType)
                    / 1000 * 100.0 / signalTimeMs;
        }
    }

BatterySipperにどの用途でどれぐらいの電力消費があったかを計算して登録する処理を行なっている。

addEntryで登録を行なっているのでそこから逆に読んでいく。

addEntryの引数は

    private BatterySipper addEntry(String label, DrainType drainType, long time, int iconId,
            double power) {

とあるので、最後のpowerが消費電力。powerは+=で足し合わせて2パートからなっており、前半ではシグナル強度の5段階(BatteryStats.NUM_SIGNAL_STRENGTH_BINS)ごとの時間と消費電力の積を合算している。

後半ではスキャンの時間とそのときの電力消費の積を足している。今回の症状から電波を掴んでいる状態での電力消費ではなく、スキャンで浪費していると推測されるので問題は後半のPOWER_RADIO_SCANNINGだろう。

どの状態のときにどれぐらい電力消費があるかという情報はPowerProfileというクラスで定義されており、各ステートと電力消費の対応はxmlから読み込んでHashMapとして保持している。

xml自体ももちろん配布系に含まれており

./frameworks/base/core/res/res/xml/power_profile.xml

に実際の数字が書いてある。が、これは端末ごとに異なるはずなので各機種版もあり各モデル毎のバイナリを作るときに差し替えているはず(読んでない)。例えば

./device/htc/heroc/overlay/frameworks/base/core/res/res/xml/power_profile.xml

とかはディレクトリ名からHTC Hero用。特に各機種版のxmlを読むとradio.scanningとradio.onの消費電力がそれぞれ分かる。同じくHTC Heroから読むと

  <item name="radio.scanning">70</item>
  <array name="radio.on"> <!-- Strength 0 to BINS-1 -->
      <value>3</value>
      <value>3</value>
  </array>

とあり、スキャン中は70mAで掴んでいるときは強度に依らず3mAとある。機種ごとに多少の大小はあるものの、スキャン中はどれも70から88と非常に電力を消費するのに対してradio.onの状態ならば20分の1以下の小さい電力で済むようだ。

フィーチャーフォン時代にも圏外となる状態で電源を入れていると基地局を探すために電池の持ちが悪くなるという話はよく聞いたので、これはそれとも合致する。

以上から、mStats.getPhoneSignalScanningTimeが非常に大きな値を返しているのではないかと推測される。文字通りスキャンに時間を消費してしまって電力を浪費しているのだろう。

(続くかもしれない)

ツイートする

Permalink | コメント(0) | トラックバック(0)