Представим следующую ситуацию. Ваш python веб-сервер собирает какие-то метрики prometheus_client-ом: счётчики, гистограммы и т. д, например, количество входящих запросов. Вы также настроили приложение, чтобы /metrics возвращал все ваши метрики. Если режим работы prometheus_client-a оставить по умолчанию, при запуске приложения gunicorn-ом с более чем одним воркером вы сталкиваетесь с проблемой консистентности метрик.
В такой конфигурации получается следующее:
каждый воркер хранит собственные метрики изолированно;
запрос
/metricsобрабатывается случайным воркером.
На примере http_requests_total это приводит к тому, что Prometheus вместо общего счётчика запросов получает счётчик запросов воркера, причем каждый раз случайного. Как следствие, получаем сброс метрики.
Напомню, что такая метрика как Counter должна быть неубывающей. В нашем случае по ней технически хоть и можно построить график RPS, но доверять его значениям невозможно.
Функция rate умеет определять такие сбросы, что невольно может завышать значения на графике. Например, ваш сервер мало нагружен. Фактических запросов в течение нескольких периодов скрапинга не было. Однако ввиду того, что у разных воркеров накопленные значения счётчика запросов могут отличаются, график может показывать сотни RPS.
В свою очередь предположим, что все воркеры на каждый момент получения метрик скрапером будут иметь одинаковые возрастающие значения счётчиков. В этом случае значения на графике будут занижаться в N раз, где N — количество воркеров.
В конечном итоге получаем абсолютный рандом и полное недоверие значениям.
Перезапуск воркеров
Ситуация ухудшается, если запуск сервера сопровождается опцией max_requests. Считается хорошей практикой после определённого количества обработанных запросов перезапускать воркер. Однако это приводит к тому, что все накопленные метрики начиная с последнего скрапинга до момента перезапуска будут утеряны.
В комплексе с предыдущими проблемами тот же график в большем масштабе будет выглядеть следующим образом:
Могут быть и другие причины перезапуска воркеров:
timeout воркера;
время жизни воркера, если запускать под uWSGI;
ручной перезапуск;
просто непредвиденные обстоятельства.
Любая из этих причин приводит к потере накопленных метрик, которые скрапер не успел забрать.
Что делать?
Не так уж много решений этой проблемы. Универсального, на мой взгляд, не существует, каждое имеет какой-то недостаток. В конце покажу решение, на котором мы остановились. Но перед этим пройдёмся по остальным, что пришли на ум.
Не используй мультипроцессинг
Эту статью я начал с проблемы консистентности, когда случайный воркер отдаёт свои изолированные метрики. Казалось бы, нет причины — нет проблем. Можно запустить приложение с одним воркером. Однако это не решает проблему потери метрик при перезапуске. Поэтому сразу этот подход подвергается критике.
Дополнительно появляется ряд других вопросов в зависимости от конфигурации:
иррациональное использование ресурсов;
пропускная способность;
отказоустойчивость.
Экспорт метрик на разных портах
Этот подход можно применить самостоятельно. Однако если ваше приложение написано на Django и оно использует библиотеку django‑prometheus, то такое решение есть из коробки. Оно подразумевает запуск экспортера в daemon thread-е, который захватывает порт из указанного диапазона PROMETHEUS_METRICS_EXPORT_PORT_RANGE.
Как следствие, нужно настраивать скрапер на разные порты. В случае запуска приложения в Kubernetes не уверен, что с помощью аннотаций этого вообще возможно добиться. Также нужно будет продумать вопрос с label-ами получаемых метрик. Очевидно, что это повлияет и на построение графиков. В общем, подход имеет право на жизнь, но, на мой взгляд, слишком сложный. И он всё так же не решает проблему потери метрик при перезапуске воркеров.
Запуск prometheus_client в режиме мультипроцессинга
Сходу данный режим накладывает ограничения. Коротко:
Дублирование метрик при неправильной настройке
MultiProcessCollector.Кастомные сборщики не работают (метрики
cpuиmemory).Метрики
InfoиEnumне работают.Pushgateway не может быть использован.
Особенности использования Gauge.
Exemplar не поддерживается.
Забегая вперёд, именно на этом подходе мы и остановились, за исключением некоторых доработок.
В качестве примера построим данное решение на FastAPI и посмотрим, что из этого выйдет.
requirements.txt
fastapi==0.104.1
uvicorn==0.24.0
gunicorn==21.2.0
prometheus-client==0.18.0server_config.py
# flake8: noqa
from gunicorn.arbiter import Arbiter
from gunicorn.workers.base import Worker
bind = '0.0.0.0:5000'
workers = 2
worker_class = 'uvicorn.workers.UvicornWorker'
log_file = '-'
max_requests = 100
max_requests_jitter = 100
def post_fork(server: Arbiter, worker: Worker):
worker.log.info(
'[post_fork] age: %s. pid: %s',
worker.age,
worker.pid,
)
def post_worker_init(worker: Worker):
worker.log.info(
'[post_worker_init] age: %s. pid: %s',
worker.age,
worker.pid,
)
def when_ready(server):
server.log.info("Server is ready. Spawning workers")
server.py
import asyncio
import logging
import os
from fastapi import FastAPI
from prometheus_client import (
CONTENT_TYPE_LATEST,
REGISTRY,
CollectorRegistry,
Counter,
generate_latest,
)
from prometheus_client.multiprocess import MultiProcessCollector
from starlette.responses import Response
logging.getLogger("uvicorn.error").setLevel(logging.ERROR)
def metrics(request):
if 'PROMETHEUS_MULTIPROC_DIR' in os.environ:
registry = CollectorRegistry()
path = os.environ['PROMETHEUS_MULTIPROC_DIR']
MultiProcessCollector(registry, path=path)
else:
registry = REGISTRY
metrics_page = generate_latest(registry)
return Response(metrics_page, media_type=CONTENT_TYPE_LATEST)
app = FastAPI()
app.add_route('/metrics', metrics, methods=['GET'])
requests_total = Counter(
'http_requests_total',
'Total of http requests',
)
@app.get("/")
async def root():
requests_total.inc()
await asyncio.sleep(0.1)
return {"message": "Hello World"}
Запускаем gunicron. Опция PROMETHEUS_MULTIPROC_DIR включает режим мультипроцессинга у prometheus_client-а. Также следуем рекомендациям по использованию MultiProcessCollector (cмотри server.py). Чуть подробней поговорим об этом позже.
mkdir -p prometheus-multiprocess
export PROMETHEUS_MULTIPROC_DIR=$(pwd)/prometheus-multiprocess
gunicorn server:app --config server_config.pyЗапускаем ab. Сделаем тысячу запросов с concurrency равным 2:
ab -n 1000 -c 2 http://0.0.0.0:5000/Так как мы указали настройки max_requests и max_requests_jitter в server_config.py, ожидаем, что каждый воркер перезагрузится примерно четыре раза. Что, собственно, и показывают логи gunicorn:
Логи gunicorn
[2023-11-12 15:49:21 +0300] [17591] [INFO] Starting gunicorn 21.2.0
[2023-11-12 15:49:21 +0300] [17591] [INFO] Listening at: http://0.0.0.0:5000 (17591)
[2023-11-12 15:49:21 +0300] [17591] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2023-11-12 15:49:21 +0300] [17591] [INFO] Server is ready. Spawning workers
[2023-11-12 15:49:21 +0300] [17596] [INFO] Booting worker with pid: 17596
[2023-11-12 15:49:21 +0300] [17596] [INFO] [post_fork] age: 1. pid: 17596
[2023-11-12 15:49:21 +0300] [17597] [INFO] Booting worker with pid: 17597
[2023-11-12 15:49:21 +0300] [17597] [INFO] [post_fork] age: 2. pid: 17597
[2023-11-12 15:49:21 +0300] [17596] [INFO] [post_worker_init] age: 1. pid: 17596
[2023-11-12 15:49:21 +0300] [17597] [INFO] [post_worker_init] age: 2. pid: 17597
[2023-11-12 15:49:36 +0300] [17597] [INFO] Worker exiting (pid: 17597)
[2023-11-12 15:49:36 +0300] [17627] [INFO] Booting worker with pid: 17627
[2023-11-12 15:49:36 +0300] [17627] [INFO] [post_fork] age: 3. pid: 17627
[2023-11-12 15:49:37 +0300] [17627] [INFO] [post_worker_init] age: 3. pid: 17627
[2023-11-12 15:49:47 +0300] [17596] [INFO] Worker exiting (pid: 17596)
[2023-11-12 15:49:48 +0300] [17643] [INFO] Booting worker with pid: 17643
[2023-11-12 15:49:48 +0300] [17643] [INFO] [post_fork] age: 4. pid: 17643
[2023-11-12 15:49:48 +0300] [17643] [INFO] [post_worker_init] age: 4. pid: 17643
[2023-11-12 15:49:51 +0300] [17627] [INFO] Worker exiting (pid: 17627)
[2023-11-12 15:49:51 +0300] [17649] [INFO] Booting worker with pid: 17649
[2023-11-12 15:49:51 +0300] [17649] [INFO] [post_fork] age: 5. pid: 17649
[2023-11-12 15:49:51 +0300] [17649] [INFO] [post_worker_init] age: 5. pid: 17649
[2023-11-12 15:50:00 +0300] [17643] [INFO] Worker exiting (pid: 17643)
[2023-11-12 15:50:00 +0300] [17663] [INFO] Booting worker with pid: 17663
[2023-11-12 15:50:00 +0300] [17663] [INFO] [post_fork] age: 6. pid: 17663
[2023-11-12 15:50:00 +0300] [17663] [INFO] [post_worker_init] age: 6. pid: 17663
[2023-11-12 15:50:11 +0300] [17649] [INFO] Worker exiting (pid: 17649)
[2023-11-12 15:50:11 +0300] [17677] [INFO] Booting worker with pid: 17677
[2023-11-12 15:50:11 +0300] [17677] [INFO] [post_fork] age: 7. pid: 17677
[2023-11-12 15:50:12 +0300] [17677] [INFO] [post_worker_init] age: 7. pid: 17677
[2023-11-12 15:50:19 +0300] [17663] [INFO] Worker exiting (pid: 17663)
[2023-11-12 15:50:19 +0300] [17691] [INFO] Booting worker with pid: 17691
[2023-11-12 15:50:19 +0300] [17691] [INFO] [post_fork] age: 8. pid: 17691
[2023-11-12 15:50:20 +0300] [17691] [INFO] [post_worker_init] age: 8. pid: 17691
Далее смотрим, что нам вернёт /metrics:
# HELP http_requests_total Total of http requests
# TYPE http_requests_total counter
http_requests_total 1000.0Наконец-то вернулся общий счётчик запросов вместо счётчика случайного воркера. И даже перезапуски не привели к потере метрик. Более того, если мы остановим сервер и запустим заново, все метрики сохранятся. Это достигается благодаря тому, что теперь каждый воркер пишет метрики в соответствующие файлы. А MultiProcessCollector считывает файлы от всех воркеров и агрегирует результат.
Вот что сейчас лежит в директории prometheus-multiprocess:
counter_17596.db
counter_17597.db
counter_17627.db
counter_17643.db
counter_17649.db
counter_17663.db
counter_17677.db
counter_17691.db
Во время тестирования было создано восемь файлов, по четыре каждым воркером. Название файла состоит из типа метрики и результата вызова функции process_identifier внутри функции MultiProcessValue. То есть, если бы в нашем примере было использование Histogram, Summary или Gauge, то был бы ещё один набор таких файлов для соответствующих типов метрик. Напомню, что согласно первоначальным ограничениям этого подхода метрики Info и Enum не работают.
Обращаем внимание на файлы и их количество. Как вы уже догадались, каждый воркер создаёт и пишет в файл, соответствующий его идентификатору процесса. А /metrics возвращает итоговый результат.
Так как MultiProcessCollector сканирует все файлы в PROMETHEUS_MULTIPROC_DIR, накопленные метрики старых воркеров также учитываются в общем результате, что наконец-то решает проблему потери метрик при перезапуске воркера. Однако нельзя не обратить внимание на тот факт, что если всё пустить на самотёк, то количество файлов будет постоянно расти.
Что делать с ростом количества файлов метрик?
Если по историческим соображениям ваше приложение запускается под uWSGI, у вас есть уникальная возможность в несколько строк кода решить эту проблему. Для этого достаточно переопределить process_identifier следующим образом:
try:
import prometheus_client
import uwsgi
values_class = prometheus_client.values.MultiProcessValue(
process_identifier=uwsgi.worker_id,
)
prometheus_client.values.ValueClass = values_class
except ImportError:
pass # not running in uwsgi
Важно выставить значение опции lazy-apps в true (в версии 2.0 по умолчанию значение false). Если этого не сделать, произойдёт утечка файловых дескрипторов (от десятков до сотен FDS в одном файле) из-за того, как uWSGI разветвляет процессы для создания рабочих процессов.
uWSGI в том числе хорош тем, что предоставляет из коробки механизм идентификации воркера. И если у вас появилась идея перетащить запуск вашего приложения на uWSGI, нужно иметь ввиду несколько важных моментов. Цитата из документации:
The project is in maintenance mode (only bugfixes and updates for new languages apis). Do not expect quick answers on github issues and/or pull requests (sorry for that) A big thanks to all of the users and contributors since 2009.
В общем, проект слабо поддерживается. Это отражается, к примеру, на такой опции как max-requests-delta. Хоть она описана в документации к версии 2.0, на самом деле её там нет. Таким образом получается, что в режиме мультипроцессинга с включённой опцией max-requests воркеры будут перезапускаться практически одновременно. Но если ваш выбор неизменен, рекомендую почитать о других особенностях опций в версии 2.0 на Bloomberg.
Как идентифицировать воркер в gunicorn?
К сожалению, gunicorn не обладает таким волшебным методом worker_id, как uWSGI. И чтобы решить проблему роста количества файлов метрик, нужно что-то придумать.
Пробуем без идентификации
Идея в том, чтобы удалять все файлы метрик при запуске нового воркера, предполагая, что другой живой воркер при обновлении метрик будет пересоздавать файл. Но, как выяснилось, этого не происходит. В таком виде становится всё очень плохо. А что если нам попытаться понять, живой ли ещё воркер, который когда-то создал файл метрик, прежде чем удалять его? Есть парочка вариантов, как это можно сделать. Например, проверить, является ли pid ключом словаря server.WORKERS. Обновим немного server_config.py:
server_config.py
# flake8: noqa
import glob
import os
import re
from gunicorn.arbiter import Arbiter
from gunicorn.workers.base import Worker
bind = '0.0.0.0:5000'
workers = 2
worker_class = 'uvicorn.workers.UvicornWorker'
log_file = '-'
max_requests = 100
max_requests_jitter = 100
pattern = re.compile(r'(?P<metric_type>\w+)_(?P<pid>\d+)\.db')
def post_fork(server: Arbiter, worker: Worker):
worker.log.info(
'[post_fork] age: %s. pid: %s',
worker.age,
worker.pid,
)
if 'PROMETHEUS_MULTIPROC_DIR' not in os.environ:
return
path = f"{os.environ['PROMETHEUS_MULTIPROC_DIR']}/*.db"
for filepath in glob.glob(path):
filename = filepath.split('/')[-1]
match = pattern.match(filename)
pid = int(match.group('pid'))
if pid not in server.WORKERS:
remove_file(worker, filepath)
def remove_file(worker: Worker, filepath: str):
worker.log.info(
'[post_fork] age: %s. pid: %s. Try remove %s',
worker.age,
worker.pid,
filepath,
)
try:
os.remove(filepath)
except Exception:
worker.log.info(
"[post_fork] age: %s. pid: %s. Can't remove %s",
worker.age,
worker.pid,
filepath,
)
else:
worker.log.info(
"[post_fork] age: %s. pid: %s. Success remove %s",
worker.age,
worker.pid,
filepath,
)
def post_worker_init(worker: Worker):
worker.log.info(
'[post_worker_init] age: %s. pid: %s',
worker.age,
worker.pid,
)
def when_ready(server):
server.log.info("Server is ready. Spawning workers")
Снова запускаем ab. Сделаем тысячу запросов с concurrency равным 2.
ab -n 1000 -c 2 http://0.0.0.0:5000/Логи gunicorn
[2023-11-12 20:44:19 +0300] [52206] [INFO] Starting gunicorn 21.2.0
[2023-11-12 20:44:19 +0300] [52206] [INFO] Listening at: http://0.0.0.0:5000 (52206)
[2023-11-12 20:44:19 +0300] [52206] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2023-11-12 20:44:19 +0300] [52206] [INFO] Server is ready. Spawning workers
[2023-11-12 20:44:19 +0300] [52208] [INFO] Booting worker with pid: 52208
[2023-11-12 20:44:19 +0300] [52208] [INFO] [post_fork] age: 1. pid: 52208
[2023-11-12 20:44:19 +0300] [52210] [INFO] Booting worker with pid: 52210
[2023-11-12 20:44:19 +0300] [52210] [INFO] [post_fork] age: 2. pid: 52210
[2023-11-12 20:44:20 +0300] [52210] [INFO] [post_worker_init] age: 2. pid: 52210
[2023-11-12 20:44:20 +0300] [52208] [INFO] [post_worker_init] age: 1. pid: 52208
[2023-11-12 20:44:38 +0300] [52208] [INFO] Worker exiting (pid: 52208)
[2023-11-12 20:44:39 +0300] [52252] [INFO] Booting worker with pid: 52252
[2023-11-12 20:44:39 +0300] [52252] [INFO] [post_fork] age: 3. pid: 52252
[2023-11-12 20:44:39 +0300] [52252] [INFO] [post_fork] age: 3. pid: 52252. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52208.db
[2023-11-12 20:44:39 +0300] [52252] [INFO] [post_fork] age: 3. pid: 52252. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52208.db
[2023-11-12 20:44:39 +0300] [52252] [INFO] [post_worker_init] age: 3. pid: 52252
[2023-11-12 20:44:39 +0300] [52210] [INFO] Worker exiting (pid: 52210)
[2023-11-12 20:44:39 +0300] [52254] [INFO] Booting worker with pid: 52254
[2023-11-12 20:44:39 +0300] [52254] [INFO] [post_fork] age: 4. pid: 52254
[2023-11-12 20:44:39 +0300] [52254] [INFO] [post_fork] age: 4. pid: 52254. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52210.db
[2023-11-12 20:44:39 +0300] [52254] [INFO] [post_fork] age: 4. pid: 52254. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52210.db
[2023-11-12 20:44:40 +0300] [52254] [INFO] [post_worker_init] age: 4. pid: 52254
[2023-11-12 20:44:56 +0300] [52254] [INFO] Worker exiting (pid: 52254)
[2023-11-12 20:44:56 +0300] [52287] [INFO] Booting worker with pid: 52287
[2023-11-12 20:44:56 +0300] [52287] [INFO] [post_fork] age: 5. pid: 52287
[2023-11-12 20:44:56 +0300] [52287] [INFO] [post_fork] age: 5. pid: 52287. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52254.db
[2023-11-12 20:44:56 +0300] [52287] [INFO] [post_fork] age: 5. pid: 52287. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52254.db
[2023-11-12 20:44:56 +0300] [52287] [INFO] [post_worker_init] age: 5. pid: 52287
[2023-11-12 20:44:59 +0300] [52252] [INFO] Worker exiting (pid: 52252)
[2023-11-12 20:44:59 +0300] [52309] [INFO] Booting worker with pid: 52309
[2023-11-12 20:44:59 +0300] [52309] [INFO] [post_fork] age: 6. pid: 52309
[2023-11-12 20:44:59 +0300] [52309] [INFO] [post_fork] age: 6. pid: 52309. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52252.db
[2023-11-12 20:44:59 +0300] [52309] [INFO] [post_fork] age: 6. pid: 52309. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52252.db
[2023-11-12 20:45:00 +0300] [52309] [INFO] [post_worker_init] age: 6. pid: 52309
[2023-11-12 20:45:14 +0300] [52287] [INFO] Worker exiting (pid: 52287)
[2023-11-12 20:45:14 +0300] [52368] [INFO] Booting worker with pid: 52368
[2023-11-12 20:45:14 +0300] [52368] [INFO] [post_fork] age: 7. pid: 52368
[2023-11-12 20:45:14 +0300] [52368] [INFO] [post_fork] age: 7. pid: 52368. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52287.db
[2023-11-12 20:45:14 +0300] [52368] [INFO] [post_fork] age: 7. pid: 52368. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52287.db
[2023-11-12 20:45:14 +0300] [52309] [INFO] Worker exiting (pid: 52309)
[2023-11-12 20:45:14 +0300] [52368] [INFO] [post_worker_init] age: 7. pid: 52368
[2023-11-12 20:45:14 +0300] [52370] [INFO] Booting worker with pid: 52370
[2023-11-12 20:45:14 +0300] [52370] [INFO] [post_fork] age: 8. pid: 52370
[2023-11-12 20:45:14 +0300] [52370] [INFO] [post_fork] age: 8. pid: 52370. Try remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52309.db
[2023-11-12 20:45:14 +0300] [52370] [INFO] [post_fork] age: 8. pid: 52370. Success remove /Users/aszubarev/projects/fastApiProject/prometheus-multiprocess/counter_52309.db
[2023-11-12 20:45:15 +0300] [52370] [INFO] [post_worker_init] age: 8. pid: 52370
Вот что сейчас лежит в директории prometheus-multiprocess:
counter_52368.db
counter_52370.db
И теперь количество файлов в директории остаётся постоянным.
Посмотрим, что нам вернёт /metrics:
# HELP http_requests_total Total of http requests
# TYPE http_requests_total counter
http_requests_total 55.0Как и ожидалось, здесь будет значение в диапазоне от 0 до 200 (max-requests + max-requests-jitter). Но это и немудрено, ведь мы получили метрики после всех перезапусков воркеров.
Если присмотреться, решение достаточно неплохое. С задачей организовать консистентность справляется. Теряет накопленные метрики после последнего скрапинга точно так же, как и все описанные ранее решения. Если настроить max-requests-jitter таким образом, чтобы в рамках одного периода скрапинга был всего один перезапуск воркера, то мы потеряем всего лишь 1 / N-ую часть метрик, где N — количество воркеров. На графиках это может отобразиться как небольшая просадка в RPS.
Простота, прозрачность и предсказуемость делает этот подход жизнеспособным.
Пробуем идентифицировать воркер
Что у нас есть в арсенале? Не так уже много:pid и age.
age — постоянно увеличивающееся число. По сути, является абсолютным во времени номером воркера. Как вы уже догадались, если использовать его в качестве process_identifier, то будут те же проблемы, что и в поведении по умолчанию.
Были следующие идеи как использовать age:
process_identifier = age % Nprocess_identifier = age % (2 * N)
Обе подвергаются критике. На примере с двумя воркерами, остаток от деления на N ломается, когда второй воркер становится третьим при живом первом. Оба воркера будут писать в одинаковые файлы, получаем коллизию.
На примере с тремя и более воркерами, даже с остатком от деления на (2 * N) ситуация может повториться только при других условиях и с меньшей вероятностью. Но в конечном итоге коллизии не избежать. Поэтому эти варианты нам не подходят.
Идентифицируем воркер filelock-ом
Идея возникла из необходимости назначить воркерам некоторый идентификатор из диапазона от 1 до N, где N — количество воркеров. Будем пробовать захватить lock файла из соответствующего набора. Кто первый захватит, тому этот worker_id и принадлежит. И, самое главное, lock будет захвачен на всё время жизни воркера. Таким образом перезапуски других воркеров не смогут на него повлиять.
Добавим в зависимости filelock:
requirements.txt
fastapi==0.104.1
uvicorn==0.24.0
gunicorn==21.2.0
prometheus-client==0.18.0
filelock==3.13.1Реализуем задуманное в server_config.py:
server_config.py
# flake8: noqa
import os
from gunicorn.arbiter import Arbiter
from gunicorn.workers.base import Worker
bind = '0.0.0.0:5000'
workers = 2
worker_class = 'uvicorn.workers.UvicornWorker'
log_file = '-'
max_requests = 100
max_requests_jitter = 100
def post_fork(server: Arbiter, worker: Worker):
worker.log.info('[post_fork] age: %s. pid: %s', worker.age, worker.pid)
if 'PROMETHEUS_MULTIPROC_DIR' not in os.environ:
return
try:
import prometheus_client
except ImportError:
worker.log.error(
"[post_fork] age: %s. pid: %s. Can't import prometheus_client",
worker.age,
worker.pid,
)
return
try:
import filelock
except ImportError:
worker.log.error(
"[post_fork] age: %s. pid: %s. Can't import filelock",
worker.age,
worker.pid,
)
return
worker_id = None
for idx in range(0, server.num_workers):
worker_id_potential = idx + 1
worker_id_lock_file = f'worker_id_{worker_id_potential}.lock'
try:
worker_id_lock = filelock.FileLock(
lock_file=worker_id_lock_file,
).acquire(blocking=False)
except filelock.Timeout:
worker.log.info(
"[post_fork] age: %s. pid: %s. worker_id %s is locked",
worker.age,
worker.pid,
worker_id_potential,
)
else:
worker_id = worker_id_potential
# необходимо сохранить ссылку на worker_id_lock,
# чтобы после выхода из области видимости функции
# не был вызван метод __del__ у этого объекта
#
# метод __del__ вызывает release, причем c force=True
setattr(worker, 'worker_id', worker_id)
setattr(worker, 'worker_id_lock', worker_id_lock)
break
if not worker_id:
worker.log.error(
"[post_fork] age: %s. pid: %s. There is no worker_id",
worker.age,
worker.pid,
)
return
# noinspection PyUnresolvedReferences,PyPep8Naming
ValueClass = prometheus_client.values.MultiProcessValue(
process_identifier=lambda: worker_id,
)
# noinspection PyUnresolvedReferences
prometheus_client.values.ValueClass = ValueClass
worker.log.info(
'[post_fork] age: %s. pid: %s. Lock worker_id %s',
worker.age,
worker.pid,
worker_id,
)
def post_worker_init(worker: Worker):
worker.log.info(
'[post_worker_init] age: %s. pid: %s. worker_id: %s',
worker.age,
worker.pid,
getattr(worker, 'worker_id', None),
)
def when_ready(server):
server.log.info("Server is ready. Spawning workers")
Запускаем ab:
ab -n 1000 -c 2 http://0.0.0.0:5000/Смотрим логи:
Логи gunicorn
[2023-11-12 22:27:28 +0300] [63265] [INFO] Starting gunicorn 21.2.0
[2023-11-12 22:27:28 +0300] [63265] [INFO] Listening at: http://0.0.0.0:5000 (63265)
[2023-11-12 22:27:28 +0300] [63265] [INFO] Using worker: uvicorn.workers.UvicornWorker
[2023-11-12 22:27:28 +0300] [63265] [INFO] Server is ready. Spawning workers
[2023-11-12 22:27:28 +0300] [63267] [INFO] Booting worker with pid: 63267
[2023-11-12 22:27:28 +0300] [63267] [INFO] [post_fork] age: 1. pid: 63267
[2023-11-12 22:27:28 +0300] [63267] [INFO] [post_fork] age: 1. pid: 63267. Lock worker_id 1
[2023-11-12 22:27:28 +0300] [63268] [INFO] Booting worker with pid: 63268
[2023-11-12 22:27:28 +0300] [63268] [INFO] [post_fork] age: 2. pid: 63268
[2023-11-12 22:27:28 +0300] [63268] [INFO] [post_fork] age: 2. pid: 63268. worker_id 1 is locked
[2023-11-12 22:27:28 +0300] [63268] [INFO] [post_fork] age: 2. pid: 63268. Lock worker_id 2
[2023-11-12 22:27:29 +0300] [63267] [INFO] [post_worker_init] age: 1. pid: 63267. worker_id: 1
[2023-11-12 22:27:29 +0300] [63268] [INFO] [post_worker_init] age: 2. pid: 63268. worker_id: 2
[2023-11-12 22:28:14 +0300] [63268] [INFO] Worker exiting (pid: 63268)
[2023-11-12 22:28:14 +0300] [63354] [INFO] Booting worker with pid: 63354
[2023-11-12 22:28:14 +0300] [63354] [INFO] [post_fork] age: 3. pid: 63354
[2023-11-12 22:28:14 +0300] [63354] [INFO] [post_fork] age: 3. pid: 63354. worker_id 1 is locked
[2023-11-12 22:28:14 +0300] [63354] [INFO] [post_fork] age: 3. pid: 63354. Lock worker_id 2
[2023-11-12 22:28:15 +0300] [63354] [INFO] [post_worker_init] age: 3. pid: 63354. worker_id: 2
[2023-11-12 22:28:19 +0300] [63267] [INFO] Worker exiting (pid: 63267)
[2023-11-12 22:28:19 +0300] [63375] [INFO] Booting worker with pid: 63375
[2023-11-12 22:28:19 +0300] [63375] [INFO] [post_fork] age: 4. pid: 63375
[2023-11-12 22:28:19 +0300] [63375] [INFO] [post_fork] age: 4. pid: 63375. Lock worker_id 1
[2023-11-12 22:28:20 +0300] [63375] [INFO] [post_worker_init] age: 4. pid: 63375. worker_id: 1
[2023-11-12 22:28:29 +0300] [63354] [INFO] Worker exiting (pid: 63354)
[2023-11-12 22:28:29 +0300] [63396] [INFO] Booting worker with pid: 63396
[2023-11-12 22:28:29 +0300] [63396] [INFO] [post_fork] age: 5. pid: 63396
[2023-11-12 22:28:29 +0300] [63396] [INFO] [post_fork] age: 5. pid: 63396. worker_id 1 is locked
[2023-11-12 22:28:29 +0300] [63396] [INFO] [post_fork] age: 5. pid: 63396. Lock worker_id 2
[2023-11-12 22:28:30 +0300] [63396] [INFO] [post_worker_init] age: 5. pid: 63396. worker_id: 2
[2023-11-12 22:28:40 +0300] [63375] [INFO] Worker exiting (pid: 63375)
[2023-11-12 22:28:40 +0300] [63417] [INFO] Booting worker with pid: 63417
[2023-11-12 22:28:40 +0300] [63417] [INFO] [post_fork] age: 6. pid: 63417
[2023-11-12 22:28:40 +0300] [63417] [INFO] [post_fork] age: 6. pid: 63417. Lock worker_id 1
[2023-11-12 22:28:40 +0300] [63417] [INFO] [post_worker_init] age: 6. pid: 63417. worker_id: 1
[2023-11-12 22:28:43 +0300] [63396] [INFO] Worker exiting (pid: 63396)
[2023-11-12 22:28:43 +0300] [63424] [INFO] Booting worker with pid: 63424
[2023-11-12 22:28:43 +0300] [63424] [INFO] [post_fork] age: 7. pid: 63424
[2023-11-12 22:28:44 +0300] [63424] [INFO] [post_fork] age: 7. pid: 63424. worker_id 1 is locked
[2023-11-12 22:28:44 +0300] [63424] [INFO] [post_fork] age: 7. pid: 63424. Lock worker_id 2
[2023-11-12 22:28:44 +0300] [63424] [INFO] [post_worker_init] age: 7. pid: 63424. worker_id: 2
Смотрим директорию prometheus-multiprocess:
counter_1.db
counter_2.db
Смотрим /metrics:
# HELP http_requests_total Total of http requests
# TYPE http_requests_total counter
http_requests_total 1000.0Метрики собираются консистентно, перезапуск воркеров не приводит к их потере. Нет бесконтрольного роста файлов метрик.
Теперь счётчик запросов строго возрастает. Нет сброса метрик из-за разницы накопленных значений между воркерами. Нет сброса метрик из-за перезапуска воркеров.
На этом решении мы и остановились.
Особенности использования MultiProcessCollector
Считается хорошей практикой создавать новый CollectorRegistry в контексте запроса /metrics и передавать его в MultiProcessCollector. Собственно, именно так мы и сделали в server.py.
Фишка в том, что когда вы создаёте объекты классов Count, Histogram и т. д., эти метрики регистрируются во встроенном REGISTRY по умолчанию. Если передать этот REGISTRY в MultiProcessCollector, то столкнёмся с ошибкой дублирования метрик.
Можете сами попробовать запустить следующий server.py и запросить /metrics:
server.py
import asyncio
import logging
import os
from fastapi import FastAPI
from prometheus_client import (
CONTENT_TYPE_LATEST,
REGISTRY,
CollectorRegistry,
Counter,
generate_latest,
)
from prometheus_client.multiprocess import MultiProcessCollector
from starlette.responses import Response
logging.getLogger("uvicorn.error").setLevel(logging.ERROR)
def metrics(request):
if 'PROMETHEUS_MULTIPROC_DIR' in os.environ:
# registry = CollectorRegistry()
# just for fun
registry = REGISTRY
path = os.environ['PROMETHEUS_MULTIPROC_DIR']
MultiProcessCollector(registry, path=path)
else:
registry = REGISTRY
metrics_page = generate_latest(registry)
return Response(metrics_page, media_type=CONTENT_TYPE_LATEST)
app = FastAPI()
app.add_route('/metrics', metrics, methods=['GET'])
requests_total = Counter(
'http_requests_total',
'Total of http requests',
)
@app.get("/")
async def root():
requests_total.inc()
await asyncio.sleep(0.1)
return {"message": "Hello World"}
Вы увидите:
ValueError: Duplicated timeseries in CollectorRegistry: {'http_requests', 'http_requests_created', 'http_requests_total'}Происходит попытка экспортировать multiprocess-метрики и метрики конкретного воркера. Получаем соответствующую ошибку. Поэтому, чтобы такого не происходило, создают новый CollectorRegistry, в котором нет зарегистрированных метрик.
К слову, такие библиотеки как django‑prometheus и starlette-prometheus тоже учитывают этот момент. Но всё равно нужно быть внимательными. Не все ещё используют переменную окружения PROMETHEUS_MULTIPROC_DIR в верхнем регистре. starlette-prometheus версии v0.9.0 не исключение.
Влияние файлов метрик на общую производительность
В этой статье до сих пор не упоминались проблемы, связанные с записью в файлы. Если приложение запускается на сервере с HDD, не трудно представить, что это будет ощутимо влиять на производительность запросов. Даже если у вас SSD, в случае запуска асинхронного приложения диск будет выступать некоторой точкой синхронизации. Эту тему не раскрыть в двух словах. На мой взгляд, тут не обойтись без вмешательства в prometheus_client, если эта проблема начнёт себя проявлять.
Существует рекомендация по уменьшению зависимости от диска: можно смонтировать директорию как tmpfs. С точки зрения приложения ничего не поменяется. Однако файлы будут храниться в памяти. Думаю, это сможет заметно помочь даже в ситуации с SSD.
Если ваше приложение запущено в Kubernetes, то можно воспользоваться специальным типом volume-а emptyDir. Если параметру emptyDir.medium установить значение Memory, то получится смонтировать tmpfs. Но нужно быть осторожным: размер этой директории учитывается в общем потреблении памяти. В более старых версиях Kubernetes ещё не было возможности указать лимит на размер этой директории. Поэтому, если ваше решение будет подразумевать бесконтрольный рост файлов, вы можете исчерпать выделенную поду память. Он упадёт в CrashLoop и вы сможете восстановить работоспособность сервиса только после ручного удаления пода, простой перезапуск не поможет. emptyDir не очищается между перезапусками пода.
Также необходимо понимать, что бесконтрольный рост файлов метрик влияет на производительность /metrics. Последовательное чтение большого количества файлов с диска с последующей агрегацией может заметно увеличить время отдачи метрик а также косвенно повлиять на общую производительность в моменте.
Что там с Gauge?
Также в этой статье не было подробного описания по работе с Gauge в режиме мультипроцессинга. Ему требуется отдельное внимание.
Заключение
Как я уже говорил, мы остановились на решении с запуском prometheus_client-a в режиме мультипроцессинга с доработкой идентификации воркеров силами filelock-ов. Для ряда наших сценариев это решение близко к идеалу. Те ограничения, что накладывает prometheus_client в таком режиме, не затрагивают наши потребности.
Метрики
cpuиmemoryмы получаем из Kubernetes.Метрики
InfoиEnumнам не пригодились.Pushgateway не используем.
С Gauge, при желании, можно подружиться.
Всем спасибо за внимание! Пишите в комментариях, сталкивались ли вы с подобной проблемой и как вы её решали в своих проектах.
Комментарии (10)
stepalxser
15.11.2023 13:31Стоит упомянуть, что в случае асинхронного кода в приложениях, прометиус клиент использует под капотом синхронный open и позволяет качественно сломать себе копчик в самых неожиданных местах
https://prometheus-async.readthedocs.io/en/stable/index.html
aszubarev Автор
15.11.2023 13:31Все верно. О существовании этой проблемы коротко упомянуто в разделе "Влияние файлов метрик на общую производительность".
К слову, библиотека prometheus-async никак не решает эту проблему.
9982th
15.11.2023 13:31А существуют какие-то стандартные решения для асинхронных приложений, которым нужно выполнять большое количество взаимодействий с диском? Если никто об этом не думает, то эта проблема должна быть повсеместной.
aszubarev Автор
15.11.2023 13:31Зависит от того, что понимать под стандартом. Конечно, существуют библиотеки, которые работают асинхронно с файлами. Из популярного на моей памяти aiofiles https://github.com/Tinche/aiofiles. Однако качественную оценку дать не могу, так как не доводилось применять в проектах.
Если смотреть в разрезе хранения метрик в файлах, я в любом случае следовал бы рекомендации смонтировать директорию как tmpfs. Это позволит убрать диск из цепочки обработки запроса. Это будет полезно как для синхронных, так и для асинхронных приложений.
Однако самому интересно посмотреть на цифрах эту пользу для асинхронного приложения. И есть ли она вообще. Хочется понять, стоит ли вмешиваться в работу prometheus_client, или приложению будет достаточно, чтобы файлы хранились в tmpfs.
Думаю, на эту тему будет вторая статья.
ef_end_y
15.11.2023 13:31Подскажите, а в варианте "каждый воркер на порту" есть возможность на стороне прометеуса агрегировать значения? Какие-то метрики просуммировать, какие-то усреднить? Или это делается руками формулами в прометеусе или графане?
aszubarev Автор
15.11.2023 13:31Не могу однозначно ответить. Всех возможностей прометеуса не знаю, к сожалению. Могу только предположить, что прометеус агрегацией не занимается. На мой взгляд его задача хранить серии векторов с соответствующими lable-ами и обрабатывать пользовательские запросы.
В моем представлении если идти по пути экспортирования метрик на разных портах, необходимо, чтобы во всех отдаваемых метриках были соответствующие label-ы, по типу port="8001". И уже в той же графане учитывать факт их наличия и строить соответсвующие запросы к прометеусу.ef_end_y
15.11.2023 13:31Да, скорее всего как вы говорите. В лейблах присутствует порт и я сегодня это использовал в графане. Там есть функция группировки по полю имени (не знаю точной графановской терминологии). Но мне нужна логика посложнее (надо вывести топ view по максимальному среднему времени их выполнения), придется читать доки, а не как обычно с наскоку))
x1netta
15.11.2023 13:31А что если просто складывать метрики в условный редис и потом просто отдавать из редиса метрики в exposition формате прометеусу? Тогда редис будет местом синхронизации метрик от всех процессов. Да, получится самописное решение, но вроде бы это сделать проще
aszubarev Автор
15.11.2023 13:31Концептуально проблемы те же самые остаются. Только теперь не количество файлов будет расти, а количество ключей в редисе. Также появилась дополнительная точка отказа и необходимость в разработке и поддержке этого решения.
ef_end_y
Ахах - истерические слезы. Ну хоть сейчас я узнал почему такие неадекватные данные у меня были при подходе подключить прометеус к джанге