trying to debug ansible and win_package

Hi,

I'm trying to debug a ansible windows issue, if someone with powershell
knowledge could help me debug it, it would be great.

I can successfully win_ping win_setup the windows 2019SE server, but not
win_package install or install using chocolatey. No idea why.

I have this piece of ansible code, to install a package via win_package.

  - name: Ensure 7-Zip is installed through win_package
    win_package:
      path: C:\temp\7z.exe
      state: present

The above fails with:

  The win_package action failed to execute in the expected time frame (5) and was terminated.

I run my playbook with -vvvvv, I see this[1] in the output. I believe
to debug this further I need to run the powershell script on the windows
box directly. I'm not quite sure how to do that. What I've done is
enable powershell script block logging, so that I can decode the
EncodedCommand string (not sure how else to decode it?). Looking at the
Event Viewer, I can see that the powershell script block is this[2].

I'm rather clueless with powershell. I'm now stuck at, how can I
execute this powershell script block[2] in the same manner as ansible is
doing it, to see why it's failing to install? Currently I take the
scriptblock[2] as is and paste it in powershell which simply returns
nothing to the screen.

Any help would be appreciated. Version details in [3].

[1]:
Using module file /home/opc/.ansible/collections/ansible_collections/ansible/windows/plugins/modules/win_package.ps1
Pipelining is enabled.
<10.20.100.184> ESTABLISH WINRM CONNECTION FOR USER: opc on PORT 5986 TO 10.20.100.184
<10.20.100.184> WINRM CONNECT: transport=credssp endpoint=https://10.20.100.184:5986/wsman
<10.20.100.184> WINRM OPEN SHELL: 37E74DAA-A27C-4642-89BB-CDDD11AF95DF
EXEC (via pipeline wrapper)
<10.20.100.184> WINRM EXEC 'PowerShell' ['-NoProfile', '-NonInteractive', '-ExecutionPolicy', 'Unrestricted', '-EncodedCommand', 'UABvAHcAZQByAFMAaABlAGwAbAAgAC0ATgBvAFAAcgBvAGYAaQBsAGUAIAAtAE4AbwBuAEkAbgB0AGUAcgBhAGMAdABpAHYAZQAgAC0ARQB4AGUAYwB1AHQAaQBvAG4AUABvAGwAaQBjAHkAIABVAG4AcgBlAHMAdAByAGkAYwB0AGUAZAAgAC0ARQBuAGMAbwBkAGUAZABDAG8AbQBtAGEAbgBkACAASgBnAEIAagBBAEcAZwBBAFkAdwBCAHcAQQBDADQAQQBZAHcAQgB2AEEARwAwAEEASQBBAEEAMgBBAEQAVQBBAE0AQQBBAHcAQQBEAEUAQQBJAEEAQQArAEEAQwBBAEEASgBBAEIAdQBBAEgAVQBBAGIAQQBCAHMAQQBBAG8AQQBhAFEAQgBtAEEAQwBBAEEASwBBAEEAawBBAEYAQQBBAFUAdwBCAFcAQQBHAFUAQQBjAGcAQgB6AEEARwBrAEEAYgB3AEIAdQBBAEYAUQBBAFkAUQBCAGkAQQBHAHcAQQBaAFEAQQB1AEEARgBBAEEAVQB3AEIAVwBBAEcAVQBBAGMAZwBCAHoAQQBHAGsAQQBiAHcAQgB1AEEAQwBBAEEATABRAEIAcwBBAEgAUQBBAEkAQQBCAGIAQQBGAFkAQQBaAFEAQgB5AEEASABNAEEAYQBRAEIAdgBBAEcANABBAFgAUQBBAGkAQQBEAE0AQQBMAGcAQQB3AEEAQwBJAEEASwBRAEEAZwBBAEgAcwBBAEMAZwBBAG4AQQBIAHMAQQBJAGcAQgBtAEEARwBFAEEAYQBRAEIAcwBBAEcAVQBBAFoAQQBBAGkAQQBEAG8AQQBkAEEAQgB5AEEASABVAEEAWgBRAEEAcwBBAEMASQBBAGIAUQBCAHoAQQBHAGMAQQBJAGcAQQA2AEEAQwBJAEEAUQBRAEIAdQBBAEgATQBBAGEAUQBCAGkAQQBHAHcAQQBaAFEAQQBnAEEASABJAEEAWgBRAEIAeABBAEgAVQBBAGEAUQBCAHkAQQBHAFUAQQBjAHcAQQBnAEEARgBBAEEAYgB3AEIAMwBBAEcAVQBBAGMAZwBCAFQAQQBHAGcAQQBaAFEAQgBzAEEARwB3AEEASQBBAEIAMgBBAEQATQBBAEwAZwBBAHcAQQBDAEEAQQBiAHcAQgB5AEEAQwBBAEEAYgBnAEIAbABBAEgAYwBBAFoAUQBCAHkAQQBDAEkAQQBmAFEAQQBuAEEAQQBvAEEAWgBRAEIANABBAEcAawBBAGQAQQBBAGcAQQBEAEUAQQBDAGcAQgA5AEEAQQBvAEEASgBBAEIAbABBAEgAZwBBAFoAUQBCAGoAQQBGADgAQQBkAHcAQgB5AEEARwBFAEEAYwBBAEIAdwBBAEcAVQBBAGMAZwBCAGYAQQBIAE0AQQBkAEEAQgB5AEEAQwBBAEEAUABRAEEAZwBBAEMAUQBBAGEAUQBCAHUAQQBIAEEAQQBkAFEAQgAwAEEAQwBBAEEAZgBBAEEAZwBBAEUAOABBAGQAUQBCADAAQQBDADAAQQBVAHcAQgAwAEEASABJAEEAYQBRAEIAdQBBAEcAYwBBAEMAZwBBAGsAQQBIAE0AQQBjAEEAQgBzAEEARwBrAEEAZABBAEIAZgBBAEgAQQBBAFkAUQBCAHkAQQBIAFEAQQBjAHcAQQBnAEEARAAwAEEASQBBAEEAawBBAEcAVQBBAGUAQQBCAGwAQQBHAE0AQQBYAHcAQgAzAEEASABJAEEAWQBRAEIAdwBBAEgAQQBBAFoAUQBCAHkAQQBGADgAQQBjAHcAQgAwAEEASABJAEEATABnAEIAVABBAEgAQQBBAGIAQQBCAHAAQQBIAFEAQQBLAEEAQgBBAEEAQwBnAEEASQBnAEIAZwBBAEQAQQBBAFkAQQBBAHcAQQBHAEEAQQBNAEEAQgBnAEEARABBAEEASQBnAEEAcABBAEMAdwBBAEkAQQBBAHkAQQBDAHcAQQBJAEEAQgBiAEEARgBNAEEAZABBAEIAeQBBAEcAawBBAGIAZwBCAG4AQQBGAE0AQQBjAEEAQgBzAEEARwBrAEEAZABBAEIAUABBAEgAQQBBAGQAQQBCAHAAQQBHADgAQQBiAGcAQgB6AEEARgAwAEEATwBnAEEANgBBAEYASQBBAFoAUQBCAHQAQQBHADgAQQBkAGcAQgBsAEEARQBVAEEAYgBRAEIAdwBBAEgAUQBBAGUAUQBCAEYAQQBHADQAQQBkAEEAQgB5AEEARwBrAEEAWgBRAEIAegBBAEMAawBBAEMAZwBCAEoAQQBHAFkAQQBJAEEAQQBvAEEAQwAwAEEAYgBnAEIAdgBBAEgAUQBBAEkAQQBBAGsAQQBIAE0AQQBjAEEAQgBzAEEARwBrAEEAZABBAEIAZgBBAEgAQQBBAFkAUQBCAHkAQQBIAFEAQQBjAHcAQQB1AEEARQB3AEEAWgBRAEIAdQBBAEcAYwBBAGQAQQBCAG8AQQBDAEEAQQBMAFEAQgBsAEEASABFAEEASQBBAEEAeQBBAEMAawBBAEkAQQBCADcAQQBDAEEAQQBkAEEAQgBvAEEASABJAEEAYgB3AEIAMwBBAEMAQQBBAEkAZwBCAHAAQQBHADQAQQBkAGcAQgBoAEEARwB3AEEAYQBRAEIAawBBAEMAQQBBAGMAQQBCAGgAQQBIAGsAQQBiAEEAQgB2AEEARwBFAEEAWgBBAEEAaQBBAEMAQQBBAGYAUQBBAEsAQQBGAE0AQQBaAFEAQgAwAEEAQwAwAEEAVgBnAEIAaABBAEgASQBBAGEAUQBCAGgAQQBHAEkAQQBiAEEAQgBsAEEAQwBBAEEATABRAEIATwBBAEcARQBBAGIAUQBCAGwAQQBDAEEAQQBhAGcAQgB6AEEARwA4AEEAYgBnAEIAZgBBAEgASQBBAFkAUQBCADMAQQBDAEEAQQBMAFEAQgBXAEEARwBFAEEAYgBBAEIAMQBBAEcAVQBBAEkAQQBBAGsAQQBIAE0AQQBjAEEAQgBzAEEARwBrAEEAZABBAEIAZgBBAEgAQQBBAFkAUQBCAHkAQQBIAFEAQQBjAHcAQgBiAEEARABFAEEAWABRAEEASwBBAEMAUQBBAFoAUQBCADQAQQBHAFUAQQBZAHcAQgBmAEEASABjAEEAYwBnAEIAaABBAEgAQQBBAGMAQQBCAGwAQQBIAEkAQQBJAEEAQQA5AEEAQwBBAEEAVwB3AEIAVABBAEcATQBBAGMAZwBCAHAAQQBIAEEAQQBkAEEAQgBDAEEARwB3AEEAYgB3AEIAagBBAEcAcwBBAFgAUQBBADYAQQBEAG8AQQBRAHcAQgB5AEEARwBVAEEAWQBRAEIAMABBAEcAVQBBAEsAQQBBAGsAQQBIAE0AQQBjAEEAQgBzAEEARwBrAEEAZABBAEIAZgBBAEgAQQBBAFkAUQBCAHkAQQBIAFEAQQBjAHcAQgBiAEEARABBAEEAWABRAEEAcABBAEEAbwBBAEoAZwBBAGsAQQBHAFUAQQBlAEEAQgBsAEEARwBNAEEAWAB3AEIAMwBBAEgASQBBAFkAUQBCAHcAQQBIAEEAQQBaAFEAQgB5AEEAQQA9AD0A']
<10.20.100.184> WINRM CLOSE SHELL: 37E74DAA-A27C-4642-89BB-CDDD11AF95DF
fatal: [divan-windows-test-prod]: FAILED! => {
    "changed": false,
    "msg": "The win_package action failed to execute in the expected time frame (5) and was terminated"
}

[2]:

{
            param (
                [String]
                $Arguments,

                [Int32]
                $ReturnCodes,

                [Object]
                $Module,

                [String]
                $Path,

                [String]
                $State,

                [String]
                $WorkingDirectory,

                [String]
                $RegistryPath,

                [Switch]
                $WaitChildren
            )

            $invokeParams = @{
                Module = $Module
                ReturnCodes = $ReturnCodes
                WorkingDirectory = $WorkingDirectory
                WaitChildren = $WaitChildren
            }

            if ($Path) {
                $invokeParams.CommandLine = ConvertTo-EscapedArgument -InputObject $Path
            }
            else {
                $registryProperties = Get-ItemProperty -LiteralPath $RegistryPath

                if ('QuietUninstallString' -in $registryProperties.PSObject.Properties.Name) {
                    $command = $registryProperties.QuietUninstallString
                }
                elseif ('UninstallString' -in $registryProperties.PSObject.Properties.Name) {
                    $command = $registryProperties.UninstallString
                }
                else {
                    $module.FailJson("Failed to find registry uninstall string at registry path '$RegistryPath'")
                }

                # If the uninstall string starts with '%', we need to expand the env vars.
                if ($command.StartsWith('%') -or $command.StartsWith('"%')) {
                    $command = [System.Environment]::ExpandEnvironmentVariables($command)
                }

                # If the command is not quoted and contains spaces we need to see if it needs to be manually quoted for the executable.
                if (-not $command.StartsWith('"') -and $command.Contains(' ')) {
                    $rawArguments = [System.Collections.Generic.List[String]]@()

                    $executable = New-Object -TypeName System.Text.StringBuilder
                    foreach ($cmd in ($command | ConvertFrom-EscapedArgument)) {
                        if ($rawArguments.Count -eq 0) {
                            # Still haven't found the path, append the arg to the executable path and see if it exists.
                            $null = $executable.Append($cmd)
                            $exe = $executable.ToString()
                            if (Test-Path -LiteralPath $exe -PathType Leaf) {
                                $rawArguments.Add($exe)
                            }
                            else {
                                $null = $executable.Append(" ") # The arg had a space and we need to preserve that.
                            }
                        }
                        else {
                            $rawArguments.Add($cmd)
                        }
                    }

                    # If we still couldn't find a file just use the command literally and hope WIndows can handle it,
                    # otherwise recombine the args which will also quote whatever is needed.
                    if ($rawArguments.Count -gt 0) {
                        $command = @($rawArguments | ConvertTo-EscapedArgument) -join ' '
                    }
                }

                $invokeParams.CommandLine = $command
            }

            if ($Arguments) {
                $invokeParams.CommandLine += " $Arguments"
            }

            Invoke-Executable @invokeParams
        }

My version details are[3]:

[3]:
ansible 2.16
python 3.10.13
ansible.windows 2.1.0

pip list:

ansible 9.0.1
ansible-compat 4.1.10
ansible-core 2.16.0
ansible-lint 6.22.0
arrow 1.3.0
attrs 23.1.0
black 23.11.0
bracex 2.4
certifi 2023.11.17
cffi 1.16.0
charset-normalizer 3.3.2
circuitbreaker 1.4.0
click 8.0.4
cryptography 41.0.5
decorator 5.1.1
filelock 3.13.1
gssapi 1.8.3
idna 3.4
Jinja2 3.1.2
jmespath 0.10.0
jsonschema 4.20.0
jsonschema-specifications 2023.11.1
krb5 0.5.1
markdown-it-py 3.0.0
MarkupSafe 2.1.3
mdurl 0.1.2
mypy-extensions 1.0.0
oci 2.116.0
oci-cli 3.36.2
packaging 23.2
pathspec 0.11.2
pip 23.0.1
platformdirs 4.0.0
prompt-toolkit 3.0.29
pycparser 2.21
Pygments 2.17.2
pykerberos 1.2.4
pyOpenSSL 23.3.0
pyspnego 0.10.2
python-dateutil 2.8.2
pytz 2023.3.post1
pywinrm 0.4.3
PyYAML 6.0.1
referencing 0.31.0
requests 2.31.0
requests-credssp 2.0.0
requests-kerberos 0.14.0
requests-ntlm 1.2.0
resolvelib 1.0.1
rich 13.7.0
rpds-py 0.13.1
ruamel.yaml 0.18.5
ruamel.yaml.clib 0.2.8
setuptools 65.5.0
six 1.16.0
subprocess-tee 0.4.1
terminaltables 3.1.0
tomli 2.0.1
types-python-dateutil 2.8.19.14
typing_extensions 4.8.0
urllib3 2.1.0
wcmatch 8.5
wcwidth 0.2.12
xmltodict 0.13.0
yamllint 1.33.0

The only time this error ever appears is if you have a timeout set on the task [1]. Check to ensure you don’t have that config entry set ‘ansible-config dump --only-changed’ or haven’t set it on the task play.

[1] https://docs.ansible.com/ansible/latest/reference_appendices/config.html#task-timeout

The win_package action failed to execute in the expected time frame (5)
and was terminated.

The only time this error ever appears is if you have a timeout set on the
task [1]. Check to ensure you don't have that config entry set
'ansible-config dump --only-changed' or haven't set it on the task play.

[1]
https://docs.ansible.com/ansible/latest/reference_appendices/config.html#task-timeout

No it's not that sadly. It times out before 5 seconds anyway.

Checking ansible-config dump --only-changed it says:

ANSIBLE_NOCOWS(/home/opc/vb-ansible-core/ansible.cfg) = True
CALLBACKS_ENABLED(/home/opc/vb-ansible-core/ansible.cfg) = ['ansible.posix.profile_tasks']
CONFIG_FILE() = /home/opc/vb-ansible-core/ansible.cfg
DEFAULT_BECOME(/home/opc/vb-ansible-core/ansible.cfg) = False
DEFAULT_FORKS(/home/opc/vb-ansible-core/ansible.cfg) = 100
DEFAULT_HOST_LIST(/home/opc/vb-ansible-core/ansible.cfg) = ['/home/opc/vb-ansible-core/inventories/auto_inventory.oci.yml', '/home/opc/vb-ansible-core/invent>
DEFAULT_LOG_PATH(/home/opc/vb-ansible-core/ansible.cfg) = /home/opc/vb-ansible-core/.logs/ansible.log
DEFAULT_ROLES_PATH(/home/opc/vb-ansible-core/ansible.cfg) = ['/home/opc/vb-ansible-core/roles_external', '/home/opc/vb-ansible-core/roles']
DEFAULT_TIMEOUT(/home/opc/vb-ansible-core/ansible.cfg) = 30
HOST_KEY_CHECKING(/home/opc/vb-ansible-core/ansible.cfg) = False
INTERPRETER_PYTHON(/home/opc/vb-ansible-core/ansible.cfg) = auto_silent
RETRY_FILES_ENABLED(/home/opc/vb-ansible-core/ansible.cfg) = True
RETRY_FILES_SAVE_PATH(/home/opc/vb-ansible-core/ansible.cfg) = /home/opc/.ansible-retry

Moreover explicitly setting task_timeout = 60 or 0 in ansible.cfg, results in the
same error.

I'm rather clueless with powershell. I'm now stuck at, how can I
execute this powershell script block[2] in the same manner as ansible is
doing it, to see why it's failing to install? Currently I take the
scriptblock[2] as is and paste it in powershell which simply returns
nothing to the screen.

OK, I think I run the powershell script like so via cmd:

powershell -NoProfile -NonInteractive -ExecutionPolicy Unrestricted Invoke-Command -ScriptBlock { param ( [String] $Arguments, [Int32] $ReturnCodes, [Object] $Module, [String] $Path, [String] $State, [String] $WorkingDirectory, [String] $RegistryPath, [Switch] $WaitChildren ) $invokeParams = @{ Module = $Module ReturnCodes = $ReturnCodes WorkingDirectory = $WorkingDirectory WaitChildren = $WaitChildren } if ($Path) { $invokeParams.CommandLine = ConvertTo-EscapedArgument -InputObject $Path } else { $registryProperties = Get-ItemProperty -LiteralPath $RegistryPath if ('QuietUninstallString' -in $registryProperties.PSObject.Properties.Name) { $command = $registryProperties.QuietUninstallString } elseif ('UninstallString' -in $registryProperties.PSObject.Properties.Name) { $command = $registryProperties.UninstallString } else { $module.FailJson("Failed to find registry uninstall string at registry path '$RegistryPath'") } # If the uninstall string starts with '%', we need to expand the env vars. if ($command.StartsWith('%') -or $command.StartsWith('"%')) { $command = [System.Environment]::ExpandEnvironmentVariables($command) } # If the command is not quoted and contains spaces we need to see if it needs to be manually quoted for the executable. if (-not $command.StartsWith('"') -and $command.Contains(' ')) { $rawArguments = [System.Collections.Generic.List[String]]@() $executable = New-Object -TypeName System.Text.StringBuilder foreach ($cmd in ($command | ConvertFrom-EscapedArgument)) { if ($rawArguments.Count -eq 0) { # Still haven't found the path, append the arg to the executable path and see if it exists. $null = $executable.Append($cmd) $exe = $executable.ToString() if (Test-Path -LiteralPath $exe -PathType Leaf) { $rawArguments.Add($exe) } else { $null = $executable.Append(" ") # The arg had a space and we need to preserve that. } } else { $rawArguments.Add($cmd) } } # If we still couldn't find a file just use the command literally and hope WIndows can handle it, # otherwise recombine the args which will also quote whatever is needed. if ($rawArguments.Count -gt 0) { $command = @($rawArguments | ConvertTo-EscapedArgument) -join ' ' } } $invokeParams.CommandLine = $command } if ($Arguments) { $invokeParams.CommandLine += " $Arguments" } Invoke-Executable @invokeParams }

That results in this error:

'ConvertFrom-EscapedArgument))' is not recognized as an internal or external command, operable program or batch file.

Anyone have a clue what's wrong?

My Powershell version is:

  Name Value
  ---- -----
  PSVersion 5.1.17763.5328
  PSEdition Desktop
  PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...}
  BuildVersion 10.0.17763.5328
  CLRVersion 4.0.30319.42000
  WSManStackVersion 3.0
  PSRemotingProtocolVersion 2.3
  SerializationVersion 1.1.0.1

.net version is:

  Release in one case says =0x00080eb1=
  InstallPath =C:\Windows\Microsoft.Net\Framework64\v4.0.30319=
  Version =4.8.03761=

The above fails with:

  The win_package action failed to execute in the expected time frame (5) and was terminated.

OK, I was being stupid. There was a timeout: 5 at the top of my play.

win_package now hangs while trying to install. I've disabled UAC, but
still it just hangs.

Divan Santana <divan@santanas.co.za> writes:

The above fails with:

  The win_package action failed to execute in the expected time frame (5) and was terminated.

OK, I was being stupid. There was a timeout: 5 at the top of my play.

win_package now hangs while trying to install. I've disabled UAC, but
still it just hangs.

OK, the win_package install works fine too. Seems one needs to look at
the exe maker and figure out which switch to use for a silent install.