😅

【AWS SDK / Kinesis】PutRecord時に改行を忘れAthenaで想定したクエリ結果が得られなかった件

2021/07/13に公開

はじめに

次の流れでAPIログを取るシステムを構築していました。

1.APIGateway -> 2.Lambda -> 3.Kinesis Firehose -> 4.S3 -> 5.Athena

構築後、APIのコール数とAthenaで取得した件数が合わないという問題が起きました。

原因は putRecord時に改行が漏れていた ことでした。それにより、S3オブジェクト内のデータが改行で区切られておらず、Athena側で想定通りデータが取得できなかったようです。具体的には putRecordの実行回数と、Athenaの結果の数が合わない 状態となりました。

やらかし再現やってみた

当時を再現して、このように検証をやってみます。

  • AWS LambdaのログをS3に出力してAthenaでクエリする環境を作成
  • 改行なしでputRecordを行うnode.jsアプリを実行
  • 改行有りでputRecordを行うnode.jsアプリを実行

準備

以下のファイルを作成します

  • app.js:改行なしでputRecordを行うnode.jsアプリ
  • app2.js:改行有りでputRecordを行うnode.jsアプリ
  • exec.bash:app.js, app2.jsをまとめて実行するスクリプト
app.js
const AWS = require("aws-sdk");
const region = process.env.AWS_REGION || 'ap-northeast-1';

AWS.config.update({ region: region });

const DELIVERY_STREAM_NAME = "katoaki-dev-log-stream";

const main = async () => {

  if (!(process.argv[2] && process.argv[3])){
    process.exit(1);
  }
  const log = {
    "key": process.argv[2],
    "value": process.argv[3],
    "created_at": Date.now(),
  }

  // See: https://docs.aws.amazon.com/ja_jp/firehose/latest/dev/writing-with-sdk.html
  const params = {
    DeliveryStreamName: DELIVERY_STREAM_NAME,
    Record: {
      Data: JSON.stringify(log)
    }
  }

  const firehose = new AWS.Firehose({apiVersion: '2015-08-04'});

  try {
    await firehose.putRecord(params).promise();
  } catch(e) {
    console.log(e);
  }
}

main();
app2.js
const AWS = require("aws-sdk");
const region = process.env.AWS_REGION || 'ap-northeast-1';

AWS.config.update({ region: region });

const DELIVERY_STREAM_NAME = "katoaki-dev-log-stream";

const main = async () => {

  if (!(process.argv[2] && process.argv[3])){
    process.exit(1);
  }
  const log = {
    "key": process.argv[2],
    "value": process.argv[3],
    "created_at": Date.now(),
  }

  // See: https://docs.aws.amazon.com/ja_jp/firehose/latest/dev/writing-with-sdk.html
  const params = {
    DeliveryStreamName: DELIVERY_STREAM_NAME,
    Record: {
      Data: JSON.stringify(log) + "\n"
    }
  }

  const firehose = new AWS.Firehose({apiVersion: '2015-08-04'});

  try {
    await firehose.putRecord(params).promise();
  } catch(e) {
    console.log(e);
  }
}

main();
exec.bash
echo "app.jsを実行します"
for i in {1..5}
do
  node app.js key${i} value${i}
  sleep 1
done

echo "app.jsでputした内容がオブジェクトへ生成されるのを待ちます..."
sleep 300

echo "app2.jsを実行します"
for i in {1..5}
do
  node app2.js key${i} value${i}
  sleep 1
done

echo "app2.jsでputした内容がオブジェクトへ生成されるのを待ちます..."
sleep 300

echo "正常終了しました"

実行

exec.bashを実行

$ bash exec.bash

S3オブジェクトが生成されていることを確認

  • exec.bashの実行により、2つのオブジェクトが生成されていることを確認します

  • それぞれのオブジェクトの内容について、以下のように改行の差異があることを確認します。

$ cat -e /Users/kato.hiroaki/dev/_temp/210711_blog-athena/1/katoaki-dev-log-stream-1-2021-07-11-07-52-00-e20ecae6-876b-4cdf-9f8a-ecae478a1f05 
{"key":"key1","value":"value1","created_at":1625989920636}{"key":"key2","value":"value2","created_at":1625989922082}{"key":"key3","value":"value3","created_at":1625989923493}{"key":"key4","value":"value4","created_at":1625989924906}{"key":"key5","value":"value5","created_at":1625989926363}$ 
$ cat -e /Users/kato.hiroaki/dev/_temp/210711_blog-athena/2/katoaki-dev-log-stream-1-2021-07-11-07-57-08-ec0efc70-15b3-47ca-b291-0782c0e79ac6 
{"key":"key1","value":"value1","created_at":1625990227983}$
{"key":"key2","value":"value2","created_at":1625990229424}$
{"key":"key3","value":"value3","created_at":1625990230824}$
{"key":"key4","value":"value4","created_at":1625990232238}$
{"key":"key5","value":"value5","created_at":1625990233615}$

クローラを実行

  • クローラを実行します

Athenaでデータを確認

  • [テーブル] - メニュー - [テーブルのプレビュー]を実行します
  • 改行なしのnode.jsアプリで出力したデータのうち、created_atが 1625989920636 移行のデータはクエリ結果に入ってこないことを確認します。

まとめ

  • AWS SDKを使ってKinesis Data FirehoseへPutRecordする際に、データ毎に改行を行わないとAthenaで想定通りのクエリ結果が得られないことがある

参考

Discussion