From 90595e9c184973f429a4a0f030f981985fc7299b Mon Sep 17 00:00:00 2001 From: Dan Helfman Date: Thu, 27 Jun 2019 14:41:21 -0700 Subject: [PATCH] Only log to syslog when run from a non-interactive console (e.g. a cron job). Related to #197. --- NEWS | 3 +- borgmatic/commands/arguments.py | 2 +- borgmatic/logger.py | 12 ++++- docs/how-to/inspect-your-backups.md | 7 +-- .../run-preparation-steps-before-backups.md | 4 +- setup.py | 2 +- tests/unit/test_logger.py | 46 +++++++++++++++++-- 7 files changed, 62 insertions(+), 14 deletions(-) diff --git a/NEWS b/NEWS index 90a84241..a925a2b7 100644 --- a/NEWS +++ b/NEWS @@ -1,4 +1,5 @@ -1.3.12.dev0 +1.3.12 + * Only log to syslog when run from a non-interactive console (e.g. a cron job). * Remove unicode byte order mark from syslog output so it doesn't show up as a literal in rsyslog output. See discussion on #197. diff --git a/borgmatic/commands/arguments.py b/borgmatic/commands/arguments.py index 3f11cf02..0171a95b 100644 --- a/borgmatic/commands/arguments.py +++ b/borgmatic/commands/arguments.py @@ -108,7 +108,7 @@ def parse_arguments(*unparsed_arguments): type=int, choices=range(0, 3), default=0, - help='Display verbose progress to syslog (from none to lots: 0, 1, or 2)', + help='Display verbose progress to syslog (from none to lots: 0, 1, or 2). Ignored when console is interactive', ) global_group.add_argument( '--version', diff --git a/borgmatic/logger.py b/borgmatic/logger.py index 8c704786..7bbb912b 100644 --- a/borgmatic/logger.py +++ b/borgmatic/logger.py @@ -21,6 +21,14 @@ def to_bool(arg): return False +def interactive_console(): + ''' + Return whether the current console is "interactive". Meaning: Capable of + user input and not just something like a cron job. + ''' + return sys.stdout.isatty() and os.environ.get('TERM') != 'dumb' + + def should_do_markup(no_color, configs): ''' Given the value of the command-line no-color argument, and a dict of configuration filename to @@ -37,7 +45,7 @@ def should_do_markup(no_color, configs): if py_colors is not None: return to_bool(py_colors) - return sys.stdout.isatty() and os.environ.get('TERM') != 'dumb' + return interactive_console() LOG_LEVEL_TO_COLOR = { @@ -82,7 +90,7 @@ def configure_logging(console_log_level, syslog_log_level=None): elif os.path.exists('/var/run/syslog'): syslog_path = '/var/run/syslog' - if syslog_path: + if syslog_path and not interactive_console(): syslog_handler = logging.handlers.SysLogHandler(address=syslog_path) syslog_handler.setFormatter(logging.Formatter('borgmatic: %(levelname)s %(message)s')) syslog_handler.setLevel(syslog_log_level) diff --git a/docs/how-to/inspect-your-backups.md b/docs/how-to/inspect-your-backups.md index fe32ce7c..27b571f2 100644 --- a/docs/how-to/inspect-your-backups.md +++ b/docs/how-to/inspect-your-backups.md @@ -39,9 +39,10 @@ borgmatic info ## Logging By default, borgmatic logs to a local syslog-compatible daemon if one is -present. Where those logs show up depends on your particular system. If you're -using systemd, try running `journalctl -xe`. Otherwise, try viewing -`/var/log/syslog` or similiar. +present and borgmatic is running in a non-interactive console. Where those +logs show up depends on your particular system. If you're using systemd, try +running `journalctl -xe`. Otherwise, try viewing `/var/log/syslog` or +similiar. You can customize the log level used for syslog logging with the `--syslog-verbosity` flag, and this is independent from the console logging diff --git a/docs/how-to/run-preparation-steps-before-backups.md b/docs/how-to/run-preparation-steps-before-backups.md index 76757fb3..5497403a 100644 --- a/docs/how-to/run-preparation-steps-before-backups.md +++ b/docs/how-to/run-preparation-steps-before-backups.md @@ -38,8 +38,8 @@ hooks: ## Hook output -Any output produced by your hooks shows up both at the console and in syslog. -For more information, read about inspecting your backups. diff --git a/setup.py b/setup.py index e15a7453..394e8411 100644 --- a/setup.py +++ b/setup.py @@ -1,6 +1,6 @@ from setuptools import find_packages, setup -VERSION = '1.3.12.dev0' +VERSION = '1.3.12' setup( diff --git a/tests/unit/test_logger.py b/tests/unit/test_logger.py index 866a7cc1..5cec8767 100644 --- a/tests/unit/test_logger.py +++ b/tests/unit/test_logger.py @@ -20,6 +20,29 @@ def test_to_bool_passes_none_through(): assert module.to_bool(None) is None +def test_interactive_console_false_when_not_isatty(capsys): + with capsys.disabled(): + flexmock(module.sys.stdout).should_receive('isatty').and_return(False) + + assert module.interactive_console() is False + + +def test_interactive_console_false_when_TERM_is_dumb(capsys): + with capsys.disabled(): + flexmock(module.sys.stdout).should_receive('isatty').and_return(True) + flexmock(module.os.environ).should_receive('get').with_args('TERM').and_return('dumb') + + assert module.interactive_console() is False + + +def test_interactive_console_true_when_isatty_and_TERM_is_not_dumb(capsys): + with capsys.disabled(): + flexmock(module.sys.stdout).should_receive('isatty').and_return(True) + flexmock(module.os.environ).should_receive('get').with_args('TERM').and_return('smart') + + assert module.interactive_console() is True + + def test_should_do_markup_respects_no_color_value(): assert module.should_do_markup(no_color=True, configs={}) is False @@ -75,15 +98,17 @@ def test_should_do_markup_prefers_no_color_value_to_PY_COLORS(): assert module.should_do_markup(no_color=True, configs={}) is False -def test_should_do_markup_respects_stdout_tty_value(): +def test_should_do_markup_respects_interactive_console_value(): flexmock(module.os.environ).should_receive('get').and_return(None) + flexmock(module).should_receive('interactive_console').and_return(True) - assert module.should_do_markup(no_color=False, configs={}) is False + assert module.should_do_markup(no_color=False, configs={}) is True -def test_should_do_markup_prefers_PY_COLORS_to_stdout_tty_value(): +def test_should_do_markup_prefers_PY_COLORS_to_interactive_console_value(): flexmock(module.os.environ).should_receive('get').and_return('True') flexmock(module).should_receive('to_bool').and_return(True) + flexmock(module).should_receive('interactive_console').and_return(False) assert module.should_do_markup(no_color=False, configs={}) is True @@ -108,11 +133,11 @@ def test_color_text_without_color_does_not_raise(): def test_configure_logging_probes_for_log_socket_on_linux(): flexmock(module).should_receive('Console_color_formatter') + 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').with_args('/dev/log').and_return(True) - flexmock(module.os.path).should_receive('exists').with_args('/var/run/syslog').and_return(False) syslog_handler = logging.handlers.SysLogHandler() flexmock(module.logging.handlers).should_receive('SysLogHandler').with_args( address='/dev/log' @@ -123,6 +148,7 @@ def test_configure_logging_probes_for_log_socket_on_linux(): def test_configure_logging_probes_for_log_socket_on_macos(): flexmock(module).should_receive('Console_color_formatter') + flexmock(module).should_receive('interactive_console').and_return(False) flexmock(module.logging).should_receive('basicConfig').with_args( level=logging.INFO, handlers=tuple ) @@ -155,3 +181,15 @@ def test_configure_logging_skips_syslog_if_not_found(): flexmock(module.logging.handlers).should_receive('SysLogHandler').never() module.configure_logging(console_log_level=logging.INFO) + + +def test_configure_logging_skips_syslog_if_interactive_console(): + flexmock(module).should_receive('Console_color_formatter') + flexmock(module).should_receive('interactive_console').and_return(True) + 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)