シャッフル主任の進捗報告

興味のあるものを作ります。進捗を不定期にご報告します。

そうだ、教祖になろう。出エジプト記 第4章1節 Cloud9にVue.js開発環境を導入する

「どうして、この山のような仕事を一人だけで片づけようとするのか。」


第3章が長かったせいでシナイ半島をだいぶさまよった気になりましたが、まだサーバサイドがなんとか動いただけです。

預言します。

 

「おお、見よ!第4章はもっと長くなるであろう!」

 

海ならぬ腹を割ったところで、クライアントサイドの準備をしていきましょう。

創世記で触れましたが、Vue.jsとはSPAフレームワークです。
といっても、結局ブラウザで動くのはHTMLとJavaScriptCSSでしかありません。
Vue.jsで書いたソースをコンパイルして配信する静的コンテンツを生成します。
言語から他言語へのコンパイルなので、トランスパイルと言います。

それではVue.jsの開発環境であるVue CLIをnode.jsで導入します。
node.jsはサーバサイドJavaScript環境です。

Cloud9にも入っています。さすが。
バージョンを見てみましょう。
デフォルトのパッケージマネージャのnpmも見ます。

$ node -v
v10.17.0
$ npm -v
6.11.3

ちょっと古いですね。
最新化します。

$ nvm install v13.3.0
$ nvm alias default v13.3.0
$ node -v
v13.3.0
$ npm update -g npm
$ npm -v
6.13.4

npmより速いパッケージマネージャのyarnをインストールします。
npmもだいぶ早くなったようですが、いまだyarnの方が早いようです。

qiita.com

$ npm install -g yarn
$ yarn -v
1.21.1

2年前はyarn initでプロジェクトを作ったのですが、最新ではvueコマンドが便利になっているようです。
そちらでやってみます。

qiita.com

Vue.js開発環境であるVue CLIをインストール。

$ yarn global add @vue/cli
$ vue -V
bash: vue: command not found

はい、パスが通っていないので.bashrcPATHyarn global binの結果を追加します。
PATHに直接yarn global binと書くとターミナルを開きなおしたときにyarnが認識されないっぽいので結果を書きました。

export PATH="$PATH:$HOME/.rvm/bin:/home/ec2-user/.yarn/bin"

Window→New Terminalでターミナルを開きなおしてみます。

$ vue -V
@vue/cli 4.1.1

うん、パスが認識できています。
それでは、Vue.jsプロジェクトを作成します。

$ vue create clientside

f:id:chief-shuffle:20191219140021j:plain

設定値はこんな感じかなー。
使わないかもしれないのは入れない方がいいかなー。
2年前はいちいち1個ずつ入れてた気がします。

  • preset:Manually select features
  • features:Babel, Router, Vuex, CSS pre-processors, Linter / Formatter, Unit Testing, E2E Testing
  • history mode:Yes
  • CSS pre-processors:Stylus
  • linter / formatter:Prettier
  • additional lint features:Lint on save
  • unit testing:Jest
  • E2E testing:Nightwatch
  • browsers:Chrome
  • config :In package.json
  • Save:N

「こんなやり方を続けていたら、あなたのほうがまいってしまうよ。」


インストールが終わりました。

f:id:chief-shuffle:20191219214138j:plain

1 error found.

E2E Testing系のjsでエラーですね。
console.log()が認識されないことってある?
まあいいか。E2Eやるときに考えましょう。

Vue CLIのサーバを起動します。

yarn serve

画面を確認してみます。
http://localhost:8080/とか表示されますが、Cloud9なので当然アクセスできません。
Preview」メニューから「Preview Running Application」で起動します。

f:id:chief-shuffle:20191219223035j:plain

はいー、セキュリティ制限に引っ掛かりました。
「Invalid Host header」です。
プロジェクトフォルダ直下にvue.config.jsを作成します。

module.exports = {
  devServer: {
    disableHostCheck: true
  }
}

もっかい起動&プレビュー。

f:id:chief-shuffle:20191219221505j:plain

表示できました。

「何もかも一人で片づけるには、荷が重すぎるのではないかな。」


ちなみにプロジェクトフォルダ直下に作成されているsrc/App.vueの一部(HomeAboutの部分)をいじると、

f:id:chief-shuffle:20191219221953j:plain

ホットデプロイが走って、プレビューをリロードすると変更が反映されてます。

f:id:chief-shuffle:20191221085744j:plain

よしよし。

ん、App.vueシンタックスエラーが出てますね。
.vueファイルの<style>タグ内のStylus記述を理解できていないようです。
エディタ右下のHTMLを「Stylus」に変更します。

f:id:chief-shuffle:20191221090123j:plain

他の.vueファイルもエラーが出てるファイルも「Stylus」に変えて、
あと、エラーが出てるやつは…

f:id:chief-shuffle:20191221090430j:plain

む。src/router/index.jsでパースエラーです。
Unexpected token importと出ています。
「こんなところでimportすんじゃねぇ、このすっとこどっこい!」と怒られています。
Vue CLIを起動するときは怒られないので、Cloud9の設定はESLintと少し違うようです。
力技ですが、「Preference」の「Hint & Warning」で「Ignore Message Matching」の欄にUnexpected token importを入れて警告を消しました。

f:id:chief-shuffle:20191221090938j:plain

Cloud9はJavaScriptをサポートしているのですが、Vue.jsは管轄外らしく、警告の消し方を調べるのに時間が掛かりました。
4章のはじめからこれではこの先思いやられますが、あせらず地道にやっていきましょう。

そうだ、教祖になろう。出エジプト記 第3章8節 サーバサイドを自動テストする

銀にはるつぼ


3章もだいぶ長くなりました。
今回も第3章7節 Cloud9のLambdaで共通処理を持つに引き続き、普通の内容かもしれません。

サーバサイドの処理が多くなってきたのでコードをテストします。
これから何回も変更が入るので、いちいち自分でテストなんかしてられません。
自動テスト機構を構築します。

やり方はサーバレスでない通常の開発と同じです。
今回はCloud9のローカル環境でテストを走らせます。
いずれAWSのCodeDeployでデプロイする前にCodeBuildでテストを走らせたいのですが、今のところデプロイはCloud9で十分なので、とりあえず泥臭くやっちゃいます。

Pythonの自動テストはunittestパッケージを使います。

金には炉


まずわかりやすいところで、 第3章4節 Lambdaでサーバサイドを実装するで作ったLifeReaderクラスのテストを作ります。
なお、今回やるのはモジュール単位のテストです。
クライアントも含めた結合テストはあとで考えます。

Lambdaアプリケーション配下にtestフォルダを作成し、配下にテストモジュールとして.pyファイルを作成します。

f:id:chief-shuffle:20191217193800j:plain

いきなりソースを載せてしまいます。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '../lib'))
sys.path.append(os.path.join(os.path.dirname(__file__), '../rebirth'))

import unittest
from unittest import TestCase, mock
from unittest.mock import patch, MagicMock
import gspread
from lifereader import LifeReader


class TestLifeReader(TestCase):
    def test_random_default(self):
        row_values = [
            '', 'アジアの小国の王様', '1000', '500', '10', '年前', '安定した治世で民に敬われながら', '',
            '40', '60', '1', '歳で'
        ]
        worksheet = MagicMock()
        worksheet.col_values = MagicMock(return_value=['who', 'row2'])
        worksheet.row_values = MagicMock(return_value=row_values)
        spreadsheet = MagicMock()
        spreadsheet.sheet1 = worksheet
        gclient = MagicMock()
        gclient.open = MagicMock(return_value=spreadsheet)
        with patch('gspread.authorize', return_value=gclient):
            record = LifeReader().random()
            self.assertEqual(gclient.open.call_args_list[0][0][0], 'シャッフル再生教')
            self.assertEqual(worksheet.row_values.call_args_list[0][0][0], 2)
            self.assertEqual(record['who'], 'アジアの小国の王様')
            self.assertEqual(record['birth-min'], '1000')
            self.assertEqual(record['birth-max'], '500')
            self.assertEqual(record['birth-step'], '10')
            self.assertEqual(record['birth-unit'], '年前')
            self.assertEqual(record['way-of-life'], '安定した治世で民に敬われながら')
            self.assertEqual(record['cause-of-death'], '')
            self.assertEqual(record['death-min'], '40')
            self.assertEqual(record['death-max'], '60')
            self.assertEqual(record['death-step'], '1')
            self.assertEqual(record['death-unit'], '歳で')


if __name__ == '__main__':
    unittest.main()

テスト対象およびテストに必要なクラス群をインポート。
test_メソッド名_defaultという疎通用のテストメソッドをとりあえず1つ作りました。

テスト対象のLifeReader().random()を呼ぶ前にごちゃごちゃやっているのは、モックオブジェクトの準備です。
テスト対象クラスが他のモジュールを呼んでいると、異常系を発生させづらかったり、テストのたびに通信したりするので、呼ぶ先のモジュールをダミーに置き換えています。
これをやってくれるのがmockパッケージで、戻り値を指定したり、パッケージに渡した引数をアサートしたりできます。

例えば、テスト対象のLifeReader.random()はちょいと複雑です。
gspread.authorize()でもらったクライアントオブジェクトでスプレッドシートオブジェクトを取得して、そこからワークシートオブジェクトを取得してメソッドを呼び出すといった具合。

        gclient = gspread.authorize(credentials)
        spreadsheet = gclient.open(settings.GSPREAD['spredsheet-title'])

        worksheet = spreadsheet.sheet1
        count = len(worksheet.col_values(2)) - 1

        row = random.randint(2, count + 1)
        values = worksheet.row_values(row)

これをシミュレートするためにモックのメソッドにモックを設定して、さらにそれを別のモックに設定して、最終的にローカル変数gclientに集約しています。
この辺のことです。

        worksheet = MagicMock()
        worksheet.col_values = MagicMock(return_value=['who', 'row2'])
        worksheet.row_values = MagicMock(return_value=row_values)
        spreadsheet = MagicMock()
        spreadsheet.sheet1 = worksheet
        gclient = MagicMock()
        gclient.open = MagicMock(return_value=spreadsheet)
        with patch('gspread.authorize', return_value=gclient):

このテストメソッドでは、Googleスプレッドシートのデータが1行だけある状態を想定し、col_valuesの戻り値にヘッダ行を含めて2つの要素の配列を返しています。

gclientオブジェクトをwithで仕込んだ後でテスト対象を呼び出します。
呼んだ後はself.assert~メソッドを使って、テスト対象の中でパッケージに渡された値と戻り値をアサートしています。

心を試すのは主


それでは、実行してみましょう。

f:id:chief-shuffle:20191217195108j:plain

Ran 1 test in 0.005s

OK

と表示されてテストが通ったことが分かります。

と簡単にできたように書いてますが、実はモックをここまで準備するのが結構大変でgspreadパッケージのメソッドの引数や戻り値の型を実装しているとき以上に丹念に調べたりします。

悪事をはたらく者は悪の唇に耳を傾け


これをテスト対象のモジュールごとに実装していくのですが、テスト対象をどの程度テストできてるか測定したいですね。
Pythoncoverageパッケージを導入します。

sudo python3.6 -m pip install coverage

パスが通っていないというような警告がでることがありますが、

  WARNING: The scripts coverage, coverage-3.6 and coverage3 are installed in '/usr/local/bin' which is not on PATH.
  Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.

一度ターミナルを開きなおすと認識されています。

ec2-user:~/environment $ coverage
Code coverage for Python.  Use 'coverage help' for help.
Full documentation is at https://coverage.readthedocs.io

レポートを出力してみます。

パッケージ各種を対象外にするため、testフォルダに.coveragercファイルを作成します。

[run]
omit = 
    /home/ec2-user/.local/lib/*
    /usr/local/*

[report]

テストモジュールごとにテストを起動し、結果を結合してから標準出力にレポートします。
ut_lifereader.pyが触るテスト対象とカバレッジ率がリスト化されます。

coverage run -p ut_lifereader.py
coverage combine
coverage report

f:id:chief-shuffle:20191217203134j:plain

テストモジュールごとに起動するのはかったるいので、存在するテストモジュールをすべて起動したあとcoverageのレポートをHTML出力するようShellを組みました。
最後にFailになったテストモジュール数とテストメソッド名を表示するようにしてあります。

#!/bin/bash
fails=0
methods=()
for p in `ls ut_*.py`
do
  echo "■ Test Module:" $p
  stdout=`coverage run --rcfile=.coveragerc -p $p 2>&1`
  if [ $? != 0 ]
  then
    fails=$((fails+1))
    methods+=( " - $p: `echo "$stdout" | grep "FAIL: " | cut -d " " -f 2 `")
  fi
  echo "$stdout"
done
coverage combine
coverage report
coverage html
echo "Fail TestModules: " $fails
echo "Fail TestMethods: " ${#methods[*]}
IFS=$'\n'
echo "${methods[*]}"
echo
echo
echo

なぜか最後の2行の標準出力が消えるので、無駄に3行ほどechoしてます。

実行します。
Cloud9は何でもRunボタンで実行できますね。

f:id:chief-shuffle:20191217203325j:plain

偽る者は滅亡の舌に耳を向ける


レポートはhtmlconvフォルダに出力されています。
index.htmlをプレビューして結果を見てみましょう。

f:id:chief-shuffle:20191217203421j:plain

モジュールごとのリンクをたどるとテストが通ったところが緑に表示されています。
あとはその他すべてのモジュールのテストモジュールを作るだけです。
カバレッジが100%に近づいていくと嬉しい感じがしますが、データパターンや異常系の網羅を忘れてはいけません。

通知クラスでSNSオブジェクトを作るときにboto3パッケージが必要なのでpipでインストールしておきます。

災いのときに喜ぶ者は赦されない


着々とテストを実装していきますが、難関はデコレータです。
トレースロガーは@classmethod@instancemethodにも適用したかったのですが、callableではない、つまりインスタンスメソッドやfunctionと違ってオブジェクトそのものを起動できないらしく、一旦あきらめました。
テストしてみないとわからないことってあるものです。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '../lib'))

import unittest
from unittest import TestCase, mock
from unittest.mock import patch, MagicMock
import logging
from tracelogger import trace


class TestTraceLogger(TestCase):
    def test_trace_instancemethod(self):
        info = MagicMock()
        with patch.object(logging.RootLogger, 'info', info):
            result = TraceClass().instancemethod('a',
                                                 2,
                                                 third='three',
                                                 fourth=4)
            self.assertEqual(result, 'instancemethod')
            self.assertRegex(
                info.call_args_list[0][0][0],
                '.*TraceClass.instancemethod.*\'a\', 2.*\'third\': \'three\', \'fourth\': 4'
            )
            self.assertRegex(
                info.call_args_list[1][0][0],
                '.*TraceClass.instancemethod.*time.*result.*instancemethod')

    def test_trace_function(self):
        info = MagicMock()
        with patch.object(logging.RootLogger, 'info', info):
            result = function('a', 2, third='three', fourth=4)
            self.assertEqual(result, 'function')
            self.assertRegex(
                info.call_args_list[0][0][0],
                '.* function.*\'a\', 2.*\'third\': \'three\', \'fourth\': 4')
            self.assertRegex(info.call_args_list[1][0][0],
                             '.* function.*time.*result.*function')


class TraceClass():
    """
    # そもそもデコレータが通らない
    @trace
    @staticmethod
    def statmethod(first, second, third, fourth):
        return 'staticmethod'

    @trace
    @classmethod
    def clsmethod(cls, first, second, third, fourth):
        return 'classmethod'
    """
    @trace
    def instancemethod(self, first, second, third, fourth):
        return 'instancemethod'


@trace
def function(first, second, third, fourth):
    return 'function'


if __name__ == '__main__':
    unittest.main()

カバレッジ100%になりました。

f:id:chief-shuffle:20191217204115j:plain

とりあえず、この辺でサーバサイドはひと段落です。
次はクライアントサイドをやっていこうと思います。

そうだ、教祖になろう。出エジプト記 第3章7節 Cloud9のLambdaで共通処理を持つ

持てるものは与へられて益々豊かならむ


第3章5節 LambdaのログをCloudWatch Logsに出力するでトレースログを実装しました。
第3章6節 CloudWatch LogsをSNSで通知するで作成したSNS通知用のLambda関数にもこれを適用したいのですが…

1つ問題があります。

通常、LambdaはLayersという領域にZIP化した共通処理をアップロードすると、各関数でその共通処理を使えるようになります。

が、Cloud9はLayersに対応していません。

ということで、AWSから推奨されるのかわかりませんが、非常に泥臭いやり方で処理を共通化したいと思います。

されど持たざるものは,その持てるものをも取らるべし


Lambdaアプリケーション配下に共通処理用のフォルダを作成します。
Lambda関数は、Cloud9で見えているこのフォルダでではなく、/var/task/配下にデプロイされてから実行されるため、Lambdaアプリケーション配下以外に配置してしまうと、実行時に参照できません。
作成したフォルダに第3章5節 LambdaのログをCloudWatch Logsに出力するで作ったトレースログ処理を移動します。

f:id:chief-shuffle:20191214145503j:plain

一方、それを読み込む側である通知用のLambda関数のlambda_function.pyではsys.path.append()で共通処理用のフォルダをインポート対象フォルダに追加します。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '../lib')) # 共通処理用のフォルダ
sys.path.append(os.path.join(os.path.dirname(__file__), '.'))

# 中略

from tracelogger import trace

# 中略


@trace # 共通処理用のデコレータ
def lambda_handler(event, context):
    # 処理

では、Lambda(local)で実行してみます。

f:id:chief-shuffle:20191214145601j:plain

SNS通知用のLambda関数でもトレースログが出力できました。

元々トレースログを呼んでいたLambda関数でも同じように、パスへ共通フォルダを追加しておきます。

ちなみに、途中で削除や移動したはずのファイルが何度デプロイしてもLambdaから消えない現象が発生したのですが、Lambdaアプリケーションフォルダ配下にある.debugという隠しフォルダに過去ファイルが残っているからでした。
.debug配下のファイルを削除すると、Lambdaにも反映されました。

今回、本当はLayersを使ってかっこよく共通化しようとしたのですが、Layersを使えないCloud9内で共通処理を認識する方法が見つからず、いたって普通のフォルダ構成になりました。
いつの日かCloud9でLayersが読めるともっときれいに共通化できそうです。

そうだ、教祖になろう。出エジプト記 第3章6節 CloudWatch LogsをSNSで通知する

しろやぎさんからおてがみついた


第3章5節 LambdaのログをCloudWatch Logsに出力するでLambdaのログがCloudWatchに出力されているのを確認しました。
開発中はいちいち見るでもいいのですが、思いもよらぬところで出たエラーは見過ごしてしまいます。
ので、AWSに知らせてもらうことにしましょう。

CloudWatch Logsで特定のキーワードを含むログをLambdaに渡してSNS(Simple Notification Service)でメール通知します。

このような構成です。

f:id:chief-shuffle:20191213210107p:plain

ネット上にはCloudWatch AlarmからSNS経由でLambdaに連携する例もあったのですが、今回はCloudWatch Logsのサブスクリプションフィルターから直接Lambdaを起動しています。

くろやぎさんたらよまずにたべた


では、SNSから作っていきます。
「トピックの作成」をクリック。

f:id:chief-shuffle:20191213222214j:plain

トピック名を入力。
この下に連絡先であるメールアドレスをぶら下げます。

f:id:chief-shuffle:20191213221756j:plain

サブスクリプションの作成」をクリック。
「詳細」で以下を入力。

  • トピックARN:さっき作ったトピック
  • プロトコル:Eメール
  • エンドポイント:自分のメールアドレス

f:id:chief-shuffle:20191213221725j:plain

通知のサブスクリプション(購読)案内のメールが届きますので「Confirm subscription」で承諾します。

f:id:chief-shuffle:20191213221834p:plain

購読開始のメッセージが表示されます。

f:id:chief-shuffle:20191213221848p:plain

サブスクリプションが「確認済み」になります。
ちなみにエンドポイントのメールアドレスを入れ間違えると承諾も削除もできなくなり、3日後に復活…することなくAWSにより削除されます。

f:id:chief-shuffle:20191213222311j:plain

しかたがないのでおてがみかいた


次にSNSに通知を指示するLambda関数を作成します。

Cloud9で「AWS Resources」から「λ+」ボタンをクリック。

  • Lambda関数名:それっぽい名前
  • Lambdaアプリケーション名:serverside(rebirthと同じ)
  • ランタイム:Python3.6
  • Blueprint:empty-python
  • メモリ:128MB
  • Role:Automatically generate role

f:id:chief-shuffle:20191213233931j:plain

この通知用の関数でログイベントを整形してSNSに渡すのですが、引数のeventはどんな形なのでしょうか。
それを確認するためにこのlambda_function.pyを以下のように変えてみます。

def lambda_handler(event, context):
    print(event)
    return ''

通知元のLambda関数のエラーログを今作った通知用のLambdaに渡してみます。
CloudWatchの「ロググループ」で通知元のログを選択し、「AWS Lambdaへのストリーム」をクリック。

f:id:chief-shuffle:20191213234405j:plain

通知用のLambda関数を選択。

f:id:chief-shuffle:20191213234524j:plain

通常ログもすべて流し込むとLambda起動費用がかさんでしまいますので、エラーログだけを連携するようにフィルターを設定します。
「CRITICAL」か「ERROR」か「WARNING」を含む、はこのように書きます。

?CRITICAL ?ERROR ?WARNING

f:id:chief-shuffle:20191213234724j:plain

「パターンのテスト」でフィルターをテストします。
第3章5節 LambdaのログをCloudWatch Logsに出力するで発生させたログでテストすると、ERRORを1か所検知しました。

f:id:chief-shuffle:20191213234921j:plain

「ストリーミングの開始」をクリックすると、ロググループの「サブスクリプション」にLambda関数名が表示されます。

f:id:chief-shuffle:20191214070717j:plain

例によって通知元のLambdaの設定をエラーが起きるように変更してデプロイします。

f:id:chief-shuffle:20191213235308j:plain

CloudFront経由でアクセスしてみます。認証エラーが起きるので、通知用のLambdaが起動されてprint(event)により引数eventが出力されています。

f:id:chief-shuffle:20191213235545j:plain

なにやら長めの文字列が出力されているので、JSON形式のままコピーします。
Cloud9に.pyファイルを作って貼り付けます。

json = # JSONデータ

これはZLIB圧縮されてBase64文字列に変換されたログデータです。
これではよくわからないのでCloud9上で展開して中身を見てみましょう。

テストデータとして読めるように'シングルクォーテーション区切りを"ダブルクォーテーション区切りに変換します。

f:id:chief-shuffle:20191214000111j:plain

lambda_function.pyを以下のように変えます。
ZLIB&Base64をほどいてログイベントデータを出力します。

import zlib
import base64
import json


def lambda_handler(event, context):
    try:
        data = json.loads(
            zlib.decompress(base64.b64decode(event['awslogs']['data']),
                            16 + zlib.MAX_WBITS))
        log_events = json.loads(
            json.dumps(data["logEvents"], ensure_ascii=False))

        print(log_events)
    except Exception as e:
        return e

Lambda(local)で「Payload」にテストデータを貼り付けて実行すると、ログイベントの中身が見えました。

f:id:chief-shuffle:20191214000352j:plain

さらに深堀りしてみます。
lambda_function.pyを以下のように変えます。

import zlib
import base64
import json


def lambda_handler(event, context):
    try:
        data = json.loads(
            zlib.decompress(base64.b64decode(event['awslogs']['data']),
                            16 + zlib.MAX_WBITS))
        log_events = json.loads(
            json.dumps(data["logEvents"], ensure_ascii=False))

        log_messages = []
        for e in log_events:
            log_messages.append(e['message'])
        print(log_messages)

    except Exception as e:
        return e

やっと[ERROR]のエラー文言までたどり着きました。

それでは、これをSNSにPublishしたいと思います。
最終ソースはこんな感じ。

メール本文はログイベント内のmessageを連結した文字列。
メール題名は本文の最初の行ですが、長いので出力時刻とメッセージIDを除外、
接頭辞を付与した上で100文字以下というSNSという制限により、途中で切っています。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '.'))

import zlib
import base64
import json
import re
import boto3
import logging
import settings

logger = logging.getLogger()
logger.setLevel(settings.LOGGER['level'])


def lambda_handler(event, context):
    try:
        data = json.loads(
            zlib.decompress(base64.b64decode(event['awslogs']['data']),
                            16 + zlib.MAX_WBITS))
        log_events = json.loads(
            json.dumps(data["logEvents"], ensure_ascii=False))

        log_messages = []
        for e in log_events:
            log_messages.append(e['message'])
        rows = re.split('\n', log_messages[0])
        words = rows[0].split()
        del (words[1:3])

        sns = boto3.client('sns')
        topic = settings.ALARM['topic']
        message = "\n".join(log_messages)
        subject = '{}{}'.format(settings.ALARM['subject-prefix'],
                                ' '.join(words))[:100]
        response = sns.publish(TopicArn=topic,
                               Message=message,
                               Subject=subject)
        return response

    except Exception as e:
        return e

ログレベルは同ディレクトリに作ったsettings.pyで指定しています。
トピックのARNがソースにべた書きですが、CloudFormationでSNSトピックごと作れるようになるまでは一旦このまま。

import logging
LOGGER = {'level': logging.INFO}
ALARM = {
    'topic': 'SNSトピックのARN',
    'subject-prefix': 'わかりやすい文言'
}

Lambda(local)で実行してみます。

f:id:chief-shuffle:20191214001024p:plain

メールでエラーログが届きました!

拝啓、LINEでよくないっすか


それでは、これをデプロイして実際に発生したエラーをリアルタイムに通知してみます。
エラーを起こしてから、CloudWatchで通知用のLambdaのログを見ると、

f:id:chief-shuffle:20191214001147j:plain

ん?

f:id:chief-shuffle:20191214001439j:plain

おっと。

cloud9-serverside-notify-XXXX is not authorized to perform: SNS:Publish on resource: arn:aws:sns:ap-northeast-1:9999:topic-notify-error

SNSにPublishする権限がないようです。
Cloud9はCloudFormationでデプロイしているため、ロールもCloudFormationで付与しないとデプロイのたびに元に戻ってしまいます。
今CloudFormationは手に負えない気がするので、なるべく簡易に権限を付与していきます。
まず、IAMでロールを作ります。

f:id:chief-shuffle:20191214001834j:plain

「このロールを使用するサービスを選択」で「Lambda」を選択。

f:id:chief-shuffle:20191214001933j:plain

ポリシーに以下を追加。
ガバガバですが、あとで見直しましょう。

  • CloudWatchFullAccess:ロググループ、ログストリーム、ログイベント作成用
  • AmazonSNSFullAccess:SNSのPublish用

f:id:chief-shuffle:20191214002110j:plain

Cloud9でLambdaアプリケーション直下にあるtemplate.yamlを開いて、通知用LambdaのProperties属性に以下を追加します。 さっきCloud9でLambda関数作るときに指定すればよかったですね。

Role: 'さっきつくったロールのARN'

ほんでもっかいデプロイ。
デプロイに時間がかかることがあるようで、ロールが反映されているかLambda画面で確認します。

f:id:chief-shuffle:20191214002510j:plain

もう一度エラーを起こしてみると、今度はちゃんと通知メールが届きました。

CloudFormationやロールが噛むと途端にわからなくなって困ります。
いずれきれいに整理したいと思います。

そうだ、教祖になろう。出エジプト記 第3章5節 LambdaのログをCloudWatch Logsに出力する

きよしこの夜


年末ですね。
年を越すというのは何か特別な感じがしてごちそうや保存食を買い込んで帰りたくなります。
冬ごもりの間の安心感を求めるからでしょうか。

安心感はシステムにも大切です。
第3章4節 Lambdaでサーバサイドを実装するでおおよその処理を実装しましたが、まだまだ実用には耐えません。
アプリケーションが動き始めると思いもよらぬ挙動をしたりして調査に時間がかかります。
調査の助けとなるよう、処理結果をトレースするログを仕込んでいきます。

このような構成です。

 f:id:chief-shuffle:20191213192837p:plain

今回は2種類のログを仕込みます。

  • エラーが発生したときのエラーの内容
  • 関数が呼ばれたときの引数と戻り値の内容 

1つ目は開発中、運用中いずれでも重要です。
2つ目はどちらかというと開発中の調査用といった向きが強いですし量が多めになるので、運用が安定したら抑止してもいいでしょう。

すくいの御子は


Lambdaにおけるログ出力は非常に簡単です。
Pythonのloggingパッケージによる出力がCloud Watchに保存されます。
早速実装していきましょう。

メイン処理であるlambda_handler()関数の中をtryexceptで囲みます。
捕捉したエラーをlogging.error()で出力します。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '../site-packages'))
sys.path.append(os.path.join(os.path.dirname(__file__), '.'))

import datetime
import json
import traceback
import logging
import gspread
from oauth2client.service_account import ServiceAccountCredentials
import settings
from lifereader import LifeReader
from responseformatter import ResponseFormatter

logger = logging.getLogger()
logger.setLevel(settings.LOGGER['level'])


def lambda_handler(event, context):
    try:

        reader = LifeReader()
        record = reader.random()

        formatter = ResponseFormatter()
        body = formatter.format(record)

        return {
            'statusCode': 200,
            'body': json.dumps(body, ensure_ascii=False)
        }

    except Exception as e:

        logger.error('{}\n{}'.format(str(e), traceback.format_exc()))

        return {
            'statusCode': 500,
        }

ちょっと乱暴なようですが、ここに来るのは予期してないエラーなのでこんなもんです。
setLevel()で設定しているのはsettings.pyに設定したログレベルです。

LOGGER = {'level': logging.INFO}

試しにエラーを起こしてみましょう。
Googleスプレッドシートのサービスアカウントキーを変更して認証エラーを発生させます。

f:id:chief-shuffle:20191213193806j:plain

なお、次回やるSNSによるエラー通知のために環境を色々いじったのでserversideという名前でLambdaアプリケーションを作り直しています。 

御母のむねに


CloudWatchに出力されているか確認してみましょう。
Lambda関数をCloud9からデプロイします。

f:id:chief-shuffle:20191213200058j:plain

CloudWatchの「ロググループ」を確認すると認証エラーが出力されていますね。  

f:id:chief-shuffle:20191213200204j:plain

f:id:chief-shuffle:20191213204059j:plain

LambdaからCloudWatchにログ出力するにはロググループを作ったり、ログイベントを出力したりする権限が必要なのですが、Cloud9がデプロイ するときによろしくロールを作ってくれているようです。 

f:id:chief-shuffle:20191213201210j:plain

f:id:chief-shuffle:20191213201254j:plain

眠りたもう


次に関数の呼び出しと戻り値のトレースログです。
エラーログと同じように仕込むと関数内が見づらくなって保守性が落ちるので、AOP=アスペクト指向で実装していきます。

Pythonに備わっているデコレーターという機構でログ出力処理を書きます。
ざっくり言うと開始ログ→関数コール→終了ログということをやります。
tracelogger.pyという名前でデコレーターを作ります。

import inspect
import time
import logging

logger = logging.getLogger(__name__)


def trace(func):
        try:
            is_method = inspect.getargspec(func)[0][0] == 'self'
        except:
            is_method = False

        if is_method:
            func_name = '{} {}.{}'.format(func.__module__,
                                          args[0].__class__.__name__,
                                          func.__name__)
        else:
            func_name = '{} {}'.format(func.__module__, func.__name__)

        logger.info('[{}] args[{}, {}]'.format(func_name, args[1:], kwargs))
        start = time.time() * 1000
        result = func(*args, **kwargs)
        finish = time.time() * 1000 - start
        logger.info('[{}] time[{}] result[{}]'.format(func_name, round(finish),
                                                      result))

        return result

    return _trace

funcが呼ばれる関数で前後でログを出力しています。
開始ログは引数を、終了ログは処理時間(ミリ秒)と戻り値を一緒に出力してます。
関数名は

  • インスタンスメソッドの場合:[モジュール名 クラス名.メソッド名]
  • その他の関数:[モジュール名 関数名]

にしています。

できたデコレーターを各モジュールでインポートして、トレースしたいメソッドにアノテーションをくっつけます。  

インスタンスメソッドの場合はこう。

from tracelogger import trace


class LifeReader():

    @trace
    def random(self, ):
    # 処理

メイン処理もこうです。

from tracelogger import trace


@trace
def lambda_handler(event, context):
    # 処理

いとやすく


では、settings.pyの設定を正常に戻して実行してみましょう。
各関数の引数、処理時間、戻り値が出力されていますね。
これで安心して年を越せそうです。  

f:id:chief-shuffle:20191213203748j:plain

次回は出力したログからエラー通知メールを送れるようにしたいと思います。

そうだ、教祖になろう。出エジプト記 第3章4節 Lambdaでサーバサイドを実装する

山の神 海の神 今年も本当にありがとう


前回の第3章3節 Lambdaでサーバサイドを実装できないUnicodeエンコーディングという後顧の憂いを断ちましたので、いよいよプログラミング祭の始まりです。

まずは、ざっくりクラス図を描きました。
読む人と返すために整える人。
あとでもうちょっと複雑化する気もしますが、今はこれでいいでしょう。

f:id:chief-shuffle:20191210210708p:plain

白い褌ひきしめた 裸若衆に雪が舞う


まずはGoogleスプレッドシートからランダムで1行取得するクラスです。
空でない行数をカウントして、ヘッダ行数を除いて2行目〜最大行目のうち、1レコードを辞書オブジェクトで返します。
取ったままの配列でもいいんですが、一応。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '.'))
import random
import gspread
from oauth2client.service_account import ServiceAccountCredentials
import settings


class LifeReader():

    def __init__(self, ):

    def random(self, ):
    
        credentials = ServiceAccountCredentials.from_json_keyfile_dict(
            settings.GSPREAD['account-key'], settings.GSPREAD['scope'])
        gclient = gspread.authorize(credentials)
        spreadsheet = gclient.open(settings.GSPREAD['spredsheet-title'])

        worksheet = spreadsheet.sheet1
        count = len(worksheet.col_values(2)) - 1

        row = random.randint(2, count + 1)
        values = worksheet.row_values(row)

        return {
            'who': values[1],
            'birth-min': values[2],
            'birth-max': values[3],
            'birth-step': values[4],
            'birth-unit': values[5],
            'way-of-life': values[6],
            'cause-of-death': values[7],
            'death-min': values[8],
            'death-max': values[9],
            'death-step': values[10],
            'death-unit': values[11]
        }

ちなみにブログのソースコードのスタイルを変えてみましたが、見やすいでしょうか。

次に1レコードをもらってクライアントに渡すレスポンスを作るクラス。

import random


class ResponseFormatter():

    def __init__(self, ):

    def format(
        self,
        record,
    ):
        list = []

        try:
            birth = '今から{}{}'.format(
                random.randrange(int(record['birth-max']),
                                 int(record['birth-min']),
                                 int(record['birth-step'])),
                record['birth-unit'])
        except:
            birth = record['birth-min']

        try:
            death = '{}{}'.format(
                random.randrange(int(record['death-min']),
                                 int(record['death-max']),
                                 int(record['death-step'])),
                record['death-unit'])
        except:
            death = record['death-min']

        list.append('あなたは{}に生まれ変わりました。'.format(record['who']))
        list.append('{}は{}に生まれました。'.format(record['who'], birth))
        list.append('{}生き'.format(record['way-of-life']))
        list.append('{}{}死にました。'.format(record['cause-of-death'], death))

        return list

正直こんな規模ならモジュール分割しなくてもいいんでしょうが、クラス化すると処理が擬人化されるみたいで可愛いですよね。

ね。

コードの匂いのしみこんだ 倅その手が宝物


settings.pyに諸々の定数を寄せました。
あとでProd用とStage用で設定分けるのもいいですね。

GSPREAD = {
    'account-key': {
        # Googleスプレッドシートのサービスアカウントキー
    },
    'scope': ['https://www.googleapis.com/auth/drive'],
    'spredsheet-title': 'シャッフル再生教'
}

あとはメイン処理。
2クラスを呼ぶだけです。

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__), '../site-packages'))
import datetime
import json
import gspread
from oauth2client.service_account import ServiceAccountCredentials
sys.path.append(os.path.join(os.path.dirname(__file__), '.'))
import settings
from lifereader import LifeReader
from responseformatter import ResponseFormatter


def lambda_handler(event, context):

    reader = LifeReader()
    record = reader.random()

    formatter = ResponseFormatter()
    response = formatter.format(record)

    return {
        'statusCode': 200,
        'body': json.dumps(response, ensure_ascii=False)
    }

実行してみます。 きちんと要素4の配列でレスポンスが返ってます。

f:id:chief-shuffle:20191210212249j:plain

祭の後のうら寂しさ。
興奮冷めやらない感覚ですが、ひとまずこれで終わりです。
画像を返したり、Googleスプレッドシートを論理削除したりは別の機会に。

そうだ、教祖になろう。出エジプト記 第3章3節 Lambdaでサーバサイドを実装できない

Can you speak Japanese?


さあ、それでは楽しい楽しいコーディングの時間…

のはずだったのですが、問題が発生してしましました。

API Gatewayのレスポンスが文字化けしてしまいます。
というか、日本語部分がUnicodeエンコードされています。

f:id:chief-shuffle:20191207150016j:plain

しかし、Cloud9のAPI Gateway(local)やAPI Gatewayのテストではエンコードされず表示されます。
これはCloud9やAPI Gatewayがうまいことデコードしてくれていそうです。
ブラウザにも同じようにデコードを指示したいものです。

f:id:chief-shuffle:20191207150316j:plain

f:id:chief-shuffle:20191207150306j:plain

API Gateway 文字コード」で調べるに、API Gatewayのレスポンスヘッダにcharset=utf-8を埋め込めば解決する気もするのですが、

dev.classmethod.jp

どうも、API Gatewayの画面仕様が変わっているらしく、もくは私の設定がおかしいらしく、マッピングテンプレートの指定項目が見当たりません。

f:id:chief-shuffle:20191209091517j:plain

無理やりソースでレスポンスヘッダに以下を指定してみましたが、状況変わらずです。

        'headers': {
            'Access-Control-Allow-Origin': '*',
            'Content-type': 'application/json; charset=UTF-8'
        },

f:id:chief-shuffle:20191209092853j:plain

Ты говоришь по-японски?


ロシア語で悩むほど困っていたのですが、原因は単純でした。

こちらのサイトに掲載されている通り、

www.sejuku.net

json.dump()関数によって日本語文字列がUnicodeエンコードされていましたので、

このように、第2引数に"ensure_ascii"を”False”を指定してやると、

f:id:chief-shuffle:20191209091954j:plain

f:id:chief-shuffle:20191209091938p:plain

Ура!!!

思わぬところで教祖のへっぽこぶりが露呈してしまいましたが、次こそはスーパープログラミングタイムをお届けしたいと思います。