Add option to disable syslog output #675

Merged
witten merged 11 commits from Soumik_Dutta/borgmatic:feat484-option-to-disable-syslog into main 2023-05-30 20:03:57 +00:00
8 changed files with 78 additions and 19 deletions

View File

@ -152,30 +152,30 @@ def make_parsers():
'-v', '-v',
'--verbosity', '--verbosity',
type=int, type=int,
choices=range(-1, 3), choices=range(-2, 3),
default=0, default=0,
help='Display verbose progress to the console (from only errors to very verbose: -1, 0, 1, or 2)', help='Display verbose progress to the console (disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2)',
Soumik_Dutta marked this conversation as resolved Outdated

At this point, it might be clearer to change this help to something like:

Display verbose progress to the console (disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2)

Or even something like:

Display verbose progress to the console at the requested level: -2 (disabled), -1 (errors only), 0 (default), 1 (some), or 2 (lots)

At this point, it might be clearer to change this help to something like: `Display verbose progress to the console (disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2)` Or even something like: `Display verbose progress to the console at the requested level: -2 (disabled), -1 (errors only), 0 (default), 1 (some), or 2 (lots)`

Maybe remove "from" here and in the other helps, as it's no longer "from"/"to".

Maybe remove "from" here and in the other helps, as it's no longer "from"/"to".
) )
global_group.add_argument( global_group.add_argument(
'--syslog-verbosity', '--syslog-verbosity',
type=int, type=int,
choices=range(-1, 3), choices=range(-2, 3),
Soumik_Dutta marked this conversation as resolved Outdated

For consistency, it would be good to add -2 support to the other verbosity flags as well. (Let me know if you disagree.)

For consistency, it would be good to add `-2` support to the other verbosity flags as well. (Let me know if you disagree.)

I was not sure initially about the scope of adding another global verbosity level so I tried to minimize the affected code.

Though I agree that it will be good for consistency and I am working on it. Otherwise we will have to document around this.

I was not sure initially about the scope of adding another global verbosity level so I tried to minimize the affected code. Though I agree that it will be good for consistency and I am working on it. Otherwise we will have to document around this.

I'll admit I haven't thought through the scope implications, so if it grows too large, please let me know!

I'll admit I haven't thought through the scope implications, so if it grows too large, please let me know!
default=0, default=0,
help='Log verbose progress to syslog (from only errors to very verbose: -1, 0, 1, or 2). Ignored when console is interactive or --log-file is given', help='Log verbose progress to syslog (disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2). Ignored when console is interactive or --log-file is given',
) )
global_group.add_argument( global_group.add_argument(
'--log-file-verbosity', '--log-file-verbosity',
type=int, type=int,
choices=range(-1, 3), choices=range(-2, 3),
default=0, default=0,
help='Log verbose progress to log file (from only errors to very verbose: -1, 0, 1, or 2). Only used when --log-file is given', help='Log verbose progress to log file (disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2). Only used when --log-file is given',
) )
global_group.add_argument( global_group.add_argument(
'--monitoring-verbosity', '--monitoring-verbosity',
type=int, type=int,
choices=range(-1, 3), choices=range(-2, 3),
default=0, default=0,
help='Log verbose progress to monitoring integrations that support logging (from only errors to very verbose: -1, 0, 1, or 2)', help='Log verbose progress to monitoring integrations that support logging (from disabled, errors only, default, some, or lots: -2, -1, 0, 1, or 2)',
) )
global_group.add_argument( global_group.add_argument(
'--log-file', '--log-file',

View File

@ -36,7 +36,7 @@ from borgmatic.borg import version as borg_version
from borgmatic.commands.arguments import parse_arguments from borgmatic.commands.arguments import parse_arguments
from borgmatic.config import checks, collect, convert, validate from borgmatic.config import checks, collect, convert, validate
from borgmatic.hooks import command, dispatch, monitor from borgmatic.hooks import command, dispatch, monitor
from borgmatic.logger import add_custom_log_levels, configure_logging, should_do_markup from borgmatic.logger import add_custom_log_levels, configure_logging, should_do_markup, DISABLED
from borgmatic.signals import configure_signals from borgmatic.signals import configure_signals
from borgmatic.verbosity import verbosity_to_log_level from borgmatic.verbosity import verbosity_to_log_level
@ -70,6 +70,7 @@ def run_configuration(config_filename, config, arguments):
error_repository = '' error_repository = ''
using_primary_action = {'create', 'prune', 'compact', 'check'}.intersection(arguments) using_primary_action = {'create', 'prune', 'compact', 'check'}.intersection(arguments)
monitoring_log_level = verbosity_to_log_level(global_arguments.monitoring_verbosity) monitoring_log_level = verbosity_to_log_level(global_arguments.monitoring_verbosity)
monitoring_hooks_are_activated = using_primary_action and monitoring_log_level != DISABLED
try: try:
local_borg_version = borg_version.local_borg_version(storage, local_path) local_borg_version = borg_version.local_borg_version(storage, local_path)
@ -78,7 +79,7 @@ def run_configuration(config_filename, config, arguments):
return return
try: try:
if using_primary_action: if monitoring_hooks_are_activated:
dispatch.call_hooks( dispatch.call_hooks(
'initialize_monitor', 'initialize_monitor',
hooks, hooks,
@ -87,7 +88,7 @@ def run_configuration(config_filename, config, arguments):
monitoring_log_level, monitoring_log_level,
global_arguments.dry_run, global_arguments.dry_run,
) )
if using_primary_action:
dispatch.call_hooks( dispatch.call_hooks(
'ping_monitor', 'ping_monitor',
hooks, hooks,
@ -165,7 +166,7 @@ def run_configuration(config_filename, config, arguments):
error_repository = repository['path'] error_repository = repository['path']
try: try:
if using_primary_action: if monitoring_hooks_are_activated:
# send logs irrespective of error # send logs irrespective of error
dispatch.call_hooks( dispatch.call_hooks(
'ping_monitor', 'ping_monitor',
@ -185,7 +186,7 @@ def run_configuration(config_filename, config, arguments):
if not encountered_error: if not encountered_error:
try: try:
if using_primary_action: if monitoring_hooks_are_activated:
dispatch.call_hooks( dispatch.call_hooks(
'ping_monitor', 'ping_monitor',
hooks, hooks,

View File

@ -141,6 +141,7 @@ def add_logging_level(level_name, level_number):
ANSWER = logging.WARN - 5 ANSWER = logging.WARN - 5
DISABLED = logging.CRITICAL + 10
Soumik_Dutta marked this conversation as resolved Outdated

Ah, yes. This makes sense to me.

Ah, yes. This makes sense to me.

Makes sense!

Makes sense!
def add_custom_log_levels(): # pragma: no cover def add_custom_log_levels(): # pragma: no cover
@ -148,6 +149,7 @@ def add_custom_log_levels(): # pragma: no cover
Add a custom log level between WARN and INFO for user-requested answers. Add a custom log level between WARN and INFO for user-requested answers.
''' '''
add_logging_level('ANSWER', ANSWER) add_logging_level('ANSWER', ANSWER)
add_logging_level('DISABLED', DISABLED)
def configure_logging( def configure_logging(
@ -175,10 +177,12 @@ def configure_logging(
# Log certain log levels to console stderr and others to stdout. This supports use cases like # Log certain log levels to console stderr and others to stdout. This supports use cases like
# grepping (non-error) output. # grepping (non-error) output.
console_disabled = logging.NullHandler()
console_error_handler = logging.StreamHandler(sys.stderr) console_error_handler = logging.StreamHandler(sys.stderr)
console_standard_handler = logging.StreamHandler(sys.stdout) console_standard_handler = logging.StreamHandler(sys.stdout)
console_handler = Multi_stream_handler( console_handler = Multi_stream_handler(
{ {
logging.DISABLED: console_disabled,
logging.CRITICAL: console_error_handler, logging.CRITICAL: console_error_handler,
logging.ERROR: console_error_handler, logging.ERROR: console_error_handler,
logging.WARN: console_error_handler, logging.WARN: console_error_handler,
@ -191,7 +195,7 @@ def configure_logging(
console_handler.setLevel(console_log_level) console_handler.setLevel(console_log_level)
Soumik_Dutta marked this conversation as resolved Outdated

Would it be possible to add a test for this logic? See tests/unit/test_logger.py for the existing tests for this function.

Would it be possible to add a test for this logic? See `tests/unit/test_logger.py` for the existing tests for this function.
syslog_path = None syslog_path = None
if log_file is None: if log_file is None and syslog_log_level != logging.DISABLED:
Soumik_Dutta marked this conversation as resolved Outdated

Based on these changes, the tests in tests/unit/test_logger.py should probably be updated / added to as well.

Based on these changes, the tests in `tests/unit/test_logger.py` should probably be updated / added to as well.
if os.path.exists('/dev/log'): if os.path.exists('/dev/log'):
syslog_path = '/dev/log' syslog_path = '/dev/log'
elif os.path.exists('/var/run/syslog'): elif os.path.exists('/var/run/syslog'):
@ -206,7 +210,7 @@ def configure_logging(
) )
syslog_handler.setLevel(syslog_log_level) syslog_handler.setLevel(syslog_log_level)
handlers = (console_handler, syslog_handler) handlers = (console_handler, syslog_handler)
elif log_file: elif log_file and log_file_log_level != logging.DISABLED:
file_handler = logging.handlers.WatchedFileHandler(log_file) file_handler = logging.handlers.WatchedFileHandler(log_file)
file_handler.setFormatter( file_handler.setFormatter(
logging.Formatter( logging.Formatter(

View File

@ -2,6 +2,7 @@ import logging
import borgmatic.logger import borgmatic.logger
VERBOSITY_DISABLED = -2
VERBOSITY_ERROR = -1 VERBOSITY_ERROR = -1
VERBOSITY_ANSWER = 0 VERBOSITY_ANSWER = 0
VERBOSITY_SOME = 1 VERBOSITY_SOME = 1
@ -15,6 +16,7 @@ def verbosity_to_log_level(verbosity):
borgmatic.logger.add_custom_log_levels() borgmatic.logger.add_custom_log_levels()
return { return {
VERBOSITY_DISABLED: logging.DISABLED,
VERBOSITY_ERROR: logging.ERROR, VERBOSITY_ERROR: logging.ERROR,
VERBOSITY_ANSWER: logging.ANSWER, VERBOSITY_ANSWER: logging.ANSWER,
VERBOSITY_SOME: logging.INFO, VERBOSITY_SOME: logging.INFO,

View File

@ -61,4 +61,4 @@ LogRateLimitIntervalSec=0
# Delay start to prevent backups running during boot. Note that systemd-inhibit requires dbus and # Delay start to prevent backups running during boot. Note that systemd-inhibit requires dbus and
# dbus-user-session to be installed. # dbus-user-session to be installed.
ExecStartPre=sleep 1m ExecStartPre=sleep 1m
ExecStart=systemd-inhibit --who="borgmatic" --what="sleep:shutdown" --why="Prevent interrupting scheduled backup" /root/.local/bin/borgmatic --verbosity -1 --syslog-verbosity 1 ExecStart=systemd-inhibit --who="borgmatic" --what="sleep:shutdown" --why="Prevent interrupting scheduled backup" /root/.local/bin/borgmatic --verbosity -2 --syslog-verbosity 1

I'd actually recommend swapping this default: Set --verbosity to -2 (which would require adding support for that), and --syslog-verbosity to 1. My rationale is that --verbosity/stdout doesn't log the log level, which --syslog-verbosity does. See the "Actual behavior" in #484 for examples of each.

I'd actually recommend swapping this default: Set `--verbosity` to `-2` (which would require adding support for that), and `--syslog-verbosity` to 1. My rationale is that `--verbosity`/stdout doesn't log the log level, which `--syslog-verbosity` does. See the "Actual behavior" in [#484](https://projects.torsion.org/borgmatic-collective/borgmatic/issues/484) for examples of each.

Yes I agree, adding verbosity level -2 will be better. It is better to show log level (as done by syslog) in output instead of indicating the log level by its colour (from console_logs) to stdout.

Yes I agree, adding verbosity level `-2` will be better. It is better to show log level (as done by `syslog`) in output instead of indicating the log level by its colour (from `console_logs`) to `stdout`.

View File

@ -169,6 +169,19 @@ def test_run_configuration_bails_for_monitor_finish_soft_failure():
assert results == [] assert results == []
def test_run_configuration_does_not_call_monitoring_hooks_if_monitoring_hooks_are_disabled():
flexmock(module).should_receive('verbosity_to_log_level').and_return(module.DISABLED)
flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
flexmock(module.dispatch).should_receive('call_hooks').never()
flexmock(module).should_receive('run_actions').and_return([])
Soumik_Dutta marked this conversation as resolved
Review

This line is duplicative of the earlier call two lines up. The first one is sufficient to assert that call_hooks() is never called.

This line is duplicative of the earlier call two lines up. The first one is sufficient to assert that `call_hooks()` is never called.
config = {'location': {'repositories': [{'path': 'foo'}]}}
arguments = {'global': flexmock(monitoring_verbosity=-2, dry_run=False), 'create': flexmock()}
results = list(module.run_configuration('test.yaml', config, arguments))
assert results == []
def test_run_configuration_logs_on_error_hook_error(): def test_run_configuration_logs_on_error_hook_error():
flexmock(module).should_receive('verbosity_to_log_level').and_return(logging.INFO) flexmock(module).should_receive('verbosity_to_log_level').and_return(logging.INFO)
flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock()) flexmock(module.borg_version).should_receive('local_borg_version').and_return(flexmock())
@ -229,8 +242,7 @@ def test_run_configuration_retries_hard_error():
).and_return([flexmock()]) ).and_return([flexmock()])
error_logs = [flexmock()] error_logs = [flexmock()]
flexmock(module).should_receive('log_error_records').with_args( flexmock(module).should_receive('log_error_records').with_args(
'foo: Error running actions for repository', 'foo: Error running actions for repository', OSError,
OSError,
).and_return(error_logs) ).and_return(error_logs)
config = {'location': {'repositories': [{'path': 'foo'}]}, 'storage': {'retries': 1}} config = {'location': {'repositories': [{'path': 'foo'}]}, 'storage': {'retries': 1}}
arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()} arguments = {'global': flexmock(monitoring_verbosity=1, dry_run=False), 'create': flexmock()}

View File

@ -285,6 +285,44 @@ def test_configure_logging_skips_syslog_if_interactive_console():
module.configure_logging(console_log_level=logging.INFO) module.configure_logging(console_log_level=logging.INFO)
def test_configure_logging_skips_syslog_if_syslog_logging_is_disabled():
flexmock(module).should_receive('add_custom_log_levels')
flexmock(module.logging).DISABLED = module.DISABLED
flexmock(module).should_receive('Multi_stream_handler').and_return(
flexmock(setFormatter=lambda formatter: None, setLevel=lambda level: None)
)
flexmock(module).should_receive('Console_color_formatter')
flexmock(module).should_receive('interactive_console').never()
flexmock(module.logging).should_receive('basicConfig').with_args(
level=logging.INFO, handlers=tuple
)
flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True)
flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
module.configure_logging(console_log_level=logging.INFO, syslog_log_level=logging.DISABLED)
def test_configure_logging_skips_log_file_if_log_file_logging_is_disabled():
flexmock(module).should_receive('add_custom_log_levels')
flexmock(module.logging).DISABLED = module.DISABLED
flexmock(module).should_receive('Multi_stream_handler').and_return(
flexmock(setFormatter=lambda formatter: None, setLevel=lambda level: None)
)
# syslog skipped in non-interactive console if --log-file argument provided
flexmock(module).should_receive('interactive_console').and_return(False)
flexmock(module.logging).should_receive('basicConfig').with_args(
level=logging.INFO, handlers=tuple
)
flexmock(module.os.path).should_receive('exists').never()
flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
flexmock(module.logging.handlers).should_receive('WatchedFileHandler').never()
module.configure_logging(
console_log_level=logging.INFO, log_file_log_level=logging.DISABLED, log_file='/tmp/logfile'
)
def test_configure_logging_to_log_file_instead_of_syslog(): def test_configure_logging_to_log_file_instead_of_syslog():
flexmock(module).should_receive('add_custom_log_levels') flexmock(module).should_receive('add_custom_log_levels')
flexmock(module.logging).ANSWER = module.ANSWER flexmock(module.logging).ANSWER = module.ANSWER
@ -297,7 +335,7 @@ def test_configure_logging_to_log_file_instead_of_syslog():
flexmock(module.logging).should_receive('basicConfig').with_args( flexmock(module.logging).should_receive('basicConfig').with_args(
level=logging.DEBUG, handlers=tuple level=logging.DEBUG, handlers=tuple
) )
flexmock(module.os.path).should_receive('exists').with_args('/dev/log').and_return(True) flexmock(module.os.path).should_receive('exists').never()
flexmock(module.logging.handlers).should_receive('SysLogHandler').never() flexmock(module.logging.handlers).should_receive('SysLogHandler').never()
file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile') file_handler = logging.handlers.WatchedFileHandler('/tmp/logfile')
flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args( flexmock(module.logging.handlers).should_receive('WatchedFileHandler').with_args(

View File

@ -17,11 +17,13 @@ def insert_logging_mock(log_level):
def test_verbosity_to_log_level_maps_known_verbosity_to_log_level(): def test_verbosity_to_log_level_maps_known_verbosity_to_log_level():
flexmock(module.borgmatic.logger).should_receive('add_custom_log_levels') flexmock(module.borgmatic.logger).should_receive('add_custom_log_levels')
flexmock(module.logging).ANSWER = module.borgmatic.logger.ANSWER flexmock(module.logging).ANSWER = module.borgmatic.logger.ANSWER
flexmock(module.logging).DISABLED = module.borgmatic.logger.DISABLED
assert module.verbosity_to_log_level(module.VERBOSITY_ERROR) == logging.ERROR assert module.verbosity_to_log_level(module.VERBOSITY_ERROR) == logging.ERROR
assert module.verbosity_to_log_level(module.VERBOSITY_ANSWER) == module.borgmatic.logger.ANSWER assert module.verbosity_to_log_level(module.VERBOSITY_ANSWER) == module.borgmatic.logger.ANSWER
assert module.verbosity_to_log_level(module.VERBOSITY_SOME) == logging.INFO assert module.verbosity_to_log_level(module.VERBOSITY_SOME) == logging.INFO
assert module.verbosity_to_log_level(module.VERBOSITY_LOTS) == logging.DEBUG assert module.verbosity_to_log_level(module.VERBOSITY_LOTS) == logging.DEBUG
assert module.verbosity_to_log_level(module.VERBOSITY_DISABLED) == logging.DISABLED
def test_verbosity_to_log_level_maps_unknown_verbosity_to_warning_level(): def test_verbosity_to_log_level_maps_unknown_verbosity_to_warning_level():