WinRM error when running win_updates task

[aventrax]

SUMMARY

The execution of the win_updates task (observed reliably when hitting a Windows 2012 R2 Standard) fails reliably as follows:

- msg: Unexpected failure during module execution.(The error was: winrm.exceptions.WinRMTransportError: Bad HTTP response returned from server. Code 400)

ISSUE TYPE

• Bug Report

COMPONENT NAME

WinRM

ANSIBLE VERSION

ansible [core 2.11.4] 
config file = /home/matteo/.ansible.cfg
configured module search path = ['/home/matteo/.ansible/plugins/modules', '/usr/share/ansible/plugins/modules']
ansible python module location = /opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible
ansible collection location = /home/matteo/.ansible/collections:/usr/share/ansible/collections
executable location = /opt/python-virtual-envs/ansible/bin/ansible
python version = 3.9.2 (default, Feb 28 2021, 17:03:44) [GCC 10.2.1 20210110]
jinja version = 3.0.1
libyaml = True

COLLECTION VERSION

# /opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible_collections
Collection      Version
--------------- -------
ansible.windows 1.7.2

CONFIGURATION

HOST_KEY_CHECKING(/home/matteo/.ansible.cfg) = False

OS / ENVIRONMENT

Controller on Debian 11, Target is: Windows 2012 R2 Standard

STEPS TO REPRODUCE

  - name: Install all updates and reboot as many times as needed
    ansible.windows.win_updates:
      category_names: '*'
      reboot: yes
      reboot_timeout: 3600
      log_path: C:\ansible_wu.txt

EXPECTED RESULTS

Completion of the task without errors.

ACTUAL RESULTS

Failure with the following output

TASK [Install all updates and reboot as many times as needed] ******************************************************************************************************************************************************************************task path: /home/matteo/Ansible/MEDarchiver/vmware_create_windows_vm.yaml:200
<10.1.0.163> ESTABLISH WINRM CONNECTION FOR USER: Administrator on PORT 5985 TO 10.1.0.163
EXEC (via pipeline wrapper)
<10.1.0.163> PUT "/home/matteo/.ansible/tmp/ansible-local-14998anhj_wcy/tmp0zwozpj_/poll.ps1" TO "C:\Users\Administrator\AppData\Local\Temp\ansible-tmp-1629380723.396093-15106-263992598811696\poll.ps1"
<10.1.0.163> PUT "/home/matteo/.ansible/tmp/ansible-local-14998anhj_wcy/tmp3o90v4m4/cancel.ps1" TO "C:\Users\Administrator\AppData\Local\Temp\ansible-tmp-1629380723.396093-15106-263992598811696\cancel.ps1"
<10.1.0.163> Running win_updates - round 1
<10.1.0.163> Starting update task
Using module file /opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible_collections/ansible/windows/plugins/modules/win_updates.ps1
Pipelining is enabled.
EXEC (via pipeline wrapper)
<10.1.0.163> Starting polling for update results
EXEC (via pipeline wrapper)
EXEC (via pipeline wrapper)
<10.1.0.163> Downlad progress - Total: 77594/126795 61%, Update (VMware, Inc. - Net - 1.9.2.0): 77594/77594 100%, Phase: Downloading
<10.1.0.163> Downlad progress - Total: 126795/126795 100%, Update (VMware, Inc. - SCSIAdapter - 1.3.17.0): 49201/49201 100%, Phase: Downloading
<10.1.0.163> Update phase download completed
EXEC (via pipeline wrapper)
[WARNING]: Unknown failure when polling update result - attempting to cancel task: Bad HTTP response returned from server. Code 400
EXEC (via pipeline wrapper)
EXEC (via pipeline wrapper)
The full traceback is:
Traceback (most recent call last):
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/protocol.py", line 248, in send_message
    root = ET.fromstring(ex.response_text)
  File "/usr/lib/python3.9/xml/etree/ElementTree.py", line 1348, in XML
    return parser.close()
xml.etree.ElementTree.ParseError: no element found: line 1, column 0

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/executor/task_executor.py", line 158, in run
    res = self._execute()
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/executor/task_executor.py", line 596, in _execute
    self._handler.cleanup()
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/plugins/action/__init__.py", line 130, in cleanup
    self._remove_tmp_path(self._connection._shell.tmpdir)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/plugins/action/__init__.py", line 454, in _remove_tmp_path
    tmp_rm_res = self._low_level_execute_command(cmd, sudoable=False)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/plugins/action/__init__.py", line 1265, in _low_level_execute_command
    rc, stdout, stderr = self._connection.exec_command(cmd, in_data=in_data, sudoable=sudoable)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/plugins/connection/winrm.py", line 563, in exec_command
    result = self._winrm_exec(cmd_parts[0], cmd_parts[1:], from_exec=True, stdin_iterator=stdin_iterator)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/ansible/plugins/connection/winrm.py", line 473, in _winrm_exec
    command_id = self.protocol.run_command(self.shell_id, to_bytes(command), map(to_bytes, args), console_mode_stdin=(stdin_iterator is None))
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/protocol.py", line 359, in run_command
    res = self.send_message(xmltodict.unparse(req))
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/protocol.py", line 251, in send_message
    raise ex
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/protocol.py", line 243, in send_message
    resp = self.transport.send_message(message)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/transport.py", line 334, in send_message
    response = self._send_message_request(prepared_request, message)
  File "/opt/python-virtual-envs/ansible/lib/python3.9/site-packages/winrm/transport.py", line 350, in _send_message_request
    raise WinRMTransportError('http', ex.response.status_code, response_text)
winrm.exceptions.WinRMTransportError: Bad HTTP response returned from server. Code 400
fatal: [10.1.0.163]: FAILED! => {
    "msg": "Unexpected failure during module execution.",
    "stdout": ""
}

Found a reference here.

[jborean93]

Looking at the download update it seems like the update VMware, Inc. - Net - 1.9.2.0 might be bringing down the WinRM endpoint by bouncing the network connection and when we go back to poll for updates it fails because it's not yet ready again. This is a very delicate situation but it sounds like we need a generic retry x times when polling for results to try and handle these particular situations.

[Udayendu]

Switching to PSRP based connection and adding the wait_for_connection in your play should be able to fix it. I have this issue and now its going after using the PSRP. Unfortunately WinRM is too much sensitive to network and if from the OS side, some component is resetting the network, then no way to get the control again from the provision server:

- name: Wait for system to become reachable over WinRM
  wait_for_connection:
    sleep: 5
    delay: 30
    connect_timeout: 120
    timeout: 900
  register: result

- debug: var=result

• An example of update code that I am using without any issue:

---
- name: Wait for system to become reachable over WinRM
  wait_for_connection:
    sleep: 5
    delay: 30
    connect_timeout: 120
    timeout: 900
  register: result

- debug: var=result

- name: Install all security, critical, and rollup updates
  win_updates:
    category_names:
      - Updates
      - SecurityUpdates
      - CriticalUpdates
      - UpdateRollups
    reboot: yes
    state: installed
    reboot_timeout: 3600
  register: result

# Output of installed patches
- debug: var=result

- name: WinRM Port Status
  wait_for:
    port: 5986
    state: started
    delay: 10
    host: "{{ inventory_hostname }}"
    timeout: 600
  register: result
  delegate_to: localhost

- debug: var=result

Hope this will help.

[MalfuncEddie]

Hey @Udayendu could you eleborate your solution a bit?

is the entire playbook running on PSRP ? I got an issue that the delegate_to: localhost tries also to connect with PSRP

[Udayendu]

@MalfuncEddie

Yes, I had to switch from WinRM to PSRP. And my group vars also have that entry:

[windows]
ansible_user=example.com\domainadmin
ansible_password=XXXXXXXXXXXXXXXXX
ansible_port=5986
ansible_connection=psrp                                  <<<<
ansible_psrp_auth=credssp
ansible_psrp_cert_validation=ignore
ansible_psrp_connection_timeout=600
ansible_psrp_read_timeout=120
ansible_psrp_operation_timeout=60
ansible_psrp_reconnection_backoff=10
ansible_psrp_reconnection_retries=30

Using PSRP based connection, you have better control over the connection time out and delay as per the pipeline's requirement.