matthieu/frr
1
0
Fork 0
forked from Mirror/frr
Code Pull requests Activity

Merge pull request #16796 from gtataranni/feat/logfmt

Browse source 
tools: add logfmt option for frr-reload.py
This commit is contained in:
Donatas Abraitis 2025-02-17 23:02:27 +02:00 committed by GitHub
parent e241882d8f 44a6e0dfed
commit b6ae929c1d
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
1 changed files with 88 additions and 35 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

123
tools/frr-reload.py
View file

@ -14,6 +14,7 @@ This program
from __future__ import print_function, unicode_literals from __future__ import print_function, unicode_literals
import argparse import argparse
import datetime
import logging import logging
import os, os.path import os, os.path
import random import random
@ -95,7 +96,7 @@ class Vtysh(object):
output = self("configure") output = self("configure")
if "configuration is locked" in output.lower(): if "configuration is locked" in output.lower():
log.error("vtysh 'configure' returned\n%s\n" % (output)) log.error(f"vtysh 'configure' returned\n{output}\n")
return False return False
return True return True
@ -104,7 +105,7 @@ class Vtysh(object):
child = self._call(["-f", filename]) child = self._call(["-f", filename])
if child.wait() != 0: if child.wait() != 0:
raise VtyshException( raise VtyshException(
"vtysh (exec file) exited with status %d" % (child.returncode) f"vtysh (exec file) exited with status {child.returncode}"
) )
def mark_file(self, filename, stdin=None): def mark_file(self, filename, stdin=None):
@ -320,7 +321,7 @@ class Config(object):
The internal representation has been marked appropriately by passing it The internal representation has been marked appropriately by passing it
through vtysh with the -m parameter through vtysh with the -m parameter
""" """
log.info("Loading Config object from file %s", filename) log.info(f"Loading Config object from file {filename}")
file_output = self.vtysh.mark_file(filename) file_output = self.vtysh.mark_file(filename)
@ -660,7 +661,7 @@ class Config(object):
self.save_contexts(ctx_keys, cur_ctx_lines) self.save_contexts(ctx_keys, cur_ctx_lines)
# exit current context # exit current context
log.debug("LINE %-50s: exit context %-50s", line, ctx_keys) log.debug(f"LINE {line:<50}: exit context {' '.join(ctx_keys):<50}")
ctx_keys.pop() ctx_keys.pop()
cur_ctx_keywords.pop() cur_ctx_keywords.pop()
@ -675,7 +676,7 @@ class Config(object):
self.save_contexts(ctx_keys, cur_ctx_lines) self.save_contexts(ctx_keys, cur_ctx_lines)
# exit current context # exit current context
log.debug("LINE %-50s: exit context %-50s", line, ctx_keys) log.debug(f"LINE {line:<50}: exit context {' '.join(ctx_keys):<50}")
ctx_keys.pop() ctx_keys.pop()
cur_ctx_keywords.pop() cur_ctx_keywords.pop()
@ -706,17 +707,21 @@ class Config(object):
cur_ctx_keywords.append(v) cur_ctx_keywords.append(v)
cur_ctx_lines = [] cur_ctx_lines = []
log.debug("LINE %-50s: enter context %-50s", line, ctx_keys) log.debug(
f"LINE {line:<50}: enter context {' '.join(ctx_keys):<50}"
)
break break
if new_ctx: if new_ctx:
continue continue
if len(ctx_keys) == 0: if len(ctx_keys) == 0:
log.debug("LINE %-50s: single-line context", line) log.debug(f"LINE {line:<50}: single-line context")
self.save_contexts([line], []) self.save_contexts([line], [])
else: else:
log.debug("LINE %-50s: add to current context %-50s", line, ctx_keys) log.debug(
f"LINE {line:<50}: add to current context {' '.join(ctx_keys):<50}"
)
cur_ctx_lines.append(line) cur_ctx_lines.append(line)
# Save the context of the last one # Save the context of the last one
@ -1711,7 +1716,7 @@ def ignore_unconfigurable_lines(lines_to_add, lines_to_del):
] ]
] ]
): ):
log.info('"%s" cannot be removed' % (ctx_keys[-1],)) log.info(f'"{ctx_keys[-1]}" cannot be removed')
lines_to_del_to_del.append((ctx_keys, line)) lines_to_del_to_del.append((ctx_keys, line))
for ctx_keys, line in lines_to_del_to_del: for ctx_keys, line in lines_to_del_to_del:
@ -1990,6 +1995,50 @@ def compare_context_objects(newconf, running):
return (lines_to_add, lines_to_del) return (lines_to_add, lines_to_del)
class LogFmtFormatter(logging.Formatter):
def format(self, record: logging.LogRecord) -> str:
"""
Creates log messages with key=value pairs, in logfmt format.
"""
# Escape double quotes in the message, replace newlines with '\n'
msg = record.getMessage().replace('"', '\\"').replace("\n", "\\n").strip()
# Format the time in RFC 3339 format
timestamp = datetime.datetime.fromtimestamp(
record.created, datetime.timezone.utc
)
asctime = timestamp.astimezone().isoformat(timespec="seconds")
# Create logfmt style log message, ignore default fields
logfmt = f'ts={asctime} level={record.levelname} msg="{msg}"'
default_fields = [
"args",
"asctime",
"created",
"exc_info",
"exc_text",
"filename",
"funcName",
"levelname",
"levelno",
"lineno",
"module",
"msecs",
"msg",
"name",
"pathname",
"process",
"processName",
"relativeCreated",
"stack_info",
"thread",
"threadName",
]
for key, value in vars(record).items():
if key in default_fields:
continue
logfmt += f" {key}={value}"
return logfmt
if __name__ == "__main__": if __name__ == "__main__":
# Command line options # Command line options
parser = argparse.ArgumentParser( parser = argparse.ArgumentParser(
@ -2057,15 +2106,24 @@ if __name__ == "__main__":
action="store_true", action="store_true",
help="Used by topotest to not delete debug or log file commands", help="Used by topotest to not delete debug or log file commands",
) )
parser.add_argument(
"--logfmt",
action="store_true",
help="Use logfmt as log format",
default=False,
)
args = parser.parse_args() args = parser.parse_args()
# Logging # Logging
# For --test log to stdout # For --test log to stdout
# For --reload log to /var/log/frr/frr-reload.log # For --reload log to /var/log/frr/frr-reload.log
if args.test or args.stdout: # If --logfmt, use the logfmt format
logging.basicConfig(format="%(asctime)s %(levelname)5s: %(message)s") formatter = logging.Formatter("%(asctime)s %(levelname)5s: %(message)s")
handler = logging.StreamHandler()
if args.logfmt:
formatter = LogFmtFormatter()
elif args.test or args.stdout:
# Color the errors and warnings in red # Color the errors and warnings in red
logging.addLevelName( logging.addLevelName(
logging.ERROR, "\033[91m %s\033[0m" % logging.getLevelName(logging.ERROR) logging.ERROR, "\033[91m %s\033[0m" % logging.getLevelName(logging.ERROR)
@ -2073,20 +2131,15 @@ if __name__ == "__main__":
logging.addLevelName( logging.addLevelName(
logging.WARNING, "\033[91m%s\033[0m" % logging.getLevelName(logging.WARNING) logging.WARNING, "\033[91m%s\033[0m" % logging.getLevelName(logging.WARNING)
) )
if args.reload:
elif args.reload:
if not os.path.isdir("/var/log/frr/"): if not os.path.isdir("/var/log/frr/"):
os.makedirs("/var/log/frr/", mode=0o0755) os.makedirs("/var/log/frr/", mode=0o0755)
handler = logging.FileHandler("/var/log/frr/frr-reload.log")
logging.basicConfig( if args.stdout:
filename="/var/log/frr/frr-reload.log", handler = logging.StreamHandler(sys.stdout)
format="%(asctime)s %(levelname)5s: %(message)s", handler.setFormatter(formatter)
)
# argparse should prevent this from happening but just to be safe...
else:
raise Exception("Must specify --reload or --test")
log = logging.getLogger(__name__) log = logging.getLogger(__name__)
log.addHandler(handler)
if args.debug: if args.debug:
log.setLevel(logging.DEBUG) log.setLevel(logging.DEBUG)
@ -2106,26 +2159,26 @@ if __name__ == "__main__":
# Verify the new config file is valid # Verify the new config file is valid
if not os.path.isfile(args.filename): if not os.path.isfile(args.filename):
log.error("Filename %s does not exist" % args.filename) log.error(f"Filename {args.filename} does not exist")
sys.exit(1) sys.exit(1)
if not os.path.getsize(args.filename): if not os.path.getsize(args.filename):
log.error("Filename %s is an empty file" % args.filename) log.error(f"Filename {args.filename} is an empty file")
sys.exit(1) sys.exit(1)
# Verify that confdir is correct # Verify that confdir is correct
if not os.path.isdir(args.confdir): if not os.path.isdir(args.confdir):
log.error("Confdir %s is not a valid path" % args.confdir) log.error(f"Confdir {args.confdir} is not a valid path")
sys.exit(1) sys.exit(1)
# Verify that bindir is correct # Verify that bindir is correct
if not os.path.isdir(args.bindir) or not os.path.isfile(args.bindir + "/vtysh"): if not os.path.isdir(args.bindir) or not os.path.isfile(args.bindir + "/vtysh"):
log.error("Bindir %s is not a valid path to vtysh" % args.bindir) log.error(f"Bindir {args.bindir} is not a valid path to vtysh")
sys.exit(1) sys.exit(1)
# verify that the vty_socket, if specified, is valid # verify that the vty_socket, if specified, is valid
if args.vty_socket and not os.path.isdir(args.vty_socket): if args.vty_socket and not os.path.isdir(args.vty_socket):
log.error("vty_socket %s is not a valid path" % args.vty_socket) log.error(f"vty_socket {args.vty_socket} is not a valid path")
sys.exit(1) sys.exit(1)
# verify that the daemon, if specified, is valid # verify that the daemon, if specified, is valid
@ -2180,7 +2233,7 @@ if __name__ == "__main__":
) )
sys.exit(1) sys.exit(1)
log.info('Called via "%s"', str(args)) log.info(f'Called via "{args}"')
# Create a Config object from the config generated by newconf # Create a Config object from the config generated by newconf
newconf = Config(vtysh) newconf = Config(vtysh)
@ -2256,7 +2309,7 @@ if __name__ == "__main__":
if not vtysh.is_config_available() or not reload_ok: if not vtysh.is_config_available() or not reload_ok:
sys.exit(1) sys.exit(1)
log.debug("New Frr Config\n%s", newconf.get_lines()) log.debug(f"New Frr Config\n{newconf.get_lines()}")
# This looks a little odd but we have to do this twice...here is why # This looks a little odd but we have to do this twice...here is why
# If the user had this running bgp config: # If the user had this running bgp config:
@ -2298,7 +2351,7 @@ if __name__ == "__main__":
for x in range(2): for x in range(2):
running = Config(vtysh) running = Config(vtysh)
running.load_from_show_running(args.daemon) running.load_from_show_running(args.daemon)
log.debug("Running Frr Config (Pass #%d)\n%s", x, running.get_lines()) log.debug(f"Running Frr Config (Pass #{x})\n{running.get_lines()}")
(lines_to_add, lines_to_del) = compare_context_objects(newconf, running) (lines_to_add, lines_to_del) = compare_context_objects(newconf, running)
@ -2355,7 +2408,7 @@ if __name__ == "__main__":
# 'no ip ospf authentication message-digest 1.1.1.1' in # 'no ip ospf authentication message-digest 1.1.1.1' in
# our example above # our example above
# - Split that last entry by whitespace and drop the last word # - Split that last entry by whitespace and drop the last word
log.error("Failed to execute %s", " ".join(cmd)) log.error(f"Failed to execute {' '.join(cmd)}")
last_arg = cmd[-1].split(" ") last_arg = cmd[-1].split(" ")
if len(last_arg) <= 2: if len(last_arg) <= 2:
@ -2372,7 +2425,7 @@ if __name__ == "__main__":
new_last_arg = last_arg[0:-1] new_last_arg = last_arg[0:-1]
cmd[-1] = " ".join(new_last_arg) cmd[-1] = " ".join(new_last_arg)
else: else:
log.info('Executed "%s"', " ".join(cmd)) log.info(f'Executed "{" ".join(cmd)}"')
break break
if lines_to_add: if lines_to_add:
@ -2399,7 +2452,7 @@ if __name__ == "__main__":
) )
filename = args.rundir + "/reload-%s.txt" % random_string filename = args.rundir + "/reload-%s.txt" % random_string
log.info("%s content\n%s" % (filename, pformat(lines_to_configure))) log.info(f"{filename} content\n{pformat(lines_to_configure)}")
with open(filename, "w") as fh: with open(filename, "w") as fh:
for line in lines_to_configure: for line in lines_to_configure:
@ -2408,7 +2461,7 @@ if __name__ == "__main__":
try: try:
vtysh.exec_file(filename) vtysh.exec_file(filename)
except VtyshException as e: except VtyshException as e:
log.warning("frr-reload.py failed due to\n%s" % e.args) log.warning(f"frr-reload.py failed due to\n{e.args}")
reload_ok = False reload_ok = False
os.unlink(filename) os.unlink(filename)