Gathering facts for windows hosts runs forever/never completes
26 views
Skip to first unread message
Gustaf Ankarloo
Mar 14, 2019, 6:10:32 AM3/14/19
to Ansible Project
From time to time I find that some windows hosts never completes the setup task.
I never quite figured out why it happens. Usually restarting the window server solves the issue but looking at the windows server I see nothing wrong.
The applications on the windows server is working fine.
This what shows in the log:
2019-03-14 10:20:38,305 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 847
2019-03-14 10:20:38,697 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 753
2019-03-14 10:20:58,705 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:21:18,712 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:21:38,720 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
...
And here is an exerpt of a full log with ANSIBLE_DEBUG=1 and -vvvvvvv
2019-03-14 10:20:37,642 p=8409 u=XXX| 8409 1552555237.64232: Loaded config def from plugin (callback/yaml)
2019-03-14 10:20:37,642 p=8409 u=XXX | 8409 1552555237.64252: in VariableManager get_vars()
2019-03-14 10:20:37,651 p=8409 u=XXX | 8409 1552555237.65143: Loading TestModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/core.py
2019-03-14 10:20:37,654 p=8409 u=XXX | 8409 1552555237.65443: Loading TestModule 'files' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/files.py
2019-03-14 10:20:37,657 p=8409 u=XXX | 8409 1552555237.65740: Loading TestModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/mathstuff.py
2019-03-14 10:20:37,693 p=8409 u=XXX | 8409 1552555237.69369: Loading FilterModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/core.py
2019-03-14 10:20:37,701 p=8409 u=XXX | 8409 1552555237.70172: Loading FilterModule 'ipaddr' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/ipaddr.py
2019-03-14 10:20:37,741 p=8409 u=XXX | 8409 1552555237.74095: Loading FilterModule 'json_query' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/json_query.py
2019-03-14 10:20:37,746 p=8409 u=XXX | 8409 1552555237.74609: Loading FilterModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/mathstuff.py
2019-03-14 10:20:37,762 p=8409 u=XXX | 8409 1552555237.76242: Loading FilterModule 'network' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/network.py
2019-03-14 10:20:37,765 p=8409 u=XXX | 8409 1552555237.76552: Loading FilterModule 'urlsplit' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/urlsplit.py
2019-03-14 10:20:37,769 p=8409 u=XXX | 8409 1552555237.76903: done with get_vars()
2019-03-14 10:20:37,777 p=8409 u=XXX | 8409 1552555237.77765: Loading StrategyModule 'linear' from /usr/lib/python2.7/dist-packages/ansible/plugins/strategy/linear.py
2019-03-14 10:20:37,780 p=8409 u=XXX | 8409 1552555237.77918: getting the remaining hosts for this loop
2019-03-14 10:20:37,780 p=8409 u=XXX | 8409 1552555237.78031: done getting the remaining hosts for this loop
2019-03-14 10:20:37,780 p=8409 u=XXX | 8409 1552555237.78054: building list of next tasks for hosts
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78100: getting the next task for host REDACTED
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78126: done getting next task for host REDACTED
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78145: ^ task is: TASK: meta (flush_handlers)
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78161: ^ state is: HOST STATE: block=1, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78177: done building task lists
2019-03-14 10:20:37,781 p=8409 u=XXX | 8409 1552555237.78191: counting tasks in each state of execution
2019-03-14 10:20:37,782 p=8409 u=XXX | 8409 1552555237.78207: done counting tasks in each state of execution:
num_setups: 0
num_tasks: 1
num_rescue: 0
num_always: 0
2019-03-14 10:20:37,782 p=8409 u=XXX | 8409 1552555237.78223: advancing hosts in ITERATING_TASKS
2019-03-14 10:20:37,782 p=8409 u=XXX | 8409 1552555237.78237: starting to advance hosts
2019-03-14 10:20:37,782 p=8409 u=XXX | 8409 1552555237.78274: getting the next task for host REDACTED
2019-03-14 10:20:37,782 p=8409 u=XXX | 8409 1552555237.78291: done getting next task for host REDACTED
2019-03-14 10:20:37,783 p=8409 u=XXX | 8409 1552555237.78308: ^ task is: TASK: meta (flush_handlers)
2019-03-14 10:20:37,783 p=8409 u=XXX | 8409 1552555237.78324: ^ state is: HOST STATE: block=1, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
2019-03-14 10:20:37,783 p=8409 u=XXX | 8409 1552555237.78338: done advancing hosts to next task
2019-03-14 10:20:37,783 p=8409 u=XXX | META: ran handlers
2019-03-14 10:20:37,784 p=8409 u=XXX | 8409 1552555237.78394: done queuing things up, now waiting for results queue to drain
2019-03-14 10:20:37,784 p=8409 u=XXX | 8409 1552555237.78435: results queue empty
2019-03-14 10:20:37,784 p=8409 u=XXX | 8409 1552555237.78450: checking for any_errors_fatal
2019-03-14 10:20:37,784 p=8409 u=XXX | 8409 1552555237.78468: done checking for any_errors_fatal
2019-03-14 10:20:37,784 p=8409 u=XXX | 8409 1552555237.78483: checking for max_fail_percentage
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78497: done checking for max_fail_percentage
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78512: checking to see if all hosts have failed and the running result is not ok
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78526: done checking to see if all hosts have failed
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78540: getting the remaining hosts for this loop
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78555: done getting the remaining hosts for this loop
2019-03-14 10:20:37,785 p=8409 u=XXX | 8409 1552555237.78572: building list of next tasks for hosts
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78614: getting the next task for host REDACTED
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78631: done getting next task for host REDACTED
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78648: ^ task is: TASK: setup
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78663: ^ state is: HOST STATE: block=2, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78678: done building task lists
2019-03-14 10:20:37,786 p=8409 u=XXX | 8409 1552555237.78692: counting tasks in each state of execution
2019-03-14 10:20:37,787 p=8409 u=XXX | 8409 1552555237.78707: done counting tasks in each state of execution:
num_setups: 0
num_tasks: 1
num_rescue: 0
num_always: 0
2019-03-14 10:20:37,787 p=8409 u=XXX | 8409 1552555237.78744: advancing hosts in ITERATING_TASKS
2019-03-14 10:20:37,787 p=8409 u=XXX | 8409 1552555237.78759: starting to advance hosts
2019-03-14 10:20:37,787 p=8409 u=XXX | 8409 1552555237.78773: getting the next task for host REDACTED
2019-03-14 10:20:37,787 p=8409 u=XXX | 8409 1552555237.78790: done getting next task for host REDACTED
2019-03-14 10:20:37,788 p=8409 u=XXX | 8409 1552555237.78807: ^ task is: TASK: setup
2019-03-14 10:20:37,788 p=8409 u=XXX | 8409 1552555237.78828: ^ state is: HOST STATE: block=2, task=1, rescue=0, always=0, run_state=ITERATING_TASKS, fail_state=FAILED_NONE, pending_setup=False, tasks child state? (None), rescue child state? (None), always child state? (None), did rescue? False, did start at task? False
2019-03-14 10:20:37,788 p=8409 u=XXX | 8409 1552555237.78843: done advancing hosts to next task
2019-03-14 10:20:37,788 p=8409 u=XXX | 8409 1552555237.78883: getting variables
2019-03-14 10:20:37,789 p=8409 u=XXX | 8409 1552555237.78898: in VariableManager get_vars()
2019-03-14 10:20:37,789 p=8409 u=XXX | 8409 1552555237.78943: Loading TestModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/core.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,789 p=8409 u=XXX | 8409 1552555237.78961: Loading TestModule 'files' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/files.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,790 p=8409 u=XXX | 8409 1552555237.78993: Loading TestModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/mathstuff.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,790 p=8409 u=XXX | 8409 1552555237.79048: Loading FilterModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/core.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,790 p=8409 u=XXX | 8409 1552555237.79065: Loading FilterModule 'ipaddr' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/ipaddr.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,790 p=8409 u=XXX | 8409 1552555237.79081: Loading FilterModule 'json_query' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/json_query.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,791 p=8409 u=XXX | 8409 1552555237.79098: Loading FilterModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/mathstuff.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,791 p=8409 u=XXX | 8409 1552555237.79135: Loading FilterModule 'network' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/network.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,791 p=8409 u=XXX | 8409 1552555237.79151: Loading FilterModule 'urlsplit' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/urlsplit.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,792 p=8409 u=XXX | 8409 1552555237.79237: Calling all_inventory to load vars for REDACTED
2019-03-14 10:20:37,792 p=8409 u=XXX | 8409 1552555237.79275: Calling groups_inventory to load vars for REDACTED
2019-03-14 10:20:37,793 p=8409 u=XXX | 8409 1552555237.79297: Calling all_plugins_inventory to load vars for REDACTED
2019-03-14 10:20:37,801 p=8409 u=XXX | 8409 1552555237.80124: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py
2019-03-14 10:20:37,801 p=8409 u=XXX | 8409 1552555237.80157: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,802 p=8409 u=XXX | 8409 1552555237.80208: Loading data from /home/XXX/ansible/inventory/group_vars/all/main.yml
2019-03-14 10:20:37,804 p=8409 u=XXX | 8409 1552555237.80438: Loading data from /home/XXX/ansible/inventory/group_vars/all/vault.yml
2019-03-14 10:20:37,807 p=8409 u=XXX | Found a vault_id (default) in the vaulttext
2019-03-14 10:20:37,807 p=8409 u=XXX | We have a secret associated with vault id (default), will try to use to decrypt /home/XXX/ansible/inventory/group_vars/all/vault.yml
2019-03-14 10:20:37,807 p=8409 u=XXX | Trying to use vault secret=(FileVaultSecret(filename='/home/XXX/.vault-apmt')) id=default to decrypt /home/XXX/ansible/inventory/group_vars/all/vault.yml
2019-03-14 10:20:37,807 p=8409 u=XXX | Trying secret FileVaultSecret(filename='/home/XXX/.vault-apmt') for vault_id=default
2019-03-14 10:20:37,842 p=8409 u=XXX | Decrypt of "/home/XXX/ansible/inventory/group_vars/all/vault.yml" successful with secret=FileVaultSecret(filename='/home/XXX/.vault-apmt') and vault_id=default
2019-03-14 10:20:37,843 p=8409 u=XXX | 8409 1552555237.84305: Calling all_plugins_play to load vars for REDACTED
2019-03-14 10:20:37,843 p=8409 u=XXX | 8409 1552555237.84341: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,843 p=8409 u=XXX | 8409 1552555237.84360: Calling groups_plugins_inventory to load vars for REDACTED
2019-03-14 10:20:37,844 p=8409 u=XXX | 8409 1552555237.84397: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,844 p=8409 u=XXX | 8409 1552555237.84426: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,844 p=8409 u=XXX | 8409 1552555237.84463: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,845 p=8409 u=XXX | 8409 1552555237.84500: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,845 p=8409 u=XXX | 8409 1552555237.84538: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,845 p=8409 u=XXX | 8409 1552555237.84574: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,846 p=8409 u=XXX | 8409 1552555237.84611: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,846 p=8409 u=XXX | 8409 1552555237.84646: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,846 p=8409 u=XXX | 8409 1552555237.84682: processing dir /home/XXX/ansible/inventory/group_vars
2019-03-14 10:20:37,847 p=8409 u=XXX | 8409 1552555237.84732: Loading data from /home/XXX/ansible/inventory/group_vars/windowsGuest/main.yml
2019-03-14 10:20:37,849 p=8409 u=XXX | 8409 1552555237.84973: Loading data from /home/XXX/ansible/inventory/group_vars/windowsGuest/vault.yml
2019-03-14 10:20:37,852 p=8409 u=XXX | Found a vault_id (default) in the vaulttext
2019-03-14 10:20:37,852 p=8409 u=XXX | We have a secret associated with vault id (default), will try to use to decrypt /home/XXX/ansible/inventory/group_vars/windowsGuest/vault.yml
2019-03-14 10:20:37,852 p=8409 u=XXX | Trying to use vault secret=(FileVaultSecret(filename='/home/XXX/.vault-apmt')) id=default to decrypt /home/XXX/ansible/inventory/group_vars/windowsGuest/vault.yml
2019-03-14 10:20:37,852 p=8409 u=XXX | Trying secret FileVaultSecret(filename='/home/XXX/.vault-apmt') for vault_id=default
2019-03-14 10:20:37,885 p=8409 u=XXX | Decrypt of "/home/XXX/ansible/inventory/group_vars/windowsGuest/vault.yml" successful with secret=FileVaultSecret(filename='/home/XXX/.vault-apmt') and vault_id=default
2019-03-14 10:20:37,886 p=8409 u=XXX | 8409 1552555237.88607: Calling groups_plugins_play to load vars for REDACTED
2019-03-14 10:20:37,886 p=8409 u=XXX | 8409 1552555237.88640: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,886 p=8409 u=XXX | 8409 1552555237.88679: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,887 p=8409 u=XXX | 8409 1552555237.88706: processing dir /home/XXX/ansible/inventory/host_vars
2019-03-14 10:20:37,887 p=8409 u=XXX | 8409 1552555237.88755: Loading VarsModule 'host_group_vars' from /usr/lib/python2.7/dist-packages/ansible/plugins/vars/host_group_vars.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,897 p=8409 u=XXX | 8409 1552555237.89733: done with get_vars()
2019-03-14 10:20:37,897 p=8409 u=XXX | 8409 1552555237.89765: done getting variables
2019-03-14 10:20:37,897 p=8409 u=XXX | 8409 1552555237.89785: sending task start callback, copying the task so we can template it temporarily
2019-03-14 10:20:37,898 p=8409 u=XXX | 8409 1552555237.89802: done copying, going to template now
2019-03-14 10:20:37,898 p=8409 u=XXX | 8409 1552555237.89820: done templating
2019-03-14 10:20:37,898 p=8409 u=XXX | 8409 1552555237.89835: here goes the callback...
2019-03-14 10:20:37,898 p=8409 u=XXX | 8409 1552555237.89853: sending task start callback
2019-03-14 10:20:37,898 p=8409 u=XXX | 8409 1552555237.89869: entering _queue_task() for REDACTED/setup
2019-03-14 10:20:37,901 p=8409 u=XXX | 8409 1552555237.90094: worker is 1 (out of 1 available)
2019-03-14 10:20:37,901 p=8409 u=XXX | 8409 1552555237.90177: exiting _queue_task() for REDACTED/setup
2019-03-14 10:20:37,902 p=8409 u=XXX | 8409 1552555237.90206: done queuing things up, now waiting for results queue to drain
2019-03-14 10:20:37,902 p=8409 u=XXX | 8409 1552555237.90224: waiting for pending results...
2019-03-14 10:20:37,906 p=8409 u=XXX | 8419 1552555237.90663: running TaskExecutor() for REDACTED/TASK: setup
2019-03-14 10:20:37,907 p=8409 u=XXX | 8419 1552555237.90734: in run() - task 005056a5-1e50-8181-16cb-00000000006e
2019-03-14 10:20:37,920 p=8409 u=XXX | 8419 1552555237.92072: calling self._execute()
2019-03-14 10:20:37,922 p=8409 u=XXX | 8419 1552555237.92231: Loading TestModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/core.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,922 p=8409 u=XXX | 8419 1552555237.92280: Loading TestModule 'files' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/files.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,923 p=8409 u=XXX | 8419 1552555237.92300: Loading TestModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/test/mathstuff.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,923 p=8409 u=XXX | 8419 1552555237.92376: Loading FilterModule 'core' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/core.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,924 p=8409 u=XXX | 8419 1552555237.92398: Loading FilterModule 'ipaddr' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/ipaddr.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,924 p=8409 u=XXX | 8419 1552555237.92421: Loading FilterModule 'json_query' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/json_query.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,924 p=8409 u=XXX | 8419 1552555237.92447: Loading FilterModule 'mathstuff' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/mathstuff.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,924 p=8409 u=XXX | 8419 1552555237.92466: Loading FilterModule 'network' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/network.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:37,924 p=8409 u=XXX | 8419 1552555237.92485: Loading FilterModule 'urlsplit' from /usr/lib/python2.7/dist-packages/ansible/plugins/filter/urlsplit.py (found_in_cache=True, class_only=False)
2019-03-14 10:20:38,085 p=8409 u=XXX | 8419 1552555238.08356: Loading Connection 'winrm' from /usr/lib/python2.7/dist-packages/ansible/plugins/connection/winrm.py
2019-03-14 10:20:38,087 p=8409 u=XXX | 8419 1552555238.08633: Loading ShellModule 'powershell' from /usr/lib/python2.7/dist-packages/ansible/plugins/shell/powershell.py
2019-03-14 10:20:38,096 p=8409 u=XXX | 8419 1552555238.09428: assigned :doc
2019-03-14 10:20:38,098 p=8409 u=XXX | 8419 1552555238.09661: Loaded config def from plugin (shell/powershell)
2019-03-14 10:20:38,106 p=8409 u=XXX | 8419 1552555238.10537: assigned :doc
2019-03-14 10:20:38,108 p=8409 u=XXX | 8419 1552555238.10747: Loaded config def from plugin (connection/winrm)
2019-03-14 10:20:38,114 p=8409 u=XXX | 8419 1552555238.11334: Loading ActionModule 'normal' from /usr/lib/python2.7/dist-packages/ansible/plugins/action/normal.py
2019-03-14 10:20:38,116 p=8409 u=XXX | 8419 1552555238.11504: starting attempt loop
2019-03-14 10:20:38,116 p=8409 u=XXX | 8419 1552555238.11662: running the handler
2019-03-14 10:20:38,142 p=8409 u=XXX | Using module file /usr/lib/python2.7/dist-packages/ansible/modules/windows/setup.ps1
2019-03-14 10:20:38,142 p=8409 u=XXX | 8419 1552555238.14275: _low_level_execute_command(): starting
2019-03-14 10:20:38,143 p=8409 u=XXX | 8419 1552555238.14293: _low_level_execute_command(): executing: -
2019-03-14 10:20:38,143 p=8409 u=XXX | checking if winrm_host xx.xx.xx.xx is an IPv6 address
2019-03-14 10:20:38,151 urllib3.connectionpool Starting new HTTPS connection (1): xx.xx.xx.xx:5986
2019-03-14 10:20:38,279 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 1627
2019-03-14 10:20:38,281 p=8409 u=XXX | EXEC (via pipeline wrapper)
2019-03-14 10:20:38,305 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 847
2019-03-14 10:20:38,697 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 753
2019-03-14 10:20:58,705 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:21:18,712 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:21:38,720 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:21:58,728 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:22:18,737 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:22:38,745 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:22:58,753 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:23:18,761 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:23:38,773 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:23:58,785 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:24:18,793 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:24:38,800 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:24:58,809 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:25:18,817 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:25:38,826 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:25:58,834 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:26:18,844 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:26:38,851 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:26:58,860 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:27:18,871 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:27:38,879 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:27:58,887 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:28:18,895 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:28:38,902 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:28:58,910 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:29:18,918 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 500 1320
2019-03-14 10:29:21,530 urllib3.connectionpool Starting new HTTPS connection (2): xx.xx.xx.xx:5986
2019-03-14 10:29:21,532 p=8409 u=XXX | 8409 1552555761.53071: RUNNING CLEANUP
2019-03-14 10:29:21,536 p=8409 u=XXX | [ERROR]: User interrupted execution
2019-03-14 10:29:21,565 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 757
2019-03-14 10:29:21,577 urllib3.connectionpool https://xx.xx.xx.xx:5986 "POST /wsman HTTP/1.1" 200 602
Jordan Borean
Mar 18, 2019, 3:30:43 PM3/18/19
to Ansible Project
What version of ansible are you on? IIRC there was a bug fixed in an older release that caused it to be really slow in a domain environment. It was fixed in 2.4, 2.5 https://github.com/ansible/ansible/pull/38646.
If that isn't it you can use gather subset to try and track down what subset is hanging like;
- hosts: windows
gather_facts: no
tasks:
- setup:
gather_subset: # uncomment it one by one until it starts hanging
- min
#- hardware
#- network
#- external
You can get a full list of groups here https://github.com/ansible/ansible/blob/devel/lib/ansible/modules/windows/setup.ps1#L68.
Thanks
Jordan
Gustaf Ankarloo
Mar 21, 2019, 5:51:34 AM3/21/19
to ansible...@googlegroups.com
Thank you for your suggestions.
I'm in version 2.7.0
and apparently it's the 'platform' subset that hangs.
--
You received this message because you are subscribed to the Google Groups "Ansible Project" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ansible-proje...@googlegroups.com.
To post to this group, send email to ansible...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ansible-project/ad918a57-5ebb-4588-965a-3c61aeb209c1%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
--
MVH
Gustaf Ankarloo
0723-232344
Reply all
Reply to author
Forward
0 new messages