diff --git a/NEWS b/NEWS index 55c836bc..f26eb23d 100644 --- a/NEWS +++ b/NEWS @@ -1,6 +1,10 @@ 2.0.14.dev0 * #485: When running commands (database clients, command hooks, etc.), elevate stderr output to borgmatic error logs. + * #858: With the "--log-json" flag, log borgmatic's own logs as JSON, not just Borg's. + * #1204: When verbosity levels differ between console/monitoring/syslog/file, log Borg's output to + each one at a different level. + * When syslog verbosity is enabled, log to systemd's journal (if present) with structured data. 2.0.13 * #1054: Allow the Btrfs hook to create and delete snapshots even when running diff --git a/borgmatic/borg/break_lock.py b/borgmatic/borg/break_lock.py index 74749160..18eae878 100644 --- a/borgmatic/borg/break_lock.py +++ b/borgmatic/borg/break_lock.py @@ -29,7 +29,7 @@ def break_lock( (local_path, 'break-lock') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/change_passphrase.py b/borgmatic/borg/change_passphrase.py index 8769802f..626e278a 100644 --- a/borgmatic/borg/change_passphrase.py +++ b/borgmatic/borg/change_passphrase.py @@ -32,7 +32,7 @@ def change_passphrase( (local_path, 'key', 'change-passphrase') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/check.py b/borgmatic/borg/check.py index 4f7fc75e..13d94dd4 100644 --- a/borgmatic/borg/check.py +++ b/borgmatic/borg/check.py @@ -176,7 +176,7 @@ def check_archives( + make_check_name_flags(checks_subset, archive_filter_flags) + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + verbosity_flags + (('--progress',) if config.get('progress') else ()) diff --git a/borgmatic/borg/compact.py b/borgmatic/borg/compact.py index 103a3d6a..3bae538e 100644 --- a/borgmatic/borg/compact.py +++ b/borgmatic/borg/compact.py @@ -31,7 +31,7 @@ def compact_segments( (local_path, 'compact') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--progress',) if config.get('progress') else ()) + (('--cleanup-commits',) if cleanup_commits else ()) diff --git a/borgmatic/borg/create.py b/borgmatic/borg/create.py index 4220bb21..b4b8ec40 100644 --- a/borgmatic/borg/create.py +++ b/borgmatic/borg/create.py @@ -217,7 +217,7 @@ def make_base_create_command( + (('--files-cache', files_cache) if files_cache else ()) + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + ( ('--list', '--filter', list_filter_flags) diff --git a/borgmatic/borg/delete.py b/borgmatic/borg/delete.py index fbfc8a9e..acfe5695 100644 --- a/borgmatic/borg/delete.py +++ b/borgmatic/borg/delete.py @@ -38,7 +38,7 @@ def make_delete_command( + borgmatic.borg.flags.make_flags('dry-run', global_arguments.dry_run) + borgmatic.borg.flags.make_flags('remote-path', remote_path) + borgmatic.borg.flags.make_flags('umask', config.get('umask')) - + borgmatic.borg.flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + borgmatic.borg.flags.make_flags('lock-wait', config.get('lock_wait')) + borgmatic.borg.flags.make_flags('list', config.get('list_details')) + ( diff --git a/borgmatic/borg/export_key.py b/borgmatic/borg/export_key.py index a85d2470..f818b016 100644 --- a/borgmatic/borg/export_key.py +++ b/borgmatic/borg/export_key.py @@ -48,7 +48,7 @@ def export_key( (local_path, 'key', 'export') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/export_tar.py b/borgmatic/borg/export_tar.py index d7cf4d28..51a1d0f2 100644 --- a/borgmatic/borg/export_tar.py +++ b/borgmatic/borg/export_tar.py @@ -41,7 +41,7 @@ def export_tar_archive( (local_path, 'export-tar') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--list',) if config.get('list_details') else ()) diff --git a/borgmatic/borg/extract.py b/borgmatic/borg/extract.py index 3004a47e..8e032338 100644 --- a/borgmatic/borg/extract.py +++ b/borgmatic/borg/extract.py @@ -49,7 +49,7 @@ def extract_last_archive_dry_run( full_extract_command = ( (local_path, 'extract', '--dry-run') + (('--remote-path', remote_path) if remote_path else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + verbosity_flags + list_flag @@ -127,7 +127,7 @@ def extract_archive( + (('--remote-path', remote_path) if remote_path else ()) + numeric_ids_flags + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--list', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/import_key.py b/borgmatic/borg/import_key.py index 9a7563fc..1d0945bf 100644 --- a/borgmatic/borg/import_key.py +++ b/borgmatic/borg/import_key.py @@ -44,7 +44,7 @@ def import_key( (local_path, 'key', 'import') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/info.py b/borgmatic/borg/info.py index 32de1057..c2d34cd3 100644 --- a/borgmatic/borg/info.py +++ b/borgmatic/borg/info.py @@ -40,7 +40,7 @@ def make_info_command( ) + flags.make_flags('remote-path', remote_path) + flags.make_flags('umask', config.get('umask')) - + flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + flags.make_flags('lock-wait', config.get('lock_wait')) + ( ( diff --git a/borgmatic/borg/list.py b/borgmatic/borg/list.py index dd65608f..eec10a2d 100644 --- a/borgmatic/borg/list.py +++ b/borgmatic/borg/list.py @@ -53,7 +53,7 @@ def make_list_command( ) + flags.make_flags('remote-path', remote_path) + flags.make_flags('umask', config.get('umask')) - + flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + flags.make_flags('lock-wait', config.get('lock_wait')) + flags.make_flags('format', list_arguments.format or config.get('file_list_format')) + flags.make_flags_from_arguments(list_arguments, excludes=MAKE_FLAGS_EXCLUDES) diff --git a/borgmatic/borg/mount.py b/borgmatic/borg/mount.py index 369b3b3b..041c1e72 100644 --- a/borgmatic/borg/mount.py +++ b/borgmatic/borg/mount.py @@ -32,7 +32,7 @@ def mount_archive( (local_path, 'mount') + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/prune.py b/borgmatic/borg/prune.py index 0aab893d..1e3bc8da 100644 --- a/borgmatic/borg/prune.py +++ b/borgmatic/borg/prune.py @@ -74,7 +74,7 @@ def prune_archives( + make_prune_flags(config, prune_arguments, local_borg_version) + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + ( ('--stats',) diff --git a/borgmatic/borg/recreate.py b/borgmatic/borg/recreate.py index 87091ba1..b16a380c 100644 --- a/borgmatic/borg/recreate.py +++ b/borgmatic/borg/recreate.py @@ -46,7 +46,7 @@ def recreate_archive( recreate_command = ( (local_path, 'recreate') + (('--remote-path', remote_path) if remote_path else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait is not None else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) diff --git a/borgmatic/borg/rename.py b/borgmatic/borg/rename.py index 9b73e96b..f4081e0b 100644 --- a/borgmatic/borg/rename.py +++ b/borgmatic/borg/rename.py @@ -25,7 +25,7 @@ def make_rename_command( + borgmatic.borg.flags.make_flags('dry-run', dry_run) + borgmatic.borg.flags.make_flags('remote-path', remote_path) + borgmatic.borg.flags.make_flags('umask', config.get('umask')) - + borgmatic.borg.flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + borgmatic.borg.flags.make_flags('lock-wait', config.get('lock_wait')) + (tuple(shlex.split(extra_borg_options)) if extra_borg_options else ()) + borgmatic.borg.flags.make_repository_archive_flags( diff --git a/borgmatic/borg/repo_create.py b/borgmatic/borg/repo_create.py index 1e3c0df9..42a59bba 100644 --- a/borgmatic/borg/repo_create.py +++ b/borgmatic/borg/repo_create.py @@ -89,7 +89,7 @@ def create_repository( + (('--make-parent-dirs',) if make_parent_directories else ()) + (('--info',) if logger.getEffectiveLevel() == logging.INFO else ()) + (('--debug',) if logger.isEnabledFor(logging.DEBUG) else ()) - + (('--log-json',) if config.get('log_json') else ()) + + ('--log-json',) + (('--lock-wait', str(lock_wait)) if lock_wait else ()) + (('--remote-path', remote_path) if remote_path else ()) + (('--umask', str(umask)) if umask else ()) diff --git a/borgmatic/borg/repo_delete.py b/borgmatic/borg/repo_delete.py index ee10c9c5..5f99e920 100644 --- a/borgmatic/borg/repo_delete.py +++ b/borgmatic/borg/repo_delete.py @@ -51,7 +51,7 @@ def make_repo_delete_command( + borgmatic.borg.flags.make_flags('dry-run', global_arguments.dry_run) + borgmatic.borg.flags.make_flags('remote-path', remote_path) + borgmatic.borg.flags.make_flags('umask', config.get('umask')) - + borgmatic.borg.flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + borgmatic.borg.flags.make_flags('lock-wait', config.get('lock_wait')) + borgmatic.borg.flags.make_flags('list', config.get('list_details')) + ( diff --git a/borgmatic/borg/repo_info.py b/borgmatic/borg/repo_info.py index 3322c467..b8c4cfcb 100644 --- a/borgmatic/borg/repo_info.py +++ b/borgmatic/borg/repo_info.py @@ -49,7 +49,7 @@ def display_repository_info( ) + flags.make_flags('remote-path', remote_path) + flags.make_flags('umask', config.get('umask')) - + flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + flags.make_flags('lock-wait', lock_wait) + (('--json',) if repo_info_arguments.json else ()) + (tuple(shlex.split(extra_borg_options)) if extra_borg_options else ()) diff --git a/borgmatic/borg/repo_list.py b/borgmatic/borg/repo_list.py index 41238a1a..47460bfd 100644 --- a/borgmatic/borg/repo_list.py +++ b/borgmatic/borg/repo_list.py @@ -77,7 +77,7 @@ def get_latest_archive( ), *flags.make_flags('remote-path', remote_path), *flags.make_flags('umask', config.get('umask')), - *flags.make_flags('log-json', config.get('log_json')), + + ('--log-json',) *flags.make_flags('lock-wait', config.get('lock_wait')), *( flags.make_flags('consider-checkpoints', consider_checkpoints) @@ -153,7 +153,7 @@ def make_repo_list_command( ) + flags.make_flags('remote-path', remote_path) + flags.make_flags('umask', config.get('umask')) - + flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + flags.make_flags('lock-wait', config.get('lock_wait')) + ( ( diff --git a/borgmatic/borg/transfer.py b/borgmatic/borg/transfer.py index a6df4b37..992fea06 100644 --- a/borgmatic/borg/transfer.py +++ b/borgmatic/borg/transfer.py @@ -33,7 +33,7 @@ def transfer_archives( + (('--debug', '--show-rc') if logger.isEnabledFor(logging.DEBUG) else ()) + flags.make_flags('remote-path', remote_path) + flags.make_flags('umask', config.get('umask')) - + flags.make_flags('log-json', config.get('log_json')) + + ('--log-json',) + flags.make_flags('lock-wait', config.get('lock_wait')) + flags.make_flags('progress', config.get('progress')) + ( diff --git a/borgmatic/commands/borgmatic.py b/borgmatic/commands/borgmatic.py index 9d95e011..7988b8d4 100644 --- a/borgmatic/commands/borgmatic.py +++ b/borgmatic/commands/borgmatic.py @@ -660,6 +660,7 @@ def load_configurations(config_filenames, arguments, overrides=None, resolve_env levelno=logging.DEBUG, levelname='DEBUG', msg=f'{config_filename}: Loading configuration file', + name=logger.name, ), ), ], @@ -682,6 +683,7 @@ def load_configurations(config_filenames, arguments, overrides=None, resolve_env levelno=logging.CRITICAL, levelname='CRITICAL', msg=f'{config_filename}: Insufficient permissions to read configuration file', + name=logger.name, ), ), ], @@ -694,10 +696,11 @@ def load_configurations(config_filenames, arguments, overrides=None, resolve_env levelno=logging.CRITICAL, levelname='CRITICAL', msg=f'{config_filename}: Error parsing configuration file', + name=logger.name, ), ), logging.makeLogRecord( - dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=str(error)), + dict(levelno=logging.CRITICAL, levelname='CRITICAL', msg=str(error), name=logger.name), ), ], ) @@ -710,7 +713,7 @@ def log_record(suppress_log=False, **kwargs): Create a log record based on the given makeLogRecord() arguments, one of which must be named "levelno". Log the record (unless suppress log is set) and return it. ''' - record = logging.makeLogRecord(kwargs) + record = logging.makeLogRecord(dict(kwargs, name=logger.name)) if suppress_log: return record @@ -823,6 +826,7 @@ def collect_highlander_action_summary_logs(configs, arguments, configuration_par levelno=logging.ANSWER, levelname='ANSWER', msg='Bootstrap successful', + name=logger.name, ), ) except ( @@ -845,6 +849,7 @@ def collect_highlander_action_summary_logs(configs, arguments, configuration_par levelno=logging.ANSWER, levelname='ANSWER', msg='Generate successful', + name=logger.name, ), ) except ( @@ -863,6 +868,7 @@ def collect_highlander_action_summary_logs(configs, arguments, configuration_par levelno=logging.CRITICAL, levelname='CRITICAL', msg='Configuration validation failed', + name=logger.name, ), ) @@ -876,6 +882,7 @@ def collect_highlander_action_summary_logs(configs, arguments, configuration_par levelno=logging.ANSWER, levelname='ANSWER', msg='All configuration files are valid', + name=logger.name, ), ) except ( @@ -968,6 +975,7 @@ def collect_configuration_run_summary_logs(configs, config_paths, arguments, log levelno=logging.INFO, levelname='INFO', msg=f'{config_filename}: Successfully ran configuration file', + name=logger.name, ), ) if results: @@ -1126,6 +1134,7 @@ def main(extra_summary_logs=()): # pragma: no cover getattr(sub_arguments, 'json', False) for sub_arguments in arguments.values() ) log_file_path = get_singular_option_value(configs, 'log_file') + log_json = get_singular_option_value(configs, 'log_json') try: configure_logging( @@ -1135,7 +1144,8 @@ def main(extra_summary_logs=()): # pragma: no cover verbosity_to_log_level(get_verbosity(configs, 'monitoring_verbosity')), log_file_path, get_singular_option_value(configs, 'log_file_format'), - color_enabled=should_do_markup(configs, any_json_flags), + log_json, + color_enabled=should_do_markup(configs, any_json_flags or log_json), ) except (FileNotFoundError, PermissionError) as error: configure_logging(logging.CRITICAL) @@ -1165,7 +1175,7 @@ def main(extra_summary_logs=()): # pragma: no cover ) summary_logs_max_level = max(log.levelno for log in summary_logs) - for message in ('', 'summary:'): + for message in ('summary:',) if log_json else ('', 'summary:'): log_record( levelno=summary_logs_max_level, levelname=logging.getLevelName(summary_logs_max_level), diff --git a/borgmatic/execute.py b/borgmatic/execute.py index 6170b0c3..5e6addfa 100644 --- a/borgmatic/execute.py +++ b/borgmatic/execute.py @@ -1,5 +1,7 @@ import collections +import contextlib import enum +import json import logging import select import subprocess @@ -89,44 +91,62 @@ def output_buffers_for_process(process, exclude_stdouts): ) -def determine_log_level(output_log_level, came_from_stderr, borg_local_path, command, line): +def borg_log_data_to_log_record(log_data): ''' - Given the requested output log level, whether the this log line came from stderr, the Borg local - path, the command as a sequence, and the line to be logged, return the log level that should be - used. - - Borg happens to log everything to stderr (except JSON output), so if this is a Borg command, use - the requested log level regardless of whether this is for stdout or stderr. (Otherwise, all Borg - logs would show up at ERROR level even if there's no error!) - - But for other commands, elevate stderr logs to ERROR while using the requested log level for - stdout. The one exception is if the log came from stderr and the string "warning" appears at the - start of the log line. In that case, just elevate the log level to a WARN. + Given a log data dict for a single Borg log entry, return it converted to a logging.LogRecord + instance. ''' + return logging.makeLogRecord( + dict( + levelno=logging._nameToLevel.get(log_data.get('levelname')), + created=log_data.get('time'), + msg=log_data.get('message'), + levelname=log_data.get('levelname'), + name=log_data.get('name'), + ) + ) + + +def log_line(last_lines, captured_output, line, default_log_level, came_from_stderr, borg_local_path, command): + ''' + Given a rolling list of last lines, a list of captured output, the line to be logged, a default + log level, whether the this log line came from stderr, the Borg local path, and the command as a + sequence, append the line to the last lines and (if the log level is None) the captured output. + Then log the line at the requested log level. + + If the command being run is Borg, and the log line is JSON-formatted log data, then grab the log + level from it and log the parsed JSON to be consumed later by a Python logging.Formatter. + + But for non-Borg commands, elevate stderr-sourced logs to ERROR. The one exception is if the log + came from stderr and the string "warning:" appears at the start of the log line. In that case, + just elevate the log level to a WARN. + ''' + log_message = line + log_level = default_log_level + line_data = None + if borg_local_path and command[0] == borg_local_path: - return output_log_level + with contextlib.suppress(json.JSONDecodeError, TypeError, KeyError): + line_data = json.loads(line) + borg_level_name = line_data['levelname'] + log_message = line_data['message'] + log_level = logging._nameToLevel.get(borg_level_name) + elif came_from_stderr: + log_level = logging.WARN if line.lower().startswith('warning:') else logging.ERROR - if came_from_stderr: - return logging.WARN if line.lower().startswith('warning:') else logging.ERROR - - return output_log_level - - -def append_last_lines(last_lines, captured_output, line, log_level): - ''' - Given a rolling list of last lines, a list of captured output, a line to append, and an output - log level, append the line to the last lines and (if necessary) the captured output. Then log - the line at the requested log level. - ''' - last_lines.append(line) + last_lines.append(log_message) if len(last_lines) > ERROR_OUTPUT_MAX_LINE_COUNT: last_lines.pop(0) if log_level is None: - captured_output.append(line) + captured_output.append(log_message) + return + + if line_data: + logger.handle(borg_log_data_to_log_record(line_data)) else: - logger.log(log_level, line) + logger.log(log_level, log_message) def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path, borg_exit_codes): # noqa: PLR0912 @@ -190,17 +210,14 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path, b # Keep the last few lines of output in case the process errors, and we need the # output for the exception below. - append_last_lines( - buffer_last_lines[ready_buffer], - captured_outputs[ready_process], - line, - determine_log_level( - output_log_level, - (ready_buffer == ready_process.stderr), - borg_local_path, - command, - line, - ), + log_line( + last_lines=buffer_last_lines[ready_buffer], + captured_output=captured_outputs[ready_process], + line=line, + default_log_level=output_log_level, + came_from_stderr=(ready_buffer == ready_process.stderr), + borg_local_path=borg_local_path, + command=command, ) if not still_running: @@ -231,17 +248,14 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path, b if not line: break - append_last_lines( - last_lines, - captured_outputs[process], - line, - determine_log_level( - output_log_level, - (output_buffer == process.stderr), - borg_local_path, - command, - line, - ), + log_line( + last_lines=last_lines, + captured_output=captured_outputs[process], + line=line, + default_log_level=output_log_level, + came_from_stderr=(output_buffer == process.stderr), + borg_local_path=borg_local_path, + command=command, ) if len(last_lines) == ERROR_OUTPUT_MAX_LINE_COUNT: diff --git a/borgmatic/logger.py b/borgmatic/logger.py index 9deee00e..2886c359 100644 --- a/borgmatic/logger.py +++ b/borgmatic/logger.py @@ -1,7 +1,9 @@ import enum +import json import logging import logging.handlers import os +import socket import sys @@ -85,6 +87,54 @@ class Multi_stream_handler(logging.Handler): handler.setLevel(level) +DEFAULT_JOURNALD_PRIORITY = 6 + + +class JournaldHandler(logging.Handler): + def __init__(self, journald_socket_path): + super().__init__() + + add_custom_log_levels() + + self.journald_socket_path = journald_socket_path + self.log_level_to_journald_priority = { + logging.ERROR: 3, + logging.WARNING: 4, + logging.ANSWER: 5, + logging.INFO: 6, + logging.DEBUG: 7, + } + + def emit(self, record): + sock = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) + + try: + message_parts = [] + entry = dict( + LOGGER_NAME=record.name, + MESSAGE=record.getMessage(), + PRIORITY=self.log_level_to_journald_priority.get(record.levelno, DEFAULT_JOURNALD_PRIORITY), + SYSLOG_IDENTIFIER='borgmatic', + SYSLOG_PID=os.getpid(), + UNIT=record.name, + ) + + for key, value in entry.items(): + key = key.upper().encode('utf-8') + value = str(value).encode('utf-8') + + # Multi-line and single-line values use different formats on the wire. + if b'\n' in value: + message_parts.extend((key, b'\n')) + message_parts.extend((len(value).to_bytes(8, 'little'), value, b'\n')) + else: + message_parts.extend((key, b'=', value, b'\n')) + + sock.sendto(b''.join(message_parts), self.journald_socket_path) + finally: + sock.close() + + class Log_prefix_formatter(logging.Formatter): def __init__(self, fmt='{prefix}{message}', *args, style='{', **kwargs): self.prefix = None @@ -97,6 +147,31 @@ class Log_prefix_formatter(logging.Formatter): return super().format(record) +def log_record_to_json(record, **extra): + ''' + Given a logging.LogRecord, return it as a JSON-encoded string containing relevant attributes. + Add in any extra kwargs that are given. + ''' + return json.dumps( + dict( + type='log_message', + time=record.created, + message=record.getMessage(), + levelname=record.levelname, + name=record.name, + **extra, + ) + ) + + +class Json_formatter(logging.Formatter): + def __init__(self, fmt='{message}', *args, style='{', **kwargs): + super().__init__(*args, fmt=fmt, style=style, **kwargs) + + def format(self, record): + return log_record_to_json(record) + + class Color(enum.Enum): RESET = 0 RED = 31 @@ -321,6 +396,10 @@ def flush_delayed_logging(target_handlers): root_logger.removeHandler(delayed_handler) +JOURNALD_SOCKET_PATH = '/run/systemd/journal/socket' +SYSLOG_PATHS = ('/dev/log', '/var/run/syslog', '/var/run/log') + + def configure_logging( console_log_level, syslog_log_level=None, @@ -328,6 +407,7 @@ def configure_logging( monitoring_log_level=None, log_file=None, log_file_format=None, + log_json=False, color_enabled=True, ): ''' @@ -364,7 +444,9 @@ def configure_logging( }, ) - if color_enabled: + if log_json: + console_handler.setFormatter(Json_formatter()) + elif color_enabled: console_handler.setFormatter(Console_color_formatter()) else: console_handler.setFormatter(Log_prefix_formatter()) @@ -373,28 +455,34 @@ def configure_logging( handlers = [console_handler] if syslog_log_level != logging.DISABLED: - syslog_path = None - - if os.path.exists('/dev/log'): - syslog_path = '/dev/log' - elif os.path.exists('/var/run/syslog'): - syslog_path = '/var/run/syslog' - elif os.path.exists('/var/run/log'): - syslog_path = '/var/run/log' - - if syslog_path: - syslog_handler = logging.handlers.SysLogHandler(address=syslog_path) - syslog_handler.setFormatter( - Log_prefix_formatter( - 'borgmatic: {levelname} {prefix}{message}', + if os.path.exists(JOURNALD_SOCKET_PATH): + journald_handler = JournaldHandler(JOURNALD_SOCKET_PATH) + journald_handler.setLevel(syslog_log_level) + handlers.append(journald_handler) + else: + syslog_path = next( + ( + path + for path in SYSLOG_PATHS + if os.path.exists(path) ), + None, ) - syslog_handler.setLevel(syslog_log_level) - handlers.append(syslog_handler) + + if syslog_path: + syslog_handler = logging.handlers.SysLogHandler(address=syslog_path) + syslog_handler.setFormatter( + Log_prefix_formatter( + 'borgmatic: {levelname} {prefix}{message}', + ), + ) + syslog_handler.setLevel(syslog_log_level) + handlers.append(syslog_handler) if log_file and log_file_log_level != logging.DISABLED: file_handler = logging.handlers.WatchedFileHandler(log_file) file_handler.setFormatter( + Json_formatter() if log_json else Log_prefix_formatter( log_file_format or '[{asctime}] {levelname}: {prefix}{message}', ),