検索の KPI (評価指標)をとりたい！

検索ページの施策って評価しづらくないですか？　検索エンジニアの tanker です。

前職でも、弊社でも同じような声をよく聞きます。

https://tech.visasq.com/es-spec-projection-on-gce-1/

私 (tanker) が開発を行っている社内スタッフ用の検索システム (上記記事参照) は、社内の検索スペシャリストのRM(Research Manager)が主に利用しています。これまでは RMから要望があがったら実装するということが基本となっていました。 (検索の専属がいなかったという理由もあります)また、機能追加ができればそのタスクは完了してしまうため、実際に改善されたかの評価をきちんと行ってきませんでした。

ここからが本題です。エンジニア側から改善案を出す前に、その改善点を洗い出すため＆改善後の評価を行うために利用状況の把握が必要なのでまずはそれをとれるようにしました。

ざっくり説明すると以下のようになります。

各アクション (検索、検索結果のアイテムをクリック、ページング) 時にログを吐く
ログを Filebeat & Logstash で集計&成形
Kibana で可視化

弊社では、主に mixpanel を使っており ( https://www.fastgrow.jp/articles/visasq-hashiba-hanamura)、
当初は検索の方もそれを使おうと考えていたのですが、ユーザ単位ではなく検索セッション(検索してから目的のものを見つけ出すまでの一連の行動)単位で集計したく、 mixpanel だとやりづらかったので独自で行うようにしました。

tracking 用のログを出力

元々、弊社のシステム的に上記の値は取りやすくなっているのでそれに乗っかったという背景もあります。というのも以下のような RM の作業フローがすでに存在したのでその中でログを吐く処理を追加しました。

クライアントからの依頼により案件ページが作成される
最適な候補者を探すために案件ページ内の「検索開始」のボタンを押す
検索ページで検索を行う
検索結果から「候補者に追加する」のボタンを押して案件ページに候補者を追加する

## 検索ログ
{"searchId": "1592196504.79", "timestamp": "2020-06-15T13:48:32+09:00", "logType": "SearchAndClick", "sessionId": "1592193858073.6265", "operation": "search", "staffNickname": "tanker", "total": 53}

## クリックログ
{"searchId": "1592196504.79", "timestamp": "2020-06-15T13:48:58+09:00", "logType": "SearchAndClick", "sessionId": "1592193858073.6265", "operation": "click", "staffNickname": "tanker", "clickIndexInAll": 1, "clickIndexByPage": 1, "clickType": "issueGroup"}

検索セッションが sessionId で、その中で行う複数の検索行動を searchIdで管理しています。そのほかに実行時間、スタッフ名、ヒット件数、クリック位置なども出力します。なお、ログ出力は専用の API を用意し、各アクション毎にAPI を叩いてサーバ側で吐いています。

Filebeat & Logstash で集計と成形

$ cat /etc/filebeat/filebeat.yml
filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /usr/share/search-log/search-and-click*.log
output.logstash:
  hosts: ["localhost:5044"]

$ cat /etc/logstash/conf.d/filebeat-kibana.conf
input {
  beats {
    port => "5044"
  }
}
filter {
  json {
    source => "message"
  }

  if [operation] == "search" {
     aggregate {
       task_id => "%{searchId}"
       code => "
         map['log_type'] = 'search'
         map['search_id'] ||= event.get('searchId')
         map['session_id'] ||= event.get('sessionId')
         map['staff_nickname'] ||= event.get('staffNickname')
         map['searches'] ||= []
         map['clicks'] ||= []
         map['total'] ||= event.get('total')
         map['timestamp'] ||= event.get('timestamp')
       "
     }
     aggregate {
        task_id => "%{sessionId}"
        code => "
          map['log_type'] = 'session'
          map['session_id'] ||= event.get('sessionId')
          map['staff_nickname'] ||= event.get('staffNickname')
          map['searches'] ||= []
          map['searches'] << event.get('searchId')
          map['clicks'] ||= []
          map['timestamp'] ||= event.get('timestamp')
        "
     }
  }

  if [operation] == "click" {
    aggregate {
      task_id => "%{searchId}"
      code => "
         map['clicks'] ||= []
         map['clicks'] << {'index_in_all' => event.get('clickIndexInAll'), 'index_by_page' => event.get('clickIndexByPage')}
      "
      timeout => 30
      push_previous_map_as_event => true
    }
    aggregate {
      task_id => "%{sessionId}"
      code => "
        map['clicks'] ||= []
        map['clicks'] << {'search_id' => event.get('searchId'), 'index_in_all' => event.get('clickIndexInAll'), 'index_by_page' => event.get('clickIndexByPage')}
      "
      timeout => 30
      push_previous_map_as_event => true
    }
  }


  if !("" in [log_type]) {
    drop { }
  } else {
    ruby {
      code => "
        event.set('search_cnt', event.get('searches').uniq.size)
        event.set('click_cnt', event.get('clicks').uniq.size)
      "
    }
  }
}
output {
  if [log_type] == "search" {
    elasticsearch {
        hosts => ["localhost:9200"]
        index => "search_and_click-%{+YYYY.MM.dd}"
    }
  }
  if [log_type] == "session" {
    elasticsearch {
        hosts => ["localhost:9200"]
        index => "session_search_and_click-%{+YYYY.MM.dd}"
    }
  }
  stdout { codec => rubydebug }
}

※ Elastic ファミリーは 7.7.0 を使っています。

まだ試験段階だったので、リアルタイムではなく後日分の tracking ログを grep で取り出してファイルに出力して、 Filebeat が watch している場所に設置するようにしました。

Logstash では aggregate filter plugin (別途 install が必要) を使って sessionId 毎 & searchId 毎に search / click を集計しています。plugin の使い方は、公式がすごく分かりやすかったです。( https://www.elastic.co/guide/en/logstash/current/plugins-filters-aggregate.html )また、そのままだと、集計前のログも出力してしまうので drop filter を使い、集計ログ以外は捨てます。また、 ruby plugin を使って、uniq 集計していますが、これはクリックログが重複して出力されてしまっており、それを回避するために行っています。これはログ出力部分のバグなので後ほど改善したいです。最後に、それぞれの index に出力して完成です。 debug 用に stdout もしていますが、こちら必要に応じて出せばよいと思います。

今回、 aggregate の timeout を 30秒に設定しています。ちなみにこの値は、集計値を保持する時間で、今回でいうと同じ sessionId のログが出力されなくなる(その検索セッションが完全に終了した)期間であるのが望ましいです。今回は事後集計だったので 30秒にしていますがリアルタイム集計の場合は調整が必要になってくると思います。(短いと、同じ sessionId のログが分割されて出力されてしまう)

余談ですが、Elasticsearch には aggregation も pipeline aggregation もあり、 Kibana も部分的に対応しているのでそちらを使ったほうが柔軟に後から変更できる点はよいのかなとも思いましたが、Kibana の dashboard を色々な人がいじりやすくしたほうが良いのかと思い集計ロジックは logstash 側に寄せてしまいました。

ES に格納するデータは以下のようになります。 timestamp と @timestamp がありますが後者は logstash が付与したものでログの生成時間なので、 Kibana の時間軸としては前者 (元のログの出力時間) を使います

## sessionId 集計
{ 
    "@version": "1", 
    "@timestamp": "2020-06-01T03:13:30.395Z",
    "timestamp": "2020-05-29T09:54:13+09:00",
    "log_type": "session",
    "session_id": "1590713156137.9377",
    "staff_nickname": "tanker",
    "searches": [ "1590713653.41", "1590713654.63", "1590713652.88", "1590713654.98", "1590713653.62", "1590713654.83", "1590713654.13", "1590713654.13", "1590713653.41", "1590713654.3", "1590713652.88", "1590713654.12", "1590713654.98", "1590713654.27", "1590713654.12", "1590713654.83", "1590713653.62", "1590713654.27", "1590713654.64", "1590714232.81", "1590714232.81", "1590713654.64", "1590713654.63", "1590713654.3", "1590714827.21" ],
    "clicks": [ { "index_by_page": 1, "search_id": "1590713653.41", "index_in_all": 1 }, { "index_by_page": 2, "search_id": "1590713653.41", "index_in_all": 2 }, { "index_by_page": 1, "search_id": "1590713652.88", "index_in_all": 1 }, { "index_by_page": 2, "search_id": "1590713653.41", "index_in_all": 2 }, { "index_by_page": 2, "search_id": "1590713652.88", "index_in_all": 2 }, { "index_by_page": 1, "search_id": "1590713654.13", "index_in_all": 1 }, { "index_by_page": 6, "search_id": "1590714232.81", "index_in_all": 6 }, { "index_by_page": 6, "search_id": "1590714232.81", "index_in_all": 6 }, { "index_by_page": 4, "search_id": "1590713654.64", "index_in_all": 4 }, { "index_by_page": 3, "search_id": "1590713653.41", "index_in_all": 3 }, { "index_by_page": 3, "search_id": "1590713653.41", "index_in_all": 3 }, { "index_by_page": 2, "search_id": "1590713652.88", "index_in_all": 2 }, { "index_by_page": 4, "search_id": "1590713654.64", "index_in_all": 4 }, { "index_by_page": 1, "search_id": "1590713654.64", "index_in_all": 1 }, { "index_by_page": 1, "search_id": "1590713652.88", "index_in_all": 1 }, { "index_by_page": 1, "search_id": "1590713653.41", "index_in_all": 1 }, { "index_by_page": 1, "search_id": "1590713654.64", "index_in_all": 1 }, { "index_by_page": 1, "search_id": "1590713654.13", "index_in_all": 1 } ]
    "search_cnt": 13,
    "click_cnt": 9,
}
## searchId 集計
{ 
    "@version" : "1",
    "@timestamp" : "2020-06-01T03:13:30.344Z"
    "timestamp" : "2020-05-29T09:54:13+09:00",
    "log_type" : "search",
    "staff_nickname" : "tanker",
    "session_id" : "1590713156137.9377",
    "search_id" : "1590713653.41",
    "searches" : [ ],
    "clicks" : [ { "index_in_all" : 1, "index_by_page" : 1 }, { "index_in_all" : 2, "index_by_page" : 2 }, { "index_in_all" : 2, "index_by_page" : 2 }, { "index_in_all" : 3, "index_by_page" : 3 }, { "index_in_all" : 3, "index_by_page" : 3 }, { "index_in_all" : 1, "index_by_page" : 1 } ],
    "total" : 8,
    "search_cnt" : 0,
    "click_cnt" : 3,
}

Kibana で可視化

Kibana で Visualize を作り、dashboard を作成しました。

例えば、集計表の Visualize は以下のような設定になります。

過去のログを Kibana で見る場合には、右上の time range をログの時間帯に変更するのをお忘れなく。(デフォルトだと現在時間から●時間前とかの直近のデータしか参照してくれないので)

一緒に働くエンジニア募集中！

ビザスクに少しでも興味のあるWebエンジニアの方がいたら、ぜひお話を聞かせてください！詳しい募集要項は下記リンクからアクセスしてください。

エンジニア採用ページ: https://visasq.co.jp/engineer-recruitment
ビザスクの中の様子はこちらから >> https://square.visasq.com/

VisasQ Dev Blog

ビザスク開発ブログ

検索の KPI (評価指標)をとりたい！

tracking 用のログを出力

Filebeat & Logstash で集計と成形

Kibana で可視化

一緒に働くエンジニア募集中！