本記事はサムザップ #1 Advent Calendar 2020の 19 日目の記事です。

はじめに

弊社で運用しているゲームアプリは、サーバ言語として PHP を使用していることが多いです。

今回は、現在のリクエスト数における PHP のアクティブなプロセス数がおおよそどれくらいかを可視化したく、CloudWatch のメトリクスに出力してみたので、そちらを紹介します。

前提

PHP の実行環境としては、Nginx + PHP-FPM を使用しています。

設定方法

PHP-FPM

PHP-FPM のステータスを出力するには、conf で以下の 1 行を追加するのみで OK です。

pm.status_path = /phpfpm_status

パスの値はわかりやすければ何でも良いです。
上記の設定を入れ、curlなどでリクエストしてみましょう。

$ curl http://localhost/phpfpm_status
pool:                 www
process manager:      dynamic
start time:           18/Dec/2020:03:12:27 +0000
start since:          1609
accepted conn:        4
listen queue:         0
max listen queue:     0
listen queue len:     128
idle processes:       1
active processes:     1
total processes:      2
max active processes: 1
max children reached: 0
slow requests:        0

このように PHP-FPM のステータスが取れます。

ちなみに、クエリストリングとして?fullを追加するとプロセスごとの詳細も見れます。

$ curl http://localhost/phpfpm_status?full
pool:                 www
process manager:      dynamic
start time:           18/Dec/2020:03:12:27 +0000
start since:          1622
accepted conn:        5
listen queue:         0
max listen queue:     0
listen queue len:     128
idle processes:       1
active processes:     1
total processes:      2
max active processes: 1
max children reached: 0
slow requests:        0

************************
pid:                  7
state:                Idle
start time:           18/Dec/2020:03:12:27 +0000
start since:          1622
requests:             2
request duration:     2814
request method:       GET
request URI:          /status
content length:       0
user:                 -
script:               -
last request cpu:     0.00
last request memory:  2097152

************************
pid:                  8
state:                Running
start time:           18/Dec/2020:03:12:27 +0000
start since:          1622
requests:             3
request duration:     1460
request method:       GET
request URI:          /status?full
content length:       0
user:                 -
script:               -
last request cpu:     0.00
last request memory:  0

また、?jsonをつけると、json 形式での出力になります。

$ curl http://localhost/phpfpm_status?json
{"pool":"www","process manager":"dynamic","start time":1608261147,"start since":1877,"accepted conn":6,"listen queue":0,"max listen queue":0,"listen queue len":128,"idle processes":1,"active processes":1,"total processes":2,"max active processes":1,"max children reached":0,"slow requests":0}

Lambda

実際に、PHP-FPM のステータス取得をリクエストするための Lambda 関数を作成します。
関数は以下のように作ってみました。

lambda_function.py

import os
import time
import json
import logging
import requests

LOGGER = logging.getLogger()
LOGGER.setLevel(logging.INFO)

config = json.load(open('config.json'))

def lambda_handler(event, context):
    # TODO implement
    """
    event:
        (Required)
        target: [string]

        (Optional)
        params: 
            env: (string)
            interval_sec: (int)
            request_cont: (int)
    """

    try:
        if "target" not in event:
            raise ValueError("targetが定義されていません。")
        target = event["target"]
        params = event["params"] if "params" in event else {}

        if "env" not in params:
            params["env"] = int(os.environ['ENV'])
        if "request_cont" not in params:
            params["request_cont"] = int(os.environ['REQUEST_COUNT'])
        if "interval_sec" not in params:
            params["interval_sec"] = int(os.environ['INTERVAL_SEC'])

        _request_status(target, params)

    except ValueError as e:
        LOGGER.error(e)
    except Exception as e:
        LOGGER.error(e)


def _request_status(target, params):
    settings = config[params["env"]]
    if target not in settings["url"]:
        raise ValueError("ステータス取得URLが存在しません。config.jsonを確認してください。")

    url = settings["url"][target]

    for i in range(params["request_cont"]):
        response = requests.get(url)
        if response.status_code == 200:
            status = json.dumps(response.json())
            print("[STATUS CHECK]|target:{target}|env:{env}|status:{status}".format(target=target, env=params["env"], status=status))
        time.sleep(params["interval_sec"])

config.json

{
    "development": {
        "url": {
            "phpfpm": "https://【ドメイン】/phpfpm_status?json"
        }
    },
    "staging": {
        "url": {
            "phpfpm": "https://【ドメイン】/phpfpm_status?json"
        }
    },
    "production": {
        "url": {
            "phpfpm": "https://【ドメイン】/phpfpm_status?json"
        }
    }
}

環境変数としては以下のように設定しました。

変数名	説明	例
ENV	環境名	development
INTERVAL_SEC	リクエストのスリープインターバル（秒）	1
REQUEST_COUNT	一回の関数実行におけるリクエスト数	10

Lambda 関数の実装内容としては、一回の実行で、ENV環境の URL に対して、INTERVAL_SECで設定した秒数のスリープインターバルで REQUEST_COUNTの回数分リクエストを送るような処理をしています。
これらは、Lambda の環境変数にデフォルト値を設定しつつ、実行の際のevent引数でも上書きで設定できるようにしてます。

config.jsonに関しては、環境ごとに PHP-FPM のステータスを取得する URL を記載しています。

例えばインターバル 1 秒で 10 回のリクエストとして実行した際は、CloudWatch Logs には以下のように 1 秒間隔で 10 行のログレコードが生成されます。

[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51874, "accepted conn": 16454, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51875, "accepted conn": 16455, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51876, "accepted conn": 16456, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51877, "accepted conn": 16457, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51878, "accepted conn": 16458, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51880, "accepted conn": 16459, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51881, "accepted conn": 16460, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51882, "accepted conn": 16461, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51883, "accepted conn": 16465, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 46, "active processes": 2, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}
[STATUS CHECK]|target:phpfpm|env:development|status:{"pool": "www", "process manager": "dynamic", "start time": 1608213868, "start since": 51884, "accepted conn": 16466, "listen queue": 0, "max listen queue": 0, "listen queue len": 128, "idle processes": 47, "active processes": 1, "total processes": 48, "max active processes": 3, "max children reached": 1, "slow requests": 0}

この Lambda 関数を CloudWatch Events を使用して定期実行させ、CloudWatch Logs に上記のようなログが定常的に出力されるように設定します。
今回は 1 分に一回のサイクルでこの Lambda 関数が実行されるように CloudWatch Events に設定しました。

CloudWatch Logs Insights

指定のロググループに対してクエリを用いて検索できるのが、CloudWatch Logs Insights です。
クエリの書き方などは少しクセがありますが、慣れてしまえば何かと便利です。
ログが json で出力されていれば、json のキーを自動認識してくれるので、そのままクエリ内で使用することができます。

そして、statsコマンドを使用すれば、ログ内の数値情報を集計することもできます。
今回はこの statsコマンドを使用して、以下のようなクエリを作ってみました。

filter @message like "STATUS CHECK"
|filter @message like "target:phpfpm"
|stats max(`active processes`) by bin(1m)

これは、ログストリーム内のログの中から、「STATUS CHECKと target:phpfpm という文字列の入ったログを抽出し、1分間ごとに active processesキーの値の最大値をプロットする」というようなクエリです。

これをにより、PHP-FPM の 1 分間の中でのおおよその最大アクティブプロセス数がグラフ化できます。

1 回のリクエストで言うと、ロードバランサに紐づくターゲットインスタンスのどれかに対してのみリクエストが飛ぶので、厳密に言うとすべてのインスタンスにおける PHP の最大のアクティブプロセス数を出力しているわけではないですが、統計上の標本を増やすために Lambda 関数の一回の実行で何度かリクエストを飛ばすように実装しておりました。

まとめ

今回は PHP-FPM のアクティブなプロセス数をグラフ化するために、Lambda 関数や CloudWatch Logs Insights を用いました。
特に CloudWatch Logs Insights はロググループ内の数値情報か簡単な集計処理も行えるので、PHP-FPM に限らず、他の用途でも使用できます。
例えば、PHP のエラーログを CloudWatch Logs に転送しておき、特定のワードで絞り込んだ際の件数（count）をグラフ化しておき、一定の件数を越えたらアラートが飛ぶような設定を行うといったシチュエーションにも使えます。

AWS が用意してくれているデフォルトのメトリクスでは足りないといった場合は、ぜひご活用ください。

PHP-FPM のステータスを CloudWatch でモニタリングしてみた

はじめに

前提

設定方法

PHP-FPM

Lambda

CloudWatch Logs Insights

まとめ