"commandExecutionTimeoutSeconds" always reverts to 2700 when deprecated config setting is 0

[ajayshikhare]

C:\Windows\system32>choco config set commandExecutionTimeoutSeconds 14400 -dvy
Chocolatey v0.10.3
Chocolatey is running on Windows v 6.1.7601.65536
Attempting to delete file "C:/ProgramData/chocolatey/choco.exe.old".
Attempting to delete file "C:\ProgramData\chocolatey\choco.exe.old".
Command line not shown - sensitive arguments may have been passed.
RemovePendingPackagesTask is now ready and waiting for PreRunMessage.
Sending message 'PreRunMessage' out if there are subscribers...
[Pending] Removing all pending packages that should not be considered installed...
The source '' evaluated to a 'normal' source type

NOTE: Hiding sensitive configuration data! Please double and triple
check to be sure no sensitive data is shown, especially if copying
output to a gist for review.
Configuration: CommandName='config'|
CacheLocation='C:\Users\shikhare_a\AppData\Local\Temp\chocolatey'|
ContainsLegacyPackageInstalls='True'|
CommandExecutionTimeoutSeconds='2700'|WebRequestTimeoutSeconds='30'|
SourceType='normal'|Debug='True'|Verbose='True'|Force='False'|
Noop='False'|HelpRequested='False'|RegularOutput='True'|
QuietOutput='False'|PromptForConfirmation='False'|AcceptLicense='True'|
AllowUnofficialBuild='False'|
Input='set commandExecutionTimeoutSeconds 14400'|AllVersions='False'|
SkipPackageInstallProvider='False'|Prerelease='False'|ForceX86='False'|
OverrideArguments='False'|NotSilent='False'|
ApplyPackageParametersToDependencies='False'|
ApplyInstallArgumentsToDependencies='False'|IgnoreDependencies='False'|
AllowMultipleVersions='False'|AllowDowngrade='False'|
ForceDependencies='False'|Information.PlatformType='Windows'|
Information.PlatformVersion='6.1.7601.65536'|
Information.PlatformName='Windows 7'|
Information.ChocolateyVersion='0.10.3.0'|
Information.ChocolateyProductVersion='0.10.3'|
Information.FullName='choco, Version=0.10.3.0, Culture=neutral, PublicKeyToken=79d02ea9cad655eb'|

Information.Is64Bit='True'|Information.IsInteractive='True'|
Information.IsUserAdministrator='True'|
Information.IsProcessElevated='True'|
Information.IsLicensedVersion='False'|Information.LicenseType='Foss'|
Features.AutoUninstaller='True'|Features.ChecksumFiles='False'|
Features.AllowEmptyChecksums='True'|
Features.AllowEmptyChecksumsSecure='True'|
Features.FailOnAutoUninstaller='False'|
Features.FailOnStandardError='False'|Features.UsePowerShellHost='True'|
Features.LogEnvironmentValues='False'|Features.VirusCheck='False'|
Features.FailOnInvalidOrMissingLicense='False'|
Features.IgnoreInvalidOptionsSwitches='True'|
Features.UsePackageExitCodes='True'|
Features.UseFipsCompliantChecksums='False'|
Features.ScriptsCheckLastExitCode='False'|
ListCommand.LocalOnly='False'|
ListCommand.IncludeRegistryPrograms='False'|ListCommand.PageSize='25'|
ListCommand.Exact='False'|ListCommand.ByIdOnly='False'|
ListCommand.IdStartsWith='False'|ListCommand.OrderByPopularity='False'|
ListCommand.ApprovedOnly='False'|
ListCommand.DownloadCacheAvailable='False'|
ListCommand.NotBroken='False'|UpgradeCommand.FailOnUnfound='False'|
UpgradeCommand.FailOnNotInstalled='False'|
UpgradeCommand.NotifyOnlyAvailableUpgrades='False'|
NewCommand.AutomaticPackage='False'|
NewCommand.UseOriginalTemplate='False'|SourceCommand.Command='unknown'|
SourceCommand.Priority='0'|FeatureCommand.Command='unknown'|
ConfigCommand.Name='commandExecutionTimeoutSeconds'|
ConfigCommand.Command='set'|PinCommand.Command='unknown'|
_ Chocolatey:ChocolateyConfigCommand - Normal Run Mode _
Attempting to copy "C:\ProgramData\chocolatey\config\chocolatey.config.update"
to "C:\ProgramData\chocolatey\config\chocolatey.config".
Attempting to delete file "C:\ProgramData\chocolatey\config\chocolatey.config.update".
Updated commandExecutionTimeoutSeconds = 14400
Sending message 'PostRunMessage' out if there are subscribers...
Exiting with 0

We see the commandExecutionTimeoutSeconds = 14400 has been set.

The very next moment when we run choco config list we see below.

C:\Windows\system32>choco config list
Chocolatey v0.10.3
Settings
cacheLocation = | Cache location if not TEMP folder.
containsLegacyPackageInstalls = true | Install has packages installed prior to 0.9.9 series.
proxy = | Explicit proxy location.
proxyUser = | Optional proxy user.
proxyPassword = | Optional proxy password. Encrypted.
webRequestTimeoutSeconds = 30 | Default timeout for web requests. Available in 0.9.10+.
timeout = 14400 |
commandExecutionTimeoutSeconds = 2700 | Default timeout for command execution.

This never gets set in the config file. When tried changing the value in Config file, it gets overwritten whenever the next choco command gets run.

choco.summary.log around this time.
2016-11-23 16:12:32,807 [INFO ] - Chocolatey v0.10.3
2016-11-23 16:12:35,212 [WARN ] - Updated commandExecutionTimeoutSeconds = 14400
2016-11-23 17:11:08,109 [INFO ] - ============================================================
2016-11-23 17:11:08,166 [INFO ] - Chocolatey v0.10.3
2016-11-23 17:11:12,554 [INFO ] - Settings
2016-11-23 17:11:12,560 [INFO ] - cacheLocation = | Cache location if not TEMP folder.
2016-11-23 17:11:12,565 [INFO ] - containsLegacyPackageInstalls = true | Install has packages installed prior to 0.9.9 series.
2016-11-23 17:11:12,568 [INFO ] - proxy = | Explicit proxy location.
2016-11-23 17:11:12,581 [INFO ] - proxyUser = | Optional proxy user.
2016-11-23 17:11:12,585 [INFO ] - proxyPassword = | Optional proxy password. Encrypted.
2016-11-23 17:11:12,589 [INFO ] - webRequestTimeoutSeconds = 30 | Default timeout for web requests. Available in 0.9.10+.
2016-11-23 17:11:12,594 [INFO ] - timeout = 14400 |
2016-11-23 17:11:12,599 [INFO ] - commandExecutionTimeoutSeconds = 2700 | Default timeout for command execution.

[ajayshikhare]

Also
why we have 2 keys for commandExecutionTimeoutSeconds
version="1.0" encoding="utf-8"?> <chocolatey xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema"> <containsLegacyPackageInstalls>false</containsLegacyPackageInstalls> <commandExecutionTimeoutSeconds>0</commandExecutionTimeoutSeconds> <config> <add key="cacheLocation" value="" description="Cache location if not TEMP folder." /> <add key="containsLegacyPackageInstalls" value="true" description="Install has packages installed prior to 0.9.9 series." /> <add key="proxy" value="" description="Explicit proxy location." /> <add key="proxyUser" value="" description="Optional proxy user." /> <add key="proxyPassword" value="" description="Optional proxy password. Encrypted." /> <add key="webRequestTimeoutSeconds" value="30" description="Default timeout for web requests. Available in 0.9.10+." /> <add key="timeout" value="14400" /> <add key="commandExecutionTimeoutSeconds" value="14400" description="Default timeout for command execution." />

If we change the top key the value reflects globally
but even if you set the value from choco config set or manually set the value in a config file, it never gets setup as needed

[ferventcoder]

Some discussion at #973 - closed as a duplicate.

[ferventcoder]

Great thing, @alex3305 has discovered what is causing this issue and has proposed a fix! So this is likely to be fixed for 0.10.4! Sit tight.

[ajayshikhare]

Hey Rob, Glad to hear this, We are getting better!
You guys have saved me atleast 1000 foreman reports from nodes with changes in the chocolatey.config file in every puppet run ;).
When is the go live planned for 0.10.4 ?

[ferventcoder]

Sometime in Feb (or March)

[ferventcoder]

Okay, figured out exactly what causes this.

<chocolatey xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <!-- this is a deprecated setting, but it wreaks havoc in less than 0.10.4 when it is zero (which it is by default) --> 
  <commandExecutionTimeoutSeconds>0</commandExecutionTimeoutSeconds>
  <config>
    <!-- will always be 2700 when the above setting is 0 in less than v0.10.4 -->
    <add key="commandExecutionTimeoutSeconds" value="2700" description="Default timeout for command execution." />
    <!-- Other settings-->
  </config>
  <!-- Other settings-->
</chocolatey>

When the top-level (deprecated) <commandExecutionTimeoutSeconds /> is set to 0, it will always reset the config setting for commandExecutionTimeoutSeconds to 2700. This is due to

choco/src/chocolatey/infrastructure.app/builders/ConfigurationBuilder.cs

Line 216 in 224c399

if (configFileSettings.CommandExecutionTimeoutSeconds <= 0)

looking at the deprecated config setting instead of looking at the local variable that was just set.

Workaround

As a workaround, set the toplevel commandExecutionTimeoutSeconds to any number but 0 and then set choco config set commandExecutionTimeoutSeconds ## as normal. Here is a linked workaround - #1150 (comment):

$executionTimeout = '2800' # pick your number here
$path = 'C:\ProgramData\chocolatey\config\chocolatey.config'

$xml = [xml](Get-Content $path)
$xml.chocolatey.commandExecutionTimeoutSeconds = "$executionTimeout"
$xml.SelectSingleNode('//chocolatey/config/add[@key="commandExecutionTimeoutSeconds"]').value = "$executionTimeout"
$xml.Save($path)

[ajayshikhare]

Hey Rob,
It Works!. looking forward to upgrade 0.10.4.

A BIG ThankYou..