ディープラーニングで写真チェックしてみる

こんにちは、田中です。

今日はディープラーニングを使ったピンぼけ写真検出について書いてみます。

るくみー撮影アプリの課題

るくみー写真アップ用 on the App Store

弊社では保育士の方にiPodアプリを提供し、アプリを使って園内の日常写真を撮ってもらっています。 自動的にサーバーにアップロードされ、その後も簡単に保護者へ公開・販売できるので写真の管理がとても楽になります。

簡単、手軽、気軽に日常写真を撮れるのはよいのですがピンぼけ写真など公開に適さない写真もたくさん含まれてしまいます..。( ；∀；)

現状はこれらを1枚1枚チェックして公開/非公開を選別する必要があり、相応の負担となっています。><

これを流行りのディープラーニングを使って自動化しようというのが今回の試みです。

今回はいくつかある公開NG写真の種別のうちピンボケ写真だけを対象としています。

ピンぼけ写真とそうでない写真

着目したのは画像の周波数成分です。

正常写真	ピンぼけ写真
高周波成分を含む （エッジ部分が鮮明）	高周波成分を含まない （エッジ部分がのっぺりしている）

これにFFT (Fast Fourier Transform) をかけて周波数を画像として可視化してみます。

正常写真(FFT)	ピンぼけ写真(FFT)

おお、明らかに違います。分類できそうな気がしてきます。(*´Д`)

FFTのコードは以下の記事を参考にしました。

yaritakunai.hatenablog.com

正直なところ、ディープラーニングを使わずともSVMなどの検出器で分類できそうな気はします。。

が、ディープラーニングの勉強も兼ねているのでディープラーニングを使います。

学習データセット

学習につかった写真の枚数は以下の通りです。

	正常写真	ピンぼけ写真
ラベル	0	1
枚数	9000	9000

正常写真は実際にるくみー撮影アプリからアップロードされた写真を適当にピックアップして使い、ピンぼけ写真は正常写真にガウシアンフィルタをかけて人工的に作りました。

学習モデル

モデルはMNISTの分類で使ったものを使い回しているだけで適当です。。　(;^_^A

ディープラーニングのライブラリは chainer を使いました。 国産のライブラリでコードも直観的に書けるので気に入っています。

学習は 20 epochs 回し、GPU使って 約90秒、CPUだと 約10分でした。 CPUでも十分学習できます。

評価

正常写真 と ピンぼけ写真 をそれぞれ 50 枚ずつピックアップして評価しました。 ピンぼけ写真は NG写真と判定されている写真の中からぼけを含む写真を適当に選んでいます。

	ピンぼけ写真	正常写真
「ぼけ写真」と判定した数	28	0
「正常写真」と判定した数	22	50

モデルも学習データセットの作りも適当なこともあり、ピンぼけ写真の分類性能はそこそこです。 ただ、特筆すべきは正常写真をピンぼけ写真として誤分類することがなかったということでしょう。 これはつまり実用性が高いことを意味しています。

ちなみに、ピンぼけ写真を正常写真と分類してしまったのは被写体の一部だけがぼけていた写真などが多かったです。 全体的にぼけた写真を学習させたのでこれは仕方ないですね。。

API & ボット

せっかくなので Heroku 上にAPIとして実装して社内のslackチャンネルからボット経由で使えるようにしてみました。 :-)

さいごに

私は参加してないのですがつい先日2/21, 22に「CNET Japan Live 2017 ビジネスに必須となるA.Iの可能性 」というイベントが開催されたようです。 そのWebページ上で 「導入前に知っておきたいAI活用のコツ～賢くコスト削減するには～」というタイトルで講演を行ったLIPの松村さんの発表スライドを見つけました。

https://japan.cnet.com/storage/2017/03/06/643b6711c05f9cb45f7fd46c3201d504/l03.JPG （写真引用元）

写真チェックとAIの相性はかなり良いのではと思います。(￣ー￣)

ピンぼけ写真以外のNG写真の検出にもチャレンジしていきたいと思います。

月に一度のBeer Bash

　こんにちは、赤沼です。今回はユニファ開発部で行なっている取り組みの一つの、Beer Bashについてご紹介させていただきます。

開発部 Beer Bash

　ユニファ システム開発部では、毎月下旬の金曜日の夜に、社内イベントとして Beer Bash を開催しています。これは昨年（2016年）の10月から始めたもので、今のところ5ヶ月間毎月開催しています。

ビール片手にLT大会

　内容としては、ビールでも飲みながら、テーマは自由でLTしましょう、というものです。最初はみんな気軽に参加できるように、とりあえず会社近くのなか卯で唐揚げ100個ぐらいと、カクヤス等でビールを手配して、イベント名も唐揚げBeer Bashとしていましたが、当日急遽参加できなくなるメンバーが多かったりすると予約していた唐揚げがかなり余ってしまったりしたので、現在は各自食べたいものを調達して集まるというスタイルにしています。

　LTの内容は自由で、仕事に全く関係なかったり、技術的な内容でなくてもOKです。今までのLTの内容の例としては下記のようなものがありました。

• これさえやればマテリアルデザイン
• tensorflowを使って遊んでみたはなし
• BLE nanoでLチカしました報告
• ガチャのためのコインをひたすら稼ぐ話
• AmazonDashButtonで遊んでみた
• 園内ドキュメンテーションとるくみーの可能性　などなど

　上記以外も含めてどれもメンバーの個性が出ていてとても面白い内容でした。

参加は自由

　開催時間を業務時間外としていることもあり、参加は任意です。毎月Confluence（社内Wiki）にイベントのページを作って、参加したい人はそこに名前とLTのテーマを書いてもらうようにしています。LTなしで聞くだけでもOK。最初はどれぐらい集まるかわかりませんでしたが、毎回一定数以上のメンバーが参加してくれています。こういったイベントは強制的に参加させられてもあまり意味がないと思っていますし、任意参加でメンバーが集まらなくなったら終了、もしくは違う形のイベントに変更ということにしようと思っています。

開発メンバーも自己発信は重要

　Beer Bashを始めた目的としては、下記のようなものがあります。

• 業務以外での気軽な交流の場を増やす
• 他のメンバーがどんなことに興味があるのか、どんなことに詳しいのかを知ることができる
• プレゼンの練習の場とすることができる
• ビールと唐揚げ

　開発メンバーは普段の仕事ではあまりプレゼンのようなことをする機会がありませんが、自己発信していくことは重要だと思っています。自己発信の手段は色々とありますが、メンバーにはもし機会があれば外部のカンファレンス等でも積極的に登壇してもらいたいと思っています。そのための練習の場としても大いに活用してもらいたいと思っています。

　参加は任意としていることもあり、どれぐらい発表者がいるかわからなかったのですが、蓋を開けてみると前述のように色々なテーマでの発表があり、一応1枠10分を目安としているものの、それでは収まりきらないぐらいの内容を持ってきてくれています。（時間内に収めるというのもそれはそれで必要ですが。）

　開発部以外のメンバーも興味ある方は参加してもらってOKということにしていて、今までに参加してくれた他部署のメンバーからは、開発部メンバーの違った一面が見れて良かった、とか、自分もプレゼンしてみたいと思った、等のポジティブな感想をもらうことができました。

課題は時間と場所

　今のところ社内イベントとしてはうまくいっていて、定着してきていますが、まだ課題も残っています。まず時間帯が業務時間外の夜の時間なので、なかなか参加でいないメンバーもいます。また、ユニファは本社が名古屋なので、名古屋にも開発メンバーがいるのですが、リモートではなかなか参加しづらいイベントになっています。この時間と場所の問題を解決する方法がないかというのは今後も考えていきたいと思っています。

2020年度から小学校でプログラミング教育必修？ 今日からお家で始められるお子様向けプログラミング入門

はじめまして、ユニファ株式会社のスマートフォンエンジニアのまさと申します。 2020年からプログラミング教育が必修となります。 でもいまいち「何から始めていいかわからない。」「私算数苦手だったし。」 「スクールに通わせるにもお金がかかるし。」と悩むこともあるかと思います。 そんな時に、お家で簡単に子供と一緒に始められるプログラミングツールをご紹介します。

今回は本当に初めてのお子様にも親しみやすいブロックをつなぐような入門環境のみご紹介します。

ゲーム好きのお子様におすすめ

Scratch Jr（無料） 5歳〜7歳

ScratchJr - Home

この後紹介する、Scratchがまだ難しい子供にもっと身近にプログラミングをとKickstarterによって開発されたアプリです。 iPadやAndroidタブレットにて使用できます。 さまざまな画像や、背景、音楽が用意されていて、ブロックをつなげていくだけでキャラクターの動く物語が作れます。入門としては最適です。

プログラミン（無料） 6歳〜

プログラミン | 文部科学省

文部科学省がプログラミングをもっと身近に感じてもらうべく開発されたプログラミング学習環境です。 Webアプリであるため、ブラウザさえあれば始められます。 Scratch Jrのようにブロックをつないで、もう少し難しい「もし〜の時はこうする」 というような条件分岐を含むプログラミングができるため、簡単なゲームも作れます。

スクラッチ（無料） 8歳〜

Scratch - Imagine, Program, Share

米国マサチューセッツ工科大学のMITメディアラボが開発したプログラミング学習環境です こちらもWebアプリであるため、ブラウザさえあれば始められます。 プログラミンではできなかった変数や乱数をつかった本格的なプログラミングが可能です。 NHKの教育番組「Why！？ プログラミング」でも有名ですね。

ロボットやラジコン好きのお子様におすすめ

little bits（1万数千円〜）5歳〜

littleBits（リトルビッツ）

ちょっとプログラミングと呼ぶまではいかないかもしれませんが、ブロックを繋げることで電子工作を楽しむことができます。 少々値段がはりますが、お子様と一緒にできる難易度の低さが魅力です。 簡単に明るさセンサーで暗いときに自動点灯する懐中電灯や、動く車などを作成できます。

chibi bits（4,000円程）　6歳〜

chibi:bit - スイッチサイエンス

http://chibibit.io/ide/

chibi:bitは、BBC（英国放送協会）が主体となって作っている教育向けマイコンボードBBC micro:bitの互換機です。 Webにて開発が可能ので、ブロックを繋げるだけで、5x5のLEDの好きなところをON,OFFしたり、文字を表示したり、音楽を奏でることも可能です（別途100円ショップなどに売っているスピーカーが必要）。 使い方も簡単。chibi bitsをusbケーブルでつなぎ、PCに認識させます。 web上でブロックをつなげて開発したら、ダウンロードボタンを押して、ファイルを保存します。 そのファイルを認識させたchibi:bitに、ドラッグアンドドロップするだけです。

まとめ

とくにプログラムをしたことのない親御さんも、触ってみるとこうやってするのかと、コツをつかめてきます。 週末にお子様と初めてのプログラミングにチャレンジしてみてはいかがでしょうか。

JaSST’17 Tokyoで登壇してきました！

こんにちは、ビールが大好きなQAの鶴岡です。

先日、あの有名なJaSSTで登壇してきました！

JaSSTとは

Japan Symposium on Software Testingの略で、「ジャスト」と読みます。

2003年から開催されている国内最大のソフトウェアテストシンポジウムで日本各地で開催されています。
詳細はこちらからどうぞ。 JaSSTソフトウェアテストシンポジウム-JaSSTについて

2日間に渡って開催されたJaSST、その2日目のセッションで登壇させていただきました。

セッションの話

Web.JaSST ～ Web Service QA Meeting in JaSST ～というセッションに参加させていただきました。

これはWebサービスに関わるQA担当者の勉強会Web Service QA MeetingをJaSSTでやろうというものでした。

～ Web Service QA Meeting のコンセプト ～

ウェブサービスの開発現場では、スピードとクオリティの両立が求められます。 組み込み開発やエンタープライズシステム開発などのドメインに比べて歴史は浅いですが、その分、QA担当者は現場で高い技術と柔軟性を求められます。 「Web Service QA Meeting」 では、発表を通して知見をぶつけ合い、シナジーを起こすことで現場の技術向上のヒントを生み出すことを目的としています。

セッション会場の様子

登壇内容について

スライドがこちら。 speakerdeck.com

弊社QAの仕様改善についての動き方は特徴があるのでそこのお話をさせていただきました。
ユーザビリティを重視した仕様チェックを1周目の開発プロセス上で最低3回行っていますという話です。

詳細はスライドを見ていただくとして、
このプロセスが成り立っている理由のひとつとしては、エンジニアとQAとの信頼関係が強いからだと思っています。

載せきれなかった小話

QAが上流工程から参加する上でのエンジニアのメリット（実際に聞いてきました）

• エンジニアだけだと作りやすさで考えがち、QA視点があると◎。
• QAはほとんどの案件、機能を見ているので対応漏れがないかチェックできる。
• 基本設計時に考えた仕様で、不安な部分の相談が気軽にできる。悩む時間が減る。
• QAに渡す時に仕様説明をしなくていいから楽。
• サポートとの間に入って調整してもらえる。

→全体的に安心感がある。というお話でした。嬉しかったです。聞いてよかった。

私はエンジニアが実装に集中できるように動くことも仕事の一つだ思っています。
それもエンジニアと良い信頼関係を築けている理由かもしれません。

登壇してみて思ったこと

大勢の人の前で話すということが初めてでした。
初舞台があのJaSST！ということで緊張しましたが、本当に光栄な話で、やってよかったと思っています。
登壇後、内容について質問をいただいたり色々な方とお話しすることができてとても刺激的な2日間でした。

あと資料作るのはいいですね！
というのも、自分がやってることの整理ができるので今後の課題だったり自分が向かいたい方向を改めて確認することができたなと。
普段無意識でやってることの理由付けというか、 あー結局ユーザーに気持ちよく使ってもらいたいんだなと改めて思いました。
スライドの「QAがやりたいこと」にもありますが、
私がQAするシステムを使うことで、ユーザーが何かを得てくれるとか、ユーザーが幸せになってほしいとかなんだなと。

そんな感じでこれからもQAの枠にはあまり捕らわれず、ユーザビリティ向上のために活動していこうと思いました。

（終わったあとのビールはとても美味しかったです。）

最後まで読んでいただきありがとうございました！

ユニファのQAの取り組みと課題

こんにちは、某VRをいまも入手できないQAの駒井です。 2017年が早くも1ヶ月経過した・・・みたいなことを毎年考えている気がします。

年の経過もそうですが、私自身もユニファに入社したのが昨年の7月ですので まだ半年ほどしか経過していないのですが、それ以上の期間いるんじゃないかと思う程入社以来濃い経験をさせてもらってます。

今回はそんな自分がユニファのQAについてほんの少し紹介させていただこうと思います。

調査しやすくするためログにリクエストIDを入れましょう

はじめまして、ユニファ株式会社のWEBエンジニアのチョウと申します。

こんなことがないでしょうか。突然調査依頼が来て、あるユーザーについて調べてほしいです。大量のログから掘り出してみましたが、ユーザー何人がアクセスするによってログが混じってしまいました。RailsのログにプロセスのIDが入ってますが、１つのプロセスは連続で複数ユーザーに使われて、リクエストとリクエストの境界が見づらく、時間かかるケースよくあります。もっと問題なのは、システムは必ず１つのログファイルに出力するわけではない。リクエストログは複数のファイルに分けられてしまったら、調査自体が邪魔されるといっても過言ではない。

ここで問題をまとめましょう。

1. ユーザーあるいはユーザーのリクエストを特定したい
2. １つのリクエストが複数のログファイルに分けても分かる

ここですぐ分かる方がいるかもしれません、１つのリクエストは複数行のログを出力しているので、この複数行のログをあるIDなどでつなげればいいのです。 もっと具体的には、リクエストごとにユニークをIDを作成し、ログを出力するところ、このIDを一緒に出せば連続の行でもわかります。

request-id-1: foo
request-id-2: bar
request-id-1: foo2

ここでrequest-id-1でgrepすればプロセスID関係なくこのリクエストのログだけフィルターできます。

Rails自体はlog_tagsという設定があります。

config.log_tags = [ :uuid ]

を有効にすれば、ログにX-Request-Idの内容を出力されます。X-Request-Idはリクエスト別で作成されましたので、要望１に合ってます。

Log tagging in Rails | We Are Stac

BEFORE

Started GET "/dashboard" for 127.0.0.1 at 2014-11-24 15:48:30 +0000

AFTER

[a00c54e0-874f-4358-a7b9-accef0c407c6] Started GET "/dashboard" for 127.0.0.1 at 2014-11-24 15:48:30 +0000

これで終わり？残念ながら、この方法はRails.loggerだけに効き、複数のログファイルに通用しないです。 しかし、log_tagsのように、ログ出力するとき、X-Request-Idを入れれば解決できると思います。

そもそもX-Request-Idはどこからですか。答えはRailsのRake Middleware：ActionDispatch::RequestIdです。このmiddlewareはX-Request-Idを決め、Rackのenvに設定してます。 envの中にあると、ログを出力するところ取得しにくいため、まずthread local variableとかに保存してみます。つまり、自分でmiddlewareを作り、X-Request-Idをthread local variableに設定します。

middlewareリスト

use ActionDispatch::Static
use Rack::Lock
use #<ActiveSupport::Cache::Strategy::LocalCache::Middleware:0x007f9112ed8258>
use Rack::Runtime
use Rack::MethodOverride
use ActionDispatch::RequestId
use Rails::Rack::Logger
use ActionDispatch::ShowExceptions
use ActionDispatch::DebugExceptions
use BetterErrors::Middleware
use ActionDispatch::RemoteIp
use RailsDevTweaks::GranularAutoload::Middleware
use ActionDispatch::Callbacks
use ActiveRecord::ConnectionAdapters::ConnectionManagement
use ActiveRecord::QueryCache
use ActionDispatch::Cookies
use ActionDispatch::Flash
use ActionDispatch::ParamsParser
use ActionDispatch::Head
use Rack::ConditionalGet
use Rack::ETag
use ActionDispatch::BestStandardsSupport
use ExceptionNotification::Rack
run Foo::Application.routes

application.rb

config.middleware.insert_after 'ActionDispatch::RequestId', 'MyLogContextCollector'

class MyLogContextCollector
  def initialize(app)
    @app = app
  end

  def call(env)
    # request id from ActionDispatch::RequestId
    request_id = env['action_dispatch.request_id']
    MyLogContext.set_current_request_id(request_id)
    @app.call(env)
  ensure
    MyLogContext.clear_current_request_id
  end
end

ここでenvからX-Request-Idを取り出し、MyLogContextのthread local variableに設定します。

class MyLogContext
  TRANS_VAR_REQUEST_ID = :request_id

  attr_reader :severity # String
  attr_reader :time # DateTime
  attr_reader :program_name # String
  attr_reader :message # Object

  # @param [String] severity
  # @param [DateTime] time
  # @param [String] program_name
  # @param [Object] message
  def initialize(severity, time, program_name, message)
    @severity = severity
    @time = time
    @program_name = program_name
    @message = message
  end

  # @return [Integer]
  def get_process_id
    $$
  end

  # @param [String] format
  # @return [String]
  def get_formatted_time(format = nil)
    return nil if @time.nil?
    return @time.strftime(format) if format

    "#{@time.strftime('%Y-%m-%d %H:%M:%S')}.#{'%06d' % @time.usec.to_s}"
  end

  # @return [String]
  def message2string
    case @message
      when ::String
        @message
      when ::Exception
        "#{ @message.message } (#{ @message.class })\n" <<
            (@message.backtrace || []).join("\n")
      else
        @message.inspect
    end
  end

  class << self
    # @param [String] request_id
    def set_current_request_id(request_id)
      set_trans_var(TRANS_VAR_REQUEST_ID, request_id)
    end

    # @return [String]
    def get_current_request_id
      get_trans_var(TRANS_VAR_REQUEST_ID)
    end

    def clear_current_request_id
      set_trans_var(TRANS_VAR_REQUEST_ID, nil)
    end

    # @param [Symbol] key
    # @param [Object] value
    def set_trans_var(key, value)
      ::Thread.current.thread_variable_set(key, value)
    end

    # @param [Symbol] key
    def get_trans_var(key)
      ::Thread.current.thread_variable_get(key)
    end
  end
end

ログを出力する時、都度thread local variableであるX-Request-Idを入れるのはしたくないため、log formatのところすこし改造してみました。

logger = Logger.new('log/foo.log')
logger.formatter = MyLogFormatter.new(lambda{|context|
  "[%s #%d] %5s -- %s: [%s] %s\n" % [
      context.get_formatted_time,
      context.get_process_id,
      context.severity,
      context.program_name,
      MyLogContext.get_current_request_id,
      context.message2string
  ]
})

class MyLogFormatter
  def initialize(lambda)
    @lambda = lambda
  end

  # @param [String] severity
  # @param [DateTime] time
  # @param [String] prog_name
  # @param [Object] msg
  # @return [String]
  def call(severity, time, prog_name, msg)
    context = ::Yoursmile::LogContext.new(severity, time, prog_name, msg)
    @lambda.call(context)
  end
end

これで全部終わりました。

==> log/1.log <==
[2016-11-25 17:26:11.350612 #66417]  INFO -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 1
[2016-11-25 17:26:11.367210 #66417]  INFO -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 2
[2016-11-25 17:26:11.367284 #66417]  INFO -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 3
[2016-11-25 17:26:11.370316 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 4
[2016-11-25 17:26:11.372182 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 5
[2016-11-25 17:26:11.374109 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 6

==> log/2.log <==
[2016-11-25 17:26:11.383344 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 7

==> log/3.log <==
[2016-11-25 17:26:11.391745 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 8

==> log/1.log <==
[2016-11-25 17:26:11.415792 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 9
[2016-11-25 17:26:11.432047 #66417]  INFO -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 10
[2016-11-25 17:26:11.441824 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 11
[2016-11-25 17:26:11.448600 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 12
[2016-11-25 17:26:11.450477 #66417] DEBUG -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 13
[2016-11-25 17:26:11.451106 #66417]  INFO -- : [b15ea4d9a43bc7aa390051e16c2dbe3b] 14

よさそう。

まとめ

あとで本番にリリースし、調査がすこし楽になった感じがします。エラーはある原因で別のファイルに出力されましたから、本来エラーを起こすリクエストを特定するのは難しかったです。そこでこの機能のおかげて、エラーを出力する行のrequest idが分かればすぐgrepで見つかりました。

実際、X-Request-Idはアプリケーション内のログではなく、１つのリクエストが複数アプリケーションに関わる場合も利用できます。それは最初のアプリケーションあるいはWEBサーバーがRequest-Idを作成し、RPCのパラメータとしてほかのアプリケーションに通信し、処理のログを繋げます。つまり、request tracerみたいなものです。

最後に、以上の内容は役に立ちましたら幸いです。

テストコード(RSpec)の高速化事例

はじめまして、ユニファ株式会社でWebエンジニアとして働いている本間と申します。 普段は、Ruby on Railsを使ったサービスのサーバーサイドの機能追加や改善を担当しています。

弊社の主要サービスである写真サービス るくみーは2013年5月に開発がスタートし、あと少しで5年目を迎えようとしています。 開発がこれだけの期間続けられているというのはとても喜ばしいことだと思うのですが、一方で開発初期にはなかった問題も発生してきています。 そのような問題の1つに「テストコードの実行完了までに時間がかかる」というものがあり、弊社でも発生しておりました。

今回、この問題に対して改善施策を実施し、それなりの効果を得ることができましたのでご紹介したいと思います。

※注意 : RSpecは2系、かつDatabaseCleanerを使用していることが前提となる箇所があります。

結果比較

はじめに改善施策の実施前後の結果の比較です。 以下は、私のローカル環境(MacBook Pro (Retina 13-inch、Early 2015))で全てのテストコードを走らせた時の実行時間の比較です。

実施前(17:02)

実施後(3:16)

改善対象の洗い出し

性能改善を始めるにあたって、最初に攻めどころを明確化を行いました。

RSpecはデフォルトで時間がかかるexampleやspecファイルを表示してくれますが、今回の用途に少しマッチしなかったため「合計実行時間」が大きい順にspecファイルを表示してくれるFormatterを自作して対応しました。作成したFormatterは扱いやすいようにGemにしてあります(※注意 RSpec 2系でしか動きません)。

このFomatterを使ってRSpecのテストを実行すると、下記のように合計実行時間の上位10specファイルが表示されます(クラス名とパスは隠しています)。

改善施策の実施

合計実行時間が長い順にspecファイルを調べ、原因と思われる箇所に対して対策を実施していきました。

不要な機能のテストコードを削除

実行時間がかかる上位のspecの中に、今後使う予定がないrakeタスクのテストコードがいくつかありました。 このコードは不要でしたので本体コードごと削除しました。

権限チェックテストの簡略化

弊社サービスには何種類かのロールがあり、ロールによって操作可能なアクションが異なります。

時間のかかるControllerのテストでは、各アクションに対して全てのロールで成功 or エラーのテストを実施していました。具体的には、以下のようなコードになります。

describe UsersController do
  describe '#index' do
    let!(:users) { create_list(:user, 10) } # テストデータ作成

    subject(:response) { get :index }

    # 全てのロールで成功 or エラーをテスト
    UsersController::PERMITTED_ROLE_IDS.each do |role_id|
      before do
        session[:role_id] = role_id
      end

      it { 
        expect(response.status).to eq(200)
        expect(assigns(:users)).to eq(users)
      }
    end
    (Role::ALL_ROLE_IDS - UsersController::PERMITTED_ROLE_IDS).each do |role_id|
      before do
        session[:role_id] = role_id
      end

      it { expect(response.status).to eq(403) }
    end
  end
end

ロールによる権限チェックのテストは重要なのですが、「テストデータ作成」と「アクション処理」が複数回実施されていて、ここに改善の余地があると考えました。

解決策としては、機能的なテストは1つの代表ロールでのみチェックし、ロールの権限チェックテストではAnonymous controllerを使用することで「テストデータの作成」と「成功時のアクション処理」をスキップするようにしました。

Anonymous controller はRSpecが提供する機能の一つで、テスト対象のControllerを継承したクラスをテストコード内で定義することができます。Anonymous contollerでアクションの中身をオーバーライドして空のレスポンスを返すことで、before_action で実施している権限チェックのコードをテストしつつ、アクション処理の実行時間を短縮できます。

修正後は以下のようなコードになりました。

describe UsersController do
  before do
    session[:role_id] = 9999 # 代表ロールID
  end

  # 機能的なテストは1つの代表ロールでのみ確認
  describe '#index' do
    let!(:users) { create_list(:user, 10) } # データ準備

    subject(:response) { get :index }

    it { 
      expect(response.status).to eq(200)
      expect(assigns(:users)).to eq(users)
    }
  end

  describe '権限チェック' do
    controller do
      # 空レスポンスを返すだけ、成功時のアクション処理時間を短縮
      def index
        head :ok
      end
    end
    before do
      routes.draw do
        resources :users, controller: :anonymous, only: [:index]
      end
    end

    describe '#index' do
      # 権限チェックではテストデータを作成しないことで時間短縮

      subject(:response) { get :index }

      UsersController::PERMITTED_ROLE_IDS.each do |role_id|
        before do
          session[:role_id] = role_id
        end

        it { expect(response.status).to eq(200) }
      end
      (Role::ALL_ROLE_IDS - UsersController::PERMITTED_ROLE_IDS).each do |role_id|
        before do
          session[:role_id] = role_id
        end

        it { expect(response.status).to eq(403) }
      end
    end
  end
end

共通データの事前作成

時間のかかるspecの多くでは、DBへのデータ書き込み(特にどのテストでも使う共通のオブジェクトの作成)で時間がかかっていました。

この問題を解決する方法として、specファイル内で共有可能なデータは before(:all) で事前に作成し、これを各exampleで参照するようにしました。

しかし、この方法はテスト間の独立性を壊してしまう可能性があるため利用には注意を払う必要があります。今回、以下のルールに沿って実施しました。

• 共有するのは参照専用のオブジェクトのみ。
• 共有する範囲は1つのspecファイル内まで。
• 対象は合計実行時間の上位20specファイルまで。
• 必ず after(:all) で作成したオブジェクトを全て削除する。

テストコードは以下のようになります。

describe SomeController do
  before(:all) do
    @user = create(:user)
  end
  after(:all) do
    DatabaseCleaner.clean_with(:truncation)
  end

  # 以降、@userでユーザーオブジェクトを参照
end

rspecの並列実行

上記施策を実施して実行時間を10分前後に減らすことはできたのですが、大きな改善を見込める箇所が見当たらなくなってしまいました。 そこで、最終手段としていたテストの並列実行を導入しました。

RSpecを並列実行するGemとしてparallel_testsとtest-queueが有名なようです。 今回は「parallel_tests」を使用しました。導入にあたって実施した内容は以下になります。

1. Gemfileに parallel_tests を追加し、 bundle install 。
2. database.ymlを開き、テスト用のデータベース名の末尾に <%= ENV['TEST_ENV_NUMBER'] %> をつけるように修正。
3. bundle exec rake parallel:setup を実行し、テスト用のデータベースを準備する。
4. parallel_rspec spec でテストを実行する。

並列化の効果は非常に大きく、これだけでテストの実行時間が3分の1程度になりました。

parallel_testsを使う場合、以下の設定をしておくとオススメです。

• 各specの実行時間を記録したログを出力しておく。公式リポジトリに説明があります。この設定を行うと前回の実行時間に基づいてspecファイルが分配されるため、プロセスごとの実行時間のばらつきが小さくなり、早く全てのテストが終わる。
• parallel_rspecを実行する際に --nice を指定すると、テスト実行中に他の作業をするとき動作がもっさりしにくくなる。

実施しなかった対策

下記の施策は検討には上がっていたのですが、実施はしませんでした。 本体への影響が大きかったり、実施に時間がかかるというのが主な理由です。

• インメモリDBを使う
• RubyやRailsのバージョンアップ
• テストの精査・サンプリング

Werckerでも並列実行

弊社ではCIサービスのWerckerを利用しており、リポジトリへのpushを検知して自動でテストを流すようにしています。 こちらも並列化により実行時間を大幅に短縮できたので、合わせてご紹介いたします。

設定は非常に簡単で wercker.yml の記載を以下のように変更するだけでした。

build:
    steps:
        - bundle-install

        # rails-database-ymlが生成するdababase.ymlにはDB名に環境変数「TEST_ENV_NUMBER」が組み込まれている。
        - rails-database-yml

        # db:schema:load の代わりに parallel:setup を、 rspecコマンドの代わりにparallel_rspecコマンドを使うだけ。
        - script:
            name: Set up db
            code: bundle exec rake parallel:setup
        - script:
            name: rspec
            code: parallel_rspec spec

まとめ

今回、弊社で実施したRSpecのテストコードの高速化事例をご紹介させていただきました。

この活動はまだまだ終わりではなく、継続して改善していく必要があります(テストコードはどんどん増えていくため...)。 今後、大きな改善をすることができたら、またこのブログで紹介したいと考えています。

それでは最後まで読んでいただきありがとうございました。