diff --git a/Duplicati/Library/Interface/CustomExceptions.cs b/Duplicati/Library/Interface/CustomExceptions.cs index 1d0cde056..2e0c90262 100644 --- a/Duplicati/Library/Interface/CustomExceptions.cs +++ b/Duplicati/Library/Interface/CustomExceptions.cs @@ -139,5 +139,48 @@ namespace Duplicati.Library.Interface public CancelException(string message, Exception innerException) : base(message, "Cancelled", innerException) { } -} + } + + /// + /// The reason why an operation is aborted + /// + public enum OperationAbortReason + { + /// + /// The operation is aborted, but this is considered a normal operation + /// + Normal, + /// + /// The operation is aborted and this should give a warning + /// + Warning, + /// + /// The operation is aborted and this is an error + /// + Error + } + + /// + /// A class that signals the operation should be aborted + /// + [Serializable] + public class OperationAbortException : UserInformationException + { + /// + /// The reason for the abort operation + /// + public readonly OperationAbortReason AbortReason; + + public OperationAbortException(OperationAbortReason reason, string message) + : base(message, "OperationAborted") + { + AbortReason = reason; + } + + public OperationAbortException(OperationAbortReason reason, string message, Exception innerException) + : base(message, "OperationAborted", innerException) + { + AbortReason = reason; + } + } } diff --git a/Duplicati/Library/Main/Controller.cs b/Duplicati/Library/Main/Controller.cs index a71a3c8d0..b744259a8 100644 --- a/Duplicati/Library/Main/Controller.cs +++ b/Duplicati/Library/Main/Controller.cs @@ -430,14 +430,29 @@ namespace Duplicati.Library.Main { result.EndTime = DateTime.UtcNow; - try { (result as BasicResults).OperationProgressUpdater.UpdatePhase(OperationPhase.Error); } - catch { } + if (ex is Library.Interface.OperationAbortException oae) + { + // Perform the module shutdown + OnOperationComplete(ex); - OnOperationComplete(ex); + // Log this as a normal operation, as the script rasing the exception, + // has already populated either warning or log messages as required + Logging.Log.WriteInformationMessage(LOGTAG, "AbortOperation", "Aborting operation by request, requested result: {0}", oae.AbortReason); - Logging.Log.WriteErrorMessage(LOGTAG, "FailedOperation", ex, Strings.Controller.FailedOperationMessage(m_options.MainAction, ex.Message)); + return result; + } + else + { + try { (result as BasicResults).OperationProgressUpdater.UpdatePhase(OperationPhase.Error); } + catch { } + + OnOperationComplete(ex); + + Logging.Log.WriteErrorMessage(LOGTAG, "FailedOperation", ex, Strings.Controller.FailedOperationMessage(m_options.MainAction, ex.Message)); + + throw; + } - throw; } finally { diff --git a/Duplicati/Library/Modules/Builtin/RunScript.cs b/Duplicati/Library/Modules/Builtin/RunScript.cs index c1897639a..7ab0ffaf7 100644 --- a/Duplicati/Library/Modules/Builtin/RunScript.cs +++ b/Duplicati/Library/Modules/Builtin/RunScript.cs @@ -24,6 +24,7 @@ using Duplicati.Library.Utility; using Duplicati.Library.Interface; using System.Linq; using Duplicati.Library.Modules.Builtin.ResultSerialization; +using System.Threading.Tasks; namespace Duplicati.Library.Modules.Builtin { @@ -220,7 +221,7 @@ namespace Duplicati.Library.Modules.Builtin psi.EnvironmentVariables["DUPLICATI__REMOTEURL"] = remoteurl; if (level != null) psi.EnvironmentVariables["DUPLICATI__PARSED_RESULT"] = level.Value.ToString(); - + if (localpath != null) psi.EnvironmentVariables["DUPLICATI__LOCALPATH"] = string.Join(System.IO.Path.PathSeparator.ToString(), localpath); @@ -230,9 +231,9 @@ namespace Duplicati.Library.Modules.Builtin if (!string.IsNullOrEmpty(datafile)) psi.EnvironmentVariables["DUPLICATI__RESULTFILE"] = datafile; - using(System.Diagnostics.Process p = System.Diagnostics.Process.Start(psi)) + using (System.Diagnostics.Process p = System.Diagnostics.Process.Start(psi)) { - ConsoleDataHandler cs = new ConsoleDataHandler(p); + var cs = new ConsoleDataHandler(p); if (timeout <= 0) p.WaitForExit(); @@ -249,14 +250,57 @@ namespace Duplicati.Library.Modules.Builtin if (p.HasExited) { + cs.WaitForCompletion(); + stderr = cs.StandardError; stdout = cs.StandardOutput; if (p.ExitCode != 0) - Logging.Log.WriteWarningMessage(LOGTAG, "InvalidExitCode", null, Strings.RunScript.InvalidExitCodeError(scriptpath, p.ExitCode)); + { + if (!requiredScript) + { + // We log a warning or an error depending on the exit code + switch (p.ExitCode) + { + case 0: + case 1: + // No messages here + break; + + case 2: + case 3: + Logging.Log.WriteWarningMessage(LOGTAG, "InvalidExitCode", null, Strings.RunScript.ExitCodeError(scriptpath, p.ExitCode, stderr)); + stderr = null; + break; + + case 4: + case 5: + default: + Logging.Log.WriteErrorMessage(LOGTAG, "InvalidExitCode", null, Strings.RunScript.ExitCodeError(scriptpath, p.ExitCode, stderr)); + stderr = null; + break; + } + + // If this is the start event, we abort the backup + if (eventname == "BEFORE") + { + switch (p.ExitCode) + { + case 1: + throw new OperationAbortException(OperationAbortReason.Normal, Strings.RunScript.InvalidExitCodeError(scriptpath, p.ExitCode)); + case 3: + throw new OperationAbortException(OperationAbortReason.Warning, Strings.RunScript.InvalidExitCodeError(scriptpath, p.ExitCode)); + case 5: + throw new OperationAbortException(OperationAbortReason.Error, Strings.RunScript.InvalidExitCodeError(scriptpath, p.ExitCode)); + } + } + } + else + Logging.Log.WriteWarningMessage(LOGTAG, "InvalidExitCode", null, Strings.RunScript.InvalidExitCodeError(scriptpath, p.ExitCode)); + } } else { - Logging.Log.WriteWarningMessage(LOGTAG, "ScriptTimeout", null, Strings.RunScript.ScriptTimeoutError(scriptpath)); + Logging.Log.WriteWarningMessage(LOGTAG, "ScriptTimeout", null, Strings.RunScript.ScriptTimeoutError(scriptpath)); } } @@ -266,7 +310,7 @@ namespace Duplicati.Library.Modules.Builtin //We only allow setting parameters on startup if (eventname == "BEFORE" && stdout != null) { - foreach(string rawline in stdout.Split(new string[] { Environment.NewLine }, StringSplitOptions.RemoveEmptyEntries)) + foreach (string rawline in stdout.Split(new string[] { Environment.NewLine }, StringSplitOptions.RemoveEmptyEntries)) { string line = rawline.Trim(); if (!line.StartsWith("--", StringComparison.Ordinal)) @@ -303,7 +347,7 @@ namespace Duplicati.Library.Modules.Builtin localpath = value.Split(System.IO.Path.PathSeparator); } else if ( - string.Equals(key, "eventname", StringComparison.OrdinalIgnoreCase) || + string.Equals(key, "eventname", StringComparison.OrdinalIgnoreCase) || string.Equals(key, "operationname", StringComparison.OrdinalIgnoreCase) || string.Equals(key, "main-action", StringComparison.OrdinalIgnoreCase) || key == "" @@ -313,10 +357,14 @@ namespace Duplicati.Library.Modules.Builtin } else options[key] = value; - } } } + catch (OperationAbortException) + { + // Do not log this, it is already logged + throw; + } catch (Exception ex) { Logging.Log.WriteWarningMessage(LOGTAG, "ScriptExecuteError", ex, Strings.RunScript.ScriptExecuteError(scriptpath, ex.Message)); @@ -325,49 +373,29 @@ namespace Duplicati.Library.Modules.Builtin } } + /// + /// Helper class to extract output from the program + /// private class ConsoleDataHandler { public ConsoleDataHandler(System.Diagnostics.Process p) { - p.OutputDataReceived += new System.Diagnostics.DataReceivedEventHandler(HandleOutputDataReceived); - p.ErrorDataReceived += new System.Diagnostics.DataReceivedEventHandler(HandleErrorDataReceived); - - p.BeginErrorReadLine(); - p.BeginOutputReadLine(); + m_task = Task.WhenAll( + Task.Run(async () => StandardOutput = await p.StandardOutput.ReadToEndAsync()), + Task.Run(async () => StandardError = await p.StandardError.ReadToEndAsync()) + ); } - private readonly StringBuilder m_standardOutput = new StringBuilder(); - private readonly StringBuilder m_standardError = new StringBuilder(); - private readonly object m_lock = new object(); - - private void HandleOutputDataReceived (object sender, System.Diagnostics.DataReceivedEventArgs e) + private readonly Task m_task; + public string StandardOutput { get; private set; } + public string StandardError { get; private set; } + public void WaitForCompletion() { - lock(m_lock) - m_standardOutput.AppendLine(e.Data); - } - - private void HandleErrorDataReceived (object sender, System.Diagnostics.DataReceivedEventArgs e) - { - lock(m_lock) - m_standardError.AppendLine(e.Data); - } - - public string StandardOutput - { - get - { - lock(m_lock) - return m_standardOutput.ToString().Trim(); - } - } - - public string StandardError - { - get - { - lock(m_lock) - return m_standardError.ToString().Trim(); - } + // NOTE: This is ugly, but there is a race where "HasExited" is set, + // but the stdout/stderr streams have not yet completed. + // If we wait a little here, we eventually get the data. + // If the streams have completed we do not wait. + m_task.Wait(TimeSpan.FromSeconds(5)); } } } diff --git a/Duplicati/Library/Modules/Builtin/Strings.cs b/Duplicati/Library/Modules/Builtin/Strings.cs index bc8852354..78946a4e0 100644 --- a/Duplicati/Library/Modules/Builtin/Strings.cs +++ b/Duplicati/Library/Modules/Builtin/Strings.cs @@ -54,6 +54,7 @@ namespace Duplicati.Library.Modules.Builtin.Strings { public static string FinishoptionLong { get { return LC.L(@"Executes a script after performing an operation. The script will receive the operation results written to stdout."); } } public static string FinishoptionShort { get { return LC.L(@"Run a script on exit"); } } public static string InvalidExitCodeError(string script, int exitcode) { return LC.L(@"The script ""{0}"" returned with exit code {1}", script, exitcode); } + public static string ExitCodeError(string script, int exitcode, string message) { return LC.L(@"The script ""{0}"" returned with exit code {1}{2}", script, exitcode, string.IsNullOrWhiteSpace(message) ? string.Empty : string.Format(": {0}", message)); } public static string RequiredoptionLong { get { return LC.L(@"Executes a script before performing an operation. The operation will block until the script has completed or timed out. If the script returns a non-zero error code or times out, the operation will be aborted."); } } public static string RequiredoptionShort { get { return LC.L(@"Run a required script on startup"); } } public static string ResultFormatShort { get { return LC.L(@"Selects the output format for results"); } } diff --git a/Duplicati/Library/Modules/Builtin/run-script-example.bat b/Duplicati/Library/Modules/Builtin/run-script-example.bat index 123c1bbe9..8ea3fd418 100644 --- a/Duplicati/Library/Modules/Builtin/run-script-example.bat +++ b/Duplicati/Library/Modules/Builtin/run-script-example.bat @@ -16,6 +16,15 @@ REM --run-script-before = REM Duplicati will run the script before the backup job and waits for its REM completion for 60 seconds (default timeout value). After a timeout a REM warning is logged and the backup is started. +REM The following exit codes are supported: +REM +REM - 0: OK, run operation +REM - 1: OK, don't run operation +REM - 2: Warning, run operation +REM - 3: Warning, don't run operation +REM - 4: Error, run operation +REM - 5: Error don't run operation +REM - other: Error don't run operation REM REM --run-script-before-required = REM Duplicati will run the script before the backup job and wait for its @@ -32,6 +41,10 @@ REM --run-script-after = REM Duplicati will run the script after the backup job and wait for its REM completion for 60 seconds (default timeout value). After a timeout a REM warning is logged. +REM The same exit codes as in --run-script-before are supported, but +REM the operation will always continue (i.e. 1 => 0, 3 => 2, 5 => 4) +REM as it has already completed so stopping it during stop is useless. + REM ############################################################################### diff --git a/Duplicati/Library/Modules/Builtin/run-script-example.sh b/Duplicati/Library/Modules/Builtin/run-script-example.sh index 150ac0d61..973dd96f4 100644 --- a/Duplicati/Library/Modules/Builtin/run-script-example.sh +++ b/Duplicati/Library/Modules/Builtin/run-script-example.sh @@ -16,6 +16,15 @@ # Duplicati will run the script before the backup job and waits for its # completion for 60 seconds (default timeout value). After a timeout a # warning is logged and the backup is started. +# The following exit codes are supported: +# +# - 0: OK, run operation +# - 1: OK, don't run operation +# - 2: Warning, run operation +# - 3: Warning, don't run operation +# - 4: Error, run operation +# - 5: Error don't run operation +# - other: Error don't run operation # # --run-script-before-required = # Duplicati will run the script before the backup job and wait for its @@ -32,6 +41,9 @@ # Duplicati will run the script after the backup job and wait for its # completion for 60 seconds (default timeout value). After a timeout a # warning is logged. +# The same exit codes as in --run-script-before are supported, but +# the operation will always continue (i.e. 1 => 0, 3 => 2, 5 => 4) +# as it has already completed so stopping it during stop is useless. ############################################################################### diff --git a/Duplicati/UnitTest/Duplicati.UnitTest.csproj b/Duplicati/UnitTest/Duplicati.UnitTest.csproj index 8ac832014..936e556f0 100644 --- a/Duplicati/UnitTest/Duplicati.UnitTest.csproj +++ b/Duplicati/UnitTest/Duplicati.UnitTest.csproj @@ -52,6 +52,7 @@ + diff --git a/Duplicati/UnitTest/RunScriptTests.cs b/Duplicati/UnitTest/RunScriptTests.cs new file mode 100644 index 000000000..28b39a91d --- /dev/null +++ b/Duplicati/UnitTest/RunScriptTests.cs @@ -0,0 +1,200 @@ +// Copyright (C) 2018, The Duplicati Team +// http://www.duplicati.com, info@duplicati.com +// +// This library is free software; you can redistribute it and/or modify +// it under the terms of the GNU Lesser General Public License as +// published by the Free Software Foundation; either version 2.1 of the +// License, or (at your option) any later version. +// +// This library is distributed in the hope that it will be useful, but +// WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +// Lesser General Public License for more details. +// +// You should have received a copy of the GNU Lesser General Public +// License along with this library; if not, write to the Free Software +// Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA +using System; +using System.Collections.Generic; +using System.IO; +using System.Linq; +using Duplicati.Library.Interface; +using NUnit.Framework; + +namespace Duplicati.UnitTest +{ + public class RunScriptTests : BasicSetupHelper + { + public override void PrepareSourceData() + { + base.PrepareSourceData(); + + Directory.CreateDirectory(DATAFOLDER); + Directory.CreateDirectory(TARGETFOLDER); + } + + [Test] + [Category("Border")] + public void RunScriptBefore() + { + PrepareSourceData(); + + var blocksize = 10 * 1024; + var options = TestOptions; + options["blocksize"] = blocksize.ToString() + "b"; + options["run-script-timeout"] = "5s"; + + // We need a small delay as we run very small backups back-to-back + var PAUSE_TIME = TimeSpan.FromSeconds(3); + + BorderTests.WriteTestFilesToFolder(DATAFOLDER, blocksize, 0); + + using (var c = new Library.Main.Controller("file://" + TARGETFOLDER, options, null)) + { + var res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Success) + throw new Exception("Unexpected result from base backup"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(0); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Success) + throw new Exception("Unexpected result from backup with return code 0"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did not examine any files for code 0?"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(1); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Success) + throw new Exception("Unexpected result from backup with return code 1"); + if (res.ExaminedFiles > 0) + throw new Exception("Backup did examine files for code 1?"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(2); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Warning) + throw new Exception("Unexpected result from backup with return code 2"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did not examine any files for code 2?"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(3); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Warning) + throw new Exception("Unexpected result from backup with return code 3"); + if (res.ExaminedFiles > 0) + throw new Exception("Backup did examine files for code 3?"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(4); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Error) + throw new Exception("Unexpected result from backup with return code 4"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did not examine any files for code 4?"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(5); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Error) + throw new Exception("Unexpected result from backup with return code 5"); + if (res.ExaminedFiles > 0) + throw new Exception("Backup did examine files for code 5?"); + + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(2, "TEST WARNING MESSAGE"); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Warning) + throw new Exception("Unexpected result from backup with return code 2"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did examine files for code 2?"); + if (!res.Warnings.Any(x => x.IndexOf("TEST WARNING MESSAGE", StringComparison.Ordinal) >= 0)) + throw new Exception("Found no warning message in output for code 2"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(3, "TEST WARNING MESSAGE"); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Warning) + throw new Exception("Unexpected result from backup with return code 3"); + if (res.ExaminedFiles > 0) + throw new Exception("Backup did examine files for code 3?"); + if (!res.Warnings.Any(x => x.IndexOf("TEST WARNING MESSAGE", StringComparison.Ordinal) >= 0)) + throw new Exception("Found no warning message in output for code 3"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(4, "TEST ERROR MESSAGE"); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Error) + throw new Exception("Unexpected result from backup with return code 4"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did examine files for code 4?"); + if (!res.Errors.Any(x => x.IndexOf("TEST ERROR MESSAGE", StringComparison.Ordinal) >= 0)) + throw new Exception("Found no error message in output for code 4"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(5, "TEST ERROR MESSAGE"); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Error) + throw new Exception("Unexpected result from backup with return code 5"); + if (res.ExaminedFiles > 0) + throw new Exception("Backup did examine files for code 5?"); + if (!res.Errors.Any(x => x.IndexOf("TEST ERROR MESSAGE", StringComparison.Ordinal) >= 0)) + throw new Exception("Found no error message in output for code 5"); + + System.Threading.Thread.Sleep(PAUSE_TIME); + options["run-script-before"] = CreateScript(0, sleeptime: 10); + res = c.Backup(new string[] { DATAFOLDER }); + if (res.ParsedResult != ParsedResultType.Warning) + throw new Exception("Unexpected result from backup with timeout script"); + if (res.ExaminedFiles <= 0) + throw new Exception("Backup did not examine any files after timeout?"); + } + } + + + private string CreateScript(int exitcode, string stderr = null, string stdout = null, int sleeptime = 0) + { + var id = Guid.NewGuid().ToString("N").Substring(0, 6); + if (Library.Utility.Utility.IsClientWindows) + { + var commands = new List(); + if (!string.IsNullOrWhiteSpace(stdout)) + commands.Add($@"echo {stdout}"); + if (!string.IsNullOrWhiteSpace(stderr)) + commands.Add($@"echo {stderr} 1>&2"); + if (sleeptime > 0) + commands.Add($@"sleep {sleeptime}"); + + commands.Add($"exit {exitcode}"); + + var filename = Path.GetFullPath(Path.Combine(DATAFOLDER, $"run-script-{id}.bat")); + File.WriteAllLines(filename, commands); + + return filename; + } + else + { + var commands = new List(); + commands.Add("#!/bin/sh"); + + if (!string.IsNullOrWhiteSpace(stdout)) + commands.Add($@"echo {stdout}"); + if (!string.IsNullOrWhiteSpace(stderr)) + commands.Add($@"(>&2 echo {stderr})"); + if (sleeptime > 0) + commands.Add($@"sleep {sleeptime}"); + + commands.Add($"exit {exitcode}"); + var filename = Path.GetFullPath(Path.Combine(DATAFOLDER, $"run-script-{id}.sh")); + File.WriteAllLines(filename, commands); + + System.Diagnostics.Process.Start("chmod", $@"+x ""{filename}""").WaitForExit(); + + return filename; + } + } + } +}