Как измерить время ответа Flask API и записать его в журналы?
У меня есть система журналов для моего API-интерфейса Flask.
import logging
def setup_logger(logp=None, debug=False):
log_level = logging.DEBUG if debug else logging.INFO
form = "[%(asctime)s][%(name)s][%(levelname)s][%(filename)s] %(message)s"
datefmt = "%Y-%m-%d-%H:%M:%S"
logging.basicConfig(level=log_level, format=form, datefmt=datefmt)
if logp is not None:
fhandler = logging.StreamHandler(open(logp, 'a'))
fhandler.setFormatter(logging.Formatter(form, datefmt))
logging.root.addHandler(fhandler)
logger = logging.getLogger("MY_APP")
setup_logger()
logger.debug(f"Import {__file__}")
И логи выглядят так:
[2024-04-19-04:20:02][werkzeug][INFO][_internal.py] 172.23.0.2 - - [19/Apr/2024 04:20:02] "GET /available/space HTTP/1.1" 200 -
Однако я хочу измерить и записать время ответа API-интерфейса Flask, а также добавить его в журналы, например 0.45 s, чтобы увидеть, какой обработчик API работает медленно.
Ожидаемое поведение выглядит следующим образом:
[2024-04-19-04:20:02][werkzeug][INFO][_internal.py][0.45 s] 172.23.0.2 - - [19/Apr/2024 04:20:02] "GET /available/space HTTP/1.1" 200 -
Есть ли какой-нибудь способ это сделать? Спасибо
@Kraigolas Спасибо за ваше предложение. Однако, если я буду следовать этому подходу, мне придется добавить декоратор к каждому методу API, а у меня есть сотни методов API. Было бы очень загромождено. Можете ли вы предложить более элегантное решение?
Ответы 1
Вы можете использовать before_request и after_request , чтобы добиться этого на всех маршрутах. Мы будем использовать g для хранения времени начала запроса, а имя функции можно получить из request.endpoint.
Я не настраивал ведение журнала для этого примера, но внедрить собственный механизм ведения журнала вместо print() должно быть тривиально.
from flask import Flask, g, request
import time
app = Flask(__name__)
@app.before_request
def log_route_start():
g.start_time = time.time()
@app.after_request
def log_route_end(response):
route = request.endpoint
print(f"{route} ended after {time.time() - g.pop('start_time', None)}")
return response
@app.route('/test', methods=['GET'])
def test():
time.sleep(1)
return "Hello"
@app.route('/test2', methods=['GET'])
def test2():
time.sleep(0.5)
return "Bye"
if __name__ == '__main__':
app.run(debug=True)
Спасибо за отличное элегантное решение, но я только что заметил, что вы используете flask.g.start_time в своем решении, и я хочу знать, что еще нам следует делать помимо этого, чтобы не запутаться, когда к нам приходят одновременные запросы. ?
@stevezkw ничего; g привязан к контексту отдельных запросов
Потрясающий! Спасибо за полезное объяснение, которое поможет мне лучше понять это. позвольте мне проверить это, ура
Держите в курсе, ваше решение работает на моей стороне и играет ключевую роль в моем приложении. Спасибо за помощь! Но я все еще думаю, как интегрировать созданный вами журнал с моим существующим механизмом журналирования. Чтобы мы могли объединить их в один, в любом случае вы проделали отличную работу!
Может быть, для этого подойдет декоратор ваших методов API?