tag:help.appveyor.com,2012-11-13:/discussions/problems/31621-robocopy-does-not-report-errors-when-run-on-appveyorAppVeyor: Discussion 2022-03-10T01:46:47Ztag:help.appveyor.com,2012-11-13:Comment/505672122022-03-09T18:23:35Z2022-03-09T18:23:35ZRobocopy does not report errors when run on AppVeyor<div><p>Hi Rob,</p>
<p>The process of collecting output from the process programmatically is different from that in Windows console. You collect the output using <a href="https://github.com/PCAssistSoftware/RoboSharp/blob/dev/RoboSharp/RoboCommand.cs#L508-L509">event handlers</a> of <code>Process</code> class. It is triggered on a new line only. AppVeyor uses the same approach, but it constantly reads an output stream. So, there could be some quirks with double redirect, like buffering issues. It's hard to tell you what's wrong and where without digging into your code. Maybe you can do a simple repro, like a small console program or test with Process class calling some robocopy command and catching the output.</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/505672122022-03-09T18:57:19Z2022-03-09T18:57:22ZRobocopy does not report errors when run on AppVeyor<div><p>So that is where it gets odd though. The entire log being written into the test results is captured using the same event.</p>
<p>We subscribe to the process events, start the process, wait for it to exit. As the process outputs the data, it gets added to a list object.</p>
<p>That list is then written into the test log at the end with a ForEach—loop.</p>
<p>The log is identical between local and AppVeyor, other than the fact that robocopy is not outputting the error lines in the AppVeyor log. That is the actual issue, since the project relies on all items being written to the log.</p>
<p>So AppVeyor is doing it’s job fine, no arguments here. The issue is whatever executable of robocopy AppVeyor has is not writing errors into its std:out.</p>
<p>I’m on mobile, so can’t copy-paste the log here, but it’s available in the link and in the AppVeyor logs, which were also linked (atleast in the GHC thread)</p></div>Rob tag:help.appveyor.com,2012-11-13:Comment/505672122022-03-09T20:33:02Z2022-03-09T20:33:02ZRobocopy does not report errors when run on AppVeyor<div><p>OK, can you give me a sample of robocopy command, its expected output and actual output on AppVeyor?</p></div>Feodor Fitsnertag:help.appveyor.com,2012-11-13:Comment/505672122022-03-10T01:46:46Z2022-03-10T01:46:47ZRobocopy does not report errors when run on AppVeyor<div><p>I would've replied hours ago, but I couldn't get appveyor to build my test repo that displays the issue. Turns out VS was not providing a reference in the CSProj file to a nuget package that was being downloaded....But now that its working, I can reply:</p>
<p>The issue at hand is that RoboCopy wasn't generating an error in its std:out, sometimes?</p>
<p>Here is the link to the new repo that I finally got working that displays the issue:<br>
<a href="https://github.com/RFBomb/RoboCopyErrorTesting/tree/master/RoboCopyUnitTest">https://github.com/RFBomb/RoboCopyErrorTesting/tree/master/RoboCopy...</a></p>
<p>In it I have two tests. Everything related to robocopy is run identical, the only thing that changes is the source folder as far as robocopy is concerned.</p>
<p>here are the test results, not sure if you can see them.<br>
<a href="https://ci.appveyor.com/project/RFBomb/robocopyerrortesting/build/tests">https://ci.appveyor.com/project/RFBomb/robocopyerrortesting/build/t...</a></p>
<p>RoboCopy Command:<br></p>
<pre>
<code>robocopy "C:\SomeSourceThatDoesNotExist" "C:\DestDoesNotMatter" /V /R:0 /W:10</code>
</pre>
Expected Output:
<pre>
<code>-------------------------------------------------------------------------------
// Header omitted for brevity
------------------------------------------------------------------------------
2022/03/09 20:32:00 ERROR 2 (0x00000002) Accessing Source Directory C:\SourceDirDoesNotExist\
The system cannot find the file specified.</code>
</pre>
<p>According to my repo, the test above works fine.</p>
<p>The test we have in our other repo though is simulating a file that is locked by another process. That test fails due to no error being reported.</p>
<p>Same RoboCommand, except have it point at a valid source and destination.<br>
Use File.Open() to lock a file, run robocopy, unlock the file, print results.</p>
<p>Expected Results:</p>
<pre>
<code>Running the Test
- Creating Destination Directory
- Locking File Path: C:\DEST\1024_Bytes.txt
Setting Up RoboCopy Process
- RoboCopy Executable Path: Robocopy.exe
- Starting RoboCopy Process
- RoboCopy Process has Exited
- Unlocking the Locked file path.
- No Error Data Received from Process (via Process.ErrorDataReceived)
- Writing Log Lines:
-------------------------------------------------------------------------------
Options : *.* /V /S /COPY:DAT /R:0 /W:3
------------------------------------------------------------------------------
4 C:\RoboCopyValidation\RoboCopyErrorTesting\RoboCopyUnitTest\bin\Debug\SourceFiles\
New File 0 0_Bytes.txt
100%
Older 1024 1024_Bytes.txt
2022/03/09 20:37:59 ERROR 32 (0x00000020) Copying File C:\RoboCopyValidation\RoboCopyErrorTesting\RoboCopyUnitTest\bin\Debug\SourceFiles\1024_Bytes.txt
The process cannot access the file because it is being used by another process.
New File 4 4_Bytes.htm
0%
100%
------------------------------------------------------------------------------
Total Copied Skipped Mismatch FAILED Extras
Dirs : 2 1 1 0 0 0
Files : 8 7 0 0 1 0
Bytes : 2.0 k 1.0 k 0 0 1.0 k 0
Times : 0:00:00 0:00:00 0:00:00 0:00:00
Speed : 37142 Bytes/sec.
Speed : 2.125 MegaBytes/min.
Ended : Wed Mar 09 20:37:59 2022</code>
</pre>
<p>Appveyor Results:</p>
<pre>
<code>- Creating Destination Directory
- Locking File Path: C:\DEST\1024_Bytes.txt
Setting Up RoboCopy Process
- RoboCopy Executable Path: Robocopy.exe
- Starting RoboCopy Process
- RoboCopy Process has Exited
- Unlocking the Locked file path.
- Assertion Failed: No Error reported in the log.
- No Error Data Received from Process (via Process.ErrorDataReceived)
- Writing Log Lines:
-------------------------------------------------------------------------------
Options : *.* /V /S /DCOPY:DA /COPY:DAT /R:0 /W:3
------------------------------------------------------------------------------
4 C:\projects\robocopyerrortesting\RoboCopyUnitTest\bin\Debug\SourceFiles\
New File 0 0_Bytes.txt
Older 1015 1024_Bytes.txt
New File 4 4_Bytes.htm
100%
------------------------------------------------------------------------------
Total Copied Skipped Mismatch FAILED Extras
Dirs : 2 1 1 0 0 0
Files : 8 7 0 0 1 0
Bytes : 1.9 k 1.0 k 0 0 1015 0
Times : 0:00:00 0:00:00 0:00:00 0:00:00
Ended : Thursday, March 10, 2022 1:25:26 AM</code>
</pre>
<p>I've condensed both logs for brevity, showing only the files immediately before and after the expected error. The file marked as 'older' is the file that is locked and unable to be written to by robocopy. As you can see, the error is reported locally, but not on appveyor.<br>
Since the source not existing test reported an error, I have no idea what the issue could be.</p></div>Rob