johanclasson / vso-agent-tasks

Build and Release Tasks for Visual Studio Online and Team Foundation Server
MIT License
20 stars 16 forks source link

Error: The environment block used to start a process cannot be longer than 65535 bytes #67

Closed francisdidden closed 3 years ago

francisdidden commented 4 years ago

Hello Johan,

We are using your Azure DevOps task to perform DbUp Migrations for several databases. Recently we have been experiencing the following issue intermittently.

The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66267 bytes long. Remove some environment variables and try again.

This happens on multiple different agents (local VMs). The value for our environment block is not always 66267. Even on the same server it varies.

When checking the environment variables for our servers we aren't even close to the length of what the error is indicating. After looking through your code a bit, I noticed that at the start you are setting a lot of parameters to environment variables. But I do not know if that can be modified.

We would be grateful for any assistance in this matter!

johanclasson commented 4 years ago

To my knowledge, the DbUp-task does not set any environment variables. What lines are you referring to?

Regarding your problem, have you checked the environment variables on the server or in the build process? Since Azure DevOps sets many variables, among others all non secret pipeline variables.

What would help is to examine the environment variables by including a powershell task in the pipeline containing something similar to ls env:\. Or possibly to start the pipeline with system.debug set to true.

francisdidden commented 4 years ago

I was talking about this file: https://github.com/johanclasson/vso-agent-tasks/blob/master/Invoke-DbUpMigration.ps1

I've printed out the variables as you suggested and it is now clear that the variables that take up this much space are all the variables that are added from our variable group that is linked to the release. It is strange however that we only have an issue with the DbUp task and not with other tasks.

I've added the error with the debug info:

2020-04-30T12:03:59.4616069Z ##[debug]Evaluating condition for step: 'DbUp Migration' 2020-04-30T12:03:59.4617638Z ##[debug]Evaluating: succeeded() 2020-04-30T12:03:59.4618414Z ##[debug]Evaluating succeeded: 2020-04-30T12:03:59.4619544Z ##[debug]=> True 2020-04-30T12:03:59.4620467Z ##[debug]Result: True 2020-04-30T12:03:59.4621294Z ##[section]Starting: DbUp Migration 2020-04-30T12:03:59.4743776Z ============================================================================== 2020-04-30T12:03:59.4744341Z Task : DbUp Migration 2020-04-30T12:03:59.4744900Z Description : Runs SQL Server change scripts, and only those which have not been run already. 2020-04-30T12:03:59.4745427Z Version : 2.1.4 2020-04-30T12:03:59.4745830Z Author : Johan Classon 2020-04-30T12:03:59.4746354Z Help : [More Information](https://github.com/johanclasson/vso-agent-tasks) 2020-04-30T12:03:59.4746974Z ============================================================================== 2020-04-30T12:04:00.5514613Z ##[debug]VstsTaskSdk 0.11.0 commit 7ff27a3e0bdd6f7b06690ae5f5b63cb84d0f23f4 2020-04-30T12:04:01.5377734Z ##[debug]INPUT_CONNECTIONSTRING: 'Server=*;Database=*;Integrated security=sspi' 2020-04-30T12:04:01.5551643Z ##[debug]INPUT_SCRIPTPATH: 'C:\VSTS-Agent\_work\r3\a\Release' 2020-04-30T12:04:01.5629455Z ##[debug]INPUT_JOURNALTOSQLTABLE: 'true' 2020-04-30T12:04:01.5653111Z ##[debug] Converted to bool: True 2020-04-30T12:04:01.5681328Z ##[debug]INPUT_JOURNALSCHEMANAME: 'dbo' 2020-04-30T12:04:01.5806011Z ##[debug]INPUT_JOURNALTABLENAME: '_SchemaVersions' 2020-04-30T12:04:01.5876206Z ##[debug]INPUT_SCRIPTFILEFILTER: '.*' 2020-04-30T12:04:01.5922774Z ##[debug]INPUT_SCRIPTENCODING: '001-Default' 2020-04-30T12:04:01.5965733Z ##[debug]INPUT_TRANSACTIONSTRATEGY: 'TransactionPerScript' 2020-04-30T12:04:01.6001825Z ##[debug]INPUT_LOGSCRIPTOUTPUT: 'true' 2020-04-30T12:04:01.6013250Z ##[debug] Converted to bool: True 2020-04-30T12:04:01.6071556Z ##[debug]INPUT_INCLUDESUBFOLDERS: 'true' 2020-04-30T12:04:01.6120534Z ##[debug] Converted to bool: True 2020-04-30T12:04:01.6287773Z ##[debug]INPUT_ORDER: 'FilePath' 2020-04-30T12:04:01.6316441Z ##[debug]INPUT_VARIABLESUBSTITUTION: 'true' 2020-04-30T12:04:01.6356449Z ##[debug] Converted to bool: True 2020-04-30T12:04:01.6548198Z ##[debug]INPUT_VARIABLESUBSTITUTIONPREFIX (empty) 2020-04-30T12:04:01.7361841Z ##[debug] 2020-04-30T12:04:01.7381496Z ##[debug]using DbUp.Engine.Output; 2020-04-30T12:04:01.7398566Z ##[debug] 2020-04-30T12:04:01.7417907Z ##[debug]public class VstsUpgradeLog : IUpgradeLog 2020-04-30T12:04:01.7441502Z ##[debug]{ 2020-04-30T12:04:01.7460528Z ##[debug] private System.Action<string> WriteHost { get; set; } 2020-04-30T12:04:01.7479161Z ##[debug] 2020-04-30T12:04:01.7497874Z ##[debug] public VstsUpgradeLog(System.Action<string> writeHost) 2020-04-30T12:04:01.7516986Z ##[debug] { 2020-04-30T12:04:01.7535696Z ##[debug] WriteHost = writeHost; 2020-04-30T12:04:01.7553963Z ##[debug] } 2020-04-30T12:04:01.7572796Z ##[debug] 2020-04-30T12:04:01.7596014Z ##[debug] public void WriteInformation(string format, params object[] args) 2020-04-30T12:04:01.7599705Z ##[debug] { 2020-04-30T12:04:01.8672207Z ##[debug] WriteHost(string.Format(format, args).Trim()); 2020-04-30T12:04:01.8694995Z ##[debug] } 2020-04-30T12:04:01.8777432Z ##[debug] 2020-04-30T12:04:01.8795409Z ##[debug] public void WriteWarning(string format, params object[] args) 2020-04-30T12:04:01.8813023Z ##[debug] { 2020-04-30T12:04:01.8832036Z ##[debug] // ## is separated from command text so that system.debug mode does not bail out 2020-04-30T12:04:01.8851482Z ##[debug] WriteHost("##" + "vso[task.logissue type=warning;]" + string.Format(format, args)); 2020-04-30T12:04:01.8870327Z ##[debug] } 2020-04-30T12:04:01.8888936Z ##[debug] 2020-04-30T12:04:01.8907502Z ##[debug] public void WriteError(string format, params object[] args) 2020-04-30T12:04:01.8926253Z ##[debug] { 2020-04-30T12:04:01.8946765Z ##[debug] WriteHost("##" + "vso[task.logissue type=error;]" + string.Format(format, args)); 2020-04-30T12:04:01.8965403Z ##[debug] } 2020-04-30T12:04:01.9003071Z ##[debug]} 2020-04-30T12:04:01.9499639Z ##[debug]Caught exception from task script. 2020-04-30T12:04:01.9512192Z ##[debug]Error record: 2020-04-30T12:04:02.0660829Z ##[debug]Add-Type : The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T12:04:02.0680819Z ##[debug]At C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-DatabaseWithDbUp.ps1:30 char:5 2020-04-30T12:04:02.0705778Z ##[debug]+ Add-Type -TypeDefinition @" 2020-04-30T12:04:02.0725065Z ##[debug]+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2020-04-30T12:04:02.0741903Z ##[debug] + CategoryInfo : NotSpecified: (:) [Add-Type], InvalidOperationException 2020-04-30T12:04:02.0839167Z ##[debug] + FullyQualifiedErrorId : System.InvalidOperationException,Microsoft.PowerShell.Commands.AddTypeCommand 2020-04-30T12:04:02.0882667Z ##[debug] 2020-04-30T12:04:02.0940779Z ##[debug]Script stack trace: 2020-04-30T12:04:02.0966214Z ##[debug]at <ScriptBlock>, C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-DatabaseWithDbUp.ps1: line 30 2020-04-30T12:04:02.0988531Z ##[debug]at <ScriptBlock>, C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-Database.ps1: line 29 2020-04-30T12:04:02.1011668Z ##[debug]at <ScriptBlock>, <No file>: line 1 2020-04-30T12:04:02.1114569Z ##[debug]at <ScriptBlock>, <No file>: line 22 2020-04-30T12:04:02.1141974Z ##[debug]at <ScriptBlock>, <No file>: line 18 2020-04-30T12:04:02.1176830Z ##[debug]at <ScriptBlock>, <No file>: line 1 2020-04-30T12:04:02.1254484Z ##[debug]Exception: 2020-04-30T12:04:02.1281322Z ##[debug]System.InvalidOperationException: The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T12:04:02.1300516Z ##[debug] at System.Diagnostics.EnvironmentBlock.ToByteArray(StringDictionary sd, Boolean unicode) 2020-04-30T12:04:02.1319138Z ##[debug] at System.CodeDom.Compiler.Executor.ExecWaitWithCaptureUnimpersonated(SafeUserTokenHandle userToken, String cmd, String currentDir, TempFileCollection tempFiles, String& outputName, String& errorName, String trueCmdLine) 2020-04-30T12:04:02.1340870Z ##[debug] at System.CodeDom.Compiler.Executor.ExecWaitWithCapture(SafeUserTokenHandle userToken, String cmd, String currentDir, TempFileCollection tempFiles, String& outputName, String& errorName, String trueCmdLine) 2020-04-30T12:04:02.1362522Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.Compile(CompilerParameters options, String compilerDirectory, String compilerExe, String arguments, String& outputFile, Int32& nativeReturnValue, String trueArgs) 2020-04-30T12:04:02.1382152Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.FromFileBatch(CompilerParameters options, String[] fileNames) 2020-04-30T12:04:02.1401397Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.FromSourceBatch(CompilerParameters options, String[] sources) 2020-04-30T12:04:02.1420555Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.System.CodeDom.Compiler.ICodeCompiler.CompileAssemblyFromSourceBatch(CompilerParameters options, String[] sources) 2020-04-30T12:04:02.1441836Z ##[debug] at Microsoft.PowerShell.Commands.AddTypeCommand.CompileAssemblyFromSource(List1 generatedTypes) 2020-04-30T12:04:02.1460697Z ##[debug] at Microsoft.PowerShell.Commands.AddTypeCommand.EndProcessing() 2020-04-30T12:04:02.1494879Z ##[debug] at System.Management.Automation.CommandProcessorBase.Complete() 2020-04-30T12:04:02.1834601Z ##[error]The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T12:04:02.1845608Z ##[debug]Processed: ##vso[task.logissue type=error]The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T12:04:02.1869175Z ##[debug]Processed: ##vso[task.complete result=Failed] 2020-04-30T12:04:02.2281424Z ##[section]Finishing: DbUp Migration`

johanclasson commented 4 years ago

Ok. That file is only used when I test the task locally. It is not published with the task.

The task do iterate all environment variables if variable substitution is checked. Can you try to uncheck variable substitution and see if that error disappear?

I realize that you might be dependent on to have variable substitution working, but just so get an idea if we can work around your problem somehow.

You did say that no other tasks had this issue.

francisdidden commented 4 years ago

I get the same error after turning variable substitution off. And we indeed use this functionality.

2020-04-30T13:17:40.7743297Z ##[debug]Evaluating condition for step: 'DbUp Migration' 2020-04-30T13:17:40.7744886Z ##[debug]Evaluating: succeeded() 2020-04-30T13:17:40.7745674Z ##[debug]Evaluating succeeded: 2020-04-30T13:17:40.7746749Z ##[debug]=> True 2020-04-30T13:17:40.7747659Z ##[debug]Result: True 2020-04-30T13:17:40.7748492Z ##[section]Starting: DbUp Migration 2020-04-30T13:17:40.7872275Z ============================================================================== 2020-04-30T13:17:40.7872859Z Task : DbUp Migration 2020-04-30T13:17:40.7873433Z Description : Runs SQL Server change scripts, and only those which have not been run already. 2020-04-30T13:17:40.7873964Z Version : 2.1.4 2020-04-30T13:17:40.7874366Z Author : Johan Classon 2020-04-30T13:17:40.7874894Z Help : [More Information](https://github.com/johanclasson/vso-agent-tasks) 2020-04-30T13:17:40.7875512Z ============================================================================== 2020-04-30T13:17:41.8580787Z ##[debug]VstsTaskSdk 0.11.0 commit 7ff27a3e0bdd6f7b06690ae5f5b63cb84d0f23f4 2020-04-30T13:17:43.1265660Z ##[debug]INPUT_CONNECTIONSTRING: '**' 2020-04-30T13:17:43.1266965Z ##[debug]INPUT_SCRIPTPATH: '**' 2020-04-30T13:17:43.1267890Z ##[debug]INPUT_JOURNALTOSQLTABLE: 'true' 2020-04-30T13:17:43.1268622Z ##[debug] Converted to bool: True 2020-04-30T13:17:43.1269327Z ##[debug]INPUT_JOURNALSCHEMANAME: 'dbo' 2020-04-30T13:17:43.1270065Z ##[debug]INPUT_JOURNALTABLENAME: '_SchemaVersions' 2020-04-30T13:17:43.1270800Z ##[debug]INPUT_SCRIPTFILEFILTER: '.*' 2020-04-30T13:17:43.1271525Z ##[debug]INPUT_SCRIPTENCODING: '001-Default' 2020-04-30T13:17:43.1272285Z ##[debug]INPUT_TRANSACTIONSTRATEGY: 'TransactionPerScript' 2020-04-30T13:17:43.1273042Z ##[debug]INPUT_LOGSCRIPTOUTPUT: 'true' 2020-04-30T13:17:43.1273741Z ##[debug] Converted to bool: True 2020-04-30T13:17:43.1274447Z ##[debug]INPUT_INCLUDESUBFOLDERS: 'true' 2020-04-30T13:17:43.1275212Z ##[debug] Converted to bool: True 2020-04-30T13:17:43.1276244Z ##[debug]INPUT_ORDER: 'FilePath' 2020-04-30T13:17:43.1276967Z ##[debug]INPUT_VARIABLESUBSTITUTION: 'false' 2020-04-30T13:17:43.1277675Z ##[debug] Converted to bool: False 2020-04-30T13:17:43.1278397Z ##[debug]INPUT_VARIABLESUBSTITUTIONPREFIX (empty) 2020-04-30T13:17:43.1279034Z ##[debug] 2020-04-30T13:17:43.1279698Z ##[debug]using DbUp.Engine.Output; 2020-04-30T13:17:43.1280301Z ##[debug] 2020-04-30T13:17:43.1280985Z ##[debug]public class VstsUpgradeLog : IUpgradeLog 2020-04-30T13:17:43.1281643Z ##[debug]{ 2020-04-30T13:17:43.1282381Z ##[debug] private System.Action<string> WriteHost { get; set; } 2020-04-30T13:17:43.1283053Z ##[debug] 2020-04-30T13:17:43.1283776Z ##[debug] public VstsUpgradeLog(System.Action<string> writeHost) 2020-04-30T13:17:43.1284477Z ##[debug] { 2020-04-30T13:17:43.1285141Z ##[debug] WriteHost = writeHost; 2020-04-30T13:17:43.1285805Z ##[debug] } 2020-04-30T13:17:43.1286383Z ##[debug] 2020-04-30T13:17:43.1287129Z ##[debug] public void WriteInformation(string format, params object[] args) 2020-04-30T13:17:43.1287847Z ##[debug] { 2020-04-30T13:17:43.1288563Z ##[debug] WriteHost(string.Format(format, args).Trim()); 2020-04-30T13:17:43.1289275Z ##[debug] } 2020-04-30T13:17:43.1289859Z ##[debug] 2020-04-30T13:17:43.1290589Z ##[debug] public void WriteWarning(string format, params object[] args) 2020-04-30T13:17:43.1291440Z ##[debug] { 2020-04-30T13:17:43.1292234Z ##[debug] // ## is separated from command text so that system.debug mode does not bail out 2020-04-30T13:17:43.1293166Z ##[debug] WriteHost("##" + "vso[task.logissue type=warning;]" + string.Format(format, args)); 2020-04-30T13:17:43.1293927Z ##[debug] } 2020-04-30T13:17:43.1294494Z ##[debug] 2020-04-30T13:17:43.1295216Z ##[debug] public void WriteError(string format, params object[] args) 2020-04-30T13:17:43.1295937Z ##[debug] { 2020-04-30T13:17:43.1298521Z ##[debug] WriteHost("##" + "vso[task.logissue type=error;]" + string.Format(format, args)); 2020-04-30T13:17:43.1299304Z ##[debug] } 2020-04-30T13:17:43.1299899Z ##[debug]} 2020-04-30T13:17:43.1300580Z ##[debug]Caught exception from task script. 2020-04-30T13:17:43.1301265Z ##[debug]Error record: 2020-04-30T13:17:43.1715392Z ##[debug]Add-Type : The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T13:17:43.1734147Z ##[debug]At C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-DatabaseWithDbUp.ps1:30 char:5 2020-04-30T13:17:43.1752869Z ##[debug]+ Add-Type -TypeDefinition @" 2020-04-30T13:17:43.1770886Z ##[debug]+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2020-04-30T13:17:43.1789288Z ##[debug] + CategoryInfo : NotSpecified: (:) [Add-Type], InvalidOperationException 2020-04-30T13:17:43.1807274Z ##[debug] + FullyQualifiedErrorId : System.InvalidOperationException,Microsoft.PowerShell.Commands.AddTypeCommand 2020-04-30T13:17:43.1881766Z ##[debug] 2020-04-30T13:17:43.1921409Z ##[debug]Script stack trace: 2020-04-30T13:17:43.1974734Z ##[debug]at <ScriptBlock>, C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-DatabaseWithDbUp.ps1: line 30 2020-04-30T13:17:43.1992859Z ##[debug]at <ScriptBlock>, C:\VSTS-Agent\_work\_tasks\UpdateDatabaseWithDbUp_4182dbda-71db-4d18-89b3-75255b7802eb\2.1.4\Update-Database.ps1: line 29 2020-04-30T13:17:43.2010623Z ##[debug]at <ScriptBlock>, <No file>: line 1 2020-04-30T13:17:43.2028657Z ##[debug]at <ScriptBlock>, <No file>: line 22 2020-04-30T13:17:43.2052308Z ##[debug]at <ScriptBlock>, <No file>: line 18 2020-04-30T13:17:43.2065660Z ##[debug]at <ScriptBlock>, <No file>: line 1 2020-04-30T13:17:43.2096853Z ##[debug]Exception: 2020-04-30T13:17:43.2156898Z ##[debug]System.InvalidOperationException: The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T13:17:43.2174725Z ##[debug] at System.Diagnostics.EnvironmentBlock.ToByteArray(StringDictionary sd, Boolean unicode) 2020-04-30T13:17:43.2192750Z ##[debug] at System.CodeDom.Compiler.Executor.ExecWaitWithCaptureUnimpersonated(SafeUserTokenHandle userToken, String cmd, String currentDir, TempFileCollection tempFiles, String& outputName, String& errorName, String trueCmdLine) 2020-04-30T13:17:43.2211032Z ##[debug] at System.CodeDom.Compiler.Executor.ExecWaitWithCapture(SafeUserTokenHandle userToken, String cmd, String currentDir, TempFileCollection tempFiles, String& outputName, String& errorName, String trueCmdLine) 2020-04-30T13:17:43.2228848Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.Compile(CompilerParameters options, String compilerDirectory, String compilerExe, String arguments, String& outputFile, Int32& nativeReturnValue, String trueArgs) 2020-04-30T13:17:43.2246610Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.FromFileBatch(CompilerParameters options, String[] fileNames) 2020-04-30T13:17:43.2264448Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.FromSourceBatch(CompilerParameters options, String[] sources) 2020-04-30T13:17:43.2282474Z ##[debug] at Microsoft.CSharp.CSharpCodeGenerator.System.CodeDom.Compiler.ICodeCompiler.CompileAssemblyFromSourceBatch(CompilerParameters options, String[] sources) 2020-04-30T13:17:43.2300468Z ##[debug] at Microsoft.PowerShell.Commands.AddTypeCommand.CompileAssemblyFromSource(List1 generatedTypes) 2020-04-30T13:17:43.2318244Z ##[debug] at Microsoft.PowerShell.Commands.AddTypeCommand.EndProcessing() 2020-04-30T13:17:43.2336254Z ##[debug] at System.Management.Automation.CommandProcessorBase.Complete() 2020-04-30T13:17:43.2687246Z ##[error]The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T13:17:43.2698224Z ##[debug]Processed: ##vso[task.logissue type=error]The environment block used to start a process cannot be longer than 65535 bytes. Your environment block is 66285 bytes long. Remove some environment variables and try again. 2020-04-30T13:17:43.2700495Z ##[debug]Processed: ##vso[task.complete result=Failed] 2020-04-30T13:17:43.2934683Z ##[section]Finishing: DbUp Migration`

johanclasson commented 4 years ago

It seams to be a limitation to .NET Framework. The task use PowerShell to orchestrate its logic, and in doing so it "compiles" .NET types from a string. While doing so the application blows.

I can think of two workarounds. Either you reduce the number of environment variables, for example removing no longer needed variables or reducing the number of artifacts.

The alternative is that the task is ported to run on .NET Core, which does not have a similar limitation.

francisdidden commented 4 years ago

Ok, thank you for your help. I will try to clean up or rearrange our variables.

The port to .NET Core sounds like a good improvement! Is that something you have time for at the moment?

johanclasson commented 4 years ago

To be honest, no. Not without help. But I guess it is something that will have to be done eventually.

johanclasson commented 3 years ago

Closing due to inactivity. Please open if this is still an issue.