Error: privilege output closed while waiting for password prompt

[DebtFromAbove]

Hi, I get the error written in the issue title when the role tries to auto detect the Virtualbox guest additions version.

I'm running ansible 2.6.1 with python 2.7.13. The guest VM is ubuntu 18.04 LTS running xubuntu desktop, the command I am running is as follows:

ansible-playbook -i ./hosts --limit=netboot_test --vault-password-file=./vault_pass.txt -u simon -K -v main.yml

and the playbook I am running looks like:

- hosts: testvms
  become: true
  roles:
    - PeterMosmans.virtualbox-guest
    - testvms

The -K option above causes ansible playbook command to prompt me for the sudo password and I haven't had a problem like this with any of my other roles or playbooks.

I get the same result when using become_method: sudo

The output that I get is as follows:

PLAY [testvms] **********************************************************************************************************************************************************************************************************************

TASK [Gathering Facts] **************************************************************************************************************************************************************************************************************
Sunday 30 December 2018 20:25:10 +0000 (0:00:00.228) 0:00:33.487 *******
ok: [netboot_test]

TASK [PeterMosmans.virtualbox-guest : remove os packages version of virtualbox guest additions] *************************************************************************************************************************************
Sunday 30 December 2018 20:25:15 +0000 (0:00:04.633) 0:00:38.120 *******
skipping: [netboot_test] => (item=[]) => {"changed": false, "item": [], "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : If virtualbox_version is set to auto then determine the host version] *************************************************************************************************************************
Sunday 30 December 2018 20:25:15 +0000 (0:00:00.250) 0:00:38.370 *******
fatal: [netboot_test]: FAILED! => {"msg": "privilege output closed while waiting for password prompt:\n/bin/sh: sudo: command not found\n"}
to retry, use: --limit @/cygdrive/d/test-server/gammavm/main.retry

Any help or suggestions appreciated.

[PeterMosmans]

Hi @DebtFromAbove - thanks for reporting this issue. Have you tried to specify a specific number, e.g. 6.0.0 for version? Does that work as intended?

[DebtFromAbove]

I've just tried that, specifying 5.2.22 and it appears to work, at least it gets past the task that had the issue before, but unfortunately it didn't succeed. It appears that it failed to upgrade (remove and install new) from 5.2.18 to 5.2.22. Here is the latest output:

PLAY [testvms] ********************************************************************************************************************************************************************************************

TASK [Gathering Facts] ************************************************************************************************************************************************************************************
Sunday 30 December 2018  22:54:00 +0000 (0:00:00.460)       0:01:27.078 *******
ok: [netboot_test]

TASK [PeterMosmans.virtualbox-guest : remove os packages version of virtualbox guest additions] ***********************************************************************************************************
Sunday 30 December 2018  22:54:14 +0000 (0:00:14.256)       0:01:41.335 *******
skipping: [netboot_test] => (item=[])  => {"changed": false, "item": [], "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : If virtualbox_version is set to auto then determine the host version] ***********************************************************************************************
Sunday 30 December 2018  22:54:15 +0000 (0:00:00.836)       0:01:42.171 *******
skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Check if virtualbox_version could be determined] ********************************************************************************************************************
Sunday 30 December 2018  22:54:16 +0000 (0:00:00.371)       0:01:42.543 *******
skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Override virtualbox_version if defaults set to auto] ****************************************************************************************************************
Sunday 30 December 2018  22:54:16 +0000 (0:00:00.380)       0:01:42.924 *******
skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Determine if (the requested version of) vboxguestadditions is installed] ********************************************************************************************
Sunday 30 December 2018  22:54:16 +0000 (0:00:00.367)       0:01:43.291 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: vbox_guest_version.stdout != "{{ virtualbox_version }}"

changed: [netboot_test] => {"changed": true, "cmd": "modinfo vboxguest 2>/dev/null|awk '/^version/{print $2}'", "delta": "0:00:00.125222", "end": "2018-12-30 22:54:24.880434", "rc": 0, "start": "2018-12-30 22:54:24.755212", "stderr": "", "stderr_lines": [], "stdout": "5.2.18_Ubuntu", "stdout_lines": ["5.2.18_Ubuntu"]}

TASK [PeterMosmans.virtualbox-guest : Check if the ISO file is present on the host] ***********************************************************************************************************************
Sunday 30 December 2018  22:54:25 +0000 (0:00:08.202)       0:01:51.494 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"changed": false, "stat": {"exists": false}}

TASK [PeterMosmans.virtualbox-guest : Check if the CD is present on the host] *****************************************************************************************************************************
Sunday 30 December 2018  22:54:32 +0000 (0:00:07.042)       0:01:58.536 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"changed": false, "stat": {"atime": 1546207268.148, "attr_flags": "", "attributes": [], "block_size": 4096, "blocks": 0, "charset": "binary", "ctime": 1546207777.4203043, "dev": 6, "device_type": 2816, "executable": false, "exists": true, "gid": 24, "gr_name": "cdrom", "inode": 151, "isblk": true, "ischr": false, "isdir": false, "isfifo": false, "isgid": false, "islnk": false, "isreg": false, "issock": false, "isuid": false, "mimetype": "inode/blockdevice", "mode": "0660", "mtime": 1546207268.148, "nlink": 1, "path": "/dev/sr0", "pw_name": "root", "readable": true, "rgrp": true, "roth": false, "rusr": true, "size": 0, "uid": 0, "version": null, "wgrp": true, "woth": false, "writeable": true, "wusr": true, "xgrp": false, "xoth": false, "xusr": false}}

TASK [PeterMosmans.virtualbox-guest : Check if CD or ISO file is present on the host] *********************************************************************************************************************
Sunday 30 December 2018  22:54:38 +0000 (0:00:06.535)       0:02:05.072 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

skipping: [netboot_test] => {}

TASK [PeterMosmans.virtualbox-guest : Download ISO file when the requested version is not present on the host] ********************************************************************************************
Sunday 30 December 2018  22:54:39 +0000 (0:00:00.396)       0:02:05.469 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Re-check if the ISO file is present on the host] ********************************************************************************************************************
Sunday 30 December 2018  22:54:39 +0000 (0:00:00.418)       0:02:05.887 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"changed": false, "stat": {"exists": false}}

TASK [PeterMosmans.virtualbox-guest : Fail if CD or ISO file is still not present on the host] ************************************************************************************************************
Sunday 30 December 2018  22:54:45 +0000 (0:00:06.304)       0:02:12.192 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Use correct ISO path (file or CD)] **********************************************************************************************************************************
Sunday 30 December 2018  22:54:46 +0000 (0:00:00.506)       0:02:12.699 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"ansible_facts": {"ISO_path": "/dev/sr0"}, "changed": false}

TASK [PeterMosmans.virtualbox-guest : Check if VBoxGuest additions ISO is mounted] ************************************************************************************************************************
Sunday 30 December 2018  22:54:47 +0000 (0:00:01.047)       0:02:13.747 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

 [WARNING]: Consider using the mount module rather than running mount.  If you need to use command because mount is insufficient you can add warn=False to this command task or set command_warnings=False
in ansible.cfg to get rid of this message.

ok: [netboot_test] => {"changed": false, "cmd": "mount -l 2>/dev/null|awk '/VBOXADDITIONS/{print $3}'", "delta": "0:00:00.872827", "end": "2018-12-30 22:54:54.742316", "rc": 0, "start": "2018-12-30 22:54:53.869489", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

TASK [PeterMosmans.virtualbox-guest : Mount VBoxGuestAdditions] *******************************************************************************************************************************************
Sunday 30 December 2018  22:54:54 +0000 (0:00:07.476)       0:02:21.223 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: mount_path is defined and "{{ mount_path.stdout }}" == ""

changed: [netboot_test] => {"changed": true, "dump": "0", "fstab": "/etc/fstab", "fstype": "iso9660", "name": "/media/cdrom", "opts": "noauto", "passno": "0", "src": "/dev/sr0"}

TASK [PeterMosmans.virtualbox-guest : Check if VBoxGuest additions ISO is mounted] ************************************************************************************************************************
Sunday 30 December 2018  22:55:03 +0000 (0:00:08.673)       0:02:29.897 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

changed: [netboot_test] => {"changed": true, "cmd": "mount -l 2>/dev/null|awk '/VBOXADDITIONS/{print $3}'", "delta": "0:00:00.261832", "end": "2018-12-30 22:55:15.138540", "rc": 0, "start": "2018-12-30 22:55:14.876708", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

TASK [PeterMosmans.virtualbox-guest : Find out kernel version] ********************************************************************************************************************************************
Sunday 30 December 2018  22:55:15 +0000 (0:00:11.824)       0:02:41.721 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"changed": false, "cmd": "uname -r", "delta": "0:00:00.040214", "end": "2018-12-30 22:55:22.231922", "rc": 0, "start": "2018-12-30 22:55:22.191708", "stderr": "", "stderr_lines": [], "stdout": "4.15.0-43-generic", "stdout_lines": ["4.15.0-43-generic"]}

TASK [PeterMosmans.virtualbox-guest : Find out architecture-independent kernel name] **********************************************************************************************************************
Sunday 30 December 2018  22:55:22 +0000 (0:00:06.959)       0:02:48.681 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"changed": false, "cmd": "uname -r | sed 's/-[az].*$//'", "delta": "0:00:00.053947", "end": "2018-12-30 22:55:29.892264", "rc": 0, "start": "2018-12-30 22:55:29.838317", "stderr": "", "stderr_lines": [], "stdout": "4.15.0-43-generic", "stdout_lines": ["4.15.0-43-generic"]}

TASK [PeterMosmans.virtualbox-guest : Save the current list of packages] **********************************************************************************************************************************
Sunday 30 December 2018  22:55:29 +0000 (0:00:07.590)       0:02:56.271 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

changed: [netboot_test] => {"changed": true, "cmd": "dpkg-query -l > /tmp/before.txt", "delta": "0:00:00.856935", "end": "2018-12-30 22:55:37.211453", "rc": 0, "start": "2018-12-30 22:55:36.354518", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

TASK [PeterMosmans.virtualbox-guest : Install necessary packages for compiling] ***************************************************************************************************************************
Sunday 30 December 2018  22:55:37 +0000 (0:00:07.324)       0:03:03.596 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => (item=[u'bzip2', u'dkms', u'gcc', u'make']) => {"cache_update_time": 1546210568, "cache_updated": true, "changed": false, "item": ["bzip2", "dkms", "gcc", "make"]}

TASK [PeterMosmans.virtualbox-guest : Install kernel headers] *********************************************************************************************************************************************
Sunday 30 December 2018  22:59:19 +0000 (0:03:41.853)       0:06:45.450 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"cache_update_time": 1546210568, "cache_updated": false, "changed": false}

TASK [PeterMosmans.virtualbox-guest : Check which packages were installed] ********************************************************************************************************************************
Sunday 30 December 2018  22:59:46 +0000 (0:00:27.346)       0:07:12.797 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

changed: [netboot_test] => {"changed": true, "cmd": "dpkg-query -l > /tmp/after.txt", "delta": "0:00:00.873970", "end": "2018-12-30 22:59:54.436959", "rc": 0, "start": "2018-12-30 22:59:53.562989", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

TASK [PeterMosmans.virtualbox-guest : Create a list of installed packages] ********************************************************************************************************************************
Sunday 30 December 2018  22:59:54 +0000 (0:00:07.991)       0:07:20.789 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

changed: [netboot_test] => {"changed": true, "cmd": "diff /tmp/before.txt /tmp/after.txt|awk '/>/{print $3}'", "delta": "0:00:00.063365", "end": "2018-12-30 23:00:01.308045", "rc": 0, "start": "2018-12-30 23:00:01.244680", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}

TASK [PeterMosmans.virtualbox-guest : Build and install x11 VBoxGuestAdditions from file] *****************************************************************************************************************
Sunday 30 December 2018  23:00:01 +0000 (0:00:06.914)       0:07:27.703 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

skipping: [netboot_test] => {"changed": false, "skip_reason": "Conditional result was False"}

TASK [PeterMosmans.virtualbox-guest : Build and install VBoxGuestAdditions from file] *********************************************************************************************************************
Sunday 30 December 2018  23:00:01 +0000 (0:00:00.368)       0:07:28.072 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

fatal: [netboot_test]: FAILED! => {"changed": true, "cmd": "/bin/bash /media/cdrom/VBoxLinuxAdditions.run --nox11", "delta": "0:00:04.143966", "end": "2018-12-30 23:00:12.723778", "msg": "non-zero return code", "rc": 1, "start": "2018-12-30 23:00:08.579812", "stderr": "VirtualBox Guest Additions installer\nThis system appears to have a version of the VirtualBox Guest Additions\nalready installed.  If it is part of the operating system and kept up-to-date,\nthere is most likely no need to replace it.  If it is not up-to-date, you\nshould get a notification when you start the system.  If you wish to replace\nit with this version, please do not continue with this installation now, but\ninstead remove the current version first, following the instructions for the\noperating system.\n\nIf your system simply has the remains of a version of the Additions you could\nnot remove you should probably continue now, and these will be removed during\ninstallation.\n\nDo you wish to continue? [yes or no]\n\nCancelling installation.", "stderr_lines": ["VirtualBox Guest Additions installer", "This system appears to have a version of the VirtualBox Guest Additions", "already installed.  If it is part of the operating system and kept up-to-date,", "there is most likely no need to replace it.  If it is not up-to-date, you", "should get a notification when you start the system.  If you wish to replace", "it with this version, please do not continue with this installation now, but", "instead remove the current version first, following the instructions for the", "operating system.", "", "If your system simply has the remains of a version of the Additions you could", "not remove you should probably continue now, and these will be removed during", "installation.", "", "Do you wish to continue? [yes or no]", "", "Cancelling installation."], "stdout": "Verifying archive integrity... All good.\nUncompressing VirtualBox 5.2.22 Guest Additions for Linux........", "stdout_lines": ["Verifying archive integrity... All good.", "Uncompressing VirtualBox 5.2.22 Guest Additions for Linux........"]}
...ignoring

TASK [PeterMosmans.virtualbox-guest : Unmount VBoxGuestAdditions] *****************************************************************************************************************************************
Sunday 30 December 2018  23:00:12 +0000 (0:00:11.030)       0:07:39.103 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

[DEPRECATION WARNING]: Using tests as filters is deprecated. Instead of using `result|changed` use `result is changed`. This feature will be removed in version 2.9. Deprecation warnings can be disabled
by setting deprecation_warnings=False in ansible.cfg.
ok: [netboot_test] => {"changed": false, "dump": "0", "fstab": "/etc/fstab", "fstype": "iso9660", "name": "", "opts": "defaults", "passno": "0", "src": "/dev/sr0"}

TASK [PeterMosmans.virtualbox-guest : Remove installed packages for compiling] ****************************************************************************************************************************
Sunday 30 December 2018  23:00:20 +0000 (0:00:07.487)       0:07:46.590 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => {"cache_update_time": 1546210568, "cache_updated": false, "changed": false}

TASK [PeterMosmans.virtualbox-guest : Remove build logfiles, artefacts and ISO files] *********************************************************************************************************************
Sunday 30 December 2018  23:00:36 +0000 (0:00:16.577)       0:08:03.168 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

ok: [netboot_test] => (item=/opt/VBoxGuestAdditions-5.2.22/src) => {"changed": false, "item": "/opt/VBoxGuestAdditions-5.2.22/src", "path": "/opt/VBoxGuestAdditions-5.2.22/src", "state": "absent"}
ok: [netboot_test] => (item=/root/VBoxGuestAdditions.iso) => {"changed": false, "item": "/root/VBoxGuestAdditions.iso", "path": "/root/VBoxGuestAdditions.iso", "state": "absent"}
changed: [netboot_test] => (item=/tmp/before.txt) => {"changed": true, "item": "/tmp/before.txt", "path": "/tmp/before.txt", "state": "absent"}
changed: [netboot_test] => (item=/tmp/after.txt) => {"changed": true, "item": "/tmp/after.txt", "path": "/tmp/after.txt", "state": "absent"}
ok: [netboot_test] => (item=/usr/src/vboxguest-5.2.22) => {"changed": false, "item": "/usr/src/vboxguest-5.2.22", "path": "/usr/src/vboxguest-5.2.22", "state": "absent"}
ok: [netboot_test] => (item=/var/lib/dkms/vboxguest) => {"changed": false, "item": "/var/lib/dkms/vboxguest", "path": "/var/lib/dkms/vboxguest", "state": "absent"}
changed: [netboot_test] => (item=/var/log/vboxadd-install.log) => {"changed": true, "item": "/var/log/vboxadd-install.log", "path": "/var/log/vboxadd-install.log", "state": "absent"}
ok: [netboot_test] => (item=/var/log/vboxadd-install-x11.log) => {"changed": false, "item": "/var/log/vboxadd-install-x11.log", "path": "/var/log/vboxadd-install-x11.log", "state": "absent"}
ok: [netboot_test] => (item=/var/log/VBoxGuestAdditions.log) => {"changed": false, "item": "/var/log/VBoxGuestAdditions.log", "path": "/var/log/VBoxGuestAdditions.log", "state": "absent"}
ok: [netboot_test] => (item=/var/log/VBoxGuestAdditions-uninstall.log) => {"changed": false, "item": "/var/log/VBoxGuestAdditions-uninstall.log", "path": "/var/log/VBoxGuestAdditions-uninstall.log", "state": "absent"}

TASK [PeterMosmans.virtualbox-guest : Remove cdrom fstab entry] *******************************************************************************************************************************************
Sunday 30 December 2018  23:01:50 +0000 (0:01:13.634)       0:09:16.802 *******
 [WARNING]: when statements should not include jinja2 templating delimiters such as {{ }} or {% %}. Found: (vbox_guest_version.stdout != "{{ virtualbox_version }}")

[DEPRECATION WARNING]: Using tests as filters is deprecated. Instead of using `result|changed` use `result is changed`. This feature will be removed in version 2.9. Deprecation warnings can be disabled
by setting deprecation_warnings=False in ansible.cfg.
changed: [netboot_test] => {"backup": "", "changed": true, "found": 1, "msg": "1 line(s) removed"}

[DebtFromAbove]

I've got an idea why the first attempt failed. Looking at your code, it specified local_action for the "If vbox-guest-additions version is 'auto'..." task. Am I right in thinking that causes the command to be run on the ansible server, not the host?

If that is the case I am running ansible on windows using Cygwin64. This isn't supported by ansible currently but seems to work for everything i've needed so far (including integration with vagrant). But it seems VBoxManage is not a command that is accessible in the current cygwin path on windows, even though I'm sure those command line virtualbox commands are accessible somewhere in windows. It might just be a case of needing to modify the cygwin path to add in their location

Doesn't explain why it didn't upgrade to 5.2.22 when i specified the version directly though