PLAIDEngineer Blog
エンジニア積極採用中

BigQueryの監査ログは役に立つ

Hiroto Harada

Posted on

BigQueryの監査ログは役に立つ

PLAID Engineerの 原田(@harada_hi) です。

弊社製品KARTEでは行動データという大量データの集計においてBigQueryを多用しています。
今回はそのBigQueryのパフォーマンス確認やトラブル時の調査に利用しているBigQueryの監査ログの話を紹介します。

集計を実施する上で確認したい内容

BigQueryはSparkやHadoopを組み合わせて実施していた集計処理を賄うことが可能です。
前述のとおりPLAIDにおいてもユーザーの行動データをBigQueryに収集し、クエリを実行して集計を実施しています。
BigQueryで集計を行う上で次のような点を確認したい場面があります。

  1. 各集計クエリの実行時間
  2. 時間帯ごとの集計クエリの同時実行数
  3. 各集計クエリで使用しているslot
  4. 動的に生成される集計クエリそのもの

1を確認したい理由はパフォーマンス確認の一つとしてです。
2,3を確認したい理由は、BigQueryの制限によるものです。

Bigquery > Documentation > Quotas & limits
https://cloud.google.com/bigquery/quotas

この中での
Concurrent rate limit for interactive queries — 100 concurrent queries
が理由です。
この制限に掛かっている場合、新規のインタラクティブ クエリを実行しようとすると強制的にエラーとなります。
2は同時実行の数そもそもを確認して、現状で危険な時間帯はないかを確認するために必要です。
3はこの制限にかかる潜在的なリスクを確認するためのものです。
slotを使いすぎている集計が存在するとその集計がボトルネックとなり他の集計が終わらず同時実行数が増えてしまうことがあります。

4を確認したい理由は、何らかのバグを確認した場合やパフォーマンスが悪いことを確認した場合に該当のクエリがわからないと対策が打てないためです。
変更のないクエリであれば問題になりませんが、動的にクエリを変更・生成している場合は重要です。

BigQueryのデータアクセスログ

上記で確認したい点はシステムからクエリを実行する以上、自前のログに書き込むことで確認は可能です。
しかしBigQueryの監査ログには自動的に上記の確認したい情報が入るので自前で用意する必要がありません。

BigQueryを含めたGoogle Cloud サービスの監査ログ(Cloud Audit Logging)の詳細は次の公式ドキュメントが存在しています。

Stackdriver > Documentation > Logging > Cloud Audit Logging
https://cloud.google.com/logging/docs/audit

この監査ログの中には以下の3つが存在しています。

  • 管理アクティビティログ
  • システムイベントログ
  • データアクセスログ

このうちのデータアクセスログが上で記載している確認したいことをカバーしています。
データアクセスログは各CRUD処理が全てログとして残ります。
こうした特徴から出力する対象のサービスは任意で指定する必要がありますが、
BigQueryに関しては標準で出力されています。

Stackdriver > Documentation > Logging > Configuring Data Access Logs
https://cloud.google.com/logging/docs/audit/configure-data-access

実際の確認方法は以下の2つです。

  1. Google Cloudが提供しているログビューワーからの確認
  2. 監査ログをGoogle Cloudサービスにエクスポートして確認

推奨は2番目の監査ログをGoogle Cloudサービスにエクスポートして確認で、BigQueryに監査ログをエクスポートして確認することです。
クエリで確認する情報を絞ることで調査を容易にすることにも繋げられる他、調査クエリを残しておくことで誰でも調査しやすい環境を作ることができます。
ただしBigQueryで監査ログを確認していくには次の対応が必要となります。

BigQuery > Overview > Stackdriver Logging exports
https://cloud.google.com/bigquery/docs/reference/auditlogs/#stackdriver-logging-exports

1のログビューワーでの確認は監査ログのデータ構成を確認するのに利用するのにおすすめです。
これはBigQueryで監査ログを確認するにあたって監査ログのデータ構成を理解する必要があるためです。
ログビューワーは次のURLで移動できます。
https://console.cloud.google.com/logs/viewer

実際に活用しているクエリの紹介

実際弊社で利用しているクエリを簡単にしたものを2つほど紹介します。
{{}}で囲んでいるところを変更していただければ使えるようにしています。

slotを消費しているクエリを確認する

WITH
{{project_id}} AS
(
  SELECT 
    '{{project_id}}' project_name,
    protopayload_auditlog.servicedata_v1_bigquery.*,
    protopayload_auditlog.serviceName as serviceName,
    protopayload_auditlog.methodName as methodName,
    protopayload_auditlog.resourceName as resourceName,
    timestamp
  FROM
    `{{project_id}}.{{dataset}}.cloudaudit_googleapis_com_data_access_{{timestamp}}`
),

{{project_id}}_COMPLETED_EVENT AS
(
  SELECT
    project_name,
    jobCompletedEvent.job.jobConfiguration.query.query as query,
    jobCompletedEvent.job.jobStatistics.createTime as jobCreateTime,
    jobCompletedEvent.job.jobStatistics.startTime as jobStartTime,
    jobCompletedEvent.job.jobStatistics.endTime as jobEndTime,
    jobCompletedEvent.job.jobConfiguration.query.queryPriority queryPriority,
    REGEXP_EXTRACT(jobCompletedEvent.job.jobConfiguration.query.query, "\"user\":\"([^\"]+)\"") mode_user,
    jobCompletedEvent.job.jobStatistics.totalSlotMs as totalSlotMs,
    timestamp
  FROM
    {{project_id}}
  WHERE
    methodName = 'jobservice.jobcompleted'
)

SELECT
  FORMAT_TIMESTAMP('%Y-%m-%d %H:%M:%S', timestamp, 'Asia/Tokyo') timestamp_jst,
  TIMESTAMP_DIFF(jobEndTime, jobStartTime, MILLISECOND) / (1000 * 60) act_span,
  TIMESTAMP_DIFF(jobEndTime, jobCreateTime, MILLISECOND) / (1000 * 60) job_span,
  project_name,
  queryPriority,
  query,
  totalSlotMs,
  totalSlotMs / (1000 * 60 * 60) totalSlotHour,
  totalSlotMs / (1000 * 60 * 60 * 24) totalSlotDay
FROM
  {{project_id}}_COMPLETED_EVENT
ORDER BY totalSlotMs DESC

slotを消費した順にクエリを並べています。
このクエリを元にして同時実行数が多くなっている時間帯を確認するなども行なっています。

エラーを発生させたクエリを確認する

WITH
{{project_id}} AS
(
  SELECT 
    '{{project_id}}' project_name,
    timestamp,
    severity,
    protopayload_auditlog.servicedata_v1_bigquery.*,
    protopayload_auditlog.serviceName as serviceName,
    protopayload_auditlog.methodName as methodName,
    protopayload_auditlog.resourceName as resourceName
  FROM
    `{{project_id}}.{{dataset}}.cloudaudit_googleapis_com_data_access_{{timestamp}}`
),

{{project_id}}_COMPLETED_EVENT AS
(
  SELECT
    project_name,
    timestamp,
    severity,
    jobCompletedEvent.job.jobConfiguration.query.query as query,
    jobCompletedEvent.job.jobConfiguration.query.queryPriority queryPriority,
    jobCompletedEvent.job.jobStatus.error.message error_message,
    jobCompletedEvent.job.jobStatistics.totalSlotMs as totalSlotMs
  FROM
    {{project_id}}
  WHERE
    methodName = 'jobservice.jobcompleted'
    AND severity = "ERROR"
)

SELECT
  project_name,
  timestamp,
  severity,
  queryPriority,
  error_message,
  query,
  totalSlotMs
FROM
  {{project_id}}_COMPLETED_EVENT 
ORDER BY timestamp DESC

ユーザーの設定によって動的にクエリが生成される場合は意図していないエラーが発生することがあります。
用意しておくことで調査をスムーズに進めることができています。

まとめ

BigQueryでは自動的に出力されている監査ログでも多くのことを調べることができるという紹介でした。
実際に確認いただくと上で紹介した以外のことも確認できるということが見えてくるかと思います。
BigQueryを利用したサービスを開発する上での参考になれば幸いです。

最後に

CX（顧客体験）プラットフォーム「KARTE」を運営するプレイドでは、KARTEを使ってこんなアプリケーションが作りたい！ KARTE自体の開発に興味がある！というエンジニア（インターンも！）を募集しています。
詳しくは弊社採用ページまたはWantedlyをご覧ください。 もしくはお気軽に、下記の「話を聞きに行きたい」ボタンを押してください！