saltstack / saltstack/salt

virt.init with overlay_image=True fails to write the overlay image

Open
#56,113 4 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug Core Execution-Module severity-medium
Dominant language
Python
Stars
15.7k
Forks
5.6k
Avg merge
2d 44m
Merged PRs (30d)
80

Description

Description of Issue

On initializing a new VM image through virt.init and providing disks{..., 'overlay_image'=True, ...} an error is produced when the cmd is run internally with __salt__['cmd.run']():

[INFO    ] Cloning qcow2 image /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2 using copy on write
[INFO    ] Executing command ['qemu-img', 'create', '-f', 'qcow2', '-o', 'backing_file="/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"', '"/pool/targethost_default.qcow2"'] in directory '/root'
[ERROR   ] Command '['qemu-img', 'create', '-f', 'qcow2', '-o', 'backing_file="/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"', '"/pool/targethost_default.qcow2"']' failed with return code: 1
[ERROR   ] stdout: qemu-img: "/pool/targethost_default.qcow2": Could not open '"/pool/"/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"': No such file or directory
Could not open backing image to determine size.

It appears that for whatever reason the formatting/escape of double quotes breaks:

https://github.com/saltstack/salt/blob/81eb15264380d82267ffc3c1930410baf1f3fbf1/salt/modules/virt.py#L808-L812

Also, backing files should be provided with qemu-img create -b. Possible fix, that returns no error:

        try:
            if create_overlay and qcow2:
                log.info('Cloning qcow2 image %s using copy on write', sfn)
                __salt__['cmd.run'](
                    'qemu-img create -f qcow2 -o backing_file={0} {1}'
                    .format(sfn, img_dest).split())
Setup

salt-call -l debug virt.init targethost1 2 4096 start=False disk=None 'disks=[{'\''name'\'':'\''default'\'','\''image'\'':'\''/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2'\'','\''overlay_image'\'': True,}]' 'graphics={'\''type'\'':'\''spice'\'','\''port'\'':'\''-1'\'','\''tls_port'\'':'\''-1'\'',}' 'interfaces=[{'\''name'\'':'\''mytestproject-eth'\'','\''type'\'':'\''network'\'','\''source'\'':'\''mytestproject'\'','\''model'\'':'\''virtio'\'','\''mac'\'':'\''00:00:00:11:11:01'\''}]' nic=None

Steps to Reproduce Issue

salt minion with libvirt.

+ salt-call -l debug virt.init targethost1 2 4096 start=False disk=None 'disks=[{'\''name'\'':'\''default'\'','\''image'\'':'\''/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2'\'','\''overlay_image'\'': True,}]' 'graphics={'\''type'\'':'\''spice'\'','\''port'\'':'\''-1'\'','\''tls_port'\'':'\''-1'\'',}' 'interfaces=[{'\''name'\'':'\''mytestproject-eth'\'','\''type'\'':'\''network'\'','\''source'\'':'\''mytestproject'\'','\''model'\'':'\''virtio'\'','\''mac'\'':'\''00:00:00:11:11:01'\''}]' nic=None
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Including configuration from '/etc/salt/minion.d/mytestproject.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/mytestproject.conf
[DEBUG   ] Using cached minion ID from /etc/salt/minion_id: mytestproject-test02
[DEBUG   ] Configuration file path: /etc/salt/minion
[WARNING ] Insecure logging configuration detected! Sensitive data may be logged.
[DEBUG   ] Grains refresh requested. Refreshing grains.
[DEBUG   ] Reading configuration from /etc/salt/minion
[DEBUG   ] Including configuration from '/etc/salt/minion.d/_schedule.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/_schedule.conf
[DEBUG   ] Including configuration from '/etc/salt/minion.d/mytestproject.conf'
[DEBUG   ] Reading configuration from /etc/salt/minion.d/mytestproject.conf
[DEBUG   ] Error while parsing IPv4 address: ::1
[DEBUG   ] Expected 4 octets in '::1'
[DEBUG   ] Error while parsing IPv4 address: fe80::c634:6bff:fe5c:715e
[DEBUG   ] Expected 4 octets in 'fe80::c634:6bff:fe5c:715e'
[DEBUG   ] Unable to resolve address fe80::c634:6bff:fe5c:715e: [Errno 0] Resolver Error 0 (no error)
[DEBUG   ] Unable to resolve address 10.211.23.1: [Errno 0] Resolver Error 0 (no error)
[DEBUG   ] Elapsed time getting FQDNs: 0.11088824272155762 seconds
[DEBUG   ] Error while parsing IPv4 address: ::1
[DEBUG   ] Expected 4 octets in '::1'
[DEBUG   ] Error while parsing IPv4 address: fe80::c634:6bff:fe5c:715e
[DEBUG   ] Expected 4 octets in 'fe80::c634:6bff:fe5c:715e'
[DEBUG   ] LazyLoaded zfs.is_supported
[DEBUG   ] Connecting to master. Attempt 1 of 1
[DEBUG   ] Error while parsing IPv4 address: mytestproject-test01
[DEBUG   ] Expected 4 octets in 'mytestproject-test01'
[DEBUG   ] Error while parsing IPv6 address: mytestproject-test01
[DEBUG   ] At least 3 parts expected in 'mytestproject-test01'
[DEBUG   ] "mytestproject-test01" Not an IP address? Assuming it is a hostname.
[DEBUG   ] Master URI: tcp://10.200.126.41:4506
[DEBUG   ] Initializing new AsyncAuth for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506')
[DEBUG   ] Generated random reconnect delay between '1000ms' and '11000ms' (3559)
[DEBUG   ] Setting zmq_reconnect_ivl to '3559ms'
[DEBUG   ] Setting zmq_reconnect_ivl_max to '11000ms'
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506', 'clear')
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://10.200.126.41:4506
[DEBUG   ] Trying to connect to: tcp://10.200.126.41:4506
[DEBUG   ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG   ] Decrypting the current master AES key
[DEBUG   ] salt.crypt.get_rsa_key: Loading private key
[DEBUG   ] salt.crypt._get_key_with_evict: Loading private key
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] salt.crypt.get_rsa_pub_key: Loading public key
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] Connecting the Minion to the Master publish port, using the URI: tcp://10.200.126.41:4505
[DEBUG   ] salt.crypt.get_rsa_key: Loading private key
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] Determining pillar cache
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506', 'aes')
[DEBUG   ] Initializing new AsyncAuth for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506')
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://10.200.126.41:4506
[DEBUG   ] Trying to connect to: tcp://10.200.126.41:4506
[DEBUG   ] salt.crypt.get_rsa_key: Loading private key
[DEBUG   ] Loaded minion key: /etc/salt/pki/minion/minion.pem
[DEBUG   ] Closing AsyncZeroMQReqChannel instance
[DEBUG   ] LazyLoaded jinja.render
[DEBUG   ] LazyLoaded yaml.render
[DEBUG   ] LazyLoaded virt.init
[DEBUG   ] LazyLoaded direct_call.execute
[DEBUG   ] LazyLoaded config.get
[DEBUG   ] key: virt.connect, ret: _|-
[DEBUG   ] key: libvirt:connection, ret: _|-
[DEBUG   ] key: virt:connection:uri, ret: _|-
[DEBUG   ] key: libvirt:hypervisor, ret: _|-
[DEBUG   ] key: libvirt:hypervisor, ret: _|-
[DEBUG   ] Using hypervisor kvm
[DEBUG   ] NIC profile is []
[DEBUG   ] Merged NICs: [{'name': 'mytestproject-eth', 'type': 'network', 'source': 'mytestproject', 'model': 'virtio', 'mac': '00:00:00:11:11:01'}]
[DEBUG   ] Image directory from config option `virt:images` is /pool/
[DEBUG   ] Creating disk for VM [ targethost ]: {'name': 'default', 'image': '/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2', 'overlay_image': True, 'format': 'qcow2', 'device': 'disk', 'model': 'virtio', 'filename': 'targethost_default.qcow2', 'source_file': '/pool/targethost_default.qcow2'}
[DEBUG   ] Image destination will be /pool/targethost_default.qcow2
[DEBUG   ] Image destination directory is /pool
[DEBUG   ] Create disk from specified image /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2
[DEBUG   ] LazyLoaded cp.cache_file
[DEBUG   ] Initializing new AsyncZeroMQReqChannel for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506', 'aes')
[DEBUG   ] Initializing new AsyncAuth for ('/etc/salt/pki/minion', 'mytestproject-test02', 'tcp://10.200.126.41:4506')
[DEBUG   ] Connecting the Minion to the Master URI (for the return server): tcp://10.200.126.41:4506
[DEBUG   ] Trying to connect to: tcp://10.200.126.41:4506
[DEBUG   ] LazyLoaded cmd.run
[INFO    ] Executing command 'qemu-img info "/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"' in directory '/root'
[DEBUG   ] stdout: image: /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2
file format: qcow2
virtual size: 8.0G (8589934592 bytes)
disk size: 1.4G
cluster_size: 65536
Format specific information:
    compat: 1.1
    lazy refcounts: false
    refcount bits: 16
    corrupt: false
[DEBUG   ] output: image: /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2
file format: qcow2
virtual size: 8.0G (8589934592 bytes)
disk size: 1.4G
cluster_size: 65536
Format specific information:
    compat: 1.1
    lazy refcounts: false
    refcount bits: 16
    corrupt: false
[INFO    ] Cloning qcow2 image /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2 using copy on write
[INFO    ] Executing command ['qemu-img', 'create', '-f', 'qcow2', '-o', 'backing_file="/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"', '"/pool/targethost_default.qcow2"'] in directory '/root'
[ERROR   ] Command '['qemu-img', 'create', '-f', 'qcow2', '-o', 'backing_file="/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"', '"/pool/targethost_default.qcow2"']' failed with return code: 1
[ERROR   ] stdout: qemu-img: "/pool/targethost_default.qcow2": Could not open '"/pool/"/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"': No such file or directory
Could not open backing image to determine size.
[ERROR   ] retcode: 1
[ERROR   ] Command '['qemu-img', 'create', '-f', 'qcow2', '-o', 'backing_file="/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"', '"/pool/targethost_default.qcow2"']' failed with return code: 1
[ERROR   ] output: qemu-img: "/pool/targethost_default.qcow2": Could not open '"/pool/"/pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2"': No such file or directory
Could not open backing image to determine size.
[DEBUG   ] Apply umask and remove exec bit
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/salt/modules/virt.py", line 787, in _qemu_image_create
    os.chmod(img_dest, mode)
FileNotFoundError: [Errno 2] No such file or directory: '/pool/targethost_default.qcow2'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/salt/cli/caller.py", line 237, in call
    ret['return'] = self.minion.executors[fname](self.opts, data, func, args, kwargs)
  File "/usr/lib/python3.6/site-packages/salt/executors/direct_call.py", line 12, in execute
    return func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/salt/modules/virt.py", line 1478, in init
    img_dest = _qemu_image_create(_disk, create_overlay, saltenv)
  File "/usr/lib/python3.6/site-packages/salt/modules/virt.py", line 792, in _qemu_image_create
    .format(disk_image, err)
salt.exceptions.CommandExecutionError: Problem while copying image. /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2 - [Errno 2] No such file or directory: '/pool/targethost_default.qcow2'
Error running 'virt.init': Problem while copying image. /pool/mytestproject-Leap-15.1.x86_64-1.15.1.qcow2 - [Errno 2] No such file or directory: '/pool/targethost_default.qcow2'
Versions Report

Note: This being openSUSE, the Salt Version might be misleading.

   Static hostname: mytestproject-test02
         Icon name: computer-desktop
           Chassis: desktop
        Machine ID: 65078f94e082487ca37c39de13bd8d7d
           Boot ID: b93b7cbfa06e4ba796578b84150cbfcd
  Operating System: openSUSE Leap 15.1
       CPE OS Name: cpe:/o:opensuse:leap:15.1
            Kernel: Linux 4.12.14-lp151.28.36-default
      Architecture: x86-64

Salt Version:
           Salt: 2019.2.0

Dependency Versions:
           cffi: 1.11.2
       cherrypy: Not Installed
       dateutil: 2.7.3
      docker-py: Not Installed
          gitdb: Not Installed
      gitpython: Not Installed
          ioflo: Not Installed
         Jinja2: 2.10.1
        libgit2: 0.26.8
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.5.6
   mysql-python: Not Installed
      pycparser: 2.17
       pycrypto: 2.6.1
   pycryptodome: Not Installed
         pygit2: 0.26.0
         Python: 3.6.9 (default, Oct 29 2019, 10:39:36) [GCC]
   python-gnupg: Not Installed
         PyYAML: 3.13
          PyZMQ: 17.0.0
           RAET: Not Installed
          smmap: Not Installed
        timelib: Not Installed
        Tornado: 4.5.3
            ZMQ: 4.2.3

System Versions:
           dist:
         locale: UTF-8
        machine: x86_64
        release: 4.12.14-lp151.28.36-default
         system: Linux
        version: Not Installed

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in salt/modules/virt.py around lines 808-812 and trace the _qemu_image_create path used by virt.init with overlay_image=True. Reproduce the qemu-img create invocation from the report, then verify that the backing and destination paths are passed without the broken embedded quotes and that overlay creation succeeds.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
infrastructure
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.