CODEWITHSUNDEEP
pythonpython-3.xflaskloggingformat
Christopher Biessener
Christopher Biessener

Reputation: 120

logging with custom format throwing "ValueError: Formatting field not found in record" when Flask is involved

OK, so I'm following the example in the Python 3 docs which is:

FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
logging.basicConfig(format=FORMAT)
d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
logging.warning('Protocol problem: %s', 'connection reset', extra=d)

Here's my code:

from flask import Flask
import logging

FORMAT = '%(asctime)s, %(endpt)s, %(message)s'
LOG_ENDPT = 'endpoint was reached'
. . .
@app.route("/status")
def status():
  app.logger.debug(LOG_ENDPT, extra={'endpt':'status'})
. . .
if __name__ == "__main__":
  logging.basicConfig(filename="app.log", format=FORMAT, level=logging.DEBUG)

When I try to run the code, I get the following error:

--- Logging error ---
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 434, in format
    return self._format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 430, in _format
    return self._fmt % record.__dict__
KeyError: 'endpt'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 1083, in emit
    msg = self.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 927, in format
    return fmt.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 666, in format
    s = self.formatMessage(record)
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 635, in formatMessage
    return self._style.format(record)
  File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/logging/__init__.py", line 436, in format
    raise ValueError('Formatting field not found in record: %s' % e)
ValueError: Formatting field not found in record: 'endpt'

I have spent over an hour googling for a solution. I have not found any answer which is specific to this error.

What is interesting, is if I use the python interpreter from the command line and type in just the logging code (no function), it works. I do not know why the function should cause the error. BTW, I also tried with my call to logging.basicConfig() on the lone after my declaration of LOG_ENDPT. There was no difference in the error.

EDIT - OK, so I learned enough to know that Flask is the reason the logging does not work. I'm still unsure why it does not work, because when I remove the custom format, the error goes away. And yes, I am now aware that the correct call is 'app.logger.debug()' within a Flask function. I've edited my code to reflect this fact.

Upvotes: 2

Views: 11033

Answers (1)

Christopher Biessener
Christopher Biessener

Reputation: 120

Eventually, I did find a way to have a custom format while Flask is in use. I would still appreciate knowing why Flask prevents the use of a custom format via a call to logging.basicConfig(format=FORMAT). Here's my code:

import logging
from flask import Flask, json
from logging.config import dictConfig

dictConfig({
  'version': 1,
  'formatters': {
    'default': {
      'format': '[%(asctime)s]:%(levelname)s:%(message)s',
    }
  },
  'handlers': {
    'wsgi': {
      'class': 'logging.StreamHandler',
      'stream': 'ext://flask.logging.wsgi_errors_stream',
      'formatter': 'default'
    },
    'file': {
      'class': 'logging.FileHandler',
      'filename': 'app.log',
      'formatter': 'default'
    }
  },
  'root': {
    'level': 'DEBUG',
#    'handlers': ['wsgi','file']
    'handlers': ['file']
  }
})

MSG_ENDPT_FMT = '%s endpoint was reached'

app = Flask(__name__)

@app.route("/")
def hello():
  return "Hello World!"

@app.route("/status")
def status():
  app.logger.debug(MSG_ENDPT_FMT, 'status')
  response = app.response_class(
    response=json.dumps({"result":"OK - healthy"}),
    status=200,
    mimetype='application/json'
  )
  return response

@app.route("/metrics")
def metrics():
  app.logger.debug(MSG_ENDPT_FMT, 'metrics')
  response = app.response_class(
    response=json.dumps({"status":"success","code":0,"data":{"UserCount":140,"UserCountActive":23}}),
    status=200,
    mimetype='application/json'
  )
  return response

if __name__ == "__main__":
  app.run(host='0.0.0.0')

Upvotes: 1

Related Questions