CloudWatch Logsのログ取得で空が返ってくることがあるっていう仕様


# 概要
CloudWatch Logsのログ取得で、AWS上にログが存在しているにもかかわらず空の情報が返ってくることがあり、その理由を調べた結果そういった仕様であったという話。

# ログがあっても空が返ってくることがある
CloudWatch Logsの特定のログストリーム内の、指定期間内のログを取得する処理を、boto3を使ってPythonで作ったものがある。

ある日、ログストリーム内に対象のログがあるのに取得されないということがあった。

いろいろ調査していると、利用しているAPI ( `get_log_events` ) のドキュメントで以下の説明を見つけた。

>This operation can return empty results while there are more log events available through the token.
>引用 : https://boto3.amazonaws.com/v1/documentation/api/latest/reference/services/logs.html#CloudWatchLogs.Client.get_log_events

日本語訳
>この操作は、トークンを介して利用可能なログイベントがさらにある間、空の結果を返す可能性があります。

この言葉の通り、ログが存在していたとしても (おそらく一時的に) 空の結果を返すこともあるということらしい。

その上で今の実装を見ると、以下のようになっていた。

```python
is_finished = False
next_token = None
log_events = []
while not is_finished:
    args = {
        "logGroupName": log_group_name,
        "logStreamName": log_stream_name,
        "startFromHead": True,
        "limit": limit
    }
    if next_token is not None:
        args["nextToken"] = next_token
    else:
        start_timestamp = datetime_to_millisec_timestamp(start_time)
        end_timestamp = datetime_to_millisec_timestamp(end_time)
        args["startTime"] = start_timestamp
        args["endTime"] = end_timestamp

    response = client.get_log_events(**args)

    if "events" not in response or len(response["events"]) == 0:
        break

    for log_event in response["events"]:
        log_events.append(log_event)

    if "nextForwardToken" not in response:
        is_finished = True
    else:
        next_token = response["nextForwardToken"]
```

レスポンスに含まれるトークンを利用してページングすることで、条件に該当するログの全件を取得することができる。上記では、そのループ処理の中でで「eventsが空の時」をページの終了と判定してにbreakをしていた。

前述の通り、ログが存在していたとしても空が返ることがあるため、これはログ取得のページングの終了判定の仕方として正しくない。この影響で、ログストリーム内に対象のログがあるのに取得されないという事象が発生したと推測した。

また、ログイベントを取得するAPIとして、`get_log_events` の他に `filter_log_events` があるが、これも空が返ってくることがある仕様となっている。
https://boto3.amazonaws.com/v1/documentation/api/latest/reference/services/logs.html#CloudWatchLogs.Client.filter_log_events

# 正しい実装方法
おそらくこのログ自体が結果整合性となっているための仕様であると考えられるが、本当にログが存在しないのか or 今回のようにログが存在するけど取得できなかったのどっちなのか判定をしたい。そのための方法はちゃんと用意されている。

## `get_log_events`の場合
レスポンスに含まれるトークン `nextForwardToken` (遡る場合は `nextBackwardToken`) で判定する。このトークンが連続して同じ値の時、ページングは終了となる。

>If you have reached the end of the stream, it returns the same token you passed in.
>引用 : https://boto3.amazonaws.com/v1/documentation/api/latest/reference/services/logs.html#CloudWatchLogs.Client.get_log_events 

これをもとに実装し直すと、以下のようになる。

```python
is_finished = False
next_token = None
log_events = []
while not is_finished:
    args = {
        "logGroupName": log_group_name,
        "logStreamName": log_stream_name,
        "startFromHead": True,
        "limit": limit
    }
    if next_token is not None:
        args["nextToken"] = next_token
    else:
        start_timestamp = datetime_to_millisec_timestamp(start_time)
        end_timestamp = datetime_to_millisec_timestamp(end_time)
        args["startTime"] = start_timestamp
        args["endTime"] = end_timestamp

    response = client.get_log_events(**args)

    for log_event in response["events"]:
        log_events.append(log_event)

    if "nextForwardToken" not in response:
        is_finished = True
    elif next_token is not None and response["nextForwardToken"] == next_token:
        is_finished = True
    else:
        next_token = response["nextForwardToken"]
```

## `filter_log_events`の場合
レスポンスに含まれるトークン `nextToken` で判定する。この `nextToken` が含まれない時、ページングは終了となる。

> If the results include a token, then there are more log events available, and you can get additional results by specifying the token in a subsequent call. 
> 引用 : https://boto3.amazonaws.com/v1/documentation/api/latest/reference/services/logs.html#CloudWatchLogs.Client.filter_log_events 

これをもとに実装すると、以下のようになる。

```python
is_finished = False
next_token = None
log_events_per_stream = {}
while not is_finished:
    args = {
        "logGroupName": log_group_name,
        "limit": limit
    }
    if next_token is not None:
        args["nextToken"] = next_token
    else:
        start_timestamp = datetime_to_millisec_timestamp(start_time)
        end_timestamp = datetime_to_millisec_timestamp(end_time)
        args["startTime"] = start_timestamp
        args["endTime"] = end_timestamp

    response = client.filter_log_events(**args)

    for log_event in response["events"]:
        message = log_event["message"]
        log_stream_name = log_event["logStreamName"]

        if log_stream_name not in log_events_per_stream:
            log_events_per_stream[log_stream_name] = []
        log_events_per_stream[log_stream_name].append(log_event)

    if "nextToken" not in response:
        is_finished = True
    else:
        next_token = response["nextToken"]
```
## 動作確認
空が返ってくる条件は不明で偶発的に起こるもののようなので、再現は出来なさそう。


## まとめ
結論としては、ちゃんとドキュメントを読んでいればわかったことであった。
このように検証では見つけるのが難しい条件もあるため、使う際はしっかり読もうということを改めて感じさせられた。