summaryrefslogtreecommitdiffstats
path: root/scripts/bugreport-journals.py
diff options
context:
space:
mode:
authorDaniel Baumann <daniel.baumann@progress-linux.org>2024-04-07 15:26:00 +0000
committerDaniel Baumann <daniel.baumann@progress-linux.org>2024-04-07 15:26:00 +0000
commit830407e88f9d40d954356c3754f2647f91d5c06a (patch)
treed6a0ece6feea91f3c656166dbaa884ef8a29740e /scripts/bugreport-journals.py
parentInitial commit. (diff)
downloadknot-resolver-830407e88f9d40d954356c3754f2647f91d5c06a.tar.xz
knot-resolver-830407e88f9d40d954356c3754f2647f91d5c06a.zip
Adding upstream version 5.6.0.upstream/5.6.0upstream
Signed-off-by: Daniel Baumann <daniel.baumann@progress-linux.org>
Diffstat (limited to 'scripts/bugreport-journals.py')
-rwxr-xr-xscripts/bugreport-journals.py194
1 files changed, 194 insertions, 0 deletions
diff --git a/scripts/bugreport-journals.py b/scripts/bugreport-journals.py
new file mode 100755
index 0000000..d66ddfb
--- /dev/null
+++ b/scripts/bugreport-journals.py
@@ -0,0 +1,194 @@
+#!/usr/bin/python3
+"""
+Collect systemd-journal log entries around time of daemon exit and coredumps.
+"""
+
+import datetime
+import json
+import logging
+import pathlib
+import shutil
+import subprocess
+import sys
+
+
+TIMESPAN_BEFORE = 600 # s
+TIMESPAN_AFTER = TIMESPAN_BEFORE
+CURSOR_DIR = pathlib.Path('/var/lib/knot-resolver')
+CURSOR_PATH = CURSOR_DIR / 'coredump_watcher.cursor'
+
+
+class Timestamp:
+ def __init__(self, usec):
+ self.usec = int(usec)
+
+ @property
+ def unix(self):
+ return self.usec // 10**6
+
+ def __str__(self):
+ return datetime.datetime.utcfromtimestamp(self.unix).strftime('%Y-%m-%d_%H:%M:%S')
+
+ def __lt__(self, other):
+ return self.usec < other.usec
+
+ def __eq__(self, other):
+ return self.usec == other.usec
+
+
+class Entry(dict):
+ @property
+ def timestamp(self):
+ usec = self.get('__REALTIME_TIMESTAMP')
+ if usec is None:
+ return None
+ return Timestamp(usec)
+
+ @property
+ def core_path(self):
+ filename = self.get('COREDUMP_FILENAME')
+ if filename is None:
+ return None
+ return pathlib.Path(filename)
+
+ def get_first(self, *keys):
+ for key in keys:
+ try:
+ return self[key]
+ except KeyError:
+ continue
+ return None
+
+ @property
+ def program(self):
+ return self.get_first('COREDUMP_UNIT', 'UNIT', '_SYSTEMD_UNIT', 'SYSLOG_IDENTIFIER')
+
+ @property
+ def pid(self):
+ return self.get_first('COREDUMP_PID', '_PID')
+
+
+def save_cursor(cursor):
+ if cursor is None:
+ return
+ CURSOR_DIR.mkdir(parents=True, exist_ok=True)
+ with CURSOR_PATH.open('w') as curfile:
+ curfile.write(cursor)
+ logging.info('log cursor saved into %s, next run will skip old logs',
+ CURSOR_PATH)
+
+
+def load_cursor():
+ try:
+ with CURSOR_PATH.open('r') as curfile:
+ logging.info('log cursor read from %s, skipping old logs',
+ CURSOR_PATH)
+ return curfile.read().strip()
+ except FileNotFoundError:
+ logging.info('log cursor file %s does not exist, parsing all logs',
+ CURSOR_PATH)
+ return None
+
+
+def get_cursor():
+ journal_args = ['journalctl', '-o', 'json', '-n', '1']
+ with subprocess.Popen(
+ journal_args,
+ bufsize=1, # line buffering
+ universal_newlines=True,
+ stdout=subprocess.PIPE) as jproc:
+ stdout, _ = jproc.communicate()
+ data = json.loads(stdout)
+ entry = Entry(**data)
+ return entry.get('__CURSOR')
+
+
+def read_journal(*args):
+ journal_args = [
+ 'journalctl',
+ '-o', 'json',
+ '-u', 'kres*',
+ '-u', 'systemd-coredump*']
+ journal_args += args
+ with subprocess.Popen(
+ journal_args,
+ bufsize=1, # line buffering
+ universal_newlines=True,
+ stdout=subprocess.PIPE) as jproc:
+ for line in jproc.stdout:
+ data = json.loads(line)
+ yield Entry(**data)
+
+
+def extract_logs(around_time, log_name):
+ start_time = Timestamp(around_time.usec - TIMESPAN_BEFORE * 10**6)
+ end_time = Timestamp(around_time.usec + TIMESPAN_AFTER * 10**6)
+ log_window = list(read_journal(
+ '--since', '@{}'.format(start_time.unix),
+ '--until', '@{}'.format(end_time.unix)))
+ with log_name.with_suffix('.json').open('w') as jsonf:
+ json.dump(log_window, jsonf, indent=4)
+ with log_name.with_suffix('.log').open('w') as logf:
+ logf.write('##### logs since {}\n'.format(start_time))
+ for entry in log_window:
+ if entry.timestamp == around_time:
+ logf.write('##### HERE #####\n')
+ logf.write('{t} {h} {prg}[{pid}]: {m}\n'.format(
+ t=entry.timestamp,
+ h=entry.get('_HOSTNAME'),
+ prg=entry.program,
+ pid=entry.pid,
+ m=entry.get('MESSAGE')))
+ logf.write('##### logs until {}\n'.format(end_time))
+
+
+def main():
+ logging.basicConfig(level=logging.INFO)
+
+ if len(sys.argv) != 2:
+ sys.exit('Usage: {} <output log directory>'.format(sys.argv[0]))
+ outdir = pathlib.Path(sys.argv[1])
+ outdir.mkdir(parents=True, exist_ok=True)
+
+ cursor_previous = load_cursor()
+ cursor_at_start = get_cursor()
+
+ exit_times = []
+ coredumps = {}
+ filter_args = []
+ if cursor_previous is not None:
+ filter_args = ['--after-cursor', cursor_previous]
+ for entry in read_journal(*filter_args):
+ if 'EXIT_CODE' in entry:
+ logging.debug('exit@%s: %s', entry.timestamp, entry)
+ exit_times.append(entry.timestamp)
+ if 'COREDUMP_FILENAME' in entry:
+ logging.debug('coredump @ %s: %s', entry.timestamp, entry.core_path)
+ coredumps[entry.core_path] = entry.timestamp
+
+ exit_times.sort()
+ logging.debug('detected exits: %s', exit_times)
+ for exit_time in exit_times:
+ extract_logs(exit_time, outdir / str(exit_time))
+
+ coredumps_missing = 0
+ logging.debug('detected coredumps: %s', coredumps)
+ for core_path, core_time in coredumps.items():
+ core_name = core_path.name
+ out_path_prefix = (outdir / str(core_time))
+ extract_logs(core_time, out_path_prefix.with_suffix('.logs'))
+ try:
+ shutil.copy(
+ str(core_path),
+ str(out_path_prefix.with_suffix('.{}'.format(core_name))))
+ except FileNotFoundError as ex:
+ logging.error('coredump file %s cannot be copied: %s', core_path, ex)
+ coredumps_missing += 1
+ logging.info('wrote %d coredumps and %d logs snippets (%s coredumps missing)',
+ len(coredumps) - coredumps_missing, len(exit_times), coredumps_missing)
+
+ save_cursor(cursor_at_start)
+
+
+if __name__ == '__main__':
+ main()