Fix traceback with "create" action and "--json" flag when a database hook is configured (#563).

This commit is contained in:
Dan Helfman 2022-07-19 10:25:10 -07:00
parent e85d551eac
commit 16066942e3
4 changed files with 71 additions and 9 deletions

1
NEWS
View file

@ -3,6 +3,7 @@
* #560: Fix all database hooks to error when the requested database to restore isn't present in the * #560: Fix all database hooks to error when the requested database to restore isn't present in the
Borg archive. Borg archive.
* #561: Fix command-line "--override" flag to continue supporting old configuration file formats. * #561: Fix command-line "--override" flag to continue supporting old configuration file formats.
* #563: Fix traceback with "create" action and "--json" flag when a database hook is configured.
1.6.5 1.6.5
* #553: Fix logging to include the full traceback when Borg experiences an internal error, not just * #553: Fix logging to include the full traceback when Borg experiences an internal error, not just

View file

@ -51,6 +51,9 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
process with the requested log level. Additionally, raise a CalledProcessError if a process process with the requested log level. Additionally, raise a CalledProcessError if a process
exits with an error (or a warning for exit code 1, if that process matches the Borg local path). exits with an error (or a warning for exit code 1, if that process matches the Borg local path).
If output log level is None, then instead of logging, capture output for each process and return
it as a dict from the process to its output.
For simplicity, it's assumed that the output buffer for each process is its stdout. But if any For simplicity, it's assumed that the output buffer for each process is its stdout. But if any
stdouts are given to exclude, then for any matching processes, log from their stderr instead. stdouts are given to exclude, then for any matching processes, log from their stderr instead.
@ -65,6 +68,7 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
if process.stdout or process.stderr if process.stdout or process.stderr
} }
output_buffers = list(process_for_output_buffer.keys()) output_buffers = list(process_for_output_buffer.keys())
captured_outputs = collections.defaultdict(list)
# Log output for each process until they all exit. # Log output for each process until they all exit.
while True: while True:
@ -99,7 +103,10 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
if len(last_lines) > ERROR_OUTPUT_MAX_LINE_COUNT: if len(last_lines) > ERROR_OUTPUT_MAX_LINE_COUNT:
last_lines.pop(0) last_lines.pop(0)
logger.log(output_log_level, line) if output_log_level is None:
captured_outputs[ready_process].append(line)
else:
logger.log(output_log_level, line)
still_running = False still_running = False
@ -133,6 +140,11 @@ def log_outputs(processes, exclude_stdouts, output_log_level, borg_local_path):
if not still_running: if not still_running:
break break
if captured_outputs:
return {
process: '\n'.join(output_lines) for process, output_lines in captured_outputs.items()
}
def log_command(full_command, input_file, output_file): def log_command(full_command, input_file, output_file):
''' '''
@ -222,13 +234,14 @@ def execute_command_with_processes(
run as well. This is useful, for instance, for processes that are streaming output to a named run as well. This is useful, for instance, for processes that are streaming output to a named
pipe that the given command is consuming from. pipe that the given command is consuming from.
If an open output file object is given, then write stdout to the file and only log stderr (but If an open output file object is given, then write stdout to the file and only log stderr. But
only if an output log level is set). If an open input file object is given, then read stdin from if output log level is None, instead suppress logging and return the captured output for (only)
the file. If shell is True, execute the command within a shell. If an extra environment dict is the given command. If an open input file object is given, then read stdin from the file. If
given, then use it to augment the current environment, and pass the result into the command. If shell is True, execute the command within a shell. If an extra environment dict is given, then
a working directory is given, use that as the present working directory when running the use it to augment the current environment, and pass the result into the command. If a working
command. If a Borg local path is given, then for any matching command or process (regardless of directory is given, use that as the present working directory when running the command. If a
arguments), treat exit code 1 as a warning instead of an error. Borg local path is given, then for any matching command or process (regardless of arguments),
treat exit code 1 as a warning instead of an error.
Raise subprocesses.CalledProcessError if an error occurs while running the command or in the Raise subprocesses.CalledProcessError if an error occurs while running the command or in the
upstream process. upstream process.
@ -259,9 +272,12 @@ def execute_command_with_processes(
process.kill() process.kill()
raise raise
log_outputs( captured_outputs = log_outputs(
tuple(processes) + (command_process,), tuple(processes) + (command_process,),
(input_file, output_file), (input_file, output_file),
output_log_level, output_log_level,
borg_local_path=borg_local_path, borg_local_path=borg_local_path,
) )
if output_log_level is None:
return captured_outputs.get(command_process)

View file

@ -54,6 +54,30 @@ def test_log_outputs_skips_logs_for_process_with_none_stdout():
) )
def test_log_outputs_returns_output_without_logging_for_output_log_level_none():
flexmock(module.logger).should_receive('log').never()
flexmock(module).should_receive('exit_code_indicates_error').and_return(False)
hi_process = subprocess.Popen(['echo', 'hi'], stdout=subprocess.PIPE)
flexmock(module).should_receive('output_buffer_for_process').with_args(
hi_process, ()
).and_return(hi_process.stdout)
there_process = subprocess.Popen(['echo', 'there'], stdout=subprocess.PIPE)
flexmock(module).should_receive('output_buffer_for_process').with_args(
there_process, ()
).and_return(there_process.stdout)
captured_outputs = module.log_outputs(
(hi_process, there_process),
exclude_stdouts=(),
output_log_level=None,
borg_local_path='borg',
)
assert captured_outputs == {hi_process: 'hi', there_process: 'there'}
def test_log_outputs_includes_error_output_in_exception(): def test_log_outputs_includes_error_output_in_exception():
flexmock(module.logger).should_receive('log') flexmock(module.logger).should_receive('log')
flexmock(module).should_receive('exit_code_indicates_error').and_return(True) flexmock(module).should_receive('exit_code_indicates_error').and_return(True)

View file

@ -289,6 +289,27 @@ def test_execute_command_with_processes_calls_full_command():
assert output is None assert output is None
def test_execute_command_with_processes_returns_output_with_output_log_level_none():
full_command = ['foo', 'bar']
processes = (flexmock(),)
flexmock(module.os, environ={'a': 'b'})
process = flexmock(stdout=None)
flexmock(module.subprocess).should_receive('Popen').with_args(
full_command,
stdin=None,
stdout=module.subprocess.PIPE,
stderr=module.subprocess.STDOUT,
shell=False,
env=None,
cwd=None,
).and_return(process).once()
flexmock(module).should_receive('log_outputs').and_return({process: 'out'})
output = module.execute_command_with_processes(full_command, processes, output_log_level=None)
assert output == 'out'
def test_execute_command_with_processes_calls_full_command_with_output_file(): def test_execute_command_with_processes_calls_full_command_with_output_file():
full_command = ['foo', 'bar'] full_command = ['foo', 'bar']
processes = (flexmock(),) processes = (flexmock(),)