Ubuntu
cloud-init package

datasource for Azure fails to load if datasource OVF starts first

Bug #1255617 reported by Ben Howard on 2013-11-27

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	cloud-init (Ubuntu)	Expired	Low	Unassigned

Bug Description

When the DataSourceOVF loads before DataSourceAzure, DataSourceAzure does not claim itself as the DataSource.

Repo Steps:
1. Boot with default Datasources (Azure will not be found)
2. Boot with Azure Datasource (Azure will be found)

ProblemType: Bug
DistroRelease: Ubuntu 14.04
Package: cloud-init 0.7.3-0ubuntu2
Uname: Linux 3.11.0-13-generic x86_64
ApportVersion: 2.12.7-0ubuntu1
Architecture: amd64
Date: Wed Nov 27 18:00:05 2013
PackageArchitecture: all
ProcEnviron: Error: [Errno 2] No such file or directory: '/proc/1798/environ'
SourcePackage: cloud-init
UpgradeStatus: No upgrade log present (probably fresh install)

See original description

Tags:

Revision history for this message

Ben Howard (darkmuggle-deactivatedaccount) wrote on 2013-11-27:

Dependencies.txt Edit (4.4 KiB, text/plain; charset="utf-8")

Revision history for this message

Ben Howard (darkmuggle-deactivatedaccount) wrote on 2013-11-27:

My hunch is that Trusty is not loading the UDF module.

$ sudo blkid /dev/sr0
/dev/sr0: LABEL="rd_rdfe_stable.131122-1638" TYPE="udf"

Revision history for this message

Ben Howard (darkmuggle-deactivatedaccount) wrote on 2013-11-27:

On a Saucy system, the following appears in dmesg:
[ 29.072953] UDF-fs: INFO Mounting volume 'rd_rdfe_stable.131122-1638', timestamp 2013/11/27 16:53 (1000)

Which means that the UDF module is likely not getting loaded.

Ben Howard (darkmuggle-deactivatedaccount) on 2013-11-27

summary:

- unable to identify ISOFS format on Trusty
+ datasource for Azure fails to load if datasource OVF starts first

Revision history for this message

Ben Howard (darkmuggle-deactivatedaccount) wrote on 2013-11-27:

Download full text (105.0 KiB)

Log with all Datasources enabled:

2013-11-27 18:46:27,822 - util.py[DEBUG]: Cloud-init v. 0.7.3 running 'init-local' at Wed, 27 Nov 2013 18:46:27 +0000. Up 25.16 seconds.
2013-11-27 18:46:27,827 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2013-11-27 18:46:27,827 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 101:4
2013-11-27 18:46:27,828 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2013-11-27 18:46:27,828 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2013-11-27 18:46:27,828 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2013-11-27 18:46:27,828 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 18:46:27,830 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 18:46:27,832 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 18:46:27,832 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 18:46:27,833 - __init__.py[DEBUG]: Looking for for data source in: ['NoCloud', 'ConfigDrive', 'OpenNebula', 'Azure', 'AltCloud', 'OVF', 'MAAS', 'Ec2', 'CloudStack', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2013-11-27 18:46:27,833 - importer.py[DEBUG]: Looking for modules ['DataSourceNoCloud', 'cloudinit.sources.DataSourceNoCloud'] that have attributes ['get_datasource_list']
2013-11-27 18:46:27,881 - importer.py[DEBUG]: Found DataSourceNoCloud with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceNoCloud']
2013-11-27 18:46:27,881 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2013-11-27 18:46:27,883 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2013-11-27 18:46:27,883 - importer.py[DEBUG]: Looking for modules ['DataSourceOpenNebula', 'cloudinit.sources.DataSourceOpenNebula'] that have attributes ['get_datasource_list']
2013-11-27 18:46:27,889 - importer.py[DEBUG]: Found DataSourceOpenNebula with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceOpenNebula']
2013-11-27 18:46:27,889 - importer.py[DEBUG]: Looking for modules ['DataSourceAzure', 'cloudinit.sources.DataSourceAzure'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,107 - importer.py[DEBUG]: Found DataSourceAzure with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAzure']
2013-11-27 18:46:28,107 - importer.py[DEBUG]: Looking for modules ['DataSourceAltCloud', 'cloudinit.sources.DataSourceAltCloud'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,108 - importer.py[DEBUG]: Found DataSourceAltCloud with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAltCloud']
2013-11-27 18:46:28,109 - importer.py[DEBUG]: Looking for modules ['DataSourceOVF', 'cloudinit.sources.DataSourceOVF'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,110 - importer.py[DEBUG]: Found DataSourceOVF with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceOVF']
2013-11-27 18:46:28,110 - importer.py[DEBUG]: Looking for modules ['DataSourceMAAS', 'cloudinit.sources.DataSourceMAAS'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,115 - importer.py[DEBUG]: Found DataSourceMAAS with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceMAAS']
2013-11-27 18:46:28,115 - importer.py[DEBUG]: Looking for modules ['DataSourceEc2', 'cloudinit.sources.DataSourceEc2'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,435 - importer.py[DEBUG]: Found DataSourceEc2 with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceEc2']
2013-11-27 18:46:28,436 - importer.py[DEBUG]: Looking for modules ['DataSourceCloudStack', 'cloudinit.sources.DataSourceCloudStack'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,437 - importer.py[DEBUG]: Found DataSourceCloudStack with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceCloudStack']
2013-11-27 18:46:28,437 - importer.py[DEBUG]: Looking for modules ['DataSourceNone', 'cloudinit.sources.DataSourceNone'] that have attributes ['get_datasource_list']
2013-11-27 18:46:28,438 - importer.py[DEBUG]: Found DataSourceNone with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceNone']
2013-11-27 18:46:28,438 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceNoCloud', 'DataSourceConfigDrive', 'DataSourceOpenNebula', 'DataSourceOVF']
2013-11-27 18:46:28,438 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloud'>
2013-11-27 18:46:28,438 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 18:46:28,438 - util.py[DEBUG]: Read 119 bytes from /proc/cmdline
2013-11-27 18:46:28,438 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud/meta-data (quiet=False)
2013-11-27 18:46:28,445 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,508 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,513 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,551 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,556 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,561 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceConfigDrive.DataSourceConfigDrive'>
2013-11-27 18:46:28,561 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,566 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,570 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,575 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,579 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=config-2', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,583 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceOpenNebula.DataSourceOpenNebula'>
2013-11-27 18:46:28,584 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CONTEXT', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,592 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=CDROM', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,598 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:28,602 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceOVF.DataSourceOVF'>
2013-11-27 18:46:28,604 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
2013-11-27 18:46:28,604 - util.py[DEBUG]: Read 903 bytes from /proc/mounts
2013-11-27 18:46:28,604 - util.py[DEBUG]: Fetched {'/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca': {'mountpoint': '/', 'opts': 'rw,relatime,discard,data=ordered', 'fstype': 'ext4'}, 'devpts': {'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000', 'fstype': 'devpts'}, 'sysfs': {'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'sysfs'}, 'none': {'mountpoint': '/sys/fs/pstore', 'opts': 'rw,relatime', 'fstype': 'pstore'}, 'udev': {'mountpoint': '/dev', 'opts': 'rw,relatime,size=846464k,nr_inodes=211616,mode=755', 'fstype': 'devtmpfs'}, 'tmpfs': {'mountpoint': '/run', 'opts': 'rw,nosuid,noexec,relatime,size=171872k,mode=755', 'fstype': 'tmpfs'}, 'proc': {'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'proc'}, 'rootfs': {'mountpoint': '/', 'opts': 'rw', 'fstype': 'rootfs'}} mounts from /proc/mounts
2013-11-27 18:46:28,605 - util.py[DEBUG]: Peeking at /dev/sr0 (max_bytes=512)
2013-11-27 18:46:28,608 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
2013-11-27 18:46:28,609 - util.py[DEBUG]: Read 903 bytes from /proc/mounts
2013-11-27 18:46:28,609 - util.py[DEBUG]: Fetched {'/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca': {'mountpoint': '/', 'opts': 'rw,relatime,discard,data=ordered', 'fstype': 'ext4'}, 'devpts': {'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000', 'fstype': 'devpts'}, 'sysfs': {'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'sysfs'}, 'none': {'mountpoint': '/sys/fs/pstore', 'opts': 'rw,relatime', 'fstype': 'pstore'}, 'udev': {'mountpoint': '/dev', 'opts': 'rw,relatime,size=846464k,nr_inodes=211616,mode=755', 'fstype': 'devtmpfs'}, 'tmpfs': {'mountpoint': '/run', 'opts': 'rw,nosuid,noexec,relatime,size=171872k,mode=755', 'fstype': 'tmpfs'}, 'proc': {'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'proc'}, 'rootfs': {'mountpoint': '/', 'opts': 'rw', 'fstype': 'rootfs'}} mounts from /proc/mounts
2013-11-27 18:46:28,799 - util.py[DEBUG]: Running command ['mount', '-o', 'ro,sync', '-t', 'iso9660', '/dev/sr0', '/tmp/tmpKbXRCS'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:28,907 - util.py[DEBUG]: Recursively deleting /tmp/tmpKbXRCS
2013-11-27 18:46:28,908 - DataSourceOVF.py[DEBUG]: /dev/sr0 not mountable as iso9660
2013-11-27 18:46:28,908 - cloud-init[DEBUG]: No local datasource found
2013-11-27 18:46:28,908 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 18:46:28,909 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 18:46:28,909 - util.py[DEBUG]: cloud-init mode 'init' took 1.204 seconds (1.20)
2013-11-27 18:46:29,323 - util.py[DEBUG]: Cloud-init v. 0.7.3 running 'init' at Wed, 27 Nov 2013 18:46:29 +0000. Up 26.72 seconds.
2013-11-27 18:46:29,325 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2013-11-27 18:46:29,326 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 101:4
2013-11-27 18:46:29,326 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:29,332 - util.py[DEBUG]: Running command ['route', '-n'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:29,378 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2013-11-27 18:46:29,378 - util.py[DEBUG]: Reading from /var/lib/cloud/data/no-net (quiet=False)
2013-11-27 18:46:29,378 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 18:46:29,379 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 18:46:29,392 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 18:46:29,393 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 18:46:29,393 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 18:46:29,393 - __init__.py[DEBUG]: Looking for for data source in: ['NoCloud', 'ConfigDrive', 'OpenNebula', 'Azure', 'AltCloud', 'OVF', 'MAAS', 'Ec2', 'CloudStack', 'None'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
2013-11-27 18:46:29,393 - importer.py[DEBUG]: Looking for modules ['DataSourceNoCloud', 'cloudinit.sources.DataSourceNoCloud'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,394 - importer.py[DEBUG]: Found DataSourceNoCloud with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceNoCloud']
2013-11-27 18:46:29,394 - importer.py[DEBUG]: Looking for modules ['DataSourceConfigDrive', 'cloudinit.sources.DataSourceConfigDrive'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,395 - importer.py[DEBUG]: Found DataSourceConfigDrive with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceConfigDrive']
2013-11-27 18:46:29,395 - importer.py[DEBUG]: Looking for modules ['DataSourceOpenNebula', 'cloudinit.sources.DataSourceOpenNebula'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,396 - importer.py[DEBUG]: Found DataSourceOpenNebula with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceOpenNebula']
2013-11-27 18:46:29,397 - importer.py[DEBUG]: Looking for modules ['DataSourceAzure', 'cloudinit.sources.DataSourceAzure'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,401 - importer.py[DEBUG]: Found DataSourceAzure with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAzure']
2013-11-27 18:46:29,401 - importer.py[DEBUG]: Looking for modules ['DataSourceAltCloud', 'cloudinit.sources.DataSourceAltCloud'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,401 - importer.py[DEBUG]: Found DataSourceAltCloud with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAltCloud']
2013-11-27 18:46:29,402 - importer.py[DEBUG]: Looking for modules ['DataSourceOVF', 'cloudinit.sources.DataSourceOVF'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,402 - importer.py[DEBUG]: Found DataSourceOVF with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceOVF']
2013-11-27 18:46:29,402 - importer.py[DEBUG]: Looking for modules ['DataSourceMAAS', 'cloudinit.sources.DataSourceMAAS'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,404 - importer.py[DEBUG]: Found DataSourceMAAS with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceMAAS']
2013-11-27 18:46:29,405 - importer.py[DEBUG]: Looking for modules ['DataSourceEc2', 'cloudinit.sources.DataSourceEc2'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,416 - importer.py[DEBUG]: Found DataSourceEc2 with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceEc2']
2013-11-27 18:46:29,416 - importer.py[DEBUG]: Looking for modules ['DataSourceCloudStack', 'cloudinit.sources.DataSourceCloudStack'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,417 - importer.py[DEBUG]: Found DataSourceCloudStack with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceCloudStack']
2013-11-27 18:46:29,417 - importer.py[DEBUG]: Looking for modules ['DataSourceNone', 'cloudinit.sources.DataSourceNone'] that have attributes ['get_datasource_list']
2013-11-27 18:46:29,417 - importer.py[DEBUG]: Found DataSourceNone with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceNone']
2013-11-27 18:46:29,417 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceNoCloudNet', 'DataSourceConfigDriveNet', 'DataSourceOpenNebulaNet', 'DataSourceAzureNet', 'DataSourceAltCloud', 'DataSourceOVFNet', 'DataSourceMAAS', 'DataSourceEc2', 'DataSourceCloudStack', 'DataSourceNone']
2013-11-27 18:46:29,417 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceNoCloud.DataSourceNoCloudNet'>
2013-11-27 18:46:29,418 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 18:46:29,418 - util.py[DEBUG]: Read 119 bytes from /proc/cmdline
2013-11-27 18:46:29,418 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/meta-data (quiet=False)
2013-11-27 18:46:29,426 - util.py[DEBUG]: Read 69 bytes from /var/lib/cloud/seed/nocloud-net/meta-data
2013-11-27 18:46:29,426 - util.py[DEBUG]: Attempting to load yaml from string of length 69 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,427 - util.py[DEBUG]: Reading from /var/lib/cloud/seed/nocloud-net/user-data (quiet=False)
2013-11-27 18:46:29,427 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/seed/nocloud-net/user-data
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,427 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,428 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,428 - __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'
2013-11-27 18:46:29,428 - DataSourceNoCloud.py[DEBUG]: Using seeded cache data from /var/lib/cloud/seed/nocloud-net
2013-11-27 18:46:29,428 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr0'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:29,432 - util.py[DEBUG]: Running command ['blkid', '-odevice', '/dev/sr1'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:29,437 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=vfat', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:29,442 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:29,447 - util.py[DEBUG]: Running command ['blkid', '-tLABEL=cidata', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 18:46:29,451 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,451 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,451 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,451 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,452 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,452 - __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'
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,452 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,453 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,453 - __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'
2013-11-27 18:46:29,453 - stages.py[DEBUG]: Loaded datasource DataSourceNoCloudNet - DataSourceNoCloudNet [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net]
2013-11-27 18:46:29,453 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 18:46:29,454 - util.py[DEBUG]: Read 119 bytes from /proc/cmdline
2013-11-27 18:46:29,454 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 18:46:29,454 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 18:46:29,454 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,477 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 18:46:29,477 - util.py[DEBUG]: Read 160 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 18:46:29,477 - util.py[DEBUG]: Attempting to load yaml from string of length 160 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,479 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 18:46:29,479 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 18:46:29,479 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,485 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,486 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,486 - __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'
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,486 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,486 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,486 - __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'
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,487 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,487 - __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'
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,487 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,488 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,488 - __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'
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,488 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,488 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,489 - __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'
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,489 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,489 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,489 - __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'
2013-11-27 18:46:29,489 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,489 - __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'
2013-11-27 18:46:29,490 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,490 - __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'
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,490 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,490 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,490 - __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'
2013-11-27 18:46:29,491 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2013-11-27 18:46:29,491 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/nocloud'
2013-11-27 18:46:29,492 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/nocloud/datasource (quiet=False)
2013-11-27 18:46:29,493 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/datasource - wb: [420] 94 bytes
2013-11-27 18:46:29,493 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [420] 94 bytes
2013-11-27 18:46:29,493 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2013-11-27 18:46:29,493 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [420] 8 bytes
2013-11-27 18:46:29,494 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [420] 8 bytes
2013-11-27 18:46:29,494 - cloud-init[DEBUG]: init will now be targeting instance id: nocloud
2013-11-27 18:46:29,494 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 18:46:29,495 - util.py[DEBUG]: Read 119 bytes from /proc/cmdline
2013-11-27 18:46:29,495 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 18:46:29,495 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 18:46:29,495 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,515 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 18:46:29,516 - util.py[DEBUG]: Read 160 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 18:46:29,516 - util.py[DEBUG]: Attempting to load yaml from string of length 160 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,518 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 18:46:29,518 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 18:46:29,518 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,523 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,523 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,523 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,524 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,524 - __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'
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,524 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,525 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,525 - __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'
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,525 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,525 - __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'
2013-11-27 18:46:29,525 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,526 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,526 - __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'
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,526 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,527 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,527 - __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'
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,527 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,528 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,528 - __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'
2013-11-27 18:46:29,528 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,528 - __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'
2013-11-27 18:46:29,528 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,528 - __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'
2013-11-27 18:46:29,528 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,528 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,528 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,528 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,529 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,529 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,529 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,529 - __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'
2013-11-27 18:46:29,530 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [256] 5166 bytes
2013-11-27 18:46:29,530 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt - wb: [384] 0 bytes
2013-11-27 18:46:29,586 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/user-data.txt.i - wb: [384] 344 bytes
2013-11-27 18:46:29,588 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 18:46:29,588 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 18:46:29,588 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 18:46:29,588 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/consume_userdata - wb: [420] 19 bytes
2013-11-27 18:46:29,589 - helpers.py[DEBUG]: Running consume_userdata using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/consume_userdata'>)
2013-11-27 18:46:29,589 - stages.py[DEBUG]: Added default handler for set(['text/cloud-config-jsonp', 'text/cloud-config']) from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2013-11-27 18:46:29,589 - stages.py[DEBUG]: Added default handler for set(['text/x-shellscript']) from ShellScriptPartHandler: [['text/x-shellscript']]
2013-11-27 18:46:29,589 - stages.py[DEBUG]: Added default handler for set(['text/cloud-boothook']) from BootHookPartHandler: [['text/cloud-boothook']]
2013-11-27 18:46:29,590 - stages.py[DEBUG]: Added default handler for set(['text/upstart-job']) from UpstartJobPartHandler: [['text/upstart-job']]
2013-11-27 18:46:29,590 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,590 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,590 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2013-11-27 18:46:29,590 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,591 - __init__.py[DEBUG]: {'Content-Type': 'text/x-not-multipart', 'Content-Disposition': 'attachment; filename="part-001"', 'MIME-Version': '1.0'}
2013-11-27 18:46:29,591 - __init__.py[DEBUG]: Empty payload of type text/x-not-multipart
2013-11-27 18:46:29,591 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,591 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,591 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2013-11-27 18:46:29,591 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/cloud-config.txt - wb: [384] 0 bytes
2013-11-27 18:46:29,592 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 18:46:29,592 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 18:46:29,592 - util.py[DEBUG]: Read 119 bytes from /proc/cmdline
2013-11-27 18:46:29,592 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 18:46:29,592 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 18:46:29,592 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,614 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 18:46:29,614 - util.py[DEBUG]: Read 160 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 18:46:29,614 - util.py[DEBUG]: Attempting to load yaml from string of length 160 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,616 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 18:46:29,616 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 18:46:29,616 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,621 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,621 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,621 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,622 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,622 - __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'
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,622 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,623 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,623 - __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'
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,623 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,623 - __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'
2013-11-27 18:46:29,623 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,624 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,624 - __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'
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,624 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,625 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,625 - __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'
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,625 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,626 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,626 - __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'
2013-11-27 18:46:29,626 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,626 - __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'
2013-11-27 18:46:29,626 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,626 - __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'
2013-11-27 18:46:29,626 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2013-11-27 18:46:29,626 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2013-11-27 18:46:29,626 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,627 - util.py[DEBUG]: load_yaml given empty string, returning default
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,627 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,627 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,627 - __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'
2013-11-27 18:46:29,628 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2013-11-27 18:46:29,628 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2013-11-27 18:46:29,628 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2013-11-27 18:46:29,629 - util.py[DEBUG]: load_yaml given empty string, returning default
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:29,629 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:29,629 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:29,629 - __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'
2013-11-27 18:46:29,633 - importer.py[DEBUG]: Looking for modules ['cc_migrator', 'cloudinit.config.cc_migrator'] that have attributes ['handle']
2013-11-27 18:46:29,634 - importer.py[DEBUG]: Found cc_migrator with attributes ['handle'] in ['cloudinit.config.cc_migrator']
2013-11-27 18:46:29,635 - importer.py[DEBUG]: Looking for modules ['cc_seed_random', 'cloudinit.config.cc_seed_random'] that have attributes ['handle']
2013-11-27 18:46:29,637 - importer.py[DEBUG]: Found cc_seed_random with attributes ['handle'] in ['cloudinit.config.cc_seed_random']
2013-11-27 18:46:29,637 - importer.py[DEBUG]: Looking for modules ['cc_bootcmd', 'cloudinit.config.cc_bootcmd'] that have attributes ['handle']
2013-11-27 18:46:29,637 - importer.py[DEBUG]: Found cc_bootcmd with attributes ['handle'] in ['cloudinit.config.cc_bootcmd']
2013-11-27 18:46:29,638 - importer.py[DEBUG]: Looking for modules ['cc_write_files', 'cloudinit.config.cc_write_files'] that have attributes ['handle']
2013-11-27 18:46:29,665 - importer.py[DEBUG]: Found cc_write_files with attributes ['handle'] in ['cloudinit.config.cc_write_files']
2013-11-27 18:46:29,665 - importer.py[DEBUG]: Looking for modules ['cc_growpart', 'cloudinit.config.cc_growpart'] that have attributes ['handle']
2013-11-27 18:46:29,667 - importer.py[DEBUG]: Found cc_growpart with attributes ['handle'] in ['cloudinit.config.cc_growpart']
2013-11-27 18:46:29,667 - importer.py[DEBUG]: Looking for modules ['cc_resizefs', 'cloudinit.config.cc_resizefs'] that have attributes ['handle']
2013-11-27 18:46:29,702 - importer.py[DEBUG]: Found cc_resizefs with attributes ['handle'] in ['cloudinit.config.cc_resizefs']
2013-11-27 18:46:29,702 - importer.py[DEBUG]: Looking for modules ['cc_set_hostname', 'cloudinit.config.cc_set_hostname'] that have attributes ['handle']
2013-11-27 18:46:29,767 - importer.py[DEBUG]: Found cc_set_hostname with attributes ['handle'] in ['cloudinit.config.cc_set_hostname']
2013-11-27 18:46:29,767 - importer.py[DEBUG]: Looking for modules ['cc_update_hostname', 'cloudinit.config.cc_update_hostname'] that have attributes ['handle']
2013-11-27 18:46:29,768 - importer.py[DEBUG]: Found cc_update_hostname with attributes ['handle'] in ['cloudinit.config.cc_update_hostname']
2013-11-27 18:46:29,768 - importer.py[DEBUG]: Looking for modules ['cc_update_etc_hosts', 'cloudinit.config.cc_update_etc_hosts'] that have attributes ['handle']
2013-11-27 18:46:29,769 - importer.py[DEBUG]: Found cc_update_etc_hosts with attributes ['handle'] in ['cloudinit.config.cc_update_etc_hosts']
2013-11-27 18:46:29,769 - importer.py[DEBUG]: Looking for modules ['cc_ca_certs', 'cloudinit.config.cc_ca_certs'] that have attributes ['handle']
2013-11-27 18:46:29,770 - importer.py[DEBUG]: Found cc_ca_certs with attributes ['handle'] in ['cloudinit.config.cc_ca_certs']
2013-11-27 18:46:29,770 - importer.py[DEBUG]: Looking for modules ['cc_rsyslog', 'cloudinit.config.cc_rsyslog'] that have attributes ['handle']
2013-11-27 18:46:29,771 - importer.py[DEBUG]: Found cc_rsyslog with attributes ['handle'] in ['cloudinit.config.cc_rsyslog']
2013-11-27 18:46:29,771 - importer.py[DEBUG]: Looking for modules ['cc_users_groups', 'cloudinit.config.cc_users_groups'] that have attributes ['handle']
2013-11-27 18:46:29,772 - importer.py[DEBUG]: Found cc_users_groups with attributes ['handle'] in ['cloudinit.config.cc_users_groups']
2013-11-27 18:46:29,772 - importer.py[DEBUG]: Looking for modules ['cc_ssh', 'cloudinit.config.cc_ssh'] that have attributes ['handle']
2013-11-27 18:46:29,781 - importer.py[DEBUG]: Found cc_ssh with attributes ['handle'] in ['cloudinit.config.cc_ssh']
2013-11-27 18:46:29,782 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 18:46:29,782 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 18:46:29,782 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 18:46:29,783 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x2df5ed0>)
2013-11-27 18:46:29,784 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2013-11-27 18:46:29,784 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_seed_random - wb: [420] 19 bytes
2013-11-27 18:46:29,784 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_seed_random'>)
2013-11-27 18:46:29,785 - cc_seed_random.py[DEBUG]: Skipping module named seed_random, no 'random_seed' configuration found
2013-11-27 18:46:29,785 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x2df5110>)
2013-11-27 18:46:29,785 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2013-11-27 18:46:29,785 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_write_files - wb: [420] 19 bytes
2013-11-27 18:46:29,786 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_write_files'>)
2013-11-27 18:46:29,786 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2013-11-27 18:46:29,786 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x2df55d0>)
2013-11-27 18:46:29,786 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg.  Using default: {'ignore_growroot_disabled': False, 'mode': 'auto', 'devices': ['/']}
2013-11-27 18:46:29,787 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:29,820 - util.py[DEBUG]: Reading from /proc/785/mountinfo (quiet=False)
2013-11-27 18:46:29,821 - util.py[DEBUG]: Read 1071 bytes from /proc/785/mountinfo
2013-11-27 18:46:29,821 - util.py[DEBUG]: Reading from /sys/class/block/sda1/partition (quiet=False)
2013-11-27 18:46:29,822 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda1/partition
2013-11-27 18:46:29,822 - util.py[DEBUG]: Reading from /sys/devices/LNXSYSTM:00/device:00/PNP0A03:00/device:08/VMBUS:00/vmbus_0_1/host2/target2:0:0/2:0:0:0/block/sda/dev (quiet=False)
2013-11-27 18:46:29,822 - util.py[DEBUG]: Read 4 bytes from /sys/devices/LNXSYSTM:00/device:00/PNP0A03:00/device:08/VMBUS:00/vmbus_0_1/host2/target2:0:0/2:0:0:0/block/sda/dev
2013-11-27 18:46:29,823 - util.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '1'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:29,875 - util.py[DEBUG]: Running command ['growpart', '/dev/sda', '1'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:30,736 - util.py[DEBUG]: resize_devices took 0.916 seconds
2013-11-27 18:46:30,737 - cc_growpart.py[INFO]: '/' resized: changed (/dev/sda, 1) from 2146435072 to 31456231424
2013-11-27 18:46:30,737 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x2df5ad0>)
2013-11-27 18:46:30,738 - util.py[DEBUG]: Reading from /proc/785/mountinfo (quiet=False)
2013-11-27 18:46:30,738 - util.py[DEBUG]: Read 1071 bytes from /proc/785/mountinfo
2013-11-27 18:46:30,739 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca mnt_point=/ path=/
2013-11-27 18:46:30,739 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca
2013-11-27 18:46:30,739 - util.py[DEBUG]: Running command ('resize2fs', '/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca') with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:31,429 - util.py[DEBUG]: Resizing took 0.689 seconds
2013-11-27 18:46:31,429 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
2013-11-27 18:46:31,430 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_hostname - wb: [420] 19 bytes
2013-11-27 18:46:31,431 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_hostname'>)
2013-11-27 18:46:31,431 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2013-11-27 18:46:31,431 - util.py[DEBUG]: Read 221 bytes from /etc/hosts
2013-11-27 18:46:31,432 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2013-11-27 18:46:31,432 - util.py[DEBUG]: Read 221 bytes from /etc/hosts
2013-11-27 18:46:31,432 - cc_set_hostname.py[DEBUG]: Setting the hostname to ubuntu (ubuntu)
2013-11-27 18:46:31,432 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2013-11-27 18:46:31,432 - util.py[DEBUG]: Read 7 bytes from /etc/hostname
2013-11-27 18:46:31,432 - util.py[DEBUG]: Writing to /etc/hostname - wb: [420] 7 bytes
2013-11-27 18:46:31,433 - __init__.py[DEBUG]: Non-persistently setting the system hostname to ubuntu
2013-11-27 18:46:31,433 - util.py[DEBUG]: Running command ['hostname', 'ubuntu'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:31,439 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x2e753d0>)
2013-11-27 18:46:31,439 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2013-11-27 18:46:31,439 - util.py[DEBUG]: Read 221 bytes from /etc/hosts
2013-11-27 18:46:31,440 - util.py[DEBUG]: Reading from /etc/hosts (quiet=False)
2013-11-27 18:46:31,440 - util.py[DEBUG]: Read 221 bytes from /etc/hosts
2013-11-27 18:46:31,440 - cc_update_hostname.py[DEBUG]: Updating hostname to ubuntu (ubuntu)
2013-11-27 18:46:31,440 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2013-11-27 18:46:31,440 - util.py[DEBUG]: Read 7 bytes from /etc/hostname
2013-11-27 18:46:31,440 - __init__.py[DEBUG]: Attempting to update hostname to ubuntu in 1 files
2013-11-27 18:46:31,440 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2013-11-27 18:46:31,440 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [420] 7 bytes
2013-11-27 18:46:31,441 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x2e753d0>)
2013-11-27 18:46:31,441 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts
2013-11-27 18:46:31,442 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ca_certs - wb: [420] 19 bytes
2013-11-27 18:46:31,442 - helpers.py[DEBUG]: Running config-ca-certs using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ca_certs'>)
2013-11-27 18:46:31,443 - cc_ca_certs.py[DEBUG]: Skipping module named ca-certs, no 'ca-certs' key in configuration
2013-11-27 18:46:31,443 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_rsyslog - wb: [420] 19 bytes
2013-11-27 18:46:31,444 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_rsyslog'>)
2013-11-27 18:46:31,444 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2013-11-27 18:46:31,444 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_users_groups - wb: [420] 19 bytes
2013-11-27 18:46:31,444 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_users_groups'>)
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:31,445 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:31,445 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:31,445 - __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'
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:31,446 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:31,446 - __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'
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:31,446 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:31,447 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:31,447 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:31,447 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:31,447 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:31,447 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:31,447 - __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'
2013-11-27 18:46:31,447 - __init__.py[DEBUG]: Adding user ubuntu
2013-11-27 18:46:31,447 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', 'ubuntu', '--shell', '/bin/bash', '--comment', 'Ubuntu', '--groups', 'adm,audio,cdrom,dialout,dip,floppy,netdev,plugdev,sudo,video', '-m']
2013-11-27 18:46:32,692 - util.py[DEBUG]: Running command ['passwd', '-l', 'ubuntu'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 18:46:32,796 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2013-11-27 18:46:32,798 - util.py[DEBUG]: Read 745 bytes from /etc/sudoers
2013-11-27 18:46:32,800 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [288] 123 bytes
2013-11-27 18:46:32,801 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh - wb: [420] 18 bytes
2013-11-27 18:46:32,801 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh'>)
2013-11-27 18:46:32,804 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 18:46:33,775 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 18:46:34,094 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 18:46:34,146 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:34,146 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:34,147 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:34,147 - __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'
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:34,147 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:34,148 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:34,148 - __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'
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 18:46:34,148 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 18:46:34,149 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 18:46:34,149 - __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'
2013-11-27 18:46:34,149 - util.py[DEBUG]: Changing the ownership of /home/ubuntu/.ssh to 1000:1000
2013-11-27 18:46:34,150 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2013-11-27 18:46:34,150 - util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
2013-11-27 18:46:34,151 - util.py[DEBUG]: Writing to /home/ubuntu/.ssh/authorized_keys - wb: [384] 0 bytes
2013-11-27 18:46:34,152 - util.py[DEBUG]: Changing the ownership of /home/ubuntu/.ssh/authorized_keys to 1000:1000
2013-11-27 18:46:34,152 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2013-11-27 18:46:34,153 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2013-11-27 18:46:34,153 - util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
2013-11-27 18:46:34,153 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [384] 0 bytes
2013-11-27 18:46:34,154 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2013-11-27 18:46:34,154 - cloud-init[DEBUG]: Ran 13 modules with 0 failures
2013-11-27 18:46:34,154 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 18:46:34,154 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 18:46:34,154 - util.py[DEBUG]: cloud-init mode 'init' took 4.887 seconds (4.89)
Nov 27 18:46:35 ubuntu [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 running 'modules:config' at Wed, 27 Nov 2013 18:46:35 +0000. Up 33.15 seconds.
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_emit_upstart', 'cloudinit.config.cc_emit_upstart'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_emit_upstart with attributes ['handle'] in ['cloudinit.config.cc_emit_upstart']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_disk_setup', 'cloudinit.config.cc_disk_setup'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_disk_setup with attributes ['handle'] in ['cloudinit.config.cc_disk_setup']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_mounts', 'cloudinit.config.cc_mounts'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_mounts with attributes ['handle'] in ['cloudinit.config.cc_mounts']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_ssh_import_id', 'cloudinit.config.cc_ssh_import_id'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_ssh_import_id with attributes ['handle'] in ['cloudinit.config.cc_ssh_import_id']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_locale', 'cloudinit.config.cc_locale'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_locale with attributes ['handle'] in ['cloudinit.config.cc_locale']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_set_passwords', 'cloudinit.config.cc_set_passwords'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_set_passwords with attributes ['handle'] in ['cloudinit.config.cc_set_passwords']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_grub_dpkg', 'cloudinit.config.cc_grub_dpkg'] that have attributes ['handle']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_grub_dpkg with attributes ['handle'] in ['cloudinit.config.cc_grub_dpkg']
Nov 27 18:46:35 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_apt_pipelining', 'cloudinit.config.cc_apt_pipelining'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_apt_pipelining with attributes ['handle'] in ['cloudinit.config.cc_apt_pipelining']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_apt_configure', 'cloudinit.config.cc_apt_configure'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_apt_configure with attributes ['handle'] in ['cloudinit.config.cc_apt_configure']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_package_update_upgrade_install', 'cloudinit.config.cc_package_update_upgrade_install'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_package_update_upgrade_install with attributes ['handle'] in ['cloudinit.config.cc_package_update_upgrade_install']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_landscape', 'cloudinit.config.cc_landscape'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_landscape with attributes ['handle'] in ['cloudinit.config.cc_landscape']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_timezone', 'cloudinit.config.cc_timezone'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_timezone with attributes ['handle'] in ['cloudinit.config.cc_timezone']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_puppet', 'cloudinit.config.cc_puppet'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_puppet with attributes ['handle'] in ['cloudinit.config.cc_puppet']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_chef', 'cloudinit.config.cc_chef'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_chef with attributes ['handle'] in ['cloudinit.config.cc_chef']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_salt_minion', 'cloudinit.config.cc_salt_minion'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_salt_minion with attributes ['handle'] in ['cloudinit.config.cc_salt_minion']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_mcollective', 'cloudinit.config.cc_mcollective'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_mcollective with attributes ['handle'] in ['cloudinit.config.cc_mcollective']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_disable_ec2_metadata', 'cloudinit.config.cc_disable_ec2_metadata'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_disable_ec2_metadata with attributes ['handle'] in ['cloudinit.config.cc_disable_ec2_metadata']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_runcmd', 'cloudinit.config.cc_runcmd'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_runcmd with attributes ['handle'] in ['cloudinit.config.cc_runcmd']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_byobu', 'cloudinit.config.cc_byobu'] that have attributes ['handle']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_byobu with attributes ['handle'] in ['cloudinit.config.cc_byobu']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
Nov 27 18:46:36 ubuntu [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
Nov 27 18:46:36 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-emit_upstart using lock (<cloudinit.helpers.DummyLock object at 0x19d1dd0>)
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['initctl', 'emit', 'cloud-config', 'CLOUD_CFG=/var/lib/cloud/instance/cloud-config.txt'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_disk_setup - wb: [420] 19 bytes
Nov 27 18:46:36 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_disk_setup'>)
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_mounts - wb: [420] 19 bytes
Nov 27 18:46:36 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_mounts'>)
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_mounts.py[DEBUG]: Ignoring nonexistant default named mount ephemeral0
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_mounts.py[DEBUG]: Ignoring nonexistant default named mount swap
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_mounts.py[DEBUG]: No modifications to fstab needed.
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_import_id - wb: [420] 18 bytes
Nov 27 18:46:36 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-ssh-import-id using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_import_id'>)
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:36 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:36 ubuntu [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'
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:36 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:36 ubuntu [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'
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:36 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:36 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:36 ubuntu [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'
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_locale - wb: [420] 19 bytes
Nov 27 18:46:36 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_locale'>)
Nov 27 18:46:36 ubuntu [CLOUDINIT] cc_locale.py[DEBUG]: Setting locale to en_US.UTF-8
Nov 27 18:46:36 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['locale-gen', 'en_US.UTF-8'] with allowed return codes [0] (shell=False, capture=False)
Nov 27 18:46:40 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['update-locale', 'en_US.UTF-8'] with allowed return codes [0] (shell=False, capture=False)
Nov 27 18:46:42 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /etc/default/locale - wb: [420] 87 bytes
Nov 27 18:46:42 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_set_passwords - wb: [420] 19 bytes
Nov 27 18:46:42 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_set_passwords'>)
Nov 27 18:46:42 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_grub_dpkg - wb: [420] 19 bytes
Nov 27 18:46:42 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-grub-dpkg using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_grub_dpkg'>)
Nov 27 18:46:42 ubuntu [CLOUDINIT] cc_grub_dpkg.py[DEBUG]: Setting grub debconf-set-selections with '/dev/sda','false'
Nov 27 18:46:42 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['debconf-set-selections'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_apt_pipelining - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-apt-pipelining using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_apt_pipelining'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /etc/apt/apt.conf.d/90cloud-init-pipelining - wb: [420] 80 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_apt_pipelining.py[DEBUG]: Wrote /etc/apt/apt.conf.d/90cloud-init-pipelining with apt pipeline depth setting 0
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_apt_configure - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-apt-configure using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_apt_configure'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['lsb_release', '-cs'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 18:46:44 ubuntu [CLOUDINIT] __init__.py[DEBUG]: filtered distro mirror info: {'security': 'http://security.ubuntu.com/ubuntu', 'primary': 'http://archive.ubuntu.com/ubuntu'}
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_apt_configure.py[DEBUG]: Mirror info: {'security': 'http://security.ubuntu.com/ubuntu', 'primary': 'http://archive.ubuntu.com/ubuntu', 'mirror': 'http://archive.ubuntu.com/ubuntu'}
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/templates/sources.list.ubuntu.tmpl (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 2768 bytes from /etc/cloud/templates/sources.list.ubuntu.tmpl
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /etc/apt/sources.list - wb: [420] 3165 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_package_update_upgrade_install - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_package_update_upgrade_install'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_landscape - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-landscape using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_landscape'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_timezone - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_timezone'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_puppet - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-puppet using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_puppet'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_puppet.py[DEBUG]: Skipping module named puppet, no 'puppet' configuration found
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_chef - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-chef using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_chef'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_chef.py[DEBUG]: Skipping module named chef, no 'chef' key in configuration
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_salt_minion - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_salt_minion'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_mcollective - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-mcollective using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_mcollective'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_mcollective.py[DEBUG]: Skipping module named mcollective, no 'mcollective' key in configuration
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x19d1350>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_runcmd - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_runcmd'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_byobu - wb: [420] 19 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-byobu using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_byobu'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_byobu.py[DEBUG]: Skipping module named byobu, no 'byobu' values found
Nov 27 18:46:44 ubuntu [CLOUDINIT] cloud-init[DEBUG]: Ran 19 modules with 0 failures
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'modules' took 8.439 seconds (8.44)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 running 'modules:final' at Wed, 27 Nov 2013 18:46:44 +0000. Up 41.90 seconds.
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_rightscale_userdata', 'cloudinit.config.cc_rightscale_userdata'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_rightscale_userdata with attributes ['handle'] in ['cloudinit.config.cc_rightscale_userdata']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_once', 'cloudinit.config.cc_scripts_per_once'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_once with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_once']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_boot', 'cloudinit.config.cc_scripts_per_boot'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_boot with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_boot']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_instance', 'cloudinit.config.cc_scripts_per_instance'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_instance with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_instance']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_user', 'cloudinit.config.cc_scripts_user'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_user with attributes ['handle'] in ['cloudinit.config.cc_scripts_user']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_ssh_authkey_fingerprints', 'cloudinit.config.cc_ssh_authkey_fingerprints'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_ssh_authkey_fingerprints with attributes ['handle'] in ['cloudinit.config.cc_ssh_authkey_fingerprints']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_keys_to_console', 'cloudinit.config.cc_keys_to_console'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_keys_to_console with attributes ['handle'] in ['cloudinit.config.cc_keys_to_console']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_phone_home', 'cloudinit.config.cc_phone_home'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_phone_home with attributes ['handle'] in ['cloudinit.config.cc_phone_home']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_final_message', 'cloudinit.config.cc_final_message'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_final_message with attributes ['handle'] in ['cloudinit.config.cc_final_message']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_power_state_change', 'cloudinit.config.cc_power_state_change'] that have attributes ['handle']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found cc_power_state_change with attributes ['handle'] in ['cloudinit.config.cc_power_state_change']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
Nov 27 18:46:44 ubuntu [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_rightscale_userdata - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_rightscale_userdata'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x3000610>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_per_instance'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_scripts_user - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_scripts_user'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_ssh_authkey_fingerprints'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:44 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:44 ubuntu [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'
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:44 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:44 ubuntu [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'
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 18:46:44 ubuntu [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 18:46:44 ubuntu [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 18:46:44 ubuntu [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'
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /home/ubuntu/.ssh/authorized_keys (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 0 bytes from /home/ubuntu/.ssh/authorized_keys
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_keys_to_console - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_keys_to_console'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_phone_home - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_phone_home'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x3000f50>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 finished at Wed, 27 Nov 2013 18:46:44 +0000. Datasource DataSourceNoCloudNet [seed=/var/lib/cloud/seed/nocloud-net][dsmode=net].  Up 42.31 seconds
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [420] 51 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/nocloud/sem/config_power_state_change - wb: [420] 20 bytes
Nov 27 18:46:44 ubuntu [CLOUDINIT] helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/nocloud/sem/config_power_state_change'>)
Nov 27 18:46:44 ubuntu [CLOUDINIT] cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
Nov 27 18:46:44 ubuntu [CLOUDINIT] cloud-init[DEBUG]: Ran 10 modules with 0 failures
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 18:46:44 ubuntu [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'modules' took 0.445 seconds (0.45)

description:

updated

Revision history for this message

Ben Howard (darkmuggle-deactivatedaccount) wrote on 2013-11-27:

Download full text (122.3 KiB)

Log from exclusively Azure DS:

2013-11-27 20:17:04,957 - util.py[DEBUG]: Cloud-init v. 0.7.3 running 'init-local' at Wed, 27 Nov 2013 20:17:04 +0000. Up 24.64 seconds.
2013-11-27 20:17:04,961 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2013-11-27 20:17:04,962 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 101:4
2013-11-27 20:17:04,962 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance/boot-finished
2013-11-27 20:17:04,962 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2013-11-27 20:17:04,962 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/data/no-net
2013-11-27 20:17:04,962 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 20:17:04,964 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 20:17:05,011 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 20:17:05,011 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 20:17:05,011 - __init__.py[DEBUG]: Looking for for data source in: ['Azure'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM']
2013-11-27 20:17:05,011 - importer.py[DEBUG]: Looking for modules ['DataSourceAzure', 'cloudinit.sources.DataSourceAzure'] that have attributes ['get_datasource_list']
2013-11-27 20:17:05,151 - importer.py[DEBUG]: Found DataSourceAzure with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAzure']
2013-11-27 20:17:05,151 - __init__.py[DEBUG]: Searching for data source in: []
2013-11-27 20:17:05,151 - cloud-init[DEBUG]: No local datasource found
2013-11-27 20:17:05,151 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 20:17:05,152 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 20:17:05,152 - util.py[DEBUG]: cloud-init mode 'init' took 0.359 seconds (0.36)
2013-11-27 20:17:05,584 - util.py[DEBUG]: Cloud-init v. 0.7.3 running 'init' at Wed, 27 Nov 2013 20:17:05 +0000. Up 25.37 seconds.
2013-11-27 20:17:05,586 - util.py[DEBUG]: Writing to /var/log/cloud-init.log - ab: [420] 0 bytes
2013-11-27 20:17:05,587 - util.py[DEBUG]: Changing the ownership of /var/log/cloud-init.log to 101:4
2013-11-27 20:17:05,587 - util.py[DEBUG]: Running command ['ifconfig', '-a'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:05,607 - util.py[DEBUG]: Running command ['route', '-n'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:05,706 - cloud-init[DEBUG]: Checking to see if files that we need already exist from a previous run that would allow us to stop early.
2013-11-27 20:17:05,706 - util.py[DEBUG]: Reading from /var/lib/cloud/data/no-net (quiet=False)
2013-11-27 20:17:05,706 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 20:17:05,706 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/obj.pkl (quiet=False)
2013-11-27 20:17:05,708 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 20:17:05,712 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 20:17:05,712 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 20:17:05,712 - __init__.py[DEBUG]: Looking for for data source in: ['Azure'], via packages ['', 'cloudinit.sources'] that matches dependencies ['FILESYSTEM', 'NETWORK']
2013-11-27 20:17:05,712 - importer.py[DEBUG]: Looking for modules ['DataSourceAzure', 'cloudinit.sources.DataSourceAzure'] that have attributes ['get_datasource_list']
2013-11-27 20:17:05,717 - importer.py[DEBUG]: Found DataSourceAzure with attributes ['get_datasource_list'] in ['cloudinit.sources.DataSourceAzure']
2013-11-27 20:17:05,717 - __init__.py[DEBUG]: Searching for data source in: ['DataSourceAzureNet']
2013-11-27 20:17:05,717 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceAzure.DataSourceAzureNet'>
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:05,721 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:05,721 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:05,722 - __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'
2013-11-27 20:17:05,722 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=iso9660', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 20:17:05,788 - util.py[DEBUG]: Running command ['blkid', '-tTYPE=udf', '-odevice'] with allowed return codes [0, 2] (shell=False, capture=True)
2013-11-27 20:17:05,793 - util.py[DEBUG]: Reading from /proc/mounts (quiet=False)
2013-11-27 20:17:05,794 - util.py[DEBUG]: Read 903 bytes from /proc/mounts
2013-11-27 20:17:05,794 - util.py[DEBUG]: Fetched {'/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca': {'mountpoint': '/', 'opts': 'rw,relatime,discard,data=ordered', 'fstype': 'ext4'}, 'devpts': {'mountpoint': '/dev/pts', 'opts': 'rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000', 'fstype': 'devpts'}, 'sysfs': {'mountpoint': '/sys', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'sysfs'}, 'none': {'mountpoint': '/sys/fs/pstore', 'opts': 'rw,relatime', 'fstype': 'pstore'}, 'udev': {'mountpoint': '/dev', 'opts': 'rw,relatime,size=846464k,nr_inodes=211616,mode=755', 'fstype': 'devtmpfs'}, 'tmpfs': {'mountpoint': '/run', 'opts': 'rw,nosuid,noexec,relatime,size=171872k,mode=755', 'fstype': 'tmpfs'}, 'proc': {'mountpoint': '/proc', 'opts': 'rw,nosuid,nodev,noexec,relatime', 'fstype': 'proc'}, 'rootfs': {'mountpoint': '/', 'opts': 'rw', 'fstype': 'rootfs'}} mounts from /proc/mounts
2013-11-27 20:17:05,918 - util.py[DEBUG]: Running command ['mount', '-o', 'ro,sync', '/dev/sr0', '/tmp/tmplA1Szd'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:06,098 - util.py[DEBUG]: Running command ['umount', '-l', '/tmp/tmplA1Szd'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:06,110 - util.py[DEBUG]: Recursively deleting /tmp/tmplA1Szd
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:06,111 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:06,111 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:06,111 - __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'
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:06,112 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:06,112 - __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'
2013-11-27 20:17:06,112 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:06,113 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:06,113 - __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'
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:06,113 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:06,114 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:06,114 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:06,114 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:06,114 - __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'
2013-11-27 20:17:06,114 - DataSourceAzure.py[DEBUG]: found datasource in /dev/sr0
2013-11-27 20:17:06,114 - util.py[DEBUG]: Reading from /sys/firmware/acpi/tables/OEM0 (quiet=True)
2013-11-27 20:17:06,114 - util.py[DEBUG]: Read 100 bytes from /sys/firmware/acpi/tables/OEM0
2013-11-27 20:17:06,114 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:06,114 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:06,114 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:06,115 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:06,115 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:06,115 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:06,115 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:06,115 - __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'
2013-11-27 20:17:06,115 - util.py[DEBUG]: Writing to /var/lib/waagent/ovf-env.xml - wb: [384] 1338 bytes
2013-11-27 20:17:06,116 - util.py[DEBUG]: Running command hostname with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:06,120 - util.py[DEBUG]: Running command ['hostname', u'utl-1127-t3'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:06,125 - DataSourceAzure.py[DEBUG]: pubhname: publishing hostname [phostname=ubuntu hostname=utl-1127-t3 policy=True interface=eth0]
2013-11-27 20:17:06,125 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 20:17:06,125 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 20:17:06,125 - util.py[DEBUG]: Running command ['sh', '-xc', 'i=$interface; x=0; ifdown $i || x=$?; ifup $i || x=$?; exit $x'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 20:17:06,772 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 20:17:06,772 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 20:17:06,773 - util.py[DEBUG]: publishing hostname took 0.647 seconds (0.65)
2013-11-27 20:17:06,773 - DataSourceAzure.py[DEBUG]: invoking agent: ['service', 'walinuxagent', 'start']
2013-11-27 20:17:06,773 - util.py[DEBUG]: Running command ['service', 'walinuxagent', 'start'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:10,932 - util.py[DEBUG]: waiting for files took 4.032 seconds
2013-11-27 20:17:10,934 - util.py[DEBUG]: Running command ['sh', '-c', 'openssl x509 -noout -pubkey < "$0" |ssh-keygen -i -m PKCS8 -f /dev/stdin', u'/var/lib/waagent/D3BCD6F2904D5E4B5E8155ED1E0A698C7B14F007.crt'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:11,017 - stages.py[DEBUG]: Loaded datasource DataSourceAzureNet - DataSourceAzureNet [seed=/dev/sr0]
2013-11-27 20:17:11,018 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 20:17:11,018 - util.py[DEBUG]: Read 151 bytes from /proc/cmdline
2013-11-27 20:17:11,018 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 20:17:11,018 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 20:17:11,018 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,063 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 20:17:11,063 - util.py[DEBUG]: Read 82 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 20:17:11,063 - util.py[DEBUG]: Attempting to load yaml from string of length 82 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,064 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90-azure.cfg (quiet=False)
2013-11-27 20:17:11,064 - util.py[DEBUG]: Read 459 bytes from /etc/cloud/cloud.cfg.d/90-azure.cfg
2013-11-27 20:17:11,064 - util.py[DEBUG]: Attempting to load yaml from string of length 459 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,073 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 20:17:11,076 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 20:17:11,076 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,085 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,085 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,086 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,086 - __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'
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,086 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,087 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,087 - __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'
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,087 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,087 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,087 - __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'
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,092 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,092 - __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'
2013-11-27 20:17:11,092 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,093 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,093 - __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'
2013-11-27 20:17:11,093 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,093 - __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'
2013-11-27 20:17:11,093 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,094 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,094 - __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'
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,094 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,095 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,095 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,095 - __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'
2013-11-27 20:17:11,095 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,095 - __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'
2013-11-27 20:17:11,095 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,095 - __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'
2013-11-27 20:17:11,095 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,095 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,095 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,096 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,100 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,100 - __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'
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,100 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,101 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,101 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,101 - __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'
2013-11-27 20:17:11,101 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,101 - __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'
2013-11-27 20:17:11,101 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,101 - __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'
2013-11-27 20:17:11,102 - util.py[DEBUG]: Attempting to remove /var/lib/cloud/instance
2013-11-27 20:17:11,102 - util.py[DEBUG]: Creating symbolic link from '/var/lib/cloud/instance' => '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6'
2013-11-27 20:17:11,105 - util.py[DEBUG]: Reading from /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/datasource (quiet=False)
2013-11-27 20:17:11,105 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/datasource - wb: [420] 55 bytes
2013-11-27 20:17:11,105 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-datasource - wb: [420] 55 bytes
2013-11-27 20:17:11,105 - util.py[DEBUG]: Reading from /var/lib/cloud/data/instance-id (quiet=False)
2013-11-27 20:17:11,106 - util.py[DEBUG]: Writing to /var/lib/cloud/data/instance-id - wb: [420] 33 bytes
2013-11-27 20:17:11,106 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-instance-id - wb: [420] 33 bytes
2013-11-27 20:17:11,106 - cloud-init[DEBUG]: init will now be targeting instance id: c11884fa5cc74b508b1ec96baa524de6
2013-11-27 20:17:11,106 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 20:17:11,107 - util.py[DEBUG]: Read 151 bytes from /proc/cmdline
2013-11-27 20:17:11,107 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 20:17:11,107 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 20:17:11,107 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,148 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 20:17:11,148 - util.py[DEBUG]: Read 82 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 20:17:11,148 - util.py[DEBUG]: Attempting to load yaml from string of length 82 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,149 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90-azure.cfg (quiet=False)
2013-11-27 20:17:11,149 - util.py[DEBUG]: Read 459 bytes from /etc/cloud/cloud.cfg.d/90-azure.cfg
2013-11-27 20:17:11,149 - util.py[DEBUG]: Attempting to load yaml from string of length 459 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,158 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 20:17:11,158 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 20:17:11,158 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,168 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,172 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,172 - __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'
2013-11-27 20:17:11,172 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,173 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,173 - __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'
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,173 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,174 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,174 - __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'
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,174 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,174 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,174 - __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'
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,175 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,175 - __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'
2013-11-27 20:17:11,175 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,175 - __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'
2013-11-27 20:17:11,175 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,176 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,180 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,180 - __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'
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,180 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,181 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,181 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,181 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,181 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,181 - __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'
2013-11-27 20:17:11,181 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,181 - __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'
2013-11-27 20:17:11,181 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,181 - __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'
2013-11-27 20:17:11,181 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,182 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,182 - __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'
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,182 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,183 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,183 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,183 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,183 - __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'
2013-11-27 20:17:11,183 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,183 - __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'
2013-11-27 20:17:11,183 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,183 - __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'
2013-11-27 20:17:11,188 - util.py[DEBUG]: Writing to /var/lib/cloud/instance/obj.pkl - wb: [256] 6707 bytes
2013-11-27 20:17:11,189 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/user-data.txt - wb: [384] 0 bytes
2013-11-27 20:17:11,194 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/user-data.txt.i - wb: [384] 344 bytes
2013-11-27 20:17:11,198 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 20:17:11,198 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 20:17:11,199 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 20:17:11,199 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/consume_userdata - wb: [420] 18 bytes
2013-11-27 20:17:11,199 - helpers.py[DEBUG]: Running consume_userdata using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/consume_userdata'>)
2013-11-27 20:17:11,200 - stages.py[DEBUG]: Added default handler for set(['text/cloud-config-jsonp', 'text/cloud-config']) from CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']]
2013-11-27 20:17:11,200 - stages.py[DEBUG]: Added default handler for set(['text/x-shellscript']) from ShellScriptPartHandler: [['text/x-shellscript']]
2013-11-27 20:17:11,200 - stages.py[DEBUG]: Added default handler for set(['text/cloud-boothook']) from BootHookPartHandler: [['text/cloud-boothook']]
2013-11-27 20:17:11,200 - stages.py[DEBUG]: Added default handler for set(['text/upstart-job']) from UpstartJobPartHandler: [['text/upstart-job']]
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__begin__, None, 3) with frequency once-per-instance
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__begin__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: {'Content-Type': 'text/x-not-multipart', 'Content-Disposition': 'attachment; filename="part-001"', 'MIME-Version': '1.0'}
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Empty payload of type text/x-not-multipart
2013-11-27 20:17:11,201 - __init__.py[DEBUG]: Calling handler BootHookPartHandler: [['text/cloud-boothook']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,202 - __init__.py[DEBUG]: Calling handler UpstartJobPartHandler: [['text/upstart-job']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,202 - __init__.py[DEBUG]: Calling handler CloudConfigPartHandler: [['text/cloud-config', 'text/cloud-config-jsonp']] (__end__, None, 3) with frequency once-per-instance
2013-11-27 20:17:11,202 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/cloud-config.txt - wb: [384] 0 bytes
2013-11-27 20:17:11,202 - __init__.py[DEBUG]: Calling handler ShellScriptPartHandler: [['text/x-shellscript']] (__end__, None, 2) with frequency once-per-instance
2013-11-27 20:17:11,203 - util.py[DEBUG]: Reading from /proc/cmdline (quiet=False)
2013-11-27 20:17:11,203 - util.py[DEBUG]: Read 151 bytes from /proc/cmdline
2013-11-27 20:17:11,203 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg (quiet=False)
2013-11-27 20:17:11,203 - util.py[DEBUG]: Read 2877 bytes from /etc/cloud/cloud.cfg
2013-11-27 20:17:11,203 - util.py[DEBUG]: Attempting to load yaml from string of length 2877 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,239 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90_dpkg.cfg (quiet=False)
2013-11-27 20:17:11,240 - util.py[DEBUG]: Read 82 bytes from /etc/cloud/cloud.cfg.d/90_dpkg.cfg
2013-11-27 20:17:11,240 - util.py[DEBUG]: Attempting to load yaml from string of length 82 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,244 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/90-azure.cfg (quiet=False)
2013-11-27 20:17:11,248 - util.py[DEBUG]: Read 459 bytes from /etc/cloud/cloud.cfg.d/90-azure.cfg
2013-11-27 20:17:11,248 - util.py[DEBUG]: Attempting to load yaml from string of length 459 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,254 - util.py[DEBUG]: Reading from /etc/cloud/cloud.cfg.d/05_logging.cfg (quiet=False)
2013-11-27 20:17:11,254 - util.py[DEBUG]: Read 1674 bytes from /etc/cloud/cloud.cfg.d/05_logging.cfg
2013-11-27 20:17:11,254 - util.py[DEBUG]: Attempting to load yaml from string of length 1674 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,259 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,260 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,260 - __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'
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,260 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,261 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,261 - __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'
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,261 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,262 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,262 - __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'
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,262 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,262 - __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'
2013-11-27 20:17:11,262 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,263 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,263 - __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'
2013-11-27 20:17:11,263 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,263 - __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'
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,263 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,264 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,264 - __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'
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,264 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,265 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,272 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,272 - __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'
2013-11-27 20:17:11,272 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,272 - __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'
2013-11-27 20:17:11,272 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,272 - __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'
2013-11-27 20:17:11,272 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2013-11-27 20:17:11,272 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2013-11-27 20:17:11,272 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,273 - util.py[DEBUG]: load_yaml given empty string, returning default
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,273 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,273 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,273 - __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'
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,274 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,274 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,274 - __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'
2013-11-27 20:17:11,274 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,274 - __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'
2013-11-27 20:17:11,274 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,275 - __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'
2013-11-27 20:17:11,280 - util.py[DEBUG]: Reading from /var/lib/cloud/instance/cloud-config.txt (quiet=False)
2013-11-27 20:17:11,280 - util.py[DEBUG]: Read 0 bytes from /var/lib/cloud/instance/cloud-config.txt
2013-11-27 20:17:11,280 - util.py[DEBUG]: Attempting to load yaml from string of length 0 with allowed root types (<type 'dict'>,)
2013-11-27 20:17:11,280 - util.py[DEBUG]: load_yaml given empty string, returning default
2013-11-27 20:17:11,280 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,280 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,281 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,281 - __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'
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:11,281 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:11,282 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:11,282 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,282 - __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'
2013-11-27 20:17:11,282 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,282 - __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'
2013-11-27 20:17:11,282 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:11,282 - __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'
2013-11-27 20:17:11,290 - importer.py[DEBUG]: Looking for modules ['cc_migrator', 'cloudinit.config.cc_migrator'] that have attributes ['handle']
2013-11-27 20:17:11,293 - importer.py[DEBUG]: Found cc_migrator with attributes ['handle'] in ['cloudinit.config.cc_migrator']
2013-11-27 20:17:11,293 - importer.py[DEBUG]: Looking for modules ['cc_seed_random', 'cloudinit.config.cc_seed_random'] that have attributes ['handle']
2013-11-27 20:17:11,365 - importer.py[DEBUG]: Found cc_seed_random with attributes ['handle'] in ['cloudinit.config.cc_seed_random']
2013-11-27 20:17:11,365 - importer.py[DEBUG]: Looking for modules ['cc_bootcmd', 'cloudinit.config.cc_bootcmd'] that have attributes ['handle']
2013-11-27 20:17:11,367 - importer.py[DEBUG]: Found cc_bootcmd with attributes ['handle'] in ['cloudinit.config.cc_bootcmd']
2013-11-27 20:17:11,367 - importer.py[DEBUG]: Looking for modules ['cc_write_files', 'cloudinit.config.cc_write_files'] that have attributes ['handle']
2013-11-27 20:17:11,375 - importer.py[DEBUG]: Found cc_write_files with attributes ['handle'] in ['cloudinit.config.cc_write_files']
2013-11-27 20:17:11,375 - importer.py[DEBUG]: Looking for modules ['cc_growpart', 'cloudinit.config.cc_growpart'] that have attributes ['handle']
2013-11-27 20:17:11,379 - importer.py[DEBUG]: Found cc_growpart with attributes ['handle'] in ['cloudinit.config.cc_growpart']
2013-11-27 20:17:11,379 - importer.py[DEBUG]: Looking for modules ['cc_resizefs', 'cloudinit.config.cc_resizefs'] that have attributes ['handle']
2013-11-27 20:17:11,383 - importer.py[DEBUG]: Found cc_resizefs with attributes ['handle'] in ['cloudinit.config.cc_resizefs']
2013-11-27 20:17:11,383 - importer.py[DEBUG]: Looking for modules ['cc_set_hostname', 'cloudinit.config.cc_set_hostname'] that have attributes ['handle']
2013-11-27 20:17:11,385 - importer.py[DEBUG]: Found cc_set_hostname with attributes ['handle'] in ['cloudinit.config.cc_set_hostname']
2013-11-27 20:17:11,385 - importer.py[DEBUG]: Looking for modules ['cc_update_hostname', 'cloudinit.config.cc_update_hostname'] that have attributes ['handle']
2013-11-27 20:17:11,387 - importer.py[DEBUG]: Found cc_update_hostname with attributes ['handle'] in ['cloudinit.config.cc_update_hostname']
2013-11-27 20:17:11,387 - importer.py[DEBUG]: Looking for modules ['cc_update_etc_hosts', 'cloudinit.config.cc_update_etc_hosts'] that have attributes ['handle']
2013-11-27 20:17:11,389 - importer.py[DEBUG]: Found cc_update_etc_hosts with attributes ['handle'] in ['cloudinit.config.cc_update_etc_hosts']
2013-11-27 20:17:11,389 - importer.py[DEBUG]: Looking for modules ['cc_ca_certs', 'cloudinit.config.cc_ca_certs'] that have attributes ['handle']
2013-11-27 20:17:11,390 - importer.py[DEBUG]: Found cc_ca_certs with attributes ['handle'] in ['cloudinit.config.cc_ca_certs']
2013-11-27 20:17:11,390 - importer.py[DEBUG]: Looking for modules ['cc_rsyslog', 'cloudinit.config.cc_rsyslog'] that have attributes ['handle']
2013-11-27 20:17:11,391 - importer.py[DEBUG]: Found cc_rsyslog with attributes ['handle'] in ['cloudinit.config.cc_rsyslog']
2013-11-27 20:17:11,391 - importer.py[DEBUG]: Looking for modules ['cc_users_groups', 'cloudinit.config.cc_users_groups'] that have attributes ['handle']
2013-11-27 20:17:11,393 - importer.py[DEBUG]: Found cc_users_groups with attributes ['handle'] in ['cloudinit.config.cc_users_groups']
2013-11-27 20:17:11,393 - importer.py[DEBUG]: Looking for modules ['cc_ssh', 'cloudinit.config.cc_ssh'] that have attributes ['handle']
2013-11-27 20:17:11,395 - importer.py[DEBUG]: Found cc_ssh with attributes ['handle'] in ['cloudinit.config.cc_ssh']
2013-11-27 20:17:11,395 - importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
2013-11-27 20:17:11,396 - importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
2013-11-27 20:17:11,396 - stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
2013-11-27 20:17:11,397 - helpers.py[DEBUG]: Running config-migrator using lock (<cloudinit.helpers.DummyLock object at 0x23e33d0>)
2013-11-27 20:17:11,397 - cc_migrator.py[DEBUG]: Migrated 0 semaphore files to there canonicalized names
2013-11-27 20:17:11,398 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_seed_random - wb: [420] 18 bytes
2013-11-27 20:17:11,398 - helpers.py[DEBUG]: Running config-seed_random using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_seed_random'>)
2013-11-27 20:17:11,398 - cc_seed_random.py[DEBUG]: Skipping module named seed_random, no 'random_seed' configuration found
2013-11-27 20:17:11,398 - helpers.py[DEBUG]: Running config-bootcmd using lock (<cloudinit.helpers.DummyLock object at 0x23e3690>)
2013-11-27 20:17:11,399 - cc_bootcmd.py[DEBUG]: Skipping module named bootcmd, no 'bootcmd' key in configuration
2013-11-27 20:17:11,399 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_write_files - wb: [420] 18 bytes
2013-11-27 20:17:11,404 - helpers.py[DEBUG]: Running config-write-files using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_write_files'>)
2013-11-27 20:17:11,404 - cc_write_files.py[DEBUG]: Skipping module named write-files, no/empty 'write_files' key in configuration
2013-11-27 20:17:11,404 - helpers.py[DEBUG]: Running config-growpart using lock (<cloudinit.helpers.DummyLock object at 0x23e3890>)
2013-11-27 20:17:11,404 - cc_growpart.py[DEBUG]: No 'growpart' entry in cfg.  Using default: {'ignore_growroot_disabled': False, 'mode': 'auto', 'devices': ['/']}
2013-11-27 20:17:11,404 - util.py[DEBUG]: Running command ['growpart', '--help'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:11,434 - util.py[DEBUG]: Reading from /proc/773/mountinfo (quiet=False)
2013-11-27 20:17:11,435 - util.py[DEBUG]: Read 1071 bytes from /proc/773/mountinfo
2013-11-27 20:17:11,435 - util.py[DEBUG]: Reading from /sys/class/block/sda1/partition (quiet=False)
2013-11-27 20:17:11,435 - util.py[DEBUG]: Read 2 bytes from /sys/class/block/sda1/partition
2013-11-27 20:17:11,435 - util.py[DEBUG]: Reading from /sys/devices/LNXSYSTM:00/device:00/PNP0A03:00/device:08/VMBUS:00/vmbus_0_1/host2/target2:0:0/2:0:0:0/block/sda/dev (quiet=False)
2013-11-27 20:17:11,436 - util.py[DEBUG]: Read 4 bytes from /sys/devices/LNXSYSTM:00/device:00/PNP0A03:00/device:08/VMBUS:00/vmbus_0_1/host2/target2:0:0/2:0:0:0/block/sda/dev
2013-11-27 20:17:11,436 - util.py[DEBUG]: Running command ['growpart', '--dry-run', '/dev/sda', '1'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:11,572 - util.py[DEBUG]: Running command ['growpart', '/dev/sda', '1'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:15,792 - util.py[DEBUG]: resize_devices took 4.358 seconds
2013-11-27 20:17:15,792 - cc_growpart.py[INFO]: '/' resized: changed (/dev/sda, 1) from 2146435072 to 31456231424
2013-11-27 20:17:15,793 - helpers.py[DEBUG]: Running config-resizefs using lock (<cloudinit.helpers.DummyLock object at 0x23e3690>)
2013-11-27 20:17:15,793 - util.py[DEBUG]: Reading from /proc/773/mountinfo (quiet=False)
2013-11-27 20:17:15,794 - util.py[DEBUG]: Read 1071 bytes from /proc/773/mountinfo
2013-11-27 20:17:15,794 - cc_resizefs.py[DEBUG]: resize_info: dev=/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca mnt_point=/ path=/
2013-11-27 20:17:15,794 - cc_resizefs.py[DEBUG]: Resizing / (ext4) using resize2fs /dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca
2013-11-27 20:17:15,794 - util.py[DEBUG]: Running command ('resize2fs', '/dev/disk/by-uuid/6c4f7fbf-3f50-4d4a-8b21-282a09533dca') with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:16,260 - util.py[DEBUG]: Resizing took 0.466 seconds
2013-11-27 20:17:16,260 - cc_resizefs.py[DEBUG]: Resized root filesystem (type=ext4, val=True)
2013-11-27 20:17:16,262 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_set_hostname - wb: [420] 19 bytes
2013-11-27 20:17:16,265 - helpers.py[DEBUG]: Running config-set_hostname using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_set_hostname'>)
2013-11-27 20:17:16,265 - cc_set_hostname.py[DEBUG]: Setting the hostname to utl-1127-t3.localdomain (utl-1127-t3)
2013-11-27 20:17:16,265 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2013-11-27 20:17:16,266 - util.py[DEBUG]: Read 7 bytes from /etc/hostname
2013-11-27 20:17:16,266 - util.py[DEBUG]: Writing to /etc/hostname - wb: [420] 12 bytes
2013-11-27 20:17:16,269 - __init__.py[DEBUG]: Non-persistently setting the system hostname to utl-1127-t3
2013-11-27 20:17:16,270 - util.py[DEBUG]: Running command ['hostname', u'utl-1127-t3'] with allowed return codes [0] (shell=False, capture=True)
2013-11-27 20:17:16,291 - helpers.py[DEBUG]: Running config-update_hostname using lock (<cloudinit.helpers.DummyLock object at 0x23e3d50>)
2013-11-27 20:17:16,291 - cc_update_hostname.py[DEBUG]: Updating hostname to utl-1127-t3.localdomain (utl-1127-t3)
2013-11-27 20:17:16,292 - util.py[DEBUG]: Reading from /etc/hostname (quiet=False)
2013-11-27 20:17:16,292 - util.py[DEBUG]: Read 12 bytes from /etc/hostname
2013-11-27 20:17:16,292 - __init__.py[DEBUG]: Attempting to update hostname to utl-1127-t3 in 1 files
2013-11-27 20:17:16,292 - util.py[DEBUG]: Reading from /var/lib/cloud/data/previous-hostname (quiet=False)
2013-11-27 20:17:16,292 - util.py[DEBUG]: Writing to /var/lib/cloud/data/previous-hostname - wb: [420] 12 bytes
2013-11-27 20:17:16,293 - helpers.py[DEBUG]: Running config-update_etc_hosts using lock (<cloudinit.helpers.DummyLock object at 0x23e3e10>)
2013-11-27 20:17:16,293 - cc_update_etc_hosts.py[DEBUG]: Configuration option 'manage_etc_hosts' is not set, not managing /etc/hosts in module update_etc_hosts
2013-11-27 20:17:16,294 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ca_certs - wb: [420] 19 bytes
2013-11-27 20:17:16,294 - helpers.py[DEBUG]: Running config-ca-certs using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ca_certs'>)
2013-11-27 20:17:16,294 - cc_ca_certs.py[DEBUG]: Skipping module named ca-certs, no 'ca-certs' key in configuration
2013-11-27 20:17:16,295 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_rsyslog - wb: [420] 18 bytes
2013-11-27 20:17:16,295 - helpers.py[DEBUG]: Running config-rsyslog using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_rsyslog'>)
2013-11-27 20:17:16,295 - cc_rsyslog.py[DEBUG]: Skipping module named rsyslog, no 'rsyslog' key in configuration
2013-11-27 20:17:16,296 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_users_groups - wb: [420] 18 bytes
2013-11-27 20:17:16,300 - helpers.py[DEBUG]: Running config-users-groups using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_users_groups'>)
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:16,301 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:16,301 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:16,302 - __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'
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:16,302 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:16,302 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:16,302 - __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'
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:16,303 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:16,303 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:16,303 - __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'
2013-11-27 20:17:16,303 - __init__.py[DEBUG]: Adding user utlemming
2013-11-27 20:17:16,304 - util.py[DEBUG]: Running hidden command to protect sensitive input/output logstring: ['useradd', u'utlemming', '--shell', '/bin/bash', '--password', 'REDACTED', '--comment', 'Ubuntu', '--groups', 'adm,audio,cdrom,dialout,dip,floppy,netdev,plugdev,sudo,video', '-m']
2013-11-27 20:17:17,656 - util.py[DEBUG]: Reading from /etc/sudoers (quiet=False)
2013-11-27 20:17:17,658 - util.py[DEBUG]: Read 745 bytes from /etc/sudoers
2013-11-27 20:17:17,662 - util.py[DEBUG]: Writing to /etc/sudoers.d/90-cloud-init-users - wb: [288] 129 bytes
2013-11-27 20:17:17,669 - util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh - wb: [420] 19 bytes
2013-11-27 20:17:17,669 - helpers.py[DEBUG]: Running config-ssh using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh'>)
2013-11-27 20:17:17,672 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'rsa', '-N', '', '-f', '/etc/ssh/ssh_host_rsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 20:17:18,216 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'dsa', '-N', '', '-f', '/etc/ssh/ssh_host_dsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 20:17:18,428 - util.py[DEBUG]: Running command ['ssh-keygen', '-t', 'ecdsa', '-N', '', '-f', '/etc/ssh/ssh_host_ecdsa_key'] with allowed return codes [0] (shell=False, capture=False)
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:18,520 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:18,521 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:18,521 - __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'
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:18,521 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:18,522 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:18,522 - __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'
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
2013-11-27 20:17:18,522 - importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
2013-11-27 20:17:18,522 - __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
2013-11-27 20:17:18,522 - __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'
2013-11-27 20:17:18,523 - util.py[DEBUG]: Changing the ownership of /home/utlemming/.ssh to 1000:1000
2013-11-27 20:17:18,528 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2013-11-27 20:17:18,528 - util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
2013-11-27 20:17:18,530 - util.py[DEBUG]: Writing to /home/utlemming/.ssh/authorized_keys - wb: [384] 381 bytes
2013-11-27 20:17:18,530 - util.py[DEBUG]: Changing the ownership of /home/utlemming/.ssh/authorized_keys to 1000:1000
2013-11-27 20:17:18,531 - util.py[DEBUG]: Changing the ownership of /root/.ssh to 0:0
2013-11-27 20:17:18,531 - util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
2013-11-27 20:17:18,531 - util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
2013-11-27 20:17:18,536 - util.py[DEBUG]: Writing to /root/.ssh/authorized_keys - wb: [384] 539 bytes
2013-11-27 20:17:18,536 - util.py[DEBUG]: Changing the ownership of /root/.ssh/authorized_keys to 0:0
2013-11-27 20:17:18,537 - cloud-init[DEBUG]: Ran 13 modules with 0 failures
2013-11-27 20:17:18,537 - util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
2013-11-27 20:17:18,537 - util.py[DEBUG]: Read 11 bytes from /proc/uptime
2013-11-27 20:17:18,537 - util.py[DEBUG]: cloud-init mode 'init' took 13.015 seconds (13.02)
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 running 'modules:config' at Wed, 27 Nov 2013 20:17:19 +0000. Up 39.59 seconds.
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_emit_upstart', 'cloudinit.config.cc_emit_upstart'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_emit_upstart with attributes ['handle'] in ['cloudinit.config.cc_emit_upstart']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_disk_setup', 'cloudinit.config.cc_disk_setup'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_disk_setup with attributes ['handle'] in ['cloudinit.config.cc_disk_setup']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_mounts', 'cloudinit.config.cc_mounts'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_mounts with attributes ['handle'] in ['cloudinit.config.cc_mounts']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_ssh_import_id', 'cloudinit.config.cc_ssh_import_id'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_ssh_import_id with attributes ['handle'] in ['cloudinit.config.cc_ssh_import_id']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_locale', 'cloudinit.config.cc_locale'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_locale with attributes ['handle'] in ['cloudinit.config.cc_locale']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_set_passwords', 'cloudinit.config.cc_set_passwords'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_set_passwords with attributes ['handle'] in ['cloudinit.config.cc_set_passwords']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_grub_dpkg', 'cloudinit.config.cc_grub_dpkg'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_grub_dpkg with attributes ['handle'] in ['cloudinit.config.cc_grub_dpkg']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_apt_pipelining', 'cloudinit.config.cc_apt_pipelining'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_apt_pipelining with attributes ['handle'] in ['cloudinit.config.cc_apt_pipelining']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_apt_configure', 'cloudinit.config.cc_apt_configure'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_apt_configure with attributes ['handle'] in ['cloudinit.config.cc_apt_configure']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_package_update_upgrade_install', 'cloudinit.config.cc_package_update_upgrade_install'] that have attributes ['handle']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_package_update_upgrade_install with attributes ['handle'] in ['cloudinit.config.cc_package_update_upgrade_install']
Nov 27 20:17:19 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_landscape', 'cloudinit.config.cc_landscape'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_landscape with attributes ['handle'] in ['cloudinit.config.cc_landscape']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_timezone', 'cloudinit.config.cc_timezone'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_timezone with attributes ['handle'] in ['cloudinit.config.cc_timezone']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_puppet', 'cloudinit.config.cc_puppet'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_puppet with attributes ['handle'] in ['cloudinit.config.cc_puppet']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_chef', 'cloudinit.config.cc_chef'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_chef with attributes ['handle'] in ['cloudinit.config.cc_chef']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_salt_minion', 'cloudinit.config.cc_salt_minion'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_salt_minion with attributes ['handle'] in ['cloudinit.config.cc_salt_minion']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_mcollective', 'cloudinit.config.cc_mcollective'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_mcollective with attributes ['handle'] in ['cloudinit.config.cc_mcollective']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_disable_ec2_metadata', 'cloudinit.config.cc_disable_ec2_metadata'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_disable_ec2_metadata with attributes ['handle'] in ['cloudinit.config.cc_disable_ec2_metadata']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_runcmd', 'cloudinit.config.cc_runcmd'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_runcmd with attributes ['handle'] in ['cloudinit.config.cc_runcmd']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_byobu', 'cloudinit.config.cc_byobu'] that have attributes ['handle']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_byobu with attributes ['handle'] in ['cloudinit.config.cc_byobu']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-emit_upstart using lock (<cloudinit.helpers.DummyLock object at 0x31548d0>)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['initctl', 'emit', 'cloud-config', 'CLOUD_CFG=/var/lib/cloud/instance/cloud-config.txt'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_disk_setup - wb: [420] 20 bytes
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-disk_setup using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_disk_setup'>)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: updated disk_setup device entry 'ephemeral0' to '/dev/sdb'
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Partitioning disks: {'/dev/sdb': {'_origname': 'ephemeral0', 'table_type': 'mbr', 'layout': True, 'overwrite': False}}
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Creating new partition table/disk
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking values for /dev/sdb definition
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking against default devices
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking if device /dev/sdb is a valid device
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/bin/lsblk', '--pairs', '--out', 'NAME,TYPE,FSTYPE,LABEL', '/dev/sdb', '--nodeps'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking if device layout matches
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/udevadm', 'settle'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blockdev', '--rereadpt', '/dev/sdb'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/udevadm', 'settle'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/sfdisk', '-l', '/dev/sdb'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Device partitioning layout matches
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Creating partition on /dev/sdb took 0.392 seconds
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: setting up filesystems: [{'device': 'ephemeral0.1', 'replace_fs': 'ntfs', 'filesystem': 'ext4'}]
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: ephemeral0.1 is mapped to disk=/dev/sdb part=1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Creating new filesystem.
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking /dev/sdb against default devices
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Manual request of partition 1 for /dev/sdb1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Checking device /dev/sdb1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/blkid', '-c', '/dev/null', '/dev/sdb1'] with allowed return codes [0, 2] (shell=False, capture=True)
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Device /dev/sdb1 has Temporary Storage ntfs
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Device /dev/sdb1 is cleared for formating
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: File system None will be created on /dev/sdb1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]: Creating file system None on /dev/sdb1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] cc_disk_setup.py[DEBUG]:      Using cmd: /sbin/mkfs.ext4 /dev/sdb1
Nov 27 20:17:20 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/sbin/mkfs.ext4', '/dev/sdb1'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Creating fs for /dev/sdb took 2.037 seconds
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_mounts - wb: [420] 20 bytes
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-mounts using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_mounts'>)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_mounts.py[DEBUG]: Attempting to determine the real name of ephemeral0
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_mounts.py[DEBUG]: Mapped metadata name ephemeral0 to /dev/sdb
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_mounts.py[DEBUG]: changed default device ephemeral0 => /dev/sdb1
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_mounts.py[DEBUG]: Attempting to determine the real name of swap
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_mounts.py[DEBUG]: Ignoring nonexistant default named mount swap
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /etc/fstab (quiet=False)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 71 bytes from /etc/fstab
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /etc/fstab - wb: [420] 135 bytes
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ('mount', '-a') with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh_import_id - wb: [420] 20 bytes
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-ssh-import-id using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh_import_id'>)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:22 utl-1127-t3 [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'
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:22 utl-1127-t3 [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'
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:22 utl-1127-t3 [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'
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_locale - wb: [420] 20 bytes
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-locale using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_locale'>)
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] cc_locale.py[DEBUG]: Setting locale to en_US.UTF-8
Nov 27 20:17:22 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['locale-gen', 'en_US.UTF-8'] with allowed return codes [0] (shell=False, capture=False)
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['update-locale', 'en_US.UTF-8'] with allowed return codes [0] (shell=False, capture=False)
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /etc/default/locale - wb: [420] 87 bytes
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_set_passwords - wb: [420] 20 bytes
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-set-passwords using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_set_passwords'>)
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 2511 bytes from /etc/ssh/sshd_config
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] cc_set_passwords.py[DEBUG]: Replacing auth line 51 with no
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /etc/ssh/sshd_config - wb: [420] 2510 bytes
Nov 27 20:17:26 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['service', 'ssh', 'restart'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:27 utl-1127-t3 [CLOUDINIT] cc_set_passwords.py[DEBUG]: Restarted the ssh daemon
Nov 27 20:17:27 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_grub_dpkg - wb: [420] 20 bytes
Nov 27 20:17:27 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-grub-dpkg using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_grub_dpkg'>)
Nov 27 20:17:27 utl-1127-t3 [CLOUDINIT] cc_grub_dpkg.py[DEBUG]: Setting grub debconf-set-selections with '/dev/sda','false'
Nov 27 20:17:27 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['debconf-set-selections'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_apt_pipelining - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-apt-pipelining using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_apt_pipelining'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /etc/apt/apt.conf.d/90cloud-init-pipelining - wb: [420] 80 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_apt_pipelining.py[DEBUG]: Wrote /etc/apt/apt.conf.d/90cloud-init-pipelining with apt pipeline depth setting 0
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_apt_configure - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-apt-configure using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_apt_configure'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['lsb_release', '-cs'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['dpkg', '--print-architecture'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: filtered distro mirror info: {'security': 'http://security.ubuntu.com/ubuntu', 'primary': 'http://azure.archive.ubuntu.com/ubuntu/'}
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_apt_configure.py[DEBUG]: Mirror info: {'security': 'http://security.ubuntu.com/ubuntu', 'primary': 'http://azure.archive.ubuntu.com/ubuntu/', 'mirror': 'http://azure.archive.ubuntu.com/ubuntu/'}
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /etc/cloud/templates/sources.list.ubuntu.tmpl (quiet=False)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 2768 bytes from /etc/cloud/templates/sources.list.ubuntu.tmpl
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /etc/apt/sources.list - wb: [420] 3263 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_universe_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_universe_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_Release to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_Release
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_main_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_main_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_main_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_main_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_Release.gpg to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_Release.gpg
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_main_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_main_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_universe_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_universe_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_Release to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_Release
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_universe_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_universe_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_restricted_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_restricted_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_main_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_main_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_multiverse_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_multiverse_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_multiverse_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_multiverse_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_restricted_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_restricted_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_multiverse_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_multiverse_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_universe_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_universe_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty_restricted_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty_restricted_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_restricted_binary-amd64_Packages to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_restricted_binary-amd64_Packages
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_multiverse_i18n_Translation-en to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_multiverse_i18n_Translation-en
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Renaming /var/lib/apt/lists/archive.ubuntu.com_ubuntu_dists_trusty-updates_Release.gpg to /var/lib/apt/lists/azure.archive.ubuntu.com_ubuntu_dists_trusty-updates_Release.gpg
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_package_update_upgrade_install - wb: [420] 19 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-package-update-upgrade-install using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_package_update_upgrade_install'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_landscape - wb: [420] 19 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-landscape using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_landscape'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_timezone - wb: [420] 19 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-timezone using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_timezone'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_timezone.py[DEBUG]: Skipping module named timezone, no 'timezone' specified
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_puppet - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-puppet using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_puppet'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_puppet.py[DEBUG]: Skipping module named puppet, no 'puppet' configuration found
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_chef - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-chef using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_chef'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_chef.py[DEBUG]: Skipping module named chef, no 'chef' key in configuration
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_salt_minion - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-salt-minion using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_salt_minion'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_salt_minion.py[DEBUG]: Skipping module named salt-minion, no 'salt_minion' key in configuration
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_mcollective - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-mcollective using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_mcollective'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_mcollective.py[DEBUG]: Skipping module named mcollective, no 'mcollective' key in configuration
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-disable-ec2-metadata using lock (<cloudinit.helpers.DummyLock object at 0x3213590>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_disable_ec2_metadata.py[DEBUG]: Skipping module named disable-ec2-metadata, disabling the ec2 route not enabled
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_runcmd - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-runcmd using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_runcmd'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_runcmd.py[DEBUG]: Skipping module named runcmd, no 'runcmd' key in configuration
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_byobu - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-byobu using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_byobu'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_byobu.py[DEBUG]: Skipping module named byobu, no 'byobu' values found
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cloud-init[DEBUG]: Ran 19 modules with 0 failures
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'modules' took 8.779 seconds (8.77)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 running 'modules:final' at Wed, 27 Nov 2013 20:17:28 +0000. Up 48.67 seconds.
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_rightscale_userdata', 'cloudinit.config.cc_rightscale_userdata'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_rightscale_userdata with attributes ['handle'] in ['cloudinit.config.cc_rightscale_userdata']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_once', 'cloudinit.config.cc_scripts_per_once'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_once with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_once']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_boot', 'cloudinit.config.cc_scripts_per_boot'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_boot with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_boot']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_per_instance', 'cloudinit.config.cc_scripts_per_instance'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_per_instance with attributes ['handle'] in ['cloudinit.config.cc_scripts_per_instance']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_scripts_user', 'cloudinit.config.cc_scripts_user'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_scripts_user with attributes ['handle'] in ['cloudinit.config.cc_scripts_user']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_ssh_authkey_fingerprints', 'cloudinit.config.cc_ssh_authkey_fingerprints'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_ssh_authkey_fingerprints with attributes ['handle'] in ['cloudinit.config.cc_ssh_authkey_fingerprints']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_keys_to_console', 'cloudinit.config.cc_keys_to_console'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_keys_to_console with attributes ['handle'] in ['cloudinit.config.cc_keys_to_console']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_phone_home', 'cloudinit.config.cc_phone_home'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_phone_home with attributes ['handle'] in ['cloudinit.config.cc_phone_home']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_final_message', 'cloudinit.config.cc_final_message'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_final_message with attributes ['handle'] in ['cloudinit.config.cc_final_message']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cc_power_state_change', 'cloudinit.config.cc_power_state_change'] that have attributes ['handle']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found cc_power_state_change with attributes ['handle'] in ['cloudinit.config.cc_power_state_change']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['ubuntu', 'cloudinit.distros.ubuntu'] that have attributes ['Distro']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found ubuntu with attributes ['Distro'] in ['cloudinit.distros.ubuntu']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] stages.py[DEBUG]: Using distro class <class 'cloudinit.distros.ubuntu.Distro'>
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_rightscale_userdata - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-rightscale_userdata using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_rightscale_userdata'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] cc_rightscale_userdata.py[DEBUG]: Failed to get raw userdata in module rightscale_userdata
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/sem/config_scripts_per_once.once - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-once using lock (<FileLock using file '/var/lib/cloud/sem/config_scripts_per_once.once'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-boot using lock (<cloudinit.helpers.DummyLock object at 0x2528f10>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_scripts_per_instance - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-per-instance using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_scripts_per_instance'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_scripts_user - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-scripts-user using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_scripts_user'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh_authkey_fingerprints - wb: [420] 20 bytes
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-ssh-authkey-fingerprints using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_ssh_authkey_fingerprints'>)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:28 utl-1127-t3 [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'
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:28 utl-1127-t3 [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'
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_list'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_list with attributes ['Merger'] in ['cloudinit.mergers.m_list']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_dict'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_dict with attributes ['Merger'] in ['cloudinit.mergers.m_dict']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Looking for modules ['cloudinit.mergers.m_str'] that have attributes ['Merger']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] importer.py[DEBUG]: Found m_str with attributes ['Merger'] in ['cloudinit.mergers.m_str']
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] __init__.py[DEBUG]: Merging 'dict' into 'dict' using method '_handle_unknown' of 'LookupMerger: (3)'
Nov 27 20:17:28 utl-1127-t3 [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'
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /etc/ssh/sshd_config (quiet=False)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 2510 bytes from /etc/ssh/sshd_config
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /home/utlemming/.ssh/authorized_keys (quiet=False)
Nov 27 20:17:28 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 381 bytes from /home/utlemming/.ssh/authorized_keys
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_keys_to_console - wb: [420] 20 bytes
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-keys-to-console using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_keys_to_console'>)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Running command ['/usr/lib/cloud-init/write-ssh-key-fingerprints', '', 'ssh-dss'] with allowed return codes [0] (shell=False, capture=True)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_phone_home - wb: [420] 20 bytes
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-phone-home using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_phone_home'>)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] cc_phone_home.py[DEBUG]: Skipping module named phone-home, no 'phone_home' configuration found
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-final-message using lock (<cloudinit.helpers.DummyLock object at 0x252efd0>)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Cloud-init v. 0.7.3 finished at Wed, 27 Nov 2013 20:17:29 +0000. Datasource DataSourceAzureNet [seed=/dev/sr0].  Up 48.97 seconds
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instance/boot-finished - wb: [420] 51 bytes
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Writing to /var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_power_state_change - wb: [420] 20 bytes
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] helpers.py[DEBUG]: Running config-power-state-change using lock (<FileLock using file '/var/lib/cloud/instances/c11884fa5cc74b508b1ec96baa524de6/sem/config_power_state_change'>)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] cc_power_state_change.py[DEBUG]: no power_state provided. doing nothing
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] cloud-init[DEBUG]: Ran 10 modules with 0 failures
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Reading from /proc/uptime (quiet=False)
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: Read 11 bytes from /proc/uptime
Nov 27 20:17:29 utl-1127-t3 [CLOUDINIT] util.py[DEBUG]: cloud-init mode 'modules' took 0.318 seconds (0.31)

Revision history for this message

Scott Moser (smoser) wrote on 2014-01-09:

Ben,
Do you see this sometime other that first boot?
I cannot recreate this problem after boot.

I honestly can't come up with an explanation for the description you've given.

Changed in cloud-init (Ubuntu):
status:	New → Triaged
importance:	Undecided → Low
assignee:	nobody → Ben Howard (utlemming)

Ben Howard (darkmuggle-deactivatedaccount) on 2016-04-21

Changed in cloud-init (Ubuntu):
assignee:	Ben Howard (utlemming) → nobody

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2016-12-13:

Setting this to incomplete, given that utlemming is unassigned, and the latest request for details unanswered.

Changed in cloud-init (Ubuntu):
status:	Triaged → Incomplete

Revision history for this message

Launchpad Janitor (janitor) wrote on 2017-02-12:

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

Changed in cloud-init (Ubuntu):
status:	Incomplete → Expired

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Bug attachments

Dependencies.txt Edit

Add attachment

Remote bug watches

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

Ubuntucloud-init package

datasource for Azure fails to load if datasource OVF starts first

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntu
cloud-init package