PythonのPrometheus Clientを試してみる

これは、なにをしたくて書いたもの？

Pythonで、Prometheusのクライアントライブラリを試してみようかなということで。

Prometheus Python Client

文字通り、PrometheusのPython向けクライアントライブラリです。

GitHub - prometheus/client_python: Prometheus instrumentation library for Python applications

そもそも、各言語でどのようなクライアントがあったのかは、こちらを参照。

Client libraries | Prometheus

Prometheus Python Clientは、Python 2およびPython 3向けのPrometheusクライアントライブラリです。

README.mdにあるコード例を見るとわかるのですが、HTTPサーバーを自前で立てるみたいですね。

from prometheus_client import start_http_server, Summary

...

if __name__ == '__main__':
    # Start up the server to expose the metrics.
    start_http_server(8000)

メトリクスのエクスポートに関する情報を見てみると、HTTP以外にも、WSGI、Flaskに組み込む等の方法もあるようです。

Exporting

Gunicornを使ったマルチプロセスに関する対応も書いていますね。

Multiprocess Mode (Gunicorn)

このあたりは、今度試してみましょう…。

とりあえず、今回はシンプルに使ってみます。

他の言語のPrometheusクライアントライブラリに関しては、以前に試しているので、こちらも（自分が）振り返りつつ。

PrometheusのJVM Clientを試してみる - CLOVER🍀

PrometheusのNode.jsクライアントを試す - CLOVER🍀

環境

今回の環境は、こちら。

$ python3 -V
Python 3.8.5

インストール

Prometheus Python Clientは、pipでインストールします。今回使用するバージョンは0.8.0です。

$ pip3 install prometheus_client==0.8.0

とりあえず組み込んでみる

なにはともあれ、とりあえず組み込んでみましょう。

http.serverモジュールを使ってHTTPサーバーを書き、これと一緒にPrometheus Python Clientを組み込みます。

http.server --- HTTP サーバ — Python 3.8.6 ドキュメント

こんな感じにしてみました。
base.py

from datetime import datetime
from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
from random import randrange
import time
from urllib.parse import parse_qs, urlparse

from prometheus_client import start_http_server

class MyHTTPRequestHandler(BaseHTTPRequestHandler):
    def do_GET(self):
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as GET'.encode('utf-8'))

    def do_POST(self):
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        content_length = int(self.headers['content-length'])
        body = self.rfile.read(content_length).decode('utf-8')

        print(f'body = {body}')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as POST'.encode('utf-8'))

if __name__ == '__main__':
    start_http_server(8000)

    with ThreadingHTTPServer(('0.0.0.0', 8080), MyHTTPRequestHandler) as server:
        print(f'[{datetime.now()}] Server startup.')
        server.serve_forever()

GETおよびPOSTメソッドに対するHandlerを書いています。

class MyHTTPRequestHandler(BaseHTTPRequestHandler):
    def do_GET(self):
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as GET'.encode('utf-8'))

    def do_POST(self):
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        content_length = int(self.headers['content-length'])
        body = self.rfile.read(content_length).decode('utf-8')

        print(f'body = {body}')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as POST'.encode('utf-8'))

動作的には、リクエストを受け取ったら、5秒以内のランダムな秒数スリープしてリクエストを受けたURLの情報などを
返します。

Prometheusからサブスクライブされるサーバーは、こんな感じで立てています。というか、README.mdのままです。

if __name__ == '__main__':
    start_http_server(8000)

軽く確認してみましょう。

起動。

$ python3 base.py 
[2020-10-21 21:29:16.755793] Server startup.

確認。

$ time curl localhost:8080/echo?message=hello
Hello World!! from /echo?message=hello as GET
real    0m1.021s
user    0m0.010s
sys 0m0.010s


$ time curl -XPOST localhost:8080/echo -d 'message=hello'
Hello World!! from /echo as POST
real    0m4.019s
user    0m0.011s
sys 0m0.004s

こんな感じです。

パスの末尾を/errorで終わらせると、エラーになります。

$ curl localhost:8080/hoge/error
curl: (52) Empty reply from server

裏ではバックトレースが吐かれています。

----------------------------------------
Exception happened during processing of request from ('127.0.0.1', 33660)
Traceback (most recent call last):
  File "/usr/lib/python3.8/socketserver.py", line 650, in process_request_thread
    self.finish_request(request, client_address)
  File "/usr/lib/python3.8/socketserver.py", line 360, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/lib/python3.8/socketserver.py", line 720, in __init__
    self.handle()
  File "/usr/lib/python3.8/http/server.py", line 427, in handle
    self.handle_one_request()
  File "/usr/lib/python3.8/http/server.py", line 415, in handle_one_request
    method()
  File "base.py", line 14, in do_GET
    raise Exception('Error')
Exception: Error
----------------------------------------

こうやってわざわざ例外を投げているのは、あとでまた。

メトリクスを取得してみましょう。

$ curl localhost:8000
# HELP python_gc_objects_collected_total Objects collected during gc
# TYPE python_gc_objects_collected_total counter
python_gc_objects_collected_total{generation="0"} 365.0
python_gc_objects_collected_total{generation="1"} 7.0
python_gc_objects_collected_total{generation="2"} 0.0
# HELP python_gc_objects_uncollectable_total Uncollectable object found during GC
# TYPE python_gc_objects_uncollectable_total counter
python_gc_objects_uncollectable_total{generation="0"} 0.0
python_gc_objects_uncollectable_total{generation="1"} 0.0
python_gc_objects_uncollectable_total{generation="2"} 0.0
# HELP python_gc_collections_total Number of times this generation was collected
# TYPE python_gc_collections_total counter
python_gc_collections_total{generation="0"} 35.0
python_gc_collections_total{generation="1"} 3.0
python_gc_collections_total{generation="2"} 0.0
# HELP python_info Python platform information
# TYPE python_info gauge
python_info{implementation="CPython",major="3",minor="8",patchlevel="5",version="3.8.5"} 1.0
# HELP process_virtual_memory_bytes Virtual memory size in bytes.
# TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 1.81542912e+08
# HELP process_resident_memory_bytes Resident memory size in bytes.
# TYPE process_resident_memory_bytes gauge
process_resident_memory_bytes 1.9755008e+07
# HELP process_start_time_seconds Start time of the process since unix epoch in seconds.
# TYPE process_start_time_seconds gauge
process_start_time_seconds 1.60328335576e+09
# HELP process_cpu_seconds_total Total user and system CPU time spent in seconds.
# TYPE process_cpu_seconds_total counter
process_cpu_seconds_total 0.15
# HELP process_open_fds Number of open file descriptors.
# TYPE process_open_fds gauge
process_open_fds 7.0
# HELP process_max_fds Maximum number of open file descriptors.
# TYPE process_max_fds gauge
process_max_fds 1024.0

組み込んだだけだと、これくらいの情報が取れるみたいですよ。

$ curl -s localhost:8000 | grep -v '#' | perl -wp -e 's! .+!!g' | sort -u
process_cpu_seconds_total
process_max_fds
process_open_fds
process_resident_memory_bytes
process_start_time_seconds
process_virtual_memory_bytes
python_gc_collections_total{generation="0"}
python_gc_collections_total{generation="1"}
python_gc_collections_total{generation="2"}
python_gc_objects_collected_total{generation="0"}
python_gc_objects_collected_total{generation="1"}
python_gc_objects_collected_total{generation="2"}
python_gc_objects_uncollectable_total{generation="0"}
python_gc_objects_uncollectable_total{generation="1"}
python_gc_objects_uncollectable_total{generation="2"}
python_info{implementation="CPython",major="3",minor="8",patchlevel="5",version="3.8.5"}

このあたりっぽいですね。

Process Collector

Platform Collector

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/process_collector.py

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/gc_collector.py

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/platform_collector.py

メトリクスをエクスポートしているサーバーは、このあたり。

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/exposition.py

Exporting / HTTP

とりあえず、Prometheusのメトリクスをエクスポートしたところで、先に進んでみましょう。

独自のメトリクスを追加する

では、アプリケーション独自のメトリクスを追加してみましょう。

Instrumenting

Prometheusのメトリクスには、Counter、Gauge、Histogram、Summaryの4種類があります。

Metric types | Prometheus

選び方は、こちらを参考に。

Counter vs. gauge, summary vs. histogram

Histograms and summaries | Prometheus

メトリクスの名前の付け方については、こちらを参照。

Metric and label naming | Prometheus

今回は、これらの情報を使って

HTTP GET、POSTのそれぞれの呼び出し回数（Counter）
HTTPステータスごとのカウント（Counter）
例外の発生回数（Counter＋ラベル）
HTTP GETのリクエスト時間（Summary）
HTTP POSTのURL単位のリクエスト時間（Summary＋ラベル）

で、作ったソースコードはこんな感じに。
app.py

from datetime import datetime
from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
from random import randrange
import time
import timeit
from urllib.parse import parse_qs, urlparse

from prometheus_client import start_http_server
from prometheus_client import Counter, Summary

get_method_counter = Counter('http_get_requests', 'HTTP GET Request Counter')
post_method_counter = Counter('http_post_requests', 'HTTP POST Request Counter')
access_counter = Counter('http_status', 'HTTP Access Counter', ['method', 'url', 'status_code'])

exception_conter = Counter('exceptions', 'HTTP Server Exception Counter')

get_request_time = Summary('http_get_request_processing_seconds', 'HTTP GET Request Time')
post_request_time = Summary('http_post_request_processing_seconds', 'HTTP POST Request Time', ['method', 'url'])

class MyHTTPRequestHandler(BaseHTTPRequestHandler):
    @exception_conter.count_exceptions()
    @get_request_time.time()
    def do_GET(self):
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as GET'.encode('utf-8'))

        get_method_counter.inc()
        access_counter.labels('GET', parsed_path.path, '200').inc()

    @exception_conter.count_exceptions()
    def do_POST(self):
        start = timeit.default_timer()
        
        parsed_path = urlparse(self.path)

        if parsed_path.path.endswith('/error'):
            raise Exception('Error')

        content_length = int(self.headers['content-length'])
        body = self.rfile.read(content_length).decode('utf-8')

        print(f'body = {body}')

        sleep_time = randrange(1, 5)
        print(f'waiting, {sleep_time} sec...')
        time.sleep(sleep_time)

        self.send_response(200)
        self.send_header('Content-Type', 'text/plain; charset=utf-8')
        self.end_headers()
        self.wfile.write(f'Hello World!! from {self.path} as POST'.encode('utf-8'))

        elapsed_time = timeit.default_timer() - start

        post_method_counter.inc()
        access_counter.labels('POST', parsed_path.path, '200').inc()
        post_request_time.labels('POST', parsed_path.path).observe(elapsed_time)

if __name__ == '__main__':
    start_http_server(8000)

    with ThreadingHTTPServer(('0.0.0.0', 8080), MyHTTPRequestHandler) as server:
        print(f'[{datetime.now()}] Server startup.')
        server.serve_forever()

Counter

メトリクスは、メトリクス名、説明を最低限指定して作成します。

get_method_counter = Counter('http_get_requests', 'HTTP GET Request Counter')
post_method_counter = Counter('http_post_requests', 'HTTP POST Request Counter')
access_counter = Counter('http_status', 'HTTP Access Counter', ['method', 'url', 'status_code'])

exception_conter = Counter('exceptions', 'HTTP Server Exception Counter')

Counterは、関数デコレーターとしても使えます。この例だと、メソッドを例外で抜けるとカウントアップしてくれます。

    @exception_conter.count_exceptions()
    def do_GET(self):


    @exception_conter.count_exceptions()
    def do_POST(self):

/errorで終わると例外を投げるのは、このために用意したものです。

自分でインクリメントしてもOKです。

        get_method_counter.inc()
        access_counter.labels('GET', parsed_path.path, '200').inc()


        post_method_counter.inc()
        access_counter.labels('POST', parsed_path.path, '200').inc()

2つ目の例は、ラベルを使ったものです。

Labels

ラベルを使う際には、メトリクスの宣言時にどのようなラベルを持つかを宣言しておく必要があります。

access_counter = Counter('http_status', 'HTTP Access Counter', ['method', 'url', 'status_code'])

Summary

get_request_time = Summary('http_get_request_processing_seconds', 'HTTP GET Request Time')
post_request_time = Summary('http_post_request_processing_seconds', 'HTTP POST Request Time', ['method', 'url'])

Summaryも、関数デコレーターとして使うことができます。

    @get_request_time.time()
    def do_GET(self):

自分で記録する場合は、observeを呼び出せばOKです。こちらは、HTTPメソッドとURLパスを記録するラベル付きに
してあります。

        post_request_time.labels('POST', parsed_path.path).observe(elapsed_time)

このあたりのメトリクスや、コンテキストマネージャーの実装は、このあたりにあります。

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/metrics.py

https://github.com/prometheus/client_python/blob/v0.8.0/prometheus_client/context_managers.py

さて、確認してみましょう。

$ python3 app.py 
[2020-10-21 22:14:19.770500] Server startup.

いくつかリクエストを送ってみます。

$ time curl localhost:8080/echo?message=hello
Hello World!! from /echo?message=hello as GET
real    0m2.014s
user    0m0.003s
sys 0m0.008s


$ time curl -XPOST localhost:8080/echo -d 'message=hello'
Hello World!! from /echo as POST
real    0m1.016s
user    0m0.004s
sys 0m0.011s


$ time curl localhost:8080/error
curl: (52) Empty reply from server


$ time curl localhost:8080/index
Hello World!! from /index as GET
real    0m3.016s
user    0m0.004s
sys 0m0.008s


$ time curl localhost:8080/index
Hello World!! from /index as GET
real    0m2.018s
user    0m0.012s
sys 0m0.004s

メトリクスを取得してみます。

$ curl -s localhost:8000 | grep -v '#' | grep -E '^http|exceptions'
http_get_requests_total 3.0
http_get_requests_created 1.6032864815062068e+09
http_post_requests_total 1.0
http_post_requests_created 1.603286481506224e+09
http_status_total{method="GET",status_code="200",url="/echo"} 1.0
http_status_total{method="POST",status_code="200",url="/echo"} 1.0
http_status_total{method="GET",status_code="200",url="/index"} 2.0
http_status_created{method="GET",status_code="200",url="/echo"} 1.603286492138344e+09
http_status_created{method="POST",status_code="200",url="/echo"} 1.6032865048808618e+09
http_status_created{method="GET",status_code="200",url="/index"} 1.6032865243353045e+09
exceptions_total 1.0
exceptions_created 1.6032864815062468e+09
http_get_request_processing_seconds_count 4.0
http_get_request_processing_seconds_sum 7.007576047995826
http_get_request_processing_seconds_created 1.6032864815062637e+09
http_post_request_processing_seconds_count{method="POST",url="/echo"} 1.0
http_post_request_processing_seconds_sum{method="POST",url="/echo"} 1.0013110560030327
http_post_request_processing_seconds_created{method="POST",url="/echo"} 1.6032865048809013e+09

よくよく考えると、/error時のステータスコードを記録してないので、その他のメトリクスとズレてますが…まあ、いいか…。

その他は、良さそうですね。

Prometheusからサブスクライブしてみる

最後に、Prometheusからサブスクライブしてみましょう。

Prometheusは、2.22.0を使います。

設定ファイルは、こんな感じで。
prometheus.yml

global:
  scrape_interval:     5s # Set the scrape interval to every 15 seconds. Default is every 1 minute.
  evaluation_interval: 5s # Evaluate rules every 15 seconds. The default is every 1 minute.

scrape_configs:
  - job_name: 'prometheus'
    static_configs:
    - targets: ['localhost:9090']
  - job_name: 'app'
    static_configs:
    - targets: ['172.17.0.1:8000']