qubes-staging molecule scenario fails at create step

[emkll]

Description

qubes-staging molecule action fails to create (clone sd-$ROLE-base) in the adminvm:

"stderr": "app: Failed to clone appmenus, qvm-appmenus missing\nqvm-clone: error: Failed to clone appmenus", "stderr_lines": ["app: Failed to clone appmenus, qvm-appmenus missing", "qvm-clone: error: Failed to clone appmenus"], "stdout": "", "stdout_lines": []}

manually running qvm-clone results in the same error (and the VMs are not cloned):

app: Failed to clone appmenus, qvm-appmenus missing
qvm-clone: error: Failed to clone appmenus

Steps to Reproduce

1. Install staging environment in qubes (using https://docs.securedrop.org/en/release-0.10.0/development/qubes_staging.html)
2. molecule converge -s qubes-staging
3. observe error described above

Expected Behavior

molecule scenario should succeed and a SecureDrop staging environment should be created

Actual Behavior

Molecule scenario fails at the Create step

Comments

qvm-clone automatically uses the class of the source of the copy (--class StandaloneVM), and passing --class StandaloneVM does not address the issue.

Workaround is to qvm-clone the base VMs in dom0, and then run the molecule converge step in the adminVM. In dom0:

qvm-clone sd-app-base sd-app
qvm-tags sd-app add created-by-sd-dev

[deeplow]

Came across this issue the other day. And it quite obnoxious. After a little digging, it seems that the problem is with qubes, particularly some part that does not seem to be yet implemented. They even have a FIXME in the code (line 407 to line 427 of the file /usr/lib/python3/dist-packages/qubesadmin/app.py).

A quick temporary fix to comment out all those lines like so:

            """
            try:
                # FIXME: convert to qrexec calls to dom0/GUI VM
                appmenus_cmd = \
                    ['qvm-appmenus', '--init', '--update',
                        '--source', src_vm.name, dst_vm.name]
                subprocess.check_output(appmenus_cmd, stderr=subprocess.STDOUT)
            except OSError:
                # this file needs to be python 2.7 compatible,so no FileNotFoundError
                self.log.error('Failed to clone appmenus, qvm-appmenus missing')
                if not ignore_errors:
                     raise qubesadmin.exc.QubesException(
                        'Failed to clone appmenus')
            except subprocess.CalledProcessError as e:
                self.log.error('Failed to clone appmenus: %s',
                    e.output.decode())
                if not ignore_errors:
                    raise qubesadmin.exc.QubesException(
                        'Failed to clone appmenus')
            """

Maybe this problem should be mentioned in the docs so people at least know it's not only happening to them.

[deeplow]

Opened an issue detailing the problem on qubes-issues as this seems to be a problem with qubes rather than this project

[conorsch]

I use this script locally to work around the problem in the meantime:

#!/bin/bash
# Helper script to manage VM lifecycle for SecureDrop staging VMs.
# Necessary as a workaround, pending resolution of upstream admin API bug.
set -e
set -x

for vm in sd-app sd-mon; do
    qvm-kill --quiet "$vm" || true
    qvm-remove --force "$vm" || true
    qvm-clone "${vm}-base" "$vm"
    qvm-tags "$vm" add created-by-sd-dev
    qvm-start "$vm"
done

Run that in dom0, then molecule converge -s qubes-staging will work.

[rmol]

@emkll @conorsch I didn't run into this while setting up staging under Qubes recently, even though we're not using qvm-clone --ignore-errors. I think we can probably close this.

[conorsch]

@rmol I'm definitely still seeing the error locally:

TASK [Clone base image for staging VMs] **************************************** fatal: [localhost]: FAILED! => {"msg": "The conditional check 'clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines' failed. The error was: error while evaluating conditional (clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines): Unable to look up a name or access an attribute in template string ({% if clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines %} True {% else %} False {% endif %}).\nMake sure your variable name does not contain invalid characters like '-': argument of type 'StrictUndefined' is not iterable"} to retry, use: --limit @/home/user/securedrop/molecule/qubes-staging/create.retry

For complete's sake, here's confirmation that I'm running latest develop, with latest pip deps installed.

Terminal session

[user@sd-dev:~/securedrop] [sd] develop+ 39s ± 
 $ git status -sb
## develop...origin/develop
[user@sd-dev:~/securedrop] [sd] develop+ 43s ± 
 $ git rev-parse HEAD
a0e26746ade9e52a45785b167859f2d3e6c654a0
[user@sd-dev:~/securedrop] [sd] develop+ 45s ± 
 $ pip install -r securedrop/requirements/python3/develop-requirements.txt  > /dev/null
WARNING: You are using pip version 19.1, however version 20.0.2 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
[user@sd-dev:~/securedrop] [sd] develop+ 50s ± 
 $ make staging
 Creating staging environment...
Creating staging environment via 'qubes-staging'...
Using active Python 3 virtualenv in /home/user/.virtualenvs/sd
--> Validating schema /home/user/securedrop/molecule/fetch-tor-packages/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/libvirt-staging-xenial/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/ansible-config/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/builder-xenial/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/vagrant-packager/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/virtualbox-staging-xenial/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/qubes-staging/molecule.yml.
Validation completed successfully.
--> Validating schema /home/user/securedrop/molecule/upgrade/molecule.yml.
Validation completed successfully.
--> Test matrix
    
└── qubes-staging
    ├── dependency
    ├── create
    ├── prepare
    └── converge
    
--> Scenario: 'qubes-staging'
--> Action: 'dependency'
Skipping, missing the requirements file.
--> Scenario: 'qubes-staging'
--> Action: 'create'
    
    PLAY [Create] ******************************************************************
    
    TASK [Gathering Facts] *********************************************************
    ok: [localhost]
    
    TASK [Clone base image for staging VMs] ****************************************
    fatal: [localhost]: FAILED! => {"msg": "The conditional check 'clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines' failed. The error was: error while evaluating conditional (clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines): Unable to look up a name or access an attribute in template string ({% if clone_result.rc != 0 and \"qvm-clone: error: VM \"+item.vm_name+\" already exists\" not in clone_result.stderr_lines %} True {% else %} False {% endif %}).\nMake sure your variable name does not contain invalid characters like '-': argument of type 'StrictUndefined' is not iterable"}
    	to retry, use: --limit @/home/user/securedrop/molecule/qubes-staging/create.retry
    
    PLAY RECAP *********************************************************************
    localhost                  : ok=1    changed=0    unreachable=0    failed=1   
    
ERROR: 
make: *** [Makefile:200: staging] Error 2

I use a patch to get around this, so I'll submit that, as well as knocking out the longstanding #3629.