RoboSharp icon indicating copy to clipboard operation
RoboSharp copied to clipboard

#195 add exception boundary for Exited event handler

Open zabulus opened this issue 11 months ago • 13 comments

zabulus avatar Mar 22 '24 19:03 zabulus

While I'm not disagreeing that the fix is required or not, you are the only person to report such an issue. Provide additional details on when/how the exception is occurring, and under what conditions it occurs. In your Issue #195 you wrote that there was a null reference exception, what is null ?

Operating System, Target Framework (.netstandard, .net8, etc), RoboSharp Version, etc

RFBomb avatar Mar 22 '24 19:03 RFBomb

Sure, I've just got another dump from the same place, but now with another exception: Windows 10 (1809) netfw 4.8 robosharp 1.2.8 stack:

   KERNELBASE.dll!RaiseException()
   [Managed to Native Transition]	
   at System.Diagnostics.Process.EnsureState(State state)
   at System.Diagnostics.Process.EnsureState(State state)
   at System.Diagnostics.Process.GetProcessHandle(Int32 access, Boolean throwIfExited)
   at System.Diagnostics.Process.WaitForExit(Int32 milliseconds)
   at RoboSharp.RoboCommand.<>c__DisplayClass105_1.<GetRoboCopyTask>b__2(Object sender, EventArgs args)
   at System.Diagnostics.Process.OnExited()
   at System.Diagnostics.Process.RaiseOnExited()

InvalidOperationException, No process is associated with this object. Would be also appreciate for any clues that could pinpoint the cause. It looks like that robocopy process crashes (?) somewhere during it's work.

zabulus avatar Mar 25 '24 11:03 zabulus

Do you get the same issues / crashed on a version of Windows 10 which is not 6 years out of date (build 1809 was released on November 13th 2018). Only asking as like @RFBomb I use this regularly on multiple computers and haven't yet had the issue you are reporting.

PCAssistSoftware avatar Mar 25 '24 11:03 PCAssistSoftware

It is the only case with such crash I'm aware of.

zabulus avatar Mar 25 '24 11:03 zabulus

That RoboSharp package (1.2.8) is 9 months old. I'm wondering if newer versions resolved this, as some tweaks were made.

Your PR suggests writing the handling to the debugger. When subscribing to it, what message is generated when the error occurs?

Does it occur reliably? What command switches are used?

RFBomb avatar Mar 25 '24 12:03 RFBomb

We use it in two scenarios: deletion of files and copying files. Options for robocomand:

                mirrorFiles.OnCommandError += MirrorFiles_OnCommandError;
                mirrorFiles.OnError += MirrorFiles_OnError;
                mirrorFiles.CopyOptions.Source = sourcePath;
                mirrorFiles.CopyOptions.Destination = destinationPath;
                mirrorFiles.CopyOptions.Mirror = true;
                mirrorFiles.CopyOptions.EnableRestartModeWithBackupFallback = true; // absent for cleanup
                mirrorFiles.LoggingOptions.NoProgress = true;
                mirrorFiles.LoggingOptions.NoFileList = true;
                mirrorFiles.LoggingOptions.NoDirectoryList = true;
                mirrorFiles.CopyOptions.MultiThreadedCopiesCount = 128;
                mirrorFiles.RetryOptions.WaitForSharenames = true;
                mirrorFiles.RetryOptions.RetryCount = 5;
                mirrorFiles.RetryOptions.RetryWaitTime = 5;
                mirrorFiles.SelectionOptions.UseFatFileTimes = true; // absent for cleanup

in this case destinationPath is a shared folder path with integrated security access. and sourcePath is an temp empty folder, so this is "file deletion" case.

zabulus avatar Mar 25 '24 12:03 zabulus

@zabulus Thats a bit of an odd way to use RoboSharp, when you could use DirectoryInfo.Delete(true).

I wrote the following test using your command options, and was unable to reproduce the fail in question. It runs without issues.

[TestMethod]
        public async Task TestMirror()
        {
            Test_Setup.ClearOutTestDestination();
            // Mirror
            var cmd = Test_Setup.GenerateCommand(true, false);
            cmd.CopyOptions.Mirror = true;
            var dest = new DirectoryInfo(cmd.CopyOptions.Destination);
            Assert.IsFalse(dest.Exists, "\n\nDestination Exists prior to test");
            await cmd.StartAsync();
            Assert.IsTrue(dest.EnumerateFiles().Any(), "\n\nAssertion: Files were not copied");
            Assert.IsTrue(dest.EnumerateDirectories().Any(), "\n\nAssertion: Directories were not copied");

            // Deletion
            string emptyDir = Path.Combine(Path.GetDirectoryName(cmd.CopyOptions.Destination), Path.GetRandomFileName().Replace(".", ""));
            
            try
            {
                Directory.CreateDirectory(emptyDir);
                Assert.IsFalse(Directory.EnumerateFiles(emptyDir).Any(), "\n\nAssertion: Random Empty Directory had files!\nDirectory: " + emptyDir);
                var mirrorFiles = new RoboCommand(emptyDir, cmd.CopyOptions.Destination);
                mirrorFiles.Configuration = cmd.Configuration;

                // Options from #203
                mirrorFiles.CopyOptions.Mirror = true;
                //mirrorFiles.CopyOptions.EnableRestartModeWithBackupFallback = true; // Enabling this causes  command to fail! - this is likely because no files are being copied
                mirrorFiles.LoggingOptions.NoProgress = true;
                mirrorFiles.LoggingOptions.NoFileList = true;
                mirrorFiles.LoggingOptions.NoDirectoryList = true;
                mirrorFiles.CopyOptions.MultiThreadedCopiesCount = 128;
                mirrorFiles.RetryOptions.WaitForSharenames = true;
                mirrorFiles.RetryOptions.RetryCount = 5;
                mirrorFiles.RetryOptions.RetryWaitTime = 5;
                mirrorFiles.SelectionOptions.UseFatFileTimes = true; // absent for cleanup


                var deletionResult = await mirrorFiles.StartAsync();
                Console.WriteLine("\n\n ---------- Deletion Result Log ------");
                deletionResult.LogLines.ToList().ForEach(Console.WriteLine);
                Assert.IsFalse(dest.EnumerateFileSystemInfos().Any(), "\n\nAssertion: Destination still children were not deleted");
            }
            finally
            {
                if (Directory.Exists(emptyDir))
                    Directory.Delete(emptyDir);
            }
        }

Note that enabling /ZB does cause the command to fail in my unit test. RoboCopy runs, but doesn't delete the files in the destination.

-------------------------------------------------------------------------------
   ROBOCOPY     ::     Robust File Copy for Windows                              
-------------------------------------------------------------------------------

  Started : Monday, March 25, 2024 1:35:02 PM
   Source : C:\Repos\RoboSharp\RoboSharpUnitTesting\bin\Debug\net472\TEST_FILES\lgku23o5n1g\
     Dest : C:\Repos\RoboSharp\RoboSharpUnitTesting\bin\Debug\net472\TEST_FILES\DESTINATION\

    Files : *.*
	    
  Options : *.* /TBD /FFT /BYTES /NDL /NFL /S /E /DCOPY:DA /COPY:DAT /PURGE /MIR /ZB /NP /MT:128 /R:5 /W:5 

------------------------------------------------------------------------------

ERROR : You do not have the Backup and Restore Files user rights.
*****  You need these to perform Backup copies (/B or /ZB).

ERROR : Robocopy ran out of memory, exiting.
ERROR : Invalid Parameter #%d : "%s"

ERROR : Invalid Job File, Line #%d :"%s"


  Started : %s %s

   Source %c 

     Dest %c 
       Simple Usage :: ROBOCOPY source destination /MIR

             source :: Source Directory (drive:\path or \\server\share\path).
        destination :: Destination Dir  (drive:\path or \\server\share\path).
               /MIR :: Mirror a complete directory tree.

    For more usage information run ROBOCOPY /?

                                                          
****  /MIR can DELETE files as well as copy them !

RFBomb avatar Mar 25 '24 17:03 RFBomb

when you could use DirectoryInfo.Delete(true).

For network shares robocopy works little better, because multithreading.

EnableRestartModeWithBackupFallback is not used for folder deletion

zabulus avatar Mar 26 '24 11:03 zabulus

So the command then completes a unit test without failure. So under what scenario is it failing for you?

Is your application closing while the command is still running? Is the network connection being severed/interrupted? OR is robocopy running on a remote computer? I could see the last one being the issue, as it specifically calls this out in the Process page in the ms docs.

@PCAssistSoftware can you provide me with 'Maintainer' status, which should give me access to pushing a commit to this PR.

RFBomb avatar Mar 27 '24 16:03 RFBomb

@PCAssistSoftware can you provide me with 'Maintainer' status, which should give me access to pushing a commit to this PR.

Sorry but I don't have required permissions to do that

PCAssistSoftware avatar Mar 27 '24 16:03 PCAssistSoftware

Is your application closing while the command is still running?

App crashes on this exception. It's long-running service, and we don't see any signs of graceful service stopping in logs.

Is the network connection being severed/interrupted?

That's my guess, as before the crash, we observed timeouts during robocopy work, which should not occur if there are no problems. I'd like to provide more details, but I have only logs and the crash dump.

OR is robocopy running on a remote computer?

Not sure I understood the question. Robocopy runs locally but mirrors empty local folder to shared folder.

zabulus avatar Mar 27 '24 17:03 zabulus

The reason I was asking is because :

https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit?view=net-8.0#system-diagnostics-process-waitforexit

No process [Id](https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.id?view=net-8.0#system-diagnostics-process-id) has been set, and a [Handle](https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.handle?view=net-8.0#system-diagnostics-process-handle) from which the [Id](https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.id?view=net-8.0#system-diagnostics-process-id) property can be determined does not exist.

-or-

There is no process associated with this [Process](https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process?view=net-8.0) object.

-or-

You are attempting to call [WaitForExit()](https://learn.microsoft.com/en-us/dotnet/api/system.diagnostics.process.waitforexit?view=net-8.0#system-diagnostics-process-waitforexit) for a process that is running on a remote computer. This method is available only for processes that are running on the local computer.

I don't see how it could be scenario 1 or 2 without encountering an error well before the Exited event triggers.

RFBomb avatar Mar 27 '24 17:03 RFBomb

@zabulus I agree that this likely needs the change you proposed. I have reworked it into #204. Please download and test using that PR in your application that this issue occurs in, and let us know if it is resolved.

RFBomb avatar Mar 27 '24 18:03 RFBomb

Implemented via #204

PCAssistSoftware avatar Apr 26 '24 10:04 PCAssistSoftware