cloud-init

cloud-init fails on debian 8

Bug #1454185 reported by Remy van Elst
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
cloud-init
Expired
Undecided
Unassigned

Bug Description

On a minimal debian 8 install, with cloud-init installed from the debian jessie repositories, it does not work as expected. The hostname does not change, the SSH key is not set and the root password is not set.

This is on a cloud provider using Openstack with the config drive (cloudvps).

The same config file works on Debian 7 (with cloud-init installed via backports).

Without a custom config file, it also fails with the same error messages (with a default debian 8 package provided config file).

When running manually:

    cloud-init modules --mode init
    Traceback (most recent call last):
      File "/usr/bin/cloud-init", line 618, in <module>
        sys.exit(main())
      File "/usr/bin/cloud-init", line 614, in main
        get_uptime=True, func=functor, args=(name, args))
      File "/usr/lib/python2.7/dist-packages/cloudinit/util.py", line 1875, in log_time
        ret = func(*args, **kwargs)
      File "/usr/bin/cloud-init", line 487, in status_wrapper
        v1[mode]['start'] = time.time()
    KeyError: 'modules-init'

The config or final part also fail, both give this error message:

    cloud-init modules --mode config
    Can not apply stage config, no datasource found! Likely bad things to come!
    ------------------------------------------------------------
    Traceback (most recent call last):
      File "/usr/bin/cloud-init", line 318, in main_modules
        init.fetch()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 308, in fetch
        return self._get_data_source()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 236, in _get_data_source
        pkg_list)
      File "/usr/lib/python2.7/dist-packages/cloudinit/sources/__init__.py", line 260, in find_source
        raise DataSourceNotFoundException(msg)
    DataSourceNotFoundException: Did not find any data source, searched classes: ()
    ------------------------------------------------------------

The config drive is available:

    root@debian:~# lsblk /dev/sr0
    NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
    sr0 11:0 1 410K 0 rom
    root@debian:~# blkid /dev/sr0
    /dev/sr0: UUID="2015-05-11-15-45-45-00" LABEL="config-2" TYPE="iso9660"

Including the metadata:

    # cat /mnt/openstack/latest/meta_data.json
    {"admin_pass": "[...]", "random_seed": "l4Zr[...]=", "uuid": "3bc8[...]370b4", "availability_zone": "NL1", "hostname": "jessie", "launch_index": 0, "public_keys": {"User": "ssh-rsa AAA[...]DIl"}, "name": "jessie"}

This is the custom config file:

    user: root
    disable_root: 0
    preserve_hostname: False

    datasource_list: [ ConfigDrive ]

    system_info:
       distro: debian

    cloud_init_modules:
     - bootcmd
     - resizefs
     - set_hostname
     - update_hostname
     - update_etc_hosts
     - ca-certs
     - ssh

    cloud_config_modules:
     - disk-setup
     - ssh-import-id
     - locale
     - set-passwords
     - runcmd

    cloud_final_modules:
     - scripts-per-once
     - scripts-per-boot
     - scripts-per-instance
     - scripts-user
     - keys-to-console
     - final-message

As said, it also fails with a default debian 8 config file.

This is the debug log:

     cat /var/log/cloud-init.log
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.6 running 'init-local' at Mon, 11 May 2015 13:46:29 +0000. Up 8.10 seconds.
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:4
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'init' took 0.024 seconds (0.02)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.6 running 'init' at Mon, 11 May 2015 13:46:29 +0000. Up 8.26 seconds.
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 0:4
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['netstat', '-rn'] with allowed return codes [0] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/data/no-net (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['debian', 'cloudinit.distros.debian'] that have attributes ['Distro']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Failed at attempted import of 'debian' due to: No module named debian
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found debian with attributes ['Distro'] in ['cloudinit.distros.debian']
    May 11 15:46:29 debian [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.debian.Distro'>
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Looking for for data source in: ['ConfigDrive'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Failed at attempted import of 'DataSourceConfigDrive' due to: No module named DataSourceConfigDrive
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Searching for data source in: ['DataSourceConfigDriveNet']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDriveNet'>
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-tLABEL=config-2', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 1780 bytes from /proc/mounts
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Fetched {'devpts': {'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000', 'fstype': 'devpts'}, 'debugfs': {'mountpoint': '/sys/kernel/debug', 'opts': 'rw,relatime', 'fstype': 'debugfs'}, 'securityfs': {'mountpoint': '/sys/kernel/security', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'securityfs'}, 'sysfs': {'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'sysfs'}, 'mqueue': {'mountpoint': '/dev/mqueue', 'opts': 'rw,relatime', 'fstype': 'mqueue'}, 'pstore': {'mountpoint': '/sys/fs/pstore', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'pstore'}, 'udev': {'mountpoint': '/dev', 'opts': 'rw,relatime,size=10240k,nr_inodes=505425,mode=755', 'fstype': 'devtmpfs'}, 'hugetlbfs': {'mountpoint': '/dev/hugepages', 'opts': 'rw,relatime', 'fstype': 'hugetlbfs'}, '/dev/vda1': {'mountpoint': '/boot', 'opts': 'rw,noatime,errors=remount-ro,data=ordered', 'fstype': 'ext4'}, 'cgroup': {'mountpoint': '/sys/fs/cgroup/perf_event', 'opts': 'rw,nosuid,nodev,noexec,relatime,perf_event', 'fstype': 'cgroup'}, 'tmpfs': {'mountpoint': '/sys/fs/cgroup', 'opts': 'ro,nosuid,nodev,noexec,mode=755', 'fstype': 'tmpfs'}, 'proc': {'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'proc'}, '/dev/vda2': {'mountpoint': '/', 'opts': 'rw,noatime,errors=remount-ro,data=ordered', 'fstype': 'ext4'}, 'systemd-1': {'mountpoint': '/proc/sys/fs/binfmt_misc', 'opts': 'rw,relatime,fd=23,pgrp=1,timeout=300,minproto=5,maxproto=5,direct', 'fstype': 'autofs'}, 'rootfs': {'mountpoint': '/', 'opts': 'rw', 'fstype': 'rootfs'}} mounts from proc
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['mount', '-o', 'ro,sync', '/dev/sr0', '/tmp/tmp8GBPpv'] with allowed return codes [0] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /tmp/tmp8GBPpv/openstack/2012-08-10/meta_data.json (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 581 bytes from /tmp/tmp8GBPpv/openstack/2012-08-10/meta_data.json
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /tmp/tmp8GBPpv/ec2/latest/meta-data.json (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 961 bytes from /tmp/tmp8GBPpv/ec2/latest/meta-data.json
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Running command ['umount', '-l', '/tmp/tmp8GBPpv'] with allowed return codes [0] (shell=False, capture=True)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Recursively deleting /tmp/tmp8GBPpv
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] stages.py[INFO]: Loaded datasource DataSourceConfigDriveNet - DataSourceConfigDriveNet [net,ver=2][source=/dev/sr0]
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 128 bytes from /proc/cmdline
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 476 bytes from /etc/cloud/cloud.cfg
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 476 with allowed root types (<type 'dict'>,)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 88 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 88 with allowed root types (<type 'dict'>,)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 1910 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 1910 with allowed root types (<type 'dict'>,)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/00_debian.cfg (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 26 bytes from /etc/cloud/cloud.cfg.d/00_debian.cfg
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to load yaml from string of length 26 with allowed root types (<type 'dict'>,)
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
    May 11 15:46:29 debian [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
    May 11 15:46:29 debian [CLOUDINIT] __init__.py[DEBUG]: Merging using located merger 'DictMerger: (method=no_replace,recurse_str=False,recurse_dict=True,recurse_array=False,allow_delete=False)' since it had method '_on_dict'
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
    May 11 15:46:29 debian [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'init' took 0.714 seconds (0.71)
    root@debian:~#

Tags: debian
Revision history for this message
Alexandre Derumier (aderumier-odiso) wrote :

Hi,
I'm seeing exactly same bug than you with debian8

Revision history for this message
Remy van Elst (raymii) wrote :

How can I get some progress in this issue? Is there any more logging or other data needed?

Revision history for this message
Dan Watkins (oddbloke) wrote :

It looks like 'cloud-init init' is running fine, but 'cloud-init modules' is not being run; I normally run cloud-init (manually) on an instance like this:

sudo cloud-init init
sudo cloud-init modules

Is there a particular reason you're trying to use modes?

Revision history for this message
Remy van Elst (raymii) wrote :

The instance images are set up at boot to run cloud init and that fails. I've tried a new instance with the commands you suggested, and they give the same error message.

Revision history for this message
Dan Watkins (oddbloke) wrote :

Remy, where are these images? Could you give me access to an instance to debug?

Revision history for this message
Scott Moser (smoser) wrote :

your 'cloud-init modules --mode init' is a bad command. it shouldnt fail like that, but its not normally called like that.
I think what might be wrong is that you're not getting the systemd files, and your boot just isn't fully working.

proper cloud-init boot consists of:
 1.) cloud-init init --local
    when root filesystem is mounted (not network guaranteed or expected)
  2.) cloud-init init
    when root filesystem is mounted and expected networking is up
  3.) cloud-init modules --mode=config
  4.) cloud-init modules --mode=final

try running those as root after system is up and see if they work.

Revision history for this message
Remy van Elst (raymii) wrote :
Download full text (6.3 KiB)

When running the suggested commands as root it also complains about not being able to find a datasource:

    root@debian:~# cloud-init init --local
    Cloud-init v. 0.7.6 running 'init-local' at Thu, 28 May 2015 15:18:35 +0000. Up 130.98 seconds.

    root@debian:~# cloud-init init
    Cloud-init v. 0.7.6 running 'init' at Thu, 28 May 2015 15:18:41 +0000. Up 136.28 seconds.
    ci-info: +++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++
    ci-info: +--------+------+---------------+---------------+-------------------+
    ci-info: | Device | Up | Address | Mask | Hw-Address |
    ci-info: +--------+------+---------------+---------------+-------------------+
    ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | . |
    ci-info: | eth0 | True | 85.222.227.48 | 255.255.255.0 | fa:16:3e:3c:ab:70 |
    ci-info: +--------+------+---------------+---------------+-------------------+
    ci-info: ++++++++++++++++++++++++++++++++++++Route info++++++++++++++++++++++++++++++++++++
    ci-info: +-------+-----------------+----------------+-----------------+-----------+-------+
    ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags |
    ci-info: +-------+-----------------+----------------+-----------------+-----------+-------+
    ci-info: | 0 | 0.0.0.0 | 85.222.227.1 | 0.0.0.0 | eth0 | UG |
    ci-info: | 1 | 85.222.227.0 | 0.0.0.0 | 255.255.255.0 | eth0 | U |
    ci-info: | 2 | 169.254.169.254 | 85.222.227.177 | 255.255.255.255 | eth0 | UGH |
    ci-info: +-------+-----------------+----------------+-----------------+-----------+-------+

    root@debian:~# cloud-init modules --mode=config
    Can not apply stage config, no datasource found! Likely bad things to come!
    ------------------------------------------------------------
    Traceback (most recent call last):
      File "/usr/bin/cloud-init", line 318, in main_modules
        init.fetch()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 308, in fetch
        return self._get_data_source()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 236, in _get_data_source
        pkg_list)
      File "/usr/lib/python2.7/dist-packages/cloudinit/sources/__init__.py", line 260, in find_source
        raise DataSourceNotFoundException(msg)
    DataSourceNotFoundException: Did not find any data source, searched classes: ()
    ------------------------------------------------------------
    root@debian:~# cloud-init modules --mode=final

    Can not apply stage final, no datasource found! Likely bad things to come!
    ------------------------------------------------------------
    Traceback (most recent call last):
      File "/usr/bin/cloud-init", line 318, in main_modules
        init.fetch()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 308, in fetch
        return self._get_data_source()
      File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line 236, in _get_data_source
        pkg_list)
      File "/usr/lib/python2.7/dist-packages/cloudinit/...

Read more...

Revision history for this message
Remy van Elst (raymii) wrote :

The images are being installed with a preseed file and a post-install script which does a very basic installation, if needed, I can post that as well.

Revision history for this message
Scott Moser (smoser) wrote :

can you push an image somewhere or point me at one public somewhere? i'm sure i can figure it out fairly quicly with access, but apparently not easily without.

Revision history for this message
Relst.nl (relst) wrote : Re: [Bug 1454185] Re: cloud-init fails on debian 8
Download full text (26.3 KiB)

I'll send you some info tomorrow regarding the images.
Op 1 jun. 2015 15:20 schreef "Scott Moser" <email address hidden>:

> can you push an image somewhere or point me at one public somewhere? i'm
> sure i can figure it out fairly quicly with access, but apparently not
> easily without.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1454185
>
> Title:
> cloud-init fails on debian 8
>
> Status in Init scripts for use on cloud images:
> New
>
> Bug description:
> On a minimal debian 8 install, with cloud-init installed from the
> debian jessie repositories, it does not work as expected. The hostname
> does not change, the SSH key is not set and the root password is not
> set.
>
> This is on a cloud provider using Openstack with the config drive
> (cloudvps).
>
> The same config file works on Debian 7 (with cloud-init installed via
> backports).
>
> Without a custom config file, it also fails with the same error
> messages (with a default debian 8 package provided config file).
>
> When running manually:
>
> cloud-init modules --mode init
> Traceback (most recent call last):
> File "/usr/bin/cloud-init", line 618, in <module>
> sys.exit(main())
> File "/usr/bin/cloud-init", line 614, in main
> get_uptime=True, func=functor, args=(name, args))
> File "/usr/lib/python2.7/dist-packages/cloudinit/util.py", line
> 1875, in log_time
> ret = func(*args, **kwargs)
> File "/usr/bin/cloud-init", line 487, in status_wrapper
> v1[mode]['start'] = time.time()
> KeyError: 'modules-init'
>
>
> The config or final part also fail, both give this error message:
>
> cloud-init modules --mode config
> Can not apply stage config, no datasource found! Likely bad things
> to come!
> ------------------------------------------------------------
> Traceback (most recent call last):
> File "/usr/bin/cloud-init", line 318, in main_modules
> init.fetch()
> File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line
> 308, in fetch
> return self._get_data_source()
> File "/usr/lib/python2.7/dist-packages/cloudinit/stages.py", line
> 236, in _get_data_source
> pkg_list)
> File
> "/usr/lib/python2.7/dist-packages/cloudinit/sources/__init__.py", line 260,
> in find_source
> raise DataSourceNotFoundException(msg)
> DataSourceNotFoundException: Did not find any data source, searched
> classes: ()
> ------------------------------------------------------------
>
>
> The config drive is available:
>
> root@debian:~# lsblk /dev/sr0
> NAME MAJ:MIN RM SIZE RO TYPE MOUNTPOINT
> sr0 11:0 1 410K 0 rom
> root@debian:~# blkid /dev/sr0
> /dev/sr0: UUID="2015-05-11-15-45-45-00" LABEL="config-2"
> TYPE="iso9660"
>
> Including the metadata:
>
> # cat /mnt/openstack/latest/meta_data.json
> {"admin_pass": "[...]", "random_seed": "l4Zr[...]=", "uuid":
> "3bc8[...]370b4", "availability_zone": "NL1", "hostname": "jessie",
> "launch_index": 0, ...

Revision history for this message
Remy van Elst (raymii) wrote :

Here's the qcow2 version of the image I use with the issue:

https://2162bb74000a471eb2839a7f1648771a.objectstore.eu/debian/compressed-debian7-jessie.qcow2 (MD5: 88f0413af8c61e6ed2e73d618438319c)

You do need to reset the root password at boot...

Revision history for this message
Remy van Elst (raymii) wrote :

Did you have a look at the image?

Revision history for this message
Remy van Elst (raymii) wrote :

@smoser did you have a look at the images?

Revision history for this message
Remy van Elst (raymii) wrote :

It seems to be a dependency issue. After manually installing the following packages cloud-init works as expected:

    python-boto python-chardet python-configobj python-crypto python-json-pointer python-ecdsa python-lxml python-minimal python-oauth python-paramiko python-pkg-resources python-prettytable python-requests python-requestbuilder python-setuptools python-six python-software-properties python-yaml python-urllib3 python3-apt

Revision history for this message
Ozgur Erturk (ozerturk) wrote :

Hi,

I have recently came across this issue within RHEV/oVirt environment while creating Debian Jessie 8.5.0 amd64 template for my VM Pool. All I wanted was to regenerate SSH keys, run a very basic script to assign a hostname to the VMs, and attach a NIC.

After applying the dependency fix addressed by Remy van Elst, cloud-init did not "init" during VM boot-up. The cloud-init.log file showed that it detected the config drive, but it complained that it could not find any datasource.

After spending several days and pulling out my hair (helping the already balding head of mine), I was able to find out what was causing the trouble.

Default install of cloud-init package of Debian Jessie (0.7.6) from default repositories, creates a directory named "instance" under /var/lib/cloud directory tree. Only after removing this "instance" directory cloud-init starts working.

I hope it helps.

Revision history for this message
Joshua Powers (powersj) wrote :

Hi! Since this bug report there has been considerable work on the cloud-init in Debian. Based on the past couple of messages it would be good to know if the latest version of cloud-init still exhibits this behavior or not.

Changed in cloud-init:
status: New → Incomplete
tags: added: debian
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for cloud-init because there has been no activity for 60 days.]

Changed in cloud-init:
status: Incomplete → Expired
Revision history for this message
James Falcon (falcojr) wrote :

Tracked in Github Issues as https://github.com/canonical/cloud-init/issues/2544

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.