Log mysqldump output to console #396

New Issue

TCr · 2021-03-10T20:05:42Z

TCr commented

2021-03-10 20:05:42 +00:00

It would be nice to have mysqldump output logged to console - I mean the err output not std. This is used when we add --verbose to options field.

This can help to better debug mysqldump state.

It would be nice to have mysqldump output logged to console - I mean the err output not std. This is used when we add `--verbose` to options field. This can help to better debug mysqldump state.

TCr commented

2021-03-11 08:26:48 +00:00

I tested to modifie execute.py (because of Bug witten/borgmatic#397) and I see output from borg - but not from mysqldump... very stange...

--- ./execute.py.orig   2021-03-11 07:58:35.078802218 +0100
+++ ./execute.py        2021-03-11 09:17:48.181554561 +0100
@@ -199,6 +199,9 @@
         (process,), (input_file, output_file), output_log_level, borg_local_path=borg_local_path
     )
 
+def log_stderr_output(full_command, pipe):
+    for line in iter(pipe.readline, b''): #NOTE: workaround read-ahead bug
+        logging.debug('stderr from {0} is: {1}'.format(full_command[0], line))
 
 def execute_command_with_processes(
     full_command,
@@ -238,13 +241,14 @@
             command,
             stdin=input_file,
             stdout=None if do_not_capture else (output_file or subprocess.PIPE),
-            stderr=None
-            if do_not_capture
-            else (subprocess.PIPE if output_file else subprocess.STDOUT),
+            stderr=subprocess.PIPE,
             shell=shell,
             env=environment,
             cwd=working_directory,
         )
+        with command_process.stderr:
+            log_stderr_output(full_command, command_process.stderr)
+
     except (subprocess.CalledProcessError, OSError):
         # Something has gone wrong. So vent each process' output buffer to prevent it from hanging.
         # And then kill the process.

I tested to modifie execute.py (because of Bug https://projects.torsion.org/witten/borgmatic/issues/397) and I see output from borg - but not from mysqldump... very stange... ``` --- ./execute.py.orig 2021-03-11 07:58:35.078802218 +0100 +++ ./execute.py 2021-03-11 09:17:48.181554561 +0100 @@ -199,6 +199,9 @@ (process,), (input_file, output_file), output_log_level, borg_local_path=borg_local_path ) +def log_stderr_output(full_command, pipe): + for line in iter(pipe.readline, b''): #NOTE: workaround read-ahead bug + logging.debug('stderr from {0} is: {1}'.format(full_command[0], line)) def execute_command_with_processes( full_command, @@ -238,13 +241,14 @@ command, stdin=input_file, stdout=None if do_not_capture else (output_file or subprocess.PIPE), - stderr=None - if do_not_capture - else (subprocess.PIPE if output_file else subprocess.STDOUT), + stderr=subprocess.PIPE, shell=shell, env=environment, cwd=working_directory, ) + with command_process.stderr: + log_stderr_output(full_command, command_process.stderr) + except (subprocess.CalledProcessError, OSError): # Something has gone wrong. So vent each process' output buffer to prevent it from hanging. # And then kill the process. ```

TCr commented

2021-03-11 08:29:05 +00:00

if I execute mysqldump ---myparams --verbose >/tmp/dump_out 2>/tmp/dump_err the file dump_err contains all the steps mysqldump has done.

if I execute `mysqldump ---myparams --verbose >/tmp/dump_out 2>/tmp/dump_err` the file dump_err contains all the steps mysqldump has done.

witten commented

2023-03-27 06:16:27 +00:00

I apologize for the super lengthy delay in getting to this. I agree that it'd make sense for mysqldump command error output to get logged by borgmatic. The main use case I can see is that when borgmatic runs mysqldump and it blows up, you want to dig into what went wrong!

I have a fix in hand that I need to do a little more testing on, and then it'll be ready for release.

Related: #485.

I apologize for the super lengthy delay in getting to this. I agree that it'd make sense for `mysqldump` command error output to get logged by borgmatic. The main use case I can see is that when borgmatic runs `mysqldump` and it blows up, you want to dig into what went wrong! I have a fix in hand that I need to do a little more testing on, and then it'll be ready for release. Related: #485.

witten referenced this issue from a commit

2023-03-27 17:36:54 +00:00

When a database command errors, display and log the error message instead of swallowing it (#396).

witten commented

2023-03-27 17:37:25 +00:00

Okay, this is fixed in master now and will be part of the next release. Thanks for reporting it!

🚀 1

witten closed this issue

2023-03-27 17:37:25 +00:00

witten commented

2023-03-27 23:22:44 +00:00

Released in borgmatic 1.7.10!