SonarScanner.MSBuild.exe failed with return code: 3762504530

[Jody Lester]

Hi there,

We've been using SonarQube for a little while now and have started receiving exceptions in our builds today when the "Run Code Analysis" step executes during the build of our applications through TFS (Visual Studio Online) with our local build agents.

The "Prepare analysis on SonarQube" completes fine.  However, when analysis begins, we see the following in the TFS logs:

Calling the SonarQube Scanner...

2018-03-20T10:33:02.7688842Z 

2018-03-20T10:33:02.8313758Z Unhandled Exception: System.ComponentModel.Win32Exception: Access is denied

2018-03-20T10:33:02.8313758Z    at System.Diagnostics.Process.StartWithCreateProcess(ProcessStartInfo startInfo)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Common.ProcessRunner.Execute(ProcessRunnerArguments runnerArgs)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.ExecuteJavaRunner(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String exeFileName, String propertiesFileName)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.InternalExecute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String fullPropertiesFilePath)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.<>c__DisplayClass6_0.<Execute>b__0()

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.Execute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.InvokeSonarScanner(IAnalysisPropertyProvider cmdLineArgs, AnalysisConfig config)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.Execute(String[] args, AnalysisConfig config, ITeamBuildSettings settings)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.BootstrapperClass.PostProcess()

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.BootstrapperClass.Execute()

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Program.Execute(String[] args, ILogger logger)

2018-03-20T10:33:02.8313758Z    at SonarScanner.MSBuild.Program.Main(String[] args)

2018-03-20T10:33:02.8626073Z ##[error]C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe failed with return code: 3762504530

2018-03-20T10:33:02.8782485Z ##[section]Finishing: Run Code Analysis

What's interesting is that the only change I can identify is that the scanner has updated from 4.0.0 to 4.1.0 (File and product version 4.1.0.1148).

It also appears that, in 4.0.0 we used

  \4.0.0\sonar-scanner-msbuild\SonarQube.Scanner.MSBuild.exe

but in 4.1.0 it's now using 

  \4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe.

Many thanks,

[valeri....@sonarsource.com]

It seems that the Scanner for MSBuild process cannot execute the Scanner CLI for some reason. I would check machine event log to see the corresponding entry, it should tell what's the reason for the failure. Most probably the build user cannot read or has no execute permissions for the files in the subfolders of "\4.1.0\classic-sonar-scanner-msbuild"...

Kind regards,

Valeri

[Jody Lester]

Hi Valeri,

That's strange.  It was working the day before when it was using version 4.0.0.  We have the build agent running as local admin, which I assume is the context TFS uses when running the SonarQube analysis build tasks on our build server.  I wouldn't expect it to be a genuine access denied in this case?

Could it be that the process is trying to launch a directory path, rather than a file path?  I think launching a process using a directory as parameter can also cause an access denied.  The event viewer just shows an unhandled exception being captured in the event log.

Can anyone provide what process is being started (e.g. startup info) so I can double check the target location exists?

Many thanks,

[valeri....@sonarsource.com]

The scanner is executing "sonar-scanner{fileExtension}" from "{binFolder}\sonar-scanner-{version}\bin\". {binFolder} is the directory where the scanner assemblies are installed, {fileExtension} depends on the OS on the machine. If the OS is not System.PlatformID.Win32NT, {fileExtension} will be string.Empty and that could be the problem. What OS are you having on the build machine?

Version 4.1 is a pretty big change, we removed the dependency on Mono when running on Linux/OSX (the same assemblies) and it is possible there is a bug in the OS detection...

Kind regards,

Valeri

[Jody Lester]

Hi Valeri,

The OS is Windows Server 2012 R2.

Looking at the "Prepare Analysis on SonarQube" step log I can see it's launching SonarScanner.MSBuild.exe ok:

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe

SonarScanner for MSBuild 4.1

2018-03-20T12:01:20.4676612Z Using the .NET Framework version of the Scanner for MSBuild

2018-03-20T12:01:20.5927623Z Default properties file was found at C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarQube.Analysis.xml

2018-03-20T12:01:20.5927623Z Loading analysis properties from C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarQube.Analysis.xml

2018-03-20T12:01:20.5927623Z Pre-processing started.

2018-03-20T12:01:20.6082835Z Preparing working directories...

On the end step, I can see from the logs:

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe failed with return code: 3762504530

So, it not only looks like the file is there, it'll run to prepare the analysis fine using the same executable, but when it runs the analysis step, it encounters this issue.

You mention it's executing "sonar-scanner{fileExtension}" from "{binFolder}\sonar-scanner-{version}\bin\.  In the paths that the TFS build tasks are running for SonarScanner.MSBuild.exe, I don't see any \bin\ component in the directory structure.

I do have a folder the following folder on the build server:

C:\agent1\_work\_tasks\SonarQubeAnalyze_6d01813a-9589-4b15-8491-8164aeb38055\4.1.0\sonar-scanner\bin where I have sonar-scanner.bat.  I notice the directories under "_tasks" are different.  Is this indicating they are in two seperate {binFolder} locations?  Should I try to copy the files from the "SonarQubeAnalyze_6d01813a-9589-4b15-8491-8164aeb38055 " directory to the "SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157" directory?

Thanks again for your assistance so far.

[valeri....@sonarsource.com]

The TFS task contains two "scanners" - one is SonarScanner.MSBuild.exe, which as you correctly found, is located in the following path on your machine:

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe

(the previous versions of the TFS task executed SonarQube.Scanner.MSBuild.exe, but now this file is renamed to SonarScanner.MSBuild.exe)

The other scanner in the package is the Java-based SonarScanner CLI, which on your build machine should be located at:

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\sonar-scanner-3.1.0.1141\

The SonarScanner CLI folder contains three subfolders: bin, lib and conf. At some point of its execution SonarScanner.MSBuild.exe is launching a process with the following path on Windows:

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\sonar-scanner-3.1.0.1141\bin\sonar-scanner.bat

The batch file makes some environment checks, such as if Java runtime is correctly installed and then executes

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\sonar-scanner-3.1.0.1141\lib\sonar-scanner-cli-3.1.0.1141.jar

I would recommend checking if these files and directories are on the machine and if they can be read and executed by the build user (I guess Administrator in your case, but please, double check). Apparently the batch file is there, because otherwise the Scanner would have logged an error message saying it cannot find the executable.

Another thing you could do is to add sonar.verbose=true in the Additional Properties box in the "Prepare Analysis on SonarQube" task. This will enable the debug logging and could probably give more clues what's the problem.

Kind regards,

Valeri

 

[Jody Lester]

Hi Valeri,

Thanks for the quick responses!  I can confirm the files are there and I have been running the prepare phase with verbose logging, this is the detail it gives at the point of the exception:

...

2018-03-20T12:05:30.0686834Z sonar.host.url={local 7 sonarqube server address}

2018-03-20T12:05:30.0686834Z sonar.projectKey={projectKey}

2018-03-20T12:05:30.0686834Z sonar.projectName={projectName}

2018-03-20T12:05:30.0686834Z sonar.projectVersion=1.0

2018-03-20T12:05:30.0686834Z sonar.verbose=true

2018-03-20T12:05:30.0686834Z sonar.visualstudio.enable=false

2018-03-20T12:05:30.0686834Z 

2018-03-20T12:05:30.0686834Z sonar.modules=DA7EC545-D974-45EB-9758-B917C4BAB3E3,5AE5BA00-FBF9-4802-95DA-567AE5A448DF,A48F7B15-E52B-4820-8C8F-170C523DA625,32347D63-9DA5-4CED-AD68-E1F2A7D83EE6,7D4CFC24-28E1-479F-BE36-B61D64FA8E47,0A507097-2506-4FF1-8963-FC188B80B439,994DC638-18A8-48D1-ACE0-B244BB0FBFC8,7A904C84-EFB1-41A6-82B9-D68A845CBBAD,07BF9B2F-25B8-4C9A-BA6B-440BFDC7D5ED,0B713C0B-3E99-4B7C-A9D6-5B31594BBF5A,34865112-F47B-498E-BE7B-7411364D0238,A13E3A3D-FB02-480D-A7B5-99C3F78CB318,EDE2C9D0-8385-4CBD-B602-53037D8AB763,E1ADAAE1-1337-4C81-A662-48C030938E0B,A7DE21A6-8822-4613-959D-5CD7C2DF4466

2018-03-20T12:05:30.0686834Z 

2018-03-20T12:05:30.0686834Z 

2018-03-20T12:05:30.0686834Z ------------------------------------------------------------------------

2018-03-20T12:05:30.0686834Z Writing processing summary to C:\agent1\_work\11\.sonarqube\out\ProjectInfo.log

2018-03-20T12:05:30.0686834Z SONAR_SCANNER_OPTS is not configured. Setting it to the default value of -Xmx1024m

2018-03-20T12:05:30.0686834Z Calling the SonarQube Scanner...

2018-03-20T12:05:30.0686834Z Setting environment variable 'SONAR_SCANNER_OPTS'. Value: -Xmx1024m

2018-03-20T12:05:30.5687332Z 

2018-03-20T12:05:30.5845773Z Unhandled Exception: System.ComponentModel.Win32Exception: Access is denied

2018-03-20T12:05:30.5845773Z    at System.Diagnostics.Process.StartWithCreateProcess(ProcessStartInfo startInfo)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Common.ProcessRunner.Execute(ProcessRunnerArguments runnerArgs)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.ExecuteJavaRunner(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String exeFileName, String propertiesFileName)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.InternalExecute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String fullPropertiesFilePath)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.<>c__DisplayClass6_0.<Execute>b__0()

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.Execute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.InvokeSonarScanner(IAnalysisPropertyProvider cmdLineArgs, AnalysisConfig config)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.Execute(String[] args, AnalysisConfig config, ITeamBuildSettings settings)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.BootstrapperClass.PostProcess()

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.BootstrapperClass.Execute()

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Program.Execute(String[] args, ILogger logger)

2018-03-20T12:05:30.5845773Z    at SonarScanner.MSBuild.Program.Main(String[] args)

2018-03-20T12:05:30.6155803Z ##[error]C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe failed with return code: 3762504530

2018-03-20T12:05:30.6312056Z ##[section]Finishing: Run Code Analysis

I can also confirm that the build agent services is logging on and running as the user we've configured to be a member of the local administrators group.

Many thanks,

[Jody Lester]

A quick update; I can see we're now using version 4.1.1.

Still getting the same issue.

2018-03-26T14:25:45.4852315Z sonar.verbose=true

2018-03-26T14:25:45.4852315Z sonar.visualstudio.enable=false

2018-03-26T14:25:45.4852315Z 

2018-03-26T14:25:45.4852315Z sonar.modules=DA7EC545-D974-45EB-9758-B917C4BAB3E3,5AE5BA00-FBF9-4802-95DA-567AE5A448DF,A48F7B15-E52B-4820-8C8F-170C523DA625,32347D63-9DA5-4CED-AD68-E1F2A7D83EE6,7D4CFC24-28E1-479F-BE36-B61D64FA8E47,0A507097-2506-4FF1-8963-FC188B80B439,994DC638-18A8-48D1-ACE0-B244BB0FBFC8,7A904C84-EFB1-41A6-82B9-D68A845CBBAD,07BF9B2F-25B8-4C9A-BA6B-440BFDC7D5ED,0B713C0B-3E99-4B7C-A9D6-5B31594BBF5A,34865112-F47B-498E-BE7B-7411364D0238,A13E3A3D-FB02-480D-A7B5-99C3F78CB318,EDE2C9D0-8385-4CBD-B602-53037D8AB763,E1ADAAE1-1337-4C81-A662-48C030938E0B,A7DE21A6-8822-4613-959D-5CD7C2DF4466

2018-03-26T14:25:45.4852315Z 

2018-03-26T14:25:45.4852315Z 

2018-03-26T14:25:45.4852315Z ------------------------------------------------------------------------

2018-03-26T14:25:45.4852315Z Writing processing summary to C:\agent1\_work\11\.sonarqube\out\ProjectInfo.log

2018-03-26T14:25:45.4852315Z SONAR_SCANNER_OPTS is not configured. Setting it to the default value of -Xmx1024m

2018-03-26T14:25:45.4852315Z Calling the SonarQube Scanner...

2018-03-26T14:25:45.4852315Z Setting environment variable 'SONAR_SCANNER_OPTS'. Value: -Xmx1024m

2018-03-26T14:25:46.0164934Z 

2018-03-26T14:25:46.0477360Z Unhandled Exception: System.ComponentModel.Win32Exception: Access is denied

2018-03-26T14:25:46.0477360Z    at System.Diagnostics.Process.StartWithCreateProcess(ProcessStartInfo startInfo)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Common.ProcessRunner.Execute(ProcessRunnerArguments runnerArgs)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.ExecuteJavaRunner(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String exeFileName, String propertiesFileName)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.InternalExecute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger, String fullPropertiesFilePath)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.<>c__DisplayClass6_0.<Execute>b__0()

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Shim.SonarScannerWrapper.Execute(AnalysisConfig config, IEnumerable`1 userCmdLineArguments, ILogger logger)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.InvokeSonarScanner(IAnalysisPropertyProvider cmdLineArgs, AnalysisConfig config)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.Execute(String[] args, AnalysisConfig config, ITeamBuildSettings settings)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.BootstrapperClass.PostProcess()

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.BootstrapperClass.Execute()

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Program.Execute(String[] args, ILogger logger)

2018-03-26T14:25:46.0477360Z    at SonarScanner.MSBuild.Program.Main(String[] args)

2018-03-26T14:25:46.0790141Z ##[error]C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.1\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe failed with return code: 3762504530

2018-03-26T14:25:46.1102339Z ##[section]Finishing: Run Code Analysis

[Jody Lester]

I've found this in the event log of the build server (not sure if it helps at all):

Application: SonarScanner.MSBuild.exe

Framework Version: v4.0.30319

Description: The process was terminated due to an unhandled exception.

Exception Info: System.ComponentModel.Win32Exception

   at System.Diagnostics.Process.StartWithCreateProcess(System.Diagnostics.ProcessStartInfo)

   at SonarScanner.MSBuild.Common.ProcessRunner.Execute(SonarScanner.MSBuild.Common.ProcessRunnerArguments)

   at SonarScanner.MSBuild.Shim.SonarScannerWrapper.ExecuteJavaRunner(SonarScanner.MSBuild.Common.AnalysisConfig, System.Collections.Generic.IEnumerable`1<System.String>, SonarScanner.MSBuild.Common.ILogger, System.String, System.String)

   at SonarScanner.MSBuild.Shim.SonarScannerWrapper.InternalExecute(SonarScanner.MSBuild.Common.AnalysisConfig, System.Collections.Generic.IEnumerable`1<System.String>, SonarScanner.MSBuild.Common.ILogger, System.String)

   at SonarScanner.MSBuild.Shim.SonarScannerWrapper+<>c__DisplayClass6_0.<Execute>b__0()

   at SonarScanner.MSBuild.Shim.SonarScannerWrapper.Execute(SonarScanner.MSBuild.Common.AnalysisConfig, System.Collections.Generic.IEnumerable`1<System.String>, SonarScanner.MSBuild.Common.ILogger)

   at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.InvokeSonarScanner(SonarScanner.MSBuild.Common.IAnalysisPropertyProvider, SonarScanner.MSBuild.Common.AnalysisConfig)

   at SonarScanner.MSBuild.PostProcessor.MSBuildPostProcessor.Execute(System.String[], SonarScanner.MSBuild.Common.AnalysisConfig, SonarScanner.MSBuild.TFS.Interfaces.ITeamBuildSettings)

   at SonarScanner.MSBuild.BootstrapperClass.PostProcess()

   at SonarScanner.MSBuild.BootstrapperClass.Execute()

   at SonarScanner.MSBuild.Program.Execute(System.String[], SonarScanner.MSBuild.Common.ILogger)

   at SonarScanner.MSBuild.Program.Main(System.String[])

[Jody Lester]

Adding this from Microsoft (https://msdn.microsoft.com/en-us/library/0w4h05yb(v=vs.110).aspx):

Win32Exception

An error occurred when opening the associated file. -or- The sum of the length of the arguments and the length of the full path to the process exceeds 2080. The error message associated with this exception can be one of the following: "The data area passed to a system call is too small." or "Access is denied."

Do we have a path length issue?  Is there a way to find out the full path/file being executed by the Process.StartWithCreateProcess?

[valeri....@sonarsource.com]

I doubt the length is the problem. There is no log message that shows what's the path of the executing process, but it should be no different than the paths I wrote in my previous reply https://groups.google.com/d/msg/sonarqube/jut59yav5zE/tnFy4JohAAAJ

C:\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.1.0\classic-sonar-scanner-msbuild\sonar-scanner-3.1.0.1141\bin\sonar-scanner.bat

The secondary reason "Access is denied" is also very plausible, even when the user of the build service is an Administrator. I would try on a different (new, if possible) build agent to see if the file system permissions were not messed up. Other option could be to try uninstalling the TFS extension, deleting all folders that start with:

C:\agent1\_work\_tasks\SonarQubePrepare on the agents and then installing the task again.

Kind regards,

Valeri

 

[Jody Lester]

Hi Valeri,

Could the batch file be executing a command that's being dynamically built/exceeding the length?

I'm now beginning to think this could be something to do with how the batch file is executing it's task.  Possibly even virus scanner related.  I'm going to dig a little deeper on our part and see what happens when the virus scanner is disabled.

Thanks again.

[Jody Lester]

Hi Valeri,

We've gotten to the bottom of it.

It would appear that the batch file "sonar-scanner" script was creating a file (in C:\Windows\Temp, filename {guid}.tmp) which was triggering panda anti virus to immediately quarantine the file.  This then led to the unexpected behavior!

I'm not sure why panda did this (maybe it's the nature in which the was being created or some other characteristic of the file), or why sonar scanner needs to create assets outside of the agent working directory (or whether it's java or something else creating it) but it's the only part of the entire build process we see this behavior.

If you could confirm what's happening there, we might be able to arrange an exclusion.

Thanks again for your help.

[valeri....@sonarsource.com]

Hi Jody,

I confirm that the scanner writes to the system temp folder. If you give me the actual file names I can quickly check if they were created by us or not.

Kind regards,

Valeri

[Jody Lester]

Hi Valeri,

The filename is: 489314d86c55a948a225789db7a93229.tmp

Many thanks,

[valeri....@sonarsource.com]

Hi Jody,

I am not sure about this file. The intentionally created files from Scanner CLI (the Java application) have a prefix saying what is this file (originally I thought that "filename {guid}.tmp" is the name, hence I wanted to know what is the "filename" prefix, but apparently it is not prefix). The Scanner CLI downloads plugins from SonarQube (jar files) and perhaps this "{guid}.tmp" is a temporary file created by the JRE while downloading...

Kind regards,

Valeri