Skip to content

Commit

Permalink
feat: contextual support for logging
Browse files Browse the repository at this point in the history
Adds plenty of connection and service information to the log record.
Allows log handlers like logstash to be able to add much more context to logging.
  • Loading branch information
joamag committed Apr 23, 2024
1 parent ba7df14 commit a610c58
Show file tree
Hide file tree
Showing 7 changed files with 56 additions and 12 deletions.
14 changes: 14 additions & 0 deletions src/netius/base/common.py
Original file line number Diff line number Diff line change
Expand Up @@ -2774,6 +2774,10 @@ def info_dict(self, full = False):
)
return info

def log_dict(self, full = False):
info = self.info_dict(full = full)
return info

def info_string(self, full = False, safe = True):
try: info = self.info_dict(full = full)
except Exception: info = dict()
Expand Down Expand Up @@ -2982,6 +2986,7 @@ def log_info(self, method = None):
for line in info_string.split("\n"): method(line)

def log(self, *args, **kwargs):
self.add_log_ctx(kwargs, self.log_ctx)
if legacy.PYTHON_3: return self.log_python_3(*args, **kwargs)
else: return self.log_python_2(*args, **kwargs)

Expand All @@ -2999,6 +3004,15 @@ def log_python_2(self, object, level = logging.INFO, **kwargs):
if not self.logger: return
self.logger.log(level, message, **kwargs)

def log_ctx(self):
return dict(service = self.log_dict(full = True))

def add_log_ctx(self, kwargs, callable):
extra = kwargs.get("extra", dict(meta_c = []))
meta_c = extra["meta_c"]
meta_c.append(callable)
kwargs["extra"] = extra

def build_poll(self):
# retrieves the reference to the parent class associated with
# the current instance, it's going t be used for class methods
Expand Down
28 changes: 28 additions & 0 deletions src/netius/base/conn.py
Original file line number Diff line number Diff line change
Expand Up @@ -674,6 +674,34 @@ def ssl_npn_protocol(self):
if not hasattr(self.socket, "selected_npn_protocol"): return None
return self.socket.selected_npn_protocol()

def debug(self, object, **kwargs):
if not self.owner: return
self.owner.add_log_ctx(kwargs, lambda: dict(connection = self.log_dict()))
self.owner.debug(object, **kwargs)

def info(self, object, **kwargs):
if not self.owner: return
self.owner.add_log_ctx(kwargs, self.log_ctx)
self.owner.info(object, **kwargs)

def warning(self, object, **kwargs):
if not self.owner: return
self.owner.add_log_ctx(kwargs, self.log_ctx)
self.owner.warning(object, **kwargs)

def error(self, object, **kwargs):
if not self.owner: return
self.owner.add_log_ctx(kwargs, self.log_ctx)
self.owner.error(object, **kwargs)

def critical(self, object, **kwargs):
if not self.owner: return
self.owner.add_log_ctx(kwargs, self.log_ctx)
self.owner.critical(object, **kwargs)

def log_ctx(self):
return dict(connection = self.log_dict())

def is_open(self):
return self.status == OPEN

Expand Down
4 changes: 3 additions & 1 deletion src/netius/base/log.py
Original file line number Diff line number Diff line change
Expand Up @@ -116,7 +116,9 @@ def emit(self, record, raise_e=False):
if hasattr(record, "meta"):
meta = record.meta
elif hasattr(record, "meta_c"):
meta = record.meta_c()
meta = dict()
for callable in record.meta_c:
meta.update(callable())
else:
meta = None

Expand Down
4 changes: 2 additions & 2 deletions src/netius/clients/smtp.py
Original file line number Diff line number Diff line change
Expand Up @@ -218,15 +218,15 @@ def send_smtp(self, code, message = "", delay = True, callback = None):
base = "%s %s" % (code, message)
data = base + "\r\n"
count = self.send(data, delay = delay, callback = callback)
self.owner.debug(base)
self.debug(base)
return count

def on_line(self, code, message, is_final = True):
# creates the base string from the provided code value and the
# message associated with it, then logs the values into the
# current debug logger support (for traceability)
base = "%s %s" % (code, message)
self.owner.debug(base)
self.debug(base)

# adds the message part of the line to the buffer that holds the
# various messages "pending" for the current response, these values
Expand Down
2 changes: 1 addition & 1 deletion src/netius/extra/file.py
Original file line number Diff line number Diff line change
Expand Up @@ -585,7 +585,7 @@ def on_normal_file(self, connection, parser, path):

# prints a debug message about the file that is going to be read
# from the current file system to be sent to the connection
self.debug("Reading file '%s' from file system" % path_s)
connection.debug("Reading file '%s' from file system" % path_s)

# uses the parser from the connection to be able to gather the
# range as a string to be used latter for conversion
Expand Down
10 changes: 5 additions & 5 deletions src/netius/servers/http.py
Original file line number Diff line number Diff line change
Expand Up @@ -774,7 +774,7 @@ def build_connection(self, socket, address, ssl = False):

def on_data_http(self, connection, parser):
is_debug = self.is_debug()
is_debug and self._log_request(connection, parser)
if is_debug: self._log_request(connection, parser)
connection.resolve_encoding(parser)

def on_send_http(
Expand All @@ -786,7 +786,7 @@ def on_send_http(
code = 200,
code_s = None
):
self.common_file and self._log_request(
if self.common_file: self._log_request(
connection,
parser,
headers = headers,
Expand All @@ -798,7 +798,7 @@ def on_send_http(
)

def on_flush_http(self, connection, parser, encoding = None):
self.debug(
connection.debug(
"Connection '%s' %s from '%s' flushed" %\
(connection.id, connection.address, self.name)
)
Expand Down Expand Up @@ -929,7 +929,7 @@ def _log_request(self, connection, parser, *args, **kwargs):
def _log_request_basic(self, connection, parser, output = None):
# runs the defaulting operation on the logger output
# method so that the default logger output is used instead
output = output or self.debug
output = output or connection.debug

# unpacks the various values that are going to be part of
# the log message to be printed in the debug
Expand Down Expand Up @@ -959,7 +959,7 @@ def _log_request_common(
):
# runs the defaulting operation on the logger output
# method so that the default logger output is used instead
output = output or self.debug
output = output or connection.debug

# unpacks the various values that are going to be part of
# the log message to be printed in the debug, these values
Expand Down
6 changes: 3 additions & 3 deletions src/netius/servers/smtp.py
Original file line number Diff line number Diff line change
Expand Up @@ -136,7 +136,7 @@ def send_smtp_base(self, code, message = "", delay = True, callback = None):
base = "%d %s" % (code, message)
data = base + "\r\n"
count = self.send(data, delay = delay, callback = callback)
self.owner.debug(base, extra = dict(meta_c = lambda: self.log_dict()))
self.debug(base)
return count

def send_smtp_lines(self, code, message = "", lines = (), delay = True, callback = None):
Expand All @@ -149,7 +149,7 @@ def send_smtp_lines(self, code, message = "", lines = (), delay = True, callback
lines_s.append("%d %s" % (code, tail))
data = "\r\n".join(lines_s) + "\r\n"
count = self.send(data, delay = delay, callback = callback)
self.owner.debug(base, extra = dict(meta_c = lambda: self.log_dict()))
self.debug(base, extra = dict(meta_c = lambda: self.log_dict()))
return count

def ready(self):
Expand Down Expand Up @@ -291,7 +291,7 @@ def on_line(self, code, message, is_final = True):
# "joins" the code and the message part of the message into the base
# string and then uses this value to print some debug information
base = "%s %s" % (code, message)
self.owner.debug(base, extra = dict(meta_c = lambda: self.log_dict()))
self.debug(base)

# calls the proper top level owner based line information handler that
# should ignore any usages as the connection will take care of the proper
Expand Down

0 comments on commit a610c58

Please sign in to comment.