Carlos Aguni

Highly motivated self-taught IT analyst. Always learning and ready to explore new skills. An eternal apprentice.


Flask request logging

17 Sep 2022 »

https://gist.github.com/alexaleluia12/e40f1dfa4ce598c2e958611f67d28966

from flask import Flask, request, jsonify, json, abort, redirect, url_for, render_template
from flask_cors import CORS, cross_origin
import logging
from logging.handlers import RotatingFileHandler

import datetime
import os
import re
from time import strftime
import subprocess
import traceback

#logger = logging.getLogger('tdm')
handler = RotatingFileHandler('app.log', maxBytes=100000, backupCount=3)
logger = logging.getLogger('tdm')
logger.setLevel(logging.ERROR)
logger.addHandler(handler)

app = Flask(__name__, template_folder='template')
cors = CORS(app)
app.config['CORS_HEADERS'] = 'Content-Type'

@app.route('/', methods=['GET', 'POST'])
def main():
    logging.debug('aasdf')
    return "hello world"

@app.route('/json', methods=['GET', 'POST'])
def r_json():
    logging.debug('aasdf')
    return jsonify(asdf)

@app.after_request
def after_request(response):
    timestamp = strftime('[%Y-%b-%d %H:%M]')
    logger.error('>>> %s %s %s %s %s %s', timestamp, request.remote_addr, request.method, request.scheme, request.full_path, response.status)
    return response

@app.errorhandler(Exception)
def exceptions(e):
    print('e>>>', type(e), e)
    print(dir(e))
    tb = traceback.format_exc()
    timestamp = strftime('[%Y-%b-%d %H:%M]')
    logger.error('%s %s %s %s %s 5xx INTERNAL SERVER ERROR\n%s', timestamp, request.remote_addr, request.method, request.scheme, request.full_path, tb)
    return tb
    return e.status_code

# gunicorn --workers=2 'app:create_app()' --bind=0.0.0.0:<port>
def create_app():
    return app

if __name__ == '__main__':
    #handler = RotatingFileHandler('app.log', maxBytes=100000, backupCount=3)
    #logger = logging.getLogger('tdm')
    #logger.setLevel(logging.ERROR)
    #logger.addHandler(handler)
    app.run(host='0.0.0.0', port=9000)
    
    #test 
    #with app.test_client() as c:
    #    rs = c.get("/")
    #    print(rs.data)

gunicorn --workers=4 app:app --bind=0:9000

app.log

>>> [2022-Sep-17 19:41] 10.7.0.1 GET http /json? 200 OK
[2022-Sep-17 19:41] 10.7.0.1 GET http /json? 5xx INTERNAL SERVER ERROR
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/root/flask-logs/app.py", line 31, in r_json
    return jsonify(asdf)
NameError: name 'asdf' is not defined

>>> [2022-Sep-17 19:41] 10.7.0.1 GET http /json? 200 OK
[2022-Sep-17 19:41] 10.7.0.1 GET http /json? 5xx INTERNAL SERVER ERROR
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/usr/local/lib/python3.6/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/root/flask-logs/app.py", line 31, in r_json
    return jsonify(asdf)
NameError: name 'asdf' is not defined

>>> [2022-Sep-17 19:41] 10.7.0.1 GET http /json? 200 OK

Logging Flask requests with structure and colors

https://dev.to/rhymes/logging-flask-requests-with-colors-and-structure–7g1

import datetime
import time

import colors
from flask import Flask, g, request, jsonify, json, abort, redirect, url_for, render_template
from flask_cors import CORS, cross_origin
from rfc3339 import rfc3339
import traceback

app = Flask(__name__, template_folder='template')
cors = CORS(app)
app.config['CORS_HEADERS'] = 'Content-Type'

@app.route('/', methods=['GET', 'POST'])
def main():
    return "hello world"

@app.route('/2', methods=['GET', 'POST'])
def main2():
    time.sleep(2)
    return "hello world"

@app.route('/json', methods=['GET', 'POST'])
def r_json():
    return jsonify(asdf)


@app.before_request
def start_timer():
    g.start = time.time()

@app.errorhandler(Exception)
def exceptions(e):
    tb = traceback.format_exc()
    #logger.error('%s %s %s %s %s 5xx INTERNAL SERVER ERROR\n%s', timestamp, request.remote_addr, request.method, request.scheme, request.full_path, tb)

    try:
        payload = request.json
    except:
        payload = {}

    now = time.time()
    duration = round(now - g.start, 2)
    dt = datetime.datetime.fromtimestamp(now)
    timestamp = rfc3339(dt, utc=True)

    ip = request.headers.get('X-Forwarded-For', request.remote_addr)
    host = request.host.split(':', 1)[0]
    args = dict(request.args)

    log_params = [
        ('method', request.method, 'blue'),
        ('path', request.path, 'blue'),
        ('payload', request.json, 'pink'),
        #('status', response.status_code, 'yellow'),
        ('status', 500, 'yellow'),
        ('duration', duration, 'green'),
        ('time', timestamp, 'magenta'),
        ('ip', ip, 'red'),
        ('host', host, 'red'),
        ('params', args, 'blue'),
        ('error', tb, 'cyan'),
    ]

    request_id = request.headers.get('X-Request-ID')
    if request_id:
        log_params.append(('request_id', request_id, 'yellow'))

    parts = []
    for name, value, color in log_params:
        part = colors.color("{}={}".format(name, value), fg=color)
        parts.append(part)
    line = " ".join(parts)

    app.logger.info(line)

    return tb
    return tb
    return e.status_code

@app.after_request
def log_request(response):
    if request.path == '/favicon.ico':
        return response
    elif request.path.startswith('/static'):
        return response

    now = time.time()
    duration = round(now - g.start, 2)
    dt = datetime.datetime.fromtimestamp(now)
    timestamp = rfc3339(dt, utc=True)

    ip = request.headers.get('X-Forwarded-For', request.remote_addr)
    host = request.host.split(':', 1)[0]
    args = dict(request.args)

    log_params = [
        ('method', request.method, 'blue'),
        ('path', request.path, 'blue'),
        ('status', response.status_code, 'yellow'),
        ('duration', duration, 'green'),
        ('time', timestamp, 'magenta'),
        ('ip', ip, 'red'),
        ('host', host, 'red'),
        ('params', args, 'blue')
    ]

    request_id = request.headers.get('X-Request-ID')
    if request_id:
        log_params.append(('request_id', request_id, 'yellow'))

    parts = []
    for name, value, color in log_params:
        part = colors.color("{}={}".format(name, value), fg=color)
        parts.append(part)
    line = " ".join(parts)

    app.logger.info(line)

    return response


if __name__ == '__main__':
    app.run(debug=True, host='0.0.0.0', port=9000)