#!/usr/bin/python3
"""
-Collect sysmted-journald log entries around time of daemon exit and coredumps.
+Collect systemd-journal log entries around time of daemon exit and coredumps.
"""
import datetime
import json
import logging
-import os
import pathlib
import shutil
import subprocess
TIMESPAN_BEFORE = 600 # s
TIMESPAN_AFTER = TIMESPAN_BEFORE
+CURSOR_DIR = pathlib.Path('/var/lib/knot-resolver')
+CURSOR_PATH = CURSOR_DIR / 'coredump_watcher.cursor'
-class Cursors:
- cursordir = pathlib.Path('/var/lib/knot-resolver')
- path = cursordir / pathlib.Path('coredump_watcher.cursor')
+class Timestamp:
+ def __init__(self, usec):
+ self.usec = int(usec)
- @staticmethod
- def overwrite_previous(new_cursor):
- logging.info('log cursor saved into %s, next run will skip old logs',
- Cursors.path)
- Cursors.cursordir.mkdir(parents=True, exist_ok=True)
- with Cursors.path.open('w') as curfile:
- curfile.write(new_cursor)
+ @property
+ def unix(self):
+ return self.usec // 10**6
- @staticmethod
- def get_previous():
- try:
- with Cursors.path.open('r') as curfile:
- logging.info('log cursor read from %s, skipping old logs',
- Cursors.path)
- return curfile.read().strip()
- except FileNotFoundError:
- logging.info('log cursor file %s does not exist, parsing all logs',
- Cursors.path)
+ 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)
- @staticmethod
- def get_current():
- 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()
- entry = json.loads(stdout)
- return entry['__CURSOR']
-
-
-class Timestamps:
- @staticmethod
- def str2unix(string):
- # systemd uses microsecond resolution
- return int(string) / 10**6
-
- def unix2print(str_or_int):
- if not isinstance(str_or_int, float):
- str_or_int = Timestamps.str2unix(str_or_int)
- return datetime.datetime.utcfromtimestamp(str_or_int).strftime('%Y-%m-%d_%H:%M:%S')
-
-
-class Journals:
- @staticmethod
- def read_logs(*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:
- yield json.loads(line)
-
- @staticmethod
- def extract_logs(around_time, log_name):
- start_time = around_time - TIMESPAN_BEFORE
- end_time = around_time + TIMESPAN_AFTER
- log_window = list(Journals.read_logs(
- '--since=@{}'.format(start_time),
- '--until=@{}'.format(end_time)
- ))
- 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(Timestamps.unix2print(start_time)))
- for entry in log_window:
- entry_time = Timestamps.str2unix(entry['__REALTIME_TIMESTAMP'])
- if entry_time == around_time:
- logf.write('##### HERE #####\n')
- logf.write('{t} {h} {prg}[{pid}]: {m}\n'.format(
- t=Timestamps.unix2print(entry_time),
- h=entry['_HOSTNAME'],
- prg=(
- entry.get('COREDUMP_UNIT')
- or entry.get('UNIT')
- or entry.get('_SYSTEMD_UNIT')
- or entry['SYSLOG_IDENTIFIER']
- ),
- pid=entry.get('COREDUMP_PID') or entry['_PID'],
- m=entry['MESSAGE']
- )
- )
- logf.write('##### logs until {}\n'.format(Timestamps.unix2print(end_time)))
+ @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: %s <output log directory>'.format(sys.argv[0]))
+ 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 = Cursors.get_previous()
- cursor_at_start = Cursors.get_current()
+ cursor_previous = load_cursor()
+ cursor_at_start = get_cursor()
exit_times = []
coredumps = {}
filter_args = []
- if cursor_previous:
+ if cursor_previous is not None:
filter_args = ['--after-cursor', cursor_previous]
- for entry in Journals.read_logs(*filter_args):
+ for entry in read_journal(*filter_args):
if 'EXIT_CODE' in entry:
- exit_time = Timestamps.str2unix(entry['__REALTIME_TIMESTAMP'])
- logging.debug('exit@%s: %s', exit_time, entry)
- exit_times.append(exit_time)
+ logging.debug('exit@%s: %s', entry.timestamp, entry)
+ exit_times.append(entry.timestamp)
if 'COREDUMP_FILENAME' in entry:
- core_path = pathlib.Path(entry['COREDUMP_FILENAME'])
- core_time = Timestamps.str2unix(entry['__REALTIME_TIMESTAMP'])
- logging.debug('coredump @ %s: %s', core_time, core_path)
- coredumps[core_path] = core_time
+ 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:
- Journals.extract_logs(exit_time, outdir / '{}'.format(Timestamps.unix2print(exit_time)))
+ 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
- timestamp = Timestamps.unix2print(core_time)
- out_path_prefix = (outdir / timestamp)
- Journals.extract_logs(core_time, out_path_prefix.with_suffix('.logs'))
+ 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(str(core_name)))))
+ 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)
- Cursors.overwrite_previous(cursor_at_start)
+ save_cursor(cursor_at_start)
+
if __name__ == '__main__':
main()
projects / thirdparty / knot-resolver.git / commitdiff
