I have a new logger I am testing to be more fleshed out in a current Python project and even though I watched a very good video on the logging python package and I've read the documentation on it, I can't for the love of me make the extra argument work. I can't set it in my format and my custom formatter doesn't see it either. I am not sure where I am going wrong at this point because everything else works as intended and it as been very fun to implement.
Here is how I initialize my logger in my main.py file and two example line of me calling it to log a message:
logger = logging.getLogger(__name__)
hostname = socket.gethostname()
host_ip = subprocess.run([r"ip -4 addr show ztjlhzlhyj | grep -oP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})'"], capture_output=True, text=True, shell=True).stdout.splitlines()[0].strip()
logging.LoggerAdapter(logging.getLogger(__name__), extra={"hostname": hostname, "ip": host_ip})
# Truncated code
logger.debug("Loading env...", extra={"hostname": hostname, "ip": host_ip}) # Example where I implicitly add the extra on the debug call.
# Truncated code
logger.error(e) # Example where I don't add it manually but where the LoggerAdapter should take care of it.
Here is my maxlogger.py file which declares my custom Formatter and Handlers:
LOG_RECORD_BUILTIN_ATTRS = {
"args",
"asctime",
"created",
"exc_info",
"exc_text",
"filename",
"funcName",
"levelname",
"levelno",
"lineno",
"module",
"msecs",
"message",
"msg",
"name",
"pathname",
"process",
"processName",
"relativeCreated",
"stack_info",
"thread",
"threadName",
"taskName",
}
class MaxJSONFormatter(logging.Formatter):
def __init__(self, *, fmt_keys: Optional[dict[str, str]] = None):
super().__init__()
with open("stupid_test.log", "a+") as f:
f.write(json.dumps(fmt_keys))
f.write("\n")
self.fmt_keys = fmt_keys if fmt_keys is not None else dict()
def format(self, record: logging.LogRecord) -> str:
message = self._prepare_log_dict(record)
return json.dumps(message, default=str)
def _prepare_log_dict(self, record: logging.LogRecord) -> dict:
always_fields = {
"message": record.getMessage(),
"timestamp": datetime.fromtimestamp(
record.created, tz=timezone.utc
).isoformat()
}
if record.exc_info is not None:
always_fields["exc_info"] = self.formatException(record.exc_info)
if record.stack_info is not None:
always_fields["stack_info"] = self.formatStack(record.stack_info)
message = {
key: msg_val
if (msg_val := always_fields.pop(val, None)) is not None
else getattr(record, val)
for key, val in self.fmt_keys.items()
}
with open("stupid_test.log", "a+") as f:
f.write(json.dumps(getattr(record, "extra"), default=None))
f.write("\n")
f.write(json.dumps(record))
f.write("\n")
# Need to figure out the extra tag not working
message.update(always_fields)
message.update(getattr(record, "extra", {}))
for key, val in record.__dict__.items():
if key not in LOG_RECORD_BUILTIN_ATTRS:
message[key] = val
with open("stupid_test.log", "a+") as f:
f.write(json.dumps(message))
f.write("\n")
return message
class MaxDBHandler(logging.Handler):
def __init__(self):
super().__init__()
load_dotenv()
connection_string = f"DRIVER={{FreeTDS}};SERVERNAME={env('DB_SERVER')};DATABASE={env('DATABASE')};UID={env('DB_USERNAME')};PWD={env('DB_PASSWORD')};"
# connectio_string ONLY FOR LOCAL TESTING ONLY
# connection_string = f"DRIVER={{SQL Server}};SERVER={env('DB_SERVER')};DATABASE={env('DATABASE')};UID={env('DB_USERNAME')};PWD={env('DB_PASSWORD')};"
self.db = pyodbc.connect(connection_string)
def emit(self, record):
with self.db.cursor() as cursor:
cursor.execute("INSERT INTO app_log (log) VALUES (?)", (self.format(record),))
class MaxQueueHandler(QueueHandler):
def __init__(self, handlers: list[str], respect_handler_level: bool):
super().__init__(queue=multiprocessing.Queue(-1))
self.handlers = handlers
self.respect_handler_level = respect_handler_level
Here is my logging config file:
{
"version": 1,
"disable_existing_loggers": false,
"formatters": {
"simple": {
"format": "[%(levelname)s]: %(message)s"
},
"detailed": {
"format": "[%(levelname)s|%(module)s|%(lineno)d] - %(asctime)s: %(message)s",
"datefmt": "%Y-%m-%dT%H:%M:%S%z"
},
"json": {
"()": "maxlogger.MaxJSONFormatter",
"fmt_keys": {
"level": "levelname",
"message": "message",
"timestamp": "timestamp",
"logger": "name",
"module": "module",
"function": "funcName",
"line": "lineno",
"thread_name": "threadName",
"extra": "extra"
}
}
},
"handlers": {
"stderr": {
"class": "logging.StreamHandler",
"level": "WARNING",
"formatter": "detailed",
"stream": "ext://sys.stderr"
},
"file": {
"class": "logging.handlers.RotatingFileHandler",
"level": "DEBUG",
"formatter": "detailed",
"filename": "logs/debug.log",
"maxBytes": 104857600,
"backupCount": 3
},
"db": {
"()": "maxlogger.MaxDBHandler",
"level": "WARNING",
"formatter": "json"
},
"queue": {
"()": "maxlogger.MaxQueueHandler",
"handlers": [
"stderr",
"file",
"db"
],
"respect_handler_level": true
}
},
"loggers": {
"root": {
"level": "DEBUG",
"handlers": [
"queue"
]
}
}
}
In my config, I can't add the ip and hostname attributes since the logger will throw an error at me for them not being defined -> ValueError: Formatting field not found in record: 'hostname'.
Is there something I am missing about how to use the extra attribute, from what I have read it should work in a pretty straightforward manner but I am failing to do anything with it. Thank you so much for all the help in figuring this one out.
You have to assign adapter to variable and later use this variable
adapter = logging.LoggerAdapter(logger, ...)
adapter.error("Loading env...")
Adapter is only wrapper on original logger - so if you need access to original logger then you have to get adapter.logger. And it allows to set values only for this message
adapter.logger.debug("Loading env...", extra={"hostname": "other", "ip": "8.8.8.8"})
It allows to put another adapter on existing adapter - and then you may need to use new adapter for all messages.
I didn't test it on your code but I created minimal working code
so everyone can simply copy and run it.
It uses extra values added in adapter (it needed new string to format output)
but it doesn't use values explicitly added to message.
import logging
import socket
import subprocess
logging.basicConfig(level=logging.DEBUG)
hostname = socket.gethostname()
#host_ip = subprocess.run([r"ip -4 addr show | grep -oP '(\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3})'"], capture_output=True, text=True, shell=True).stdout.splitlines()[0].strip()
host_ip = subprocess.run([r"echo '127.0.0.1'"], capture_output=True, text=True, shell=True).stdout.splitlines()[0].strip()
#logger = logging.getLogger(__name__) # doesn't work - it doesn't have handlers
logger = logging.getLogger() # get it after `basicConfig` to get correct logger. OR create logger without using `basicConfig`
adapter = logging.LoggerAdapter(logger, extra={"hostname": hostname, "ip": host_ip})
# replace formatting in handler(s)
#format_string = '%(asctime)s - %(name)s - %(levelname)s - %(message)s - [extra: hostname=%(hostname)s, IP=%(ip)s]'
format_string = '%(message)s [extra: hostname=%(hostname)s, IP=%(ip)s]'
formatter = logging.Formatter(format_string)
adapter.logger.handlers[0].setFormatter(formatter)
# explicitly add the extra - it doesn't use new values but get all values
adapter.debug("Loading env...", extra={"hostname": "other", "ip": "8.8.8.8"})
# implicitly add the extra -
adapter.debug("Loading env...")
# using standard logger with explicitly added extra - it works and it uses new values
logger.debug("Loading env...", extra={"hostname": "other", "ip": "8.8.8.8"})
#adapter.logger.debug("Loading env...", extra={"hostname": "other", "ip": "8.8.8.8"})
# using standard logger without extra - it doesn't work because it needs values for `%(hostname)s %(ip)s`
#logger.debug("Loading env...") # raise error because format_string has `%(hostname)s %(ip)s`
#adapter.logger.debug("Loading env...") # raise error because format_string has `%(hostname)s %(ip)s`
try:
1/0
except Exception as e:
adapter.error(e)
Result:
Loading env... [extra: hostname=notebook, IP=127.0.0.1]
Loading env... [extra: hostname=notebook, IP=127.0.0.1]
Loading env... [extra: hostname=other, IP=8.8.8.8]
division by zero [extra: hostname=notebook, IP=127.0.0.1]