Xcode のビルドログの読込

モバイル基盤グループのヴァンサン(@vincentisambart)です。

開発者がどれくらいアプリのビルドを待っているのか気になったことありませんか?計測してみたらおもしろいかもしれません。どうすれば Xcode でビルド時間を計測できるのでしょうか。

プロジェクトの Build Phases の一番上と一番下にスクリプトを入れたら、ある程度計測できそうですが、制限が多そうですね。失敗したビルドや途中で止められたビルドは計測できないし、ビルドのどういうところに時間が掛かったのか詳しく分かりません。

ビルド時に Xcode がログを取っているはずなので、ログの中に時間が入っていないかな…?

最初から複雑なプロジェクトで試すのは不便でしかないので、始める前に Xcode (現時点で 9.1 ) で新規のプロジェクト(例えば iOS の Single View App)を作って、いじらずに1〜2回ビルドします。以下の調査はそのビルドで生成されたファイルを見ます。

ビルドログの在り処

求めているデータが入っているのを確認するために、まずどこに保存されているのを探す必要があります。

既に知っている開発者が多いかと思いますが、 Xcode はビルド時に生成する殆どのファイルを ~/Library/Developer/Xcode/DerivedData/<アプリ名>-<ID> に入れます。そのディレクトリの中を見てみると、 Logs/Build にビルドログが入っていそうですね。最近ビルドされたプロジェクトの場合、そこに Cache.db というファイルと、拡張子が xcactivitylog のファイルが入っています。

因みに、ビルドログがビルド終了後に更新されるので、ビルドの途中は前のビルドのログしか見られないようです。

Cache.db

Cache.db の中身をエディターなどで見てみると、バイナリファイルではありますが、頭に bplist があります。バイナリ plist なのでは?ターミナルで plutil -p を使って中身を見てみましょう。

$ plutil -p Cache.db
{
  "logs" => {
    "4E46321A-9204-42C9-AC76-BF6F01B77E64" => {
      "timeStartedRecording" => 532831205.501172
      "timeStoppedRecording" => 532831210.725163
      "domainType" => "Xcode.IDEActivityLogDomainType.BuildLog"
      "title" => "Build BlogTest"
      "signature" => "Build BlogTest"
      "schemeIdentifier-schemeName" => "BlogTest"
      "schemeIdentifier-containerName" => "BlogTest project"
      "schemeIdentifier-sharedScheme" => 1
      "documentTypeString" => "<nil>"
      "highLevelStatus" => "S"
    }
    "A6D6AD38-4367-439C-8021-31156A579B81" => {
      "timeStartedRecording" => 532831597.574763
      "timeStoppedRecording" => 532831597.597417
      "domainType" => "Xcode.IDEActivityLogDomainType.BuildLog"
      "title" => "Build BlogTest"
      "signature" => "Build BlogTest"
      "schemeIdentifier-schemeName" => "BlogTest"
      "schemeIdentifier-containerName" => "BlogTest project"
      "schemeIdentifier-sharedScheme" => 1
      "documentTypeString" => "<nil>"
      "highLevelStatus" => "S"
    }
  }
  "logFormatVersion" => 8
}

時間

timeStartedRecordingtimeStoppedRecording が興味深いですね。 time という名前だけど、浮動小数点数のようですね。よく考えてみると、 Swift で Date を浮動小数点数から作成する方法が幾つかあります:

  • Date(timeIntervalSinceNow: TimeInterval)
  • Date(timeIntervalSince1970: TimeInterval)
  • Date(timeIntervalSinceReferenceDate: TimeInterval)

Date(timeIntervalSinceNow:) は呼ばれるタイミングによって結果が変わるので、違うはずですね。

全般的に、タイムスタンプは 1970 年からの秒数がよく使われるので、 Playground で試してみましょう。

Date(timeIntervalSince1970: 532831205.501172)
"Nov 20, 1986 at 9:40 AM"

ビルドしたばかりなので、 1986 年のはずがない(笑)

Date(timeIntervalSinceReferenceDate:) だとどうなるんだろう。

Date(timeIntervalSinceReferenceDate: 532831205.501172)
"Nov 20, 2017 at 9:40 AM"

お、丁度いい!実際ビルドにどれくらい掛かったのかは timeStoppedRecordingtimeStartedRecording を引けば秒数が分かるので Date にする必要ないのですが(笑)

因みに、 timeIntervalSinceReferenceDate が Apple 独自のものだとはいえ、 Ruby でも簡単にできます。

APPLE_REFERENCE_DATE = Time.new(2001, 1, 1, 0, 0, 0, 0) # 2001/01/01 00:00:00 UTC
def time_from_time_interval_since_reference_date(time_interval)
  APPLE_REFERENCE_DATE + time_interval
end

time_from_time_interval_since_reference_date(532831205.501172).getlocal
# => 2017-11-20 09:40:05 +0900

他の項目

Cache.db の他の項目は分かりやすいものが多いですね。

logs に入っている GUID が同じディレクトリに入っている xcactivitylog ファイルのファイル名と一致しています。

logFormatVersion は Xcode のバージョンによるもののようです。 Xcode 8.3.3 が生成した Cache.dblogFormatVersion は 7 ですが、 Xcode 9.0~9.1 が生成したやつはlogFormatVersion が 8 です。でも logFormatVersion 7 も 8 も Cache.db の中身が同じのようです。

これでビルド時間が正確に分かります。ただし、詳細が分かりませんし、ビルドが成功したのかどうか分かりません。

xcactivitylog

もっと詳しくは xcactivitylog ファイルの中身を見る必要があるかもしれません。少しネットで調べてみたら、 xcactivitylog の中身が gzip で圧縮されているらしいことが分かりました。

でも gzip -cd で展開してみると、テキストファイルに見えなくもないが、変な文字が入っているし、改行がおかしいし、時間らしいものが見当たりません…一応ファイルの最後を見ると Build stopped-Build failed-Build succeeded- でビルドの結果が分かります。ファイル名と Cache.db に入っている GUID が一致するので、情報を合わせるとビルド時間とビルド結果が分かりますけど、詳細がまだ…

トークン読込

ネットでもう少し調べてみたら Haskell で書かれた xcactivitylog を読み込むコードがありました。結局テキストファイルじゃなかった。

Haskell はよく分からないけど、 Haskell でのコードやそのコメントを見ながら、 xcactivitylog を Ruby スクリプトで読み込もうとして試行錯誤で分かった形式は以下の通りです。

まず、ファイルが SLF0 で始まって、その後はトークンのリストが並んでいるだけです。

トークンは以下の7種類のようです。

正規表現 種類 頭の数字が表しているもの
- nil
[0-9]+# 数字
[0-9]+" 文字列 文字列の長さ
[0-9]+\( リスト リストに入っている項目の数
[0-9]+% クラス名 クラス名の長さ
[0-9]+@ オブジェクト クラス名の番号(% で定義された最初のクラス名が 1 となる)
[a-f0-9]{16}\^ 浮動小数点数 16進法でメモリ上のリトルエンディアンの64-bitの浮動小数点数(double)

では、 Ruby で読み込むスクリプトを書きましょう。まず gzip で圧縮されたデータを展開します。

require 'zlib'

raise "Syntax: #{$0} file.xcactivitylog" unless ARGV.length == 1
file_path = ARGV[0]
raw_data = Zlib::GzipReader.open(file_path, encoding: Encoding::BINARY) { |gzip| gzip.read }

その後、トークンを1個ずつ読み込みます。

require 'strscan'
scanner = StringScanner.new(raw_data)

# なぜか StringScanner に特定の文字数を読み込むメソッドはないので生やす
def scanner.read(length)
  string = peek(length)
  self.pos += length
  string
end

raise 'Invalid format' unless scanner.scan(/SLF0/)
class_names = []
tokens = []

while !scanner.eos?
  if scanner.scan(/([0-9]+)#/) # integer
    value = scanner[1].to_i # 頭の数字が値
    tokens << { type: :int, value: value }
  elsif scanner.scan(/([0-9]+)%/) # class name
    length = scanner[1].to_i # 頭の数字がクラス名の長さ
    name = scanner.read(length)
    raise "Class name #{name} should not be present multiple times" if class_names.include?(name)
    class_names << name.to_sym
  elsif scanner.scan(/([0-9]+)@/) # object
    class_index = scanner[1].to_i # 頭の数字がクラスの番号(最初に定義されたクラスが 1)
    raise "Unknown class reference #{class_index} - Known classes are #{class_names.join(', ')}" if class_index > class_names.length
    tokens << { type: :object, class_name: class_names[class_index-1] }
  elsif scanner.scan(/([0-9]+)"/) # string
    length = scanner[1].to_i # 頭の数字が文字列の長さ
    string = scanner.read(length)
    tokens << { type: :string, value: string }
  elsif scanner.scan(/([0-9]+)\(/) # list
    # 頭の数字がリストの項目数
    count = scanner[1].to_i
    tokens << { type: :list, count: count }
  elsif scanner.scan(/([a-f0-9]+)\^/) # double
    hexadecimal = scanner[1] # 16進法でメモリ上のリトルエンディアンのdouble
    # "cf4c80e55bc2bf41" -> ["cf", "4c", "80", "e5", "5b", "c2", "bf", "41"]
    characters_grouped_by_2 = hexadecimal.each_char.each_slice(2).map(&:join)
    # ["cf", "4c", "80", "e5", "5b", "c2", "bf", "41"] -> [207, 76, 128, 229, 91, 194, 191, 65]
    bytes = characters_grouped_by_2.map { |hex| hex.to_i(16) }
    # [207, 76, 128, 229, 91, 194, 191, 65] -> "\xCFL\x80\xE5[\xC2\xBFA" -> [532831205.501172] -> 532831205.501172
    double = bytes.pack('C*').unpack('E').first
    tokens << { type: :double, value: double }
  elsif scanner.scan(/-/) # nil
    tokens << { type: :nil }
  else
    raise "unknown data #{scanner.peek(30).inspect}"
  end
end

require 'pp'
pp tokens

シンプルなプロジェクトのビルドで生成された xcactivitylog ファイルを上記のスクリプトに読み込ませると以下のような出力が出ます。

[{:type=>:int, :value=>8},
 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>0},
 {:type=>:string, :value=>"Xcode.IDEActivityLogDomainType.BuildLog"},
 {:type=>:string, :value=>"Build BlogTest"},
 {:type=>:string, :value=>"Build BlogTest"},
 {:type=>:double, :value=>532831205.501172},
 {:type=>:double, :value=>532831210.725163},
 {:type=>:list, :count=>1},
 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>1},
 {:type=>:string,
  :value=>"Xcode.IDEActivityLogDomainType.target.product-type.tool"},
 {:type=>:string, :value=>"Build target BlogTest"},
 {:type=>:string, :value=>"BlogTest-ehwnkjvfrwpvqwdylenlszdndskk"},
 {:type=>:double, :value=>532831205.611886},
 {:type=>:double, :value=>532831210.71247},
 {:type=>:list, :count=>7},
 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>2},
 {:type=>:string, :value=>"com.apple.dt.IDE.BuildLogSection"},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:double, :value=>532831205.611923},
 {:type=>:double, :value=>532831205.613694},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:int, :value=>0},
 {:type=>:int, :value=>1},
 {:type=>:int, :value=>0},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:string, :value=>"E8680327-DEA4-4414-8A84-5FD0D3E2C765"},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>2},
 {:type=>:string, :value=>"com.apple.dt.IDE.BuildLogSection"},
 {:type=>:string, :value=>"Compile Swift source files"},
 {:type=>:string,
  :value=>"CompileSwiftSources normal x86_64 com.apple.xcode.tools.swift.compiler"},
 {:type=>:double, :value=>532831205.61325},
 {:type=>:double, :value=>532831209.491755},
 {:type=>:list, :count=>2},
 (略)
 {:type=>:int, :value=>0},
 {:type=>:int, :value=>0},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:string, :value=>"4E46321A-9204-42C9-AC76-BF6F01B77E64"},
 {:type=>:string, :value=>"Build succeeded"},
 {:type=>:nil}]

もっと多くの情報が取れそう。でも上記のスクリプトと出力に不自然だと思われるところがあるかもしれません。なぜリストは作らずに項目数を取っておくだけ?オブジェクトはクラス名は分かるけど中身は?

実はオブジェクトトークンは「ここからこのクラスのオブジェクトが始まる」ことを表しています。オブジェクトの属性はその直後に来るいくつかトークンです。ただし属性の種類や数は分かりません。 Xcode はもちろん各クラスの属性を分かっているでしょうけど、僕らは色々調査してみるしかありません。

リストは入っているオブジェクトの属性の数が分からないと各オブジェクトがどこまでなのか分からないのでまだ作れません。

属性の種類や数は少し時間掛かるけどそこまで難しくありません。

ログバージョン

オブジェクトに入っている属性に集中する前に、まずファイルの最初のトークンを見ましょう。8Cache.db に入っていた logFormatVersion と同じ。偶然? Xcode 8.3 でアプリをビルドしてみて、生成されたログでは、 Cache.dblogFormatVersion 同様 7 になります。やっぱり、 logFormatVersion でしょう。因みに、 xcactivitylog は見てみた限りでは、 78 で変わった部分が1ヶ所があります(具体的には IDEActivityLogSection の最後に項目が1つ追加された)。

分かりやすさのため、以下は Xcode 9 のログ形式バージョン 8 だけに集中します。

オブジェクトの属性を調査

属性はどうしましょう。試行錯誤するしかないですね。トークンのリストを見て仮説をたてて、その仮説を元にスクリプトを変えて、スクリプトをいくつかの xcactivitylog ファイルに処理させてみて、結果によって仮説とスクリプトを調整する、の繰り返しです。

トークンのリストを見ると、 IDEActivityLogSection がいつも以下のような項目で始まるようですね。その仮説を検証してみましょう。

 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>2},
 {:type=>:string, :value=>"com.apple.dt.IDE.BuildLogSection"},
 {:type=>:string, :value=>"Compile Swift source files"},
 {:type=>:string,
  :value=>"CompileSwiftSources normal x86_64 com.apple.xcode.tools.swift.compiler"},
 {:type=>:double, :value=>532831205.61325},
 {:type=>:double, :value=>532831209.491755},
 {:type=>:list, :count=>2},
 {:type=>:object, :class_name=>:IDEActivityLogSection},

仮説を検証するために、期待していない値がある時点ですぐ raise (例外発生)をしましょう。以前のスクリプトが出したトークンのリストを見れば属性の型はある程度分かるけど、名前は分からないので一旦 fieldXXX にします。 IDEActivityLogSection を幾つか見てみると7番目に入るリストは nil になることもあるようなのでそれに対応しました。最初からそれに気づかなくても問題ありません。実行したらエラーが出て、直して、また実行する、の繰り返しなので。あと開発中、コード内にデバッグ出力のため ppp をよく使いますが、読む時はノイズになるので以下のコードではそれを省きました。また、このブログが長くなりすぎないように、細かい試行錯誤については省略しています。

class TokenReader
  def initialize(tokens)
    @tokens = tokens.dup
  end

  def tokens_left_count
    @tokens.length
  end

  def read(expected_type, args = {})
    token = @tokens.shift
    return nil if token[:type] == :nil && args[:nullable]
    raise "Expecting token of type #{expected_type.inspect} but got #{token.inspect}" if token[:type] != expected_type

    case expected_type
    when :list
      expected_class_name = args[:class_name]
      (0...token[:count]).map { read(:object, class_name: expected_class_name) }

    when :object
      expected_class_name = args[:class_name]
      class_name = token[:class_name]
      raise "Expected an object of class #{expected_class_name} but got an instance of #{class_name}" if class_name != expected_class_name
      fields = { class_name: class_name }
      case class_name
      when 'IDEActivityLogSection'
        fields[:field1] = read(:int)
        fields[:field2] = read(:string)
        fields[:field3] = read(:string)
        fields[:field4] = read(:string)
        fields[:field5] = read(:double)
        fields[:field6] = read(:double)
        fields[:field7] = read(:list, nullable: true, class_name: :IDEActivityLogSection)

      else
        raise "Unknown class name #{class_name}"
      end
      
      fields

    else
      token[:value]
    end
  end
end

# tokens は上記のスクリプトで生成したもの
reader = TokenReader.new(tokens)
log_format_version = reader.read(:int)
raise "Unknown log format version #{log_format_version}" if log_format_version != 8
pp reader.read(:object, class_name: :IDEActivityLogSection)
p reader.tokens_left_count

実行してみたら Expecting token of type :object but got {:type=>:nil} と怒られました。スタックトレースを見ると、リストを読み込もうとしている時です。もう少し調査してみると、7つめの属性である IDEActivityLogSection のリストは1項目が無事に読み込まれたけど2項目目を読もうとしている時にエラーが起こります。リストの全項目が同じ型を想定していましたが、 IDEActivityLogSection の直後に nil が入っている。リストにオブジェクトに混ざって nil が入っていると考えにくいので、理由は別にありそうです。

リストの始めからエラーが起きた少しあとまでのトークンを見てみましょう。

 {:type=>:list, :count=>7},
 {:type=>:object, :class_name=>:IDEActivityLogSection},
 {:type=>:int, :value=>2},
 {:type=>:string, :value=>"com.apple.dt.IDE.BuildLogSection"},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:double, :value=>532831205.611923},
 {:type=>:double, :value=>532831205.613694},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:int, :value=>0},
 {:type=>:int, :value=>1},
 {:type=>:int, :value=>0},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:string, :value=>"E8680327-DEA4-4414-8A84-5FD0D3E2C765"},
 {:type=>:nil},
 {:type=>:nil},
 {:type=>:object, :class_name=>:IDEActivityLogSection},

このリストには項目が7つもある。どの項目も IDEActivityLogSection の可能性が高い。なら少し下にある IDEActivityLogSection はリストの2項目目なのでは?別のオブジェクトの属性の可能性もありますが、まずそれで試してみましょう。

fields[:field1] = read(:int)
fields[:field2] = read(:string)
fields[:field3] = read(:string)
fields[:field4] = read(:string)
fields[:field5] = read(:double)
fields[:field6] = read(:double)
fields[:field7] = read(:list, nullable: true, class_name: :IDEActivityLogSection)
fields[:field8] = read(:nil)
fields[:field9] = read(:nil)
fields[:field10] = read(:int)
fields[:field11] = read(:int)
fields[:field12] = read(:int)
fields[:field13] = read(:nil)
fields[:field14] = read(:nil)
fields[:field15] = read(:string)
fields[:field16] = read(:string)
fields[:field17] = read(:nil)
fields[:field18] = read(:nil)

また実行してみましょう。field14 を読み込もうとする時に以下のエラーが出ました。

Expecting token of type :nil but got {:type=>:object, :class_name=>:DVTDocumentLocation}

field14nil の場合もあれば、 DVTDocumentLocation のインスタンスの場合もあるようですね。

fields[:field14] = read(:object, nullable: true, class_name: DVTDocumentLocation)

DVTDocumentLocation の中身も探る必要がありますね。

 {:type=>:object, :class_name=>:DVTDocumentLocation},
 {:type=>:string,
  :value=>
   "file:///Users/vincent-isambart/Desktop/BlogTest/BlogTest/main.swift"},
 {:type=>:double, :value=>0.0},
 {:type=>:string,
  :value=>"CompileSwift normal x86_64 (略)"},
 {:type=>:string, :value=>"1D50F5EA-D2D1-4F45-9017-8D2CEFE85CBC"},
 (略)
 {:type=>:object, :class_name=>:DVTDocumentLocation},
 {:type=>:string,
  :value=>"file:///Users/vincent-isambart/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/Objects-normal/x86_64/BlogTest.swiftmodule"},
 {:type=>:double, :value=>140736883871744.0},
 {:type=>:string,
  :value=>"MergeSwiftModule normal x86_64 (略)"},
 {:type=>:string, :value=>"D19441A3-B3BE-4814-B29D-173A5F24F876"},

DVTDocumentLocation の属性はどこまででしょうか。ログファイル全体のトークンのリストを見て、ヒントになりそうなところを探しましょう。 IDEActivityLogSectionfield14nil の場合がありますね。その時、直後の field15field16 が以下の通りだったところがあります。

 {:type=>:string, :value=>"Check dependencies"},
 {:type=>:string, :value=>"E8680327-DEA4-4414-8A84-5FD0D3E2C765"},

DVTDocumentLocation の属性が2つだったらうまくいきそうです。それでやってみましょう。

when :DVTDocumentLocation
  fields[:field1] = read(:string)
  fields[:field2] = read(:double)

その後出ていた nullable 関連のエラーをちょこっと直したら、テストで使っていたすごくシンプルなプロジェクトのビルドログが無事に解析できました。オブジェクトの属性の読込が以下のようになりました。

case class_name
when :IDEActivityLogSection
  fields[:field1] = read(:int)
  fields[:field2] = read(:string)
  fields[:field3] = read(:string)
  fields[:field4] = read(:string)
  fields[:field5] = read(:double)
  fields[:field6] = read(:double)
  fields[:field7] = read(:list, nullable: true, class_name: :IDEActivityLogSection)
  fields[:field8] = read(:nil)
  fields[:field9] = read(:nil)
  fields[:field10] = read(:int)
  fields[:field11] = read(:int)
  fields[:field12] = read(:int)
  fields[:field13] = read(:string, nullable: true)
  fields[:field14] = read(:object, nullable: true, class_name: :DVTDocumentLocation)
  fields[:field15] = read(:string, nullable: true)
  fields[:field16] = read(:string)
  fields[:field17] = read(:string, nullable: true)
  fields[:field18] = read(:nil)

when :DVTDocumentLocation
  fields[:field1] = read(:string)
  fields[:field2] = read(:double)

else
  raise "Unknown class name #{class_name}"
end

IDEActivityLogSection を読み込んだあとに残っているトークンを見ようとしたら、トークンが残っていないので、ファイルに入っているのはログバージョンと1つの IDEActivityLogSection だけのようですね。もちろんその IDEActivityLogSection には色々入っています。

もう少し複雑なビルドログで同じことを繰り返したら、こんな感じになりました。

命名

オブジェクトを読み込めたのはいいのですが、オブジェクトに入っている属性に名前がまだありません。どう付ければいいのでしょうか。

まず、 IDEActivityLogSection に入っている2つの double に簡単に名前を付けられます。最初に読み込もうとした xcactivitylog ファイルでは最初の2つ double532831205.501172532831210.725163 でした。見た覚えあるような…そう、 Cache.db に入っていた timeStartedRecordingtimeStoppedRecording と同じ値なので、 Cache.db に入っていた名前を使えばいいです。

同様、 Cache.db の中身と比べて domainTypetitlesignature も分かります(titlesignature は値が同じなのでどっちがどっちか逆になってしまうかもしれませんが)。

あとはクラス名や値自体を元に名前を付けてみましょう。何もないよりマシです。DVTDocumentLocation の最初の項目が file:///Users/... で始まる文字列なので名前は url で良さそう。 DVTDocumentLocation が入る属性は location でいいんじゃないかな。 IDEClangDiagnosticActivityLogMessageIDEActivityLogMessage のリストは messages でいかが。

一部の項目に名前を付けたスクリプトのバージョンがこちらで見られます。因みにログバージョン 7 にも対応しています。

もっと多くの属性に名前を付けるには方法が色々ありそうです。例えば意図的にビルドログに影響ありそうなもの(ビルド結果、警告、エラー)を変えて、何が変わったのかを見て名前を付けられそうですね。僕は目的がビルド時間だけだったのでそこまでやっていませんが。

名前を付けているスクリプトをシンプルなログに実行すると以下のような出力が出ます。読みやすさのためにクラス名、 nil な値、各 Swift ファイルのビルド詳細、を省いておきました。各ステップにどれくらい時間が掛かったのかがよく分かります。

{:domain_type=>"Xcode.IDEActivityLogDomainType.BuildLog",
 :title=>"Build BlogTest",
 :signature=>"Build BlogTest",
 :time_started_recording=>532831205.501172,
 :time_stopped_recording=>532831210.725163,
 :result=>"Build succeeded",
 :subsections=>
  [{:domain_type=>"Xcode.IDEActivityLogDomainType.target.product-type.tool",
    :title=>"Build target BlogTest",
    :signature=>"BlogTest-ehwnkjvfrwpvqwdylenlszdndskk",
    :time_started_recording=>532831205.611886,
    :time_stopped_recording=>532831210.71247,
    :subsections=>
     [{:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Check dependencies",
       :signature=>"Check dependencies",
       :time_started_recording=>532831205.611923,
       :time_stopped_recording=>532831205.613694},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Compile Swift source files",
       :signature=>"CompileSwiftSources normal x86_64 com.apple.xcode.tools.swift.compiler",
       :time_started_recording=>532831205.61325,
       :time_stopped_recording=>532831209.491755,
       :subsections=>[(略)]
       :location=>{:url=>"file:///Users/user-name/Desktop/BlogTest/BlogTest/main.swift"}},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Copy /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/DerivedSources/BlogTest-Swift.h",
       :signature=>"Ditto /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/DerivedSources/BlogTest-Swift.h /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/Objects-normal/x86_64/BlogTest-Swift.h",
       :time_started_recording=>532831209.492459,
       :time_stopped_recording=>532831209.500314,
       :location=>{:url=>"file:///Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/DerivedSources/BlogTest-Swift.h"}},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Link /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest",
       :signature=>"Ld /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest normal x86_64",
       :time_started_recording=>532831209.500942,
       :time_stopped_recording=>532831210.568323},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Copy /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftdoc",
       :signature=>"Ditto /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftdoc /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/Objects-normal/x86_64/BlogTest.swiftdoc",
       :time_started_recording=>532831209.50099,
       :time_stopped_recording=>532831209.507525,
       :location=>{:url=>"file:///Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftdoc"}},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Copy /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftmodule",
       :signature=>"Ditto /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftmodule /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Intermediates.noindex/BlogTest.build/Debug/BlogTest.build/Objects-normal/x86_64/BlogTest.swiftmodule",
       :time_started_recording=>532831209.50093,
       :time_stopped_recording=>532831209.507456,
       :location=>{:url=>"file:///Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest.swiftmodule/x86_64.swiftmodule"}},
      {:domain_type=>"com.apple.dt.IDE.BuildLogSection",
       :title=>"Sign /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest",
       :signature=>"CodeSign /Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest",
       :time_started_recording=>532831210.571077,
       :time_stopped_recording=>532831210.711349,
       :location=>{:url=>"file:///Users/user-name/Library/Developer/Xcode/DerivedData/BlogTest-ehwnkjvfrwpvqwdylenlszdndskk/Build/Products/Debug/BlogTest"}}]}]}

集計

ログファイルを読み込めたのは良いけど、それでどうやって開発者のビルド時間を集計できるのでしょうか。僕はプロジェクトの Build Phases で Xcode にスクリプトを実行させています。スクリプトがまだ処理されていないログファイルから必要なデータだけを抽出してサーバーに送ります。ビルドが終わるまでログファイルが生成されないので、データは1個前のビルドになりますが、実行された日時が入っているのでデータが少し遅れて送られれても問題ありません。

この仕組は制限が色々あります。1個前のビルドログなので、処理が走る前にログが削除されたらデータがなくなります。 DerivedData 内のデータを自分で消さなくても、例えば別のログバージョンを使う Xcode で同じプロジェクトを開くとビルドログが全部削除されるようです。

でもビルド時間の計測が完璧じゃなくていいのではないでしょうか。

まとめ

どうやって Xcode のビルド時間を計測できるのか考えてみたら、 Xcode のログファイルからできないのか試してみました。結果的にビルドの各ステップの時間まで取得できるようになりました。

弊社では、集計されたビルド時間をグラフ化して、開発者が毎日どれくらいビルドを待っているのか、何回ビルドを実行しているのか、ビルドに平均でどれくらい時間が掛かるのか、が見えるようにしています。

そのデータでビルド時間短縮の必要性を証明できるようになったと思います。

サービスイメージをより魅力的に見せる写真撮影

国内事業開発部のデザイナー、木村です。私が現在携わっている「おうちレッスン」*というサービス上で利用する写真を撮影するために、久しぶりにプロのカメラマンさんとお仕事をする機会がありました。

今回は、外部のカメラマンさんとサービスのイメージ写真を撮影する際に参考になりそうなことをブログに残そうと思います。

ヒアリング

まず写真撮影の目的を定めます。どういった目的で、ユーザーにどんな印象を与えたいか、ゴールはなにか、といった項目を洗い出し、オーナーと話し合いました。

今回は「ランディングページやサービス上で、サービスの魅力をユーザーに伝えたい」「楽しさや親しみやすさが増幅されるようなイメージ」「気取らない、日常の延長線上で」といった要望が上がりました。

イメージを固める

ヒアリングが終わったら、次はサービスのイメージを固めます。

以下は私がチームに参加した際に、競合・類似サービスなどをまとめ、ポジショニングしたデザインのマトリクス図です。

f:id:mura24:20171201152034p:plain

また、撮影する写真のイメージをキーワードとして書き出し、イメージに齟齬はないかも合わせて確認しました。

f:id:mura24:20171201152041p:plain

これらのすり合わせの作業をどこまで深掘りするかは、プロジェクトへの携わり方で調整するとよいでしょう(今回はサービス全体設計からの参加だったので結構がっちりやっています)。

トンマナのすり合わせ

並行して、写真のトンマナのサンプルをPinterestのシークレットボードを利用して収集しました。方向性をオーナーに確認してもらい、問題なさそうであれば、具体的なカットのラフ作業へ進みます。

f:id:mura24:20171201152044p:plain

絵コンテの作成

サービスのイメージを踏まえながら、ユーザーストーリーに沿って、デザイン上必要なカットを割り出し、絵コンテに起こしていきます。

f:id:mura24:20171201174301p:plain

テキストを交えながら、オーナーやカメラマンに、おうちレッスンのリラックスした和やかな雰囲気が伝わるよう気を配りました。

なお、イラストが不得手、イメージ通りのサンプル写真が用意できない場合などは、既存のストックフォトをコラージュしたり、自分やメンバーを素材としてスマホで撮影してコンテを用意するのもよいでしょう。

方法はなんでもよいので、なるべくコストをかけず、頭の中のイメージをスピーディーにメンバーに共有できる方法を選ぶことが重要です。

実際に写真をデザインに当て込んだデザインカンプなどがあれば、より完成形をイメージしやすくなるので、準備しておくとよいでしょう。

カメラマンとの打ち合わせ

写真のイメージ・必要カットが確定したらカメラマンと打ち合わせをします。

サービスの概要説明、写真のイメージ、絵コンテなどを元に、スケジュール、撮影場所や衣装、必要な機材などの相談と確認を行いました。

画角について

今回は、一部、9:16(スマートフォン縦サイズ)での利用を検討しておりましたが、コンテでその場合の指定が不十分であったことが判明しました。

複数の画角で撮影を予定している場合は、予めリストアップし、そのフレームに応じてコンテを切るようにしましょう。

撮影場所・衣装・小物について

今回は実際のユーザーさんのお宅にお邪魔して撮影することになっていたので、当日の間取りの確認、ユーザーさんの衣装(服装や髪形のかぶりがないか、サービスのイメージに沿った服装の依頼など)、当日のメニューの確認などを行いました。

撮影

撮影日当日は、プロダクトオーナー・カメラマン・デザイナーの3名でユーザーさんのお宅に伺い、撮影に協力してくださるユーザーさんに、絵コンテを見せながら撮影のイメージを伝え、撮影に望みました。

撮影立会時に、今回は私が撮影の進行管理・写真の確認などを担当しました。

進行管理では、撮影順の調整、カットの抜け漏れがないかのチェック、時間帯や天候により撮影状況が変わってしまった際の判断(カット数の増減、ほかのシチュエーションへの変更)なども行います。今回の撮影では、天候に恵まれ滞りなく進行できました。

カットごとに撮影時間を確保する

今回はユーザーさんが実際にお料理する流れに沿って、リラックスした自然な様子を撮影したいと考え、撮影に望みました。

ですが、被写体が複数人の場合、状況をコントロールしないと、誰かが目をつぶってしまっている、画面に対し立ち位置が左右一方に寄りすぎてしまうということが発生しがちです。

サービスの利用シーンを撮影する場合は、手順ごとに手を止めて、撮影時間を確保してから進行させたほうが結果的にスムーズに撮影が進みました。

写真確認

撮影終了後、追ってカメラマンから確認用のデータが送られてくるので、その中から納品用のカットを指定します。

f:id:mura24:20171201152053j:plain

私は昔から利用しているAdobe Bridgeを使用して、写真選別を行っております。Finderでも似たようなことは可能ですが、ビューワー機能のあるツールを利用し、効率よく写真を選別してゆくのがオススメです。

納品

納品してもらう写真が決まったら、納品形式(ファイル形式、カラープロファイル、画像サイズなど)を指定して、撮影データを受け取ります。

進行・撮影ともに、カメラマン、そして参加してくださったユーザーさんにかなり助けていただだいたおかげで、めちゃんこエモい写真に仕上がったので、一部公開します。

f:id:mura24:20171201152517j:plain

Photo by 福田 栄美子

おわりに

目的を定め、最小限のコストでチーム内で合意を取りながらユーザーに届ける…というプロセスは、写真撮影でもサービス開発でも、そう違いはありません。

自社サービス以外にも、採用募集やイベント用の写真などで、デザイナーに写真撮影の相談が入ることも多いと思います。みなさまの参考になれば幸いです。


*…「おうちレッスン」は現在クローズドテスト中のCtoC料理教室プラットフォームです。

【開催レポ】Cookpad Tech Kitchen #13 〜クックパッドにおける研究開発のサービス活用事例〜

こんにちは!人事部の冨永です。

2017年11月15日に「Cookpad Tech Kitchen #13 〜クックパッドにおける研究開発のサービス活用事例〜」を開催しました。クックパッドではこのイベントを通して、技術的やサービス開発に関する知見を定期的に発信しています。

第13回のテーマはずばり「研究開発」です。クックパッド 研究開発部では、既存技術ではなかなか難しかった事を新しい研究などをもとに解決して、ユーザにより高水準な価値を届けることを目標としています。研究成果としても、既にいくつかの技術がプロダクトに組み込まれているものがあります。そこで今回は発足から1年*1が経った研究開発部の、研究成果のサービス活用事例に焦点をあてました。

それでは各登壇についてご紹介します。

f:id:cookpadtech:20171126172143p:plain

Encoder-Decoder にもとづく材料名の正規化(原島)

最初は研究開発部長 原島(jun-harashima.net)がクックパッドにおける自然言語処理について発表しました。

クックパッドのレシピはユーザの自由記述によって作成されています。そのため、材料名に種々のバリエーションがあります。例えば、「しょうゆ」には 100 種類以上のバリエーションがあります。

これらのバリエーションを吸収するため、クックパッドでは Encoder-Decoder を利用しています。レシピ中の材料名(e.g. ★醤油)を入力に、その正規化された表現(e.g. しょうゆ)を出力にして、Encoder-Decoder を学習しています。学習されたモデルを使用すれば、様々な材料名を正規化できます。

この発表については以下のエントリでも解説しているので、よろしければご覧ください。

画像分析によるレシピのカテゴリ分類(菊田)

次は画像分析の発表で、研究開発部 菊田(@yohei_kikuta)が画像分析を用いたレシピのカテゴリ分類に関して話しました。 ここで言うレシピのカテゴリとは {カレー, から揚げ, ...} などの料理の種類に対応しています。

クックパッドのアプリでは「料理きろく」というユーザの携帯端末から料理の画像のみを抽出してカレンダー形式で表示するサービスを提供しており、2017年9月28日時点で料理と判定された画像が1000万枚 *2に達しています。 これらの画像を活用してユーザにとってより良いサービスを創っていきたいわけですが、そのためには色々な情報(レシピのカテゴリ、朝昼晩、カロリー、...)を付与することが助けとなります。

ユーザの画像はプライバシーの観点から我々が目でチェックすることはできないため、機械学習を用いてレシピのカテゴリ分類をしよう、そしてそのためにはどんな工夫をしているか、ということが発表の主旨となります。

資料内では実サービスにおける画像分析の難しさや、サービスとして成立する precision をどう実現するか、などを紹介しています。
難しい問題でまだまだ改善すべき点も多いですが、面白い内容ですので、どこかのタイミングでまた詳しく解説をしたいと考えています。

また今回は、料理を提供してくれたシェフにお願いをして、料理の中にレシピのカテゴリ分類の対象となるから揚げを入れていただきました。 菊田の携帯で写真を撮ったところ、適切にから揚げと判別され結果が表示されました。

f:id:cookpadtech:20171126141646j:plain つくっていただいたから揚げの写真がこちらです。

f:id:cookpadtech:20171126154923p:plain
この時の写真がから揚げと認識されて、サムネイル画像として選出されたときのスクリーンショットがこちらです。

また、レシピのカテゴリ分類の前段となる「料理きろく」に関して興味のある方は、以下の過去エントリをご覧下さい。

Alexa Skill 開発のあれこれ(山田)

最後は最近日本に上陸したばかりの Amazon Echo 向けにリリースしたクックパッドのスキル( Amazon Echo ではアプリと呼ばずにスキルと呼びます)について研究開発部 山田(@y_am_a_da)が発表をしました。内容としては開発の際に意識をしたこと、またAmazon Echo の特徴である音声インターフェースの強みと弱みについて話をしました。

Amazon Echo はAmazon社から発売された音声アシスタント搭載デバイスで、基本的に入出力は音声のみです。サードパーティにより提供されているスキルを有効化することでさまざまなことができるようになりますが、スキルのアイコンを目にするタイミングが有効化の時のみなので一度存在を忘れられてしまうと再び利用してもらうことが困難です。そのため、ある統計の結果でスキルのリテンション率は3%とも言われています。

また、視覚による情報の取得と比較して、聴覚による情報の取得は一覧性の乏しさやフィルタリングの難しさなどからいわゆるモバイルアプリケーションとして提供しているサービスをそのまま移植しても上手くいきません。

そのため、プロトタイピングを重ねつつ音声インターフェースに適したサービスを提供できるよう開発を進めました。

スキルの開発について、以下に詳しくまとめられているので興味のある方はぜひご覧ください。

イベントの様子をご紹介

f:id:cookpadtech:20171126170325j:plain
Cookpad Tech Kitchenでは、よりリラックスした状態で発表を聞いていただくために、イベントの開始とともに乾杯をします!この日は中華料理をメインとした絶品ご飯が登場しました♪

f:id:cookpadtech:20171126165844j:plain
中でも目玉はクックパッドのロゴをあしらったライスケーキ。ご飯が2層になっていて間に具材が挟まれているんです。見た目がきれいなことはもちろん、美味しくてお腹いっぱいになるので大人気なメニューとなりました。

f:id:cookpadtech:20171126170449j:plain
ご飯を食べながら発表を聞いた後には、付箋方式でのQAディスカッションを行います。発表を聞いて気になったことをその場でメモをしていただくことで、より新鮮な質問を気兼ねなくできるように工夫しています。

まとめ

いかがでしたか?クックパッドではテーマを変えて定期的に技術イベントを開催しています。みなさんも是非遊びに来てくださいね。

👇イベントページはこちら
クックパッド株式会社 - connpass

また今回登壇したメンバーが所属する研究開発部では新しい仲間を募集しています!ご興味がある方は是非ページをご覧になってください。

👇研究開発部では仲間を募集しています🔍
・リサーチエンジニア
・研究員

*1:クックパッドの研究開発部は2016年7月に発足しました

*2:https://info.cookpad.com/pr/news/press_2017_0928

/* */ @import "/css/theme/report/report.css"; /* */ /* */ body{ background-image: url('http://cdn-ak.f.st-hatena.com/images/fotolife/c/cookpadtech/20140527/20140527163350.png'); background-repeat: repeat-x; background-color:transparent; background-attachment: scroll; background-position: left top;} /* */ body{ border-top: 3px solid orange; color: #3c3c3c; font-family: 'Helvetica Neue', Helvetica, 'ヒラギノ角ゴ Pro W3', 'Hiragino Kaku Gothic Pro', Meiryo, Osaka, 'MS Pゴシック', sans-serif; line-height: 1.8; font-size: 16px; } a { text-decoration: underline; color: #693e1c; } a:hover { color: #80400e; text-decoration: underline; } .entry-title a{ color: rgb(176, 108, 28); cursor: auto; display: inline; font-family: 'Helvetica Neue', Helvetica, 'ヒラギノ角ゴ Pro W3', 'Hiragino Kaku Gothic Pro', Meiryo, Osaka, 'MS Pゴシック', sans-serif; font-size: 30px; font-weight: bold; height: auto; line-height: 40.5px; text-decoration: underline solid rgb(176, 108, 28); width: auto; line-height: 1.35; } .date a { color: #9b8b6c; font-size: 14px; text-decoration: none; font-weight: normal; } .urllist-title-link { font-size: 14px; } /* Recent Entries */ .recent-entries a{ color: #693e1c; } .recent-entries a:visited { color: #4d2200; text-decoration: none; } .hatena-module-recent-entries li { padding-bottom: 8px; border-bottom-width: 0px; } /*Widget*/ .hatena-module-body li { list-style-type: circle; } .hatena-module-body a{ text-decoration: none; } .hatena-module-body a:hover{ text-decoration: underline; } /* Widget name */ .hatena-module-title, .hatena-module-title a{ color: #b06c1c; margin-top: 20px; margin-bottom: 7px; } /* work frame*/ #container { width: 970px; text-align: center; margin: 0 auto; background: transparent; padding: 0 30px; } #wrapper { float: left; overflow: hidden; width: 660px; } #box2 { width: 240px; float: right; font-size: 14px; word-wrap: break-word; } /*#blog-title-inner{*/ /*margin-top: 3px;*/ /*height: 125px;*/ /*background-position: left 0px;*/ /*}*/ /*.header-image-only #blog-title-inner {*/ /*background-repeat: no-repeat;*/ /*position: relative;*/ /*height: 200px;*/ /*display: none;*/ /*}*/ /*#blog-title {*/ /*margin-top: 3px;*/ /*height: 125px;*/ /*background-image: url('http://cdn-ak.f.st-hatena.com/images/fotolife/c/cookpadtech/20140527/20140527172848.png');*/ /*background-repeat: no-repeat;*/ /*background-position: left 0px;*/ /*}*/