OiO.lk Community platform!

Oio.lk is an excellent forum for developers, providing a wide range of resources, discussions, and support for those in the developer community. Join oio.lk today to connect with like-minded professionals, share insights, and stay updated on the latest trends and technologies in the development field.
  You need to log in or register to access the solved answers to this problem.
  • You have reached the maximum number of guest views allowed
  • Please register below to remove this limitation

Cannot use the extra attribute with a custom formatter in Python with the Logging module

  • Thread starter Thread starter LaZoR_Bear
  • Start date Start date
L

LaZoR_Bear

Guest
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:

Code:
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:

Code:
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:

Code:
{
  "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.
<p>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.</p>
<p>Here is how I initialize my logger in my main.py file and two example line of me calling it to log a message:</p>
<pre><code>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.

</code></pre>
<p>Here is my maxlogger.py file which declares my custom Formatter and Handlers:</p>
<pre><code>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
</code></pre>
<p>Here is my logging config file:</p>
<pre><code>{
"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"
]
}
}
}
</code></pre>
<p>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 -> <strong>ValueError: Formatting field not found in record: 'hostname'</strong>.</p>
<p>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.</p>
 

Latest posts

Top