| |
@@ -14,49 +14,6 @@
|
| |
from ..constants import default_log_format
|
| |
|
| |
|
| |
- level_map = {
|
| |
- "info": logging.INFO,
|
| |
- "debug": logging.DEBUG,
|
| |
- "error": logging.ERROR,
|
| |
- }
|
| |
-
|
| |
-
|
| |
- class LogRouterFilter(logging.Filter):
|
| |
- def __init__(self, who):
|
| |
- """
|
| |
- Value of field `who` which should be present to propagate LogRecord
|
| |
- """
|
| |
- super(LogRouterFilter, self).__init__()
|
| |
- self.who = who
|
| |
-
|
| |
- def filter(self, record):
|
| |
- return record.event.get("who") == self.who
|
| |
-
|
| |
-
|
| |
- class CustomFilter(logging.Filter):
|
| |
-
|
| |
- def filter(self, record):
|
| |
- if not hasattr(record, "event"):
|
| |
- return False
|
| |
-
|
| |
- event = record.event
|
| |
- if "traceback" in event:
|
| |
- record.msg = "{}\n{}".format(record.msg, event.pop("traceback"))
|
| |
-
|
| |
- # '%s %s' % (a, b) requires tuple, while
|
| |
- # json.loads(json.dumps(tuple)) returns array
|
| |
- if "args" in event and isinstance(event["args"], list):
|
| |
- event["args"] = tuple(event["args"])
|
| |
-
|
| |
- record.lineno = int(event.pop("lineno", "-1"))
|
| |
- record.funcName = event.pop("funcName", None)
|
| |
- record.pathname = event.pop("pathname", None)
|
| |
- for k, v in event.items():
|
| |
- setattr(record, k, v)
|
| |
-
|
| |
- return True
|
| |
-
|
| |
-
|
| |
class RedisLogHandler(object):
|
| |
"""
|
| |
Single point to collect logs through redis pub/sub and write
|
| |
@@ -81,43 +38,31 @@
|
| |
self.main_handler.setFormatter(default_log_format)
|
| |
self.main_logger.addHandler(self.main_handler)
|
| |
|
| |
- self.router_logger = logging.Logger("log_router")
|
| |
- self.router_logger.addFilter(CustomFilter())
|
| |
+ level = getattr(logging, self.opts.log_level.upper(), None)
|
| |
+ self.loggers = {}
|
| |
|
| |
for component in self.components:
|
| |
+ logger = logging.Logger(component)
|
| |
handler = logging.handlers.WatchedFileHandler(
|
| |
filename=os.path.join(self.log_dir, "{}.log".format(component)))
|
| |
handler.setFormatter(default_log_format)
|
| |
- handler.setLevel(level=level_map[self.opts.log_level])
|
| |
- # not very good from performance point:
|
| |
- # filter called for each message, but only one handler process record
|
| |
- # but it shouldn't be a real problem
|
| |
- handler.addFilter(filter=LogRouterFilter(component))
|
| |
- self.router_logger.addHandler(handler)
|
| |
+ handler.setLevel(level)
|
| |
+ logger.addHandler(handler)
|
| |
+ self.loggers[component] = logger
|
| |
|
| |
def handle_msg(self, raw):
|
| |
try:
|
| |
event = json.loads(raw["data"])
|
| |
|
| |
- # expected fields:
|
| |
- # - who: self.components
|
| |
- # - level: "info", "debug", "error", None --> default is "info"
|
| |
- # - msg: str with log msg
|
| |
- # [- traceback: str with error traceback ]
|
| |
- # [ more LogRecord kwargs, see: https://docs.python.org/2/library/logging.html#logrecord-objects]
|
| |
-
|
| |
- for key in ["who", "msg"]:
|
| |
- if key not in event:
|
| |
- raise Exception("Handler received msg without `{}` field, msg: {}".format(key, event))
|
| |
-
|
| |
- who = event["who"]
|
| |
- if who not in self.components:
|
| |
- raise Exception("Handler received msg with unknown `who` field: {}, msg: {}".format(who, event))
|
| |
-
|
| |
- level = level_map[event.pop("level", "info")]
|
| |
- msg = event.pop("msg")
|
| |
+ who = event.get('who', None)
|
| |
+ if not who:
|
| |
+ raise Exception("No LogRecord.who field, raw: {}".format(event))
|
| |
+ if who not in self.loggers:
|
| |
+ raise Exception("Unknown LogRecord.who field: {}, raw event: {}"
|
| |
+ .format(who, event))
|
| |
|
| |
- self.router_logger.log(level, msg, extra={"event": event})
|
| |
+ log_record = logging.makeLogRecord(event)
|
| |
+ self.loggers[who].handle(log_record)
|
| |
|
| |
except Exception as err:
|
| |
self.main_logger.exception(err)
|
| |
praiskup
commented 5 years ago
[backend] simplify logging through redis After 3d642d711eb9cf1e10d224fa4d379c5edf6fc34a commit, I started to observe weird errors (see below). So while debugging, I noticed that the filters are unnecessary complicated, and that we can bypass LogErrors through Redis queue a more convenient way: -> start with LogRecord -> if traceback -> encode traceback as msg (as before) -> else -> encode message (as before) -> drop some fields which are not json.dump()able -> and then send to redis On the RedisLogHandler side it is then only matter of logging.makeLogRecord() call and logger.handle(record). While I was on it, I removed the router_logger mechanism, and created separate logger for each daemon (this is actually faster, because not all the loggers have to go through all log records). Hopefully this means final fight with RedisLog* stuff, should be much solid. copr_run_logger.py[26166]: --- Logging error --- copr_run_logger.py[26166]: Traceback (most recent call last): copr_run_logger.py[26166]: File "/usr/lib64/python3.6/logging/__init__.py", line 994, in emit copr_run_logger.py[26166]: msg = self.format(record) copr_run_logger.py[26166]: File "/usr/lib64/python3.6/logging/__init__.py", line 840, in format copr_run_logger.py[26166]: return fmt.format(record) copr_run_logger.py[26166]: File "/usr/lib64/python3.6/logging/__init__.py", line 585, in format copr_run_logger.py[26166]: record.exc_text = self.formatException(record.exc_info) copr_run_logger.py[26166]: File "/usr/lib64/python3.6/logging/__init__.py", line 535, in formatException copr_run_logger.py[26166]: traceback.print_exception(ei[0], ei[1], tb, None, sio) copr_run_logger.py[26166]: File "/usr/lib64/python3.6/traceback.py", line 104, in print_exception copr_run_logger.py[26166]: type(value), value, tb, limit=limit).format(chain=chain): copr_run_logger.py[26166]: File "/usr/lib64/python3.6/traceback.py", line 477, in __init__ copr_run_logger.py[26166]: if (exc_value and exc_value.__cause__ is not None copr_run_logger.py[26166]: AttributeError: 'str' object has no attribute '__cause__' copr_run_logger.py[26166]: Call stack: copr_run_logger.py[26166]: File "/usr/bin/copr_run_logger.py", line 15, in <module> copr_run_logger.py[26166]: main() copr_run_logger.py[26166]: File "/usr/bin/copr_run_logger.py", line 11, in main copr_run_logger.py[26166]: handler.run() copr_run_logger.py[26166]: File "/usr/share/copr/backend/daemons/log.py", line 135, in run copr_run_logger.py[26166]: self.handle_msg(raw) copr_run_logger.py[26166]: File "/usr/share/copr/backend/daemons/log.py", line 120, in handle_msg copr_run_logger.py[26166]: self.router_logger.log(level, msg, extra={"event": event}) copr_run_logger.py[26166]: Message: 'Healtcheck failed for VM 172.25.150.214 with error Connection broke:\nOUT:\n\nERR:\nssh: