Project

General

Profile

Bug #12725 » ansible-2.log

Loïc Dachary, 08/18/2015 08:03 PM

 
2015-08-18T19:53:11.386 DEBUG:teuthology.run:Teuthology command: teuthology /tmp/teuthology-worker.vA1oig.tmp -- --verbose --lock --description ceph-deploy/basic/{ceph-deploy-overrides/ceph_deploy_dmcrypt.yaml config_options/cephdeploy_conf.yaml distros/centos_7.0.yaml tasks/ceph-deploy_hello_world.yaml} --name ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack --block --owner scheduled_ubuntu@teuthology --archive /usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1
2015-08-18T19:53:11.429 DEBUG:teuthology.report:Pushing job info to http://localhost:8080/
2015-08-18T19:53:11.505 DEBUG:teuthology.run:Config:
archive-on-error: true
archive_path: /usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1
archive_upload_key: teuthology/openstack/archive-key
branch: wip-11881-multipath
description: ceph-deploy/basic/{ceph-deploy-overrides/ceph_deploy_dmcrypt.yaml config_options/cephdeploy_conf.yaml
distros/centos_7.0.yaml tasks/ceph-deploy_hello_world.yaml}
email: loic@dachary.org
job_id: '1'
last_in_suite: false
machine_type: openstack
name: ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack
nuke-on-error: true
openstack:
machine:
cpus: 1
disk: 10
ram: 2000
volumes:
count: 3
size: 10
os_type: centos
os_version: '7.0'
overrides:
admin_socket:
branch: wip-11881-multipath
ceph:
conf:
global:
mon lease: 15
mon lease ack timeout: 25
osd heartbeat grace: 100
mon:
debug mon: 20
debug ms: 1
debug paxos: 20
osd:
debug filestore: 20
debug journal: 20
debug ms: 1
debug osd: 20
log-whitelist:
- slow request
sha1: bc2c1c3b2f205e322639aef89956f7475e064ac2
ceph-deploy:
branch:
dev: wip-11881-multipath
conf:
client:
log file: /var/log/ceph/ceph-$name.$pid.log
global:
debug ms: 1
mon pg warn min per osd: 2
osd pool default size: 2
mon:
debug mon: 10
debug ms: 20
debug paxos: 20
osd default pool size: 2
osd:
debug osd: 10
dmcrypt: true
install:
ceph:
sha1: bc2c1c3b2f205e322639aef89956f7475e064ac2
rgw:
default_idle_timeout: 1200
s3tests:
idle_timeout: 1200
workunit:
sha1: bc2c1c3b2f205e322639aef89956f7475e064ac2
owner: scheduled_ubuntu@teuthology
priority: 1000
roles:
- - mon.a
- mds.0
- osd.0
- - osd.1
- mon.b
- client.0
sha1: bc2c1c3b2f205e322639aef89956f7475e064ac2
suite: ceph-deploy
suite_branch: wip-11881-multipath
suite_path: /home/ubuntu/src/ceph-qa-suite_wip-11881-multipath
tasks:
- ansible.cephlab: null
- clock.check: null
- install:
extras: true
- print: '**** done install extras'
- ssh_keys: null
- print: '**** done ssh_keys'
- ceph-deploy: null
- print: '**** done ceph-deploy'
- workunit:
clients:
client.0:
- ceph-deploy/ceph-deploy_hello_world.sh
- print: '**** done ceph-deploy/ceph-deploy_hello_world.sh'
teuthology_branch: master
tube: openstack
verbose: true
worker_log: /tmp/log/worker.openstack.24842
2015-08-18T19:53:11.505 INFO:teuthology.run:suite_path is set to /home/ubuntu/src/ceph-qa-suite_wip-11881-multipath; will attempt to use it
2015-08-18T19:53:11.505 INFO:teuthology.run:Found tasks at /home/ubuntu/src/ceph-qa-suite_wip-11881-multipath/tasks
2015-08-18T19:53:11.513 INFO:teuthology.run_tasks:Running task internal.check_packages...
2015-08-18T19:53:11.513 INFO:teuthology.task.internal:Checking packages...
2015-08-18T19:53:11.520 INFO:teuthology.task.internal:Checking packages for os_type,'centos' flavor 'basic' and ceph hash 'bc2c1c3b2f205e322639aef89956f7475e064ac2'
2015-08-18T19:53:11.520 INFO:teuthology.packaging:Looking for package version: http://gitbuilder.ceph.com/ceph-rpm-centos7-x86_64-basic/sha1/bc2c1c3b2f205e322639aef89956f7475e064ac2/version
2015-08-18T19:53:11.816 INFO:teuthology.packaging:Found version: 9.0.2
2015-08-18T19:53:11.816 INFO:teuthology.task.internal:Found packages for ceph version 9.0.2
2015-08-18T19:53:11.816 INFO:teuthology.run_tasks:Running task internal.lock_machines...
2015-08-18T19:53:11.817 INFO:teuthology.task.internal:Locking machines...
2015-08-18T19:53:11.817 DEBUG:teuthology.report:Pushing job info to http://localhost:8080/
2015-08-18T19:53:11.857 DEBUG:teuthology.provision:ProvisionOpenStack: {'machine': {'disk': 20, 'ram': 8000, 'cpus': 1}, 'subnet': '149.202.160.0/19', 'volumes': {'count': 0, 'size': 1}, 'user-data': 'teuthology/openstack/openstack-{os_type}-{os_version}-user-data.txt', 'ip': '149.202.170.149', 'flavor-select-regexp': '^(vps|eg)-', 'nameserver': '149.202.170.149'}
2015-08-18T19:53:11.858 DEBUG:teuthology.provision:ProvisionOpenStack:create
2015-08-18T19:53:11.858 DEBUG:teuthology.misc:openstack image list -f json --property name='teuthology-centos-7.0'
2015-08-18T19:53:13.158 DEBUG:teuthology.misc:openstack image list -f json --property name='teuthology-centos-7.0' output [{"ID": "94967743-087d-44d3-a9bc-1bfe9481127b", "Name": "teuthology-centos-7.0"}]

2015-08-18T19:53:13.158 DEBUG:teuthology.misc:openstack flavor list -f json
2015-08-18T19:53:14.204 DEBUG:teuthology.misc:openstack flavor list -f json output [{"ID": "0c36bb1d-bd1e-4294-ac75-60fd727054c8", "Name": "win-eg-15", "RAM": 15000, "Disk": 400, "Ephemeral": 0, "VCPUs": 4, "Is Public": true}, {"ID": "0e2b8841-d764-49b4-b2ac-24c8df2c6806", "Name": "sp-30", "RAM": 30000, "Disk": 200, "Ephemeral": 0, "VCPUs": 2, "Is Public": true}, {"ID": "169e7020-0436-4e8c-b2c8-213a57a044b5", "Name": "win-sp-120", "RAM": 120000, "Disk": 800, "Ephemeral": 0, "VCPUs": 8, "Is Public": true}, {"ID": "18811d09-053e-4ad0-b297-3c11ceefd136", "Name": "sp-60", "RAM": 60000, "Disk": 400, "Ephemeral": 0, "VCPUs": 4, "Is Public": true}, {"ID": "1e2c13fc-4ba9-4773-a13e-75ce96fb4e96", "Name": "eg-120", "RAM": 120000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 32, "Is Public": true}, {"ID": "1e5a7cf5-d58c-4633-8069-5aba49b00be1", "Name": "win-sp-240", "RAM": 240000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 16, "Is Public": true}, {"ID": "22096e9d-5150-4f54-bb8d-6c8b243a28bb", "Name": "win-sp-60", "RAM": 60000, "Disk": 400, "Ephemeral": 0, "VCPUs": 4, "Is Public": true}, {"ID": "23ec7924-483c-4414-9aaf-bf03575f0bfe", "Name": "eg-15", "RAM": 15000, "Disk": 400, "Ephemeral": 0, "VCPUs": 4, "Is Public": true}, {"ID": "24c1f706-3278-4ca7-a773-7df7f999cf14", "Name": "win-eg-60", "RAM": 60000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 16, "Is Public": true}, {"ID": "30b43ca1-131f-4b0d-8087-e03bc99f7ec6", "Name": "sp-120", "RAM": 120000, "Disk": 800, "Ephemeral": 0, "VCPUs": 8, "Is Public": true}, {"ID": "3502c448-8c96-4062-bf78-c5d2ac962e6d", "Name": "win-eg-120", "RAM": 120000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 32, "Is Public": true}, {"ID": "3a9711d2-a4fb-4d2f-a3cd-1972fd53eb5e", "Name": "vps-ssd-3", "RAM": 8000, "Disk": 40, "Ephemeral": 0, "VCPUs": 2, "Is Public": true}, {"ID": "6763bd1b-5d23-4c87-aca7-d46e35d343a4", "Name": "win-eg-7", "RAM": 7000, "Disk": 200, "Ephemeral": 0, "VCPUs": 2, "Is Public": true}, {"ID": "7eacbe7c-5033-4123-8eec-d61bf27359f9", "Name": "win-sp-30", "RAM": 30000, "Disk": 200, "Ephemeral": 0, "VCPUs": 2, "Is Public": true}, {"ID": "8f08b006-a68b-4eed-80cf-36f8212f8d73", "Name": "win-eg-30", "RAM": 30000, "Disk": 800, "Ephemeral": 0, "VCPUs": 8, "Is Public": true}, {"ID": "98c1e679-5f2c-4069-b4da-4a4f7179b758", "Name": "vps-ssd-1", "RAM": 2000, "Disk": 10, "Ephemeral": 0, "VCPUs": 1, "Is Public": true}, {"ID": "a42a6051-16c7-4563-9cca-9c1abf36e460", "Name": "sp-240", "RAM": 240000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 16, "Is Public": true}, {"ID": "b41c89be-7b7d-4ecc-9cd8-bea145bbbd76", "Name": "eg-7", "RAM": 7000, "Disk": 200, "Ephemeral": 0, "VCPUs": 2, "Is Public": true}, {"ID": "b62d1735-774d-4983-9ed6-283c921d29d7", "Name": "eg-30", "RAM": 30000, "Disk": 800, "Ephemeral": 0, "VCPUs": 8, "Is Public": true}, {"ID": "c3d1d22a-03b3-4fa4-bcc4-1dff4e2b2d32", "Name": "vps-ssd-2", "RAM": 4000, "Disk": 20, "Ephemeral": 0, "VCPUs": 1, "Is Public": true}, {"ID": "ccb922b6-04ad-422d-a8bc-7aff1eae6954", "Name": "eg-60", "RAM": 60000, "Disk": 1600, "Ephemeral": 0, "VCPUs": 16, "Is Public": true}]

2015-08-18T19:53:14.204 DEBUG:teuthology.openstack:sorted flavor = [{u'Name': u'vps-ssd-1', u'RAM': 2000, u'Ephemeral': 0, u'VCPUs': 1, u'Is Public': True, u'Disk': 10, u'ID': u'98c1e679-5f2c-4069-b4da-4a4f7179b758'}, {u'Name': u'vps-ssd-2', u'RAM': 4000, u'Ephemeral': 0, u'VCPUs': 1, u'Is Public': True, u'Disk': 20, u'ID': u'c3d1d22a-03b3-4fa4-bcc4-1dff4e2b2d32'}, {u'Name': u'eg-7', u'RAM': 7000, u'Ephemeral': 0, u'VCPUs': 2, u'Is Public': True, u'Disk': 200, u'ID': u'b41c89be-7b7d-4ecc-9cd8-bea145bbbd76'}, {u'Name': u'vps-ssd-3', u'RAM': 8000, u'Ephemeral': 0, u'VCPUs': 2, u'Is Public': True, u'Disk': 40, u'ID': u'3a9711d2-a4fb-4d2f-a3cd-1972fd53eb5e'}, {u'Name': u'eg-15', u'RAM': 15000, u'Ephemeral': 0, u'VCPUs': 4, u'Is Public': True, u'Disk': 400, u'ID': u'23ec7924-483c-4414-9aaf-bf03575f0bfe'}, {u'Name': u'eg-30', u'RAM': 30000, u'Ephemeral': 0, u'VCPUs': 8, u'Is Public': True, u'Disk': 800, u'ID': u'b62d1735-774d-4983-9ed6-283c921d29d7'}, {u'Name': u'eg-60', u'RAM': 60000, u'Ephemeral': 0, u'VCPUs': 16, u'Is Public': True, u'Disk': 1600, u'ID': u'ccb922b6-04ad-422d-a8bc-7aff1eae6954'}, {u'Name': u'eg-120', u'RAM': 120000, u'Ephemeral': 0, u'VCPUs': 32, u'Is Public': True, u'Disk': 1600, u'ID': u'1e2c13fc-4ba9-4773-a13e-75ce96fb4e96'}]
2015-08-18T19:53:14.205 DEBUG:teuthology.misc:openstack server create -f json --image 'teuthology-centos-7.0' --flavor 'vps-ssd-1' --key-name teuthology --user-data /tmp/tmp45alHn --min 2 --max 2 --security-group teuthology --property teuthology=333a94d2ac741af4e6ec9ea2b246159c --property ownedby=149.202.170.149 --wait target
2015-08-18T19:53:54.399 DEBUG:teuthology.misc:openstack server create -f json --image 'teuthology-centos-7.0' --flavor 'vps-ssd-1' --key-name teuthology --user-data /tmp/tmp45alHn --min 2 --max 2 --security-group teuthology --property teuthology=333a94d2ac741af4e6ec9ea2b246159c --property ownedby=149.202.170.149 --wait target output
[{"Field": "OS-DCF:diskConfig", "Value": "MANUAL"}, {"Field": "OS-EXT-AZ:availability_zone", "Value": "nova"}, {"Field": "OS-EXT-STS:power_state", "Value": 1}, {"Field": "OS-EXT-STS:task_state", "Value": null}, {"Field": "OS-EXT-STS:vm_state", "Value": "active"}, {"Field": "OS-SRV-USG:launched_at", "Value": "2015-08-18T19:53:50.000000"}, {"Field": "OS-SRV-USG:terminated_at", "Value": null}, {"Field": "accessIPv4", "Value": ""}, {"Field": "accessIPv6", "Value": ""}, {"Field": "addresses", "Value": "Ext-Net=149.202.170.153"}, {"Field": "adminPass", "Value": "Ryb8e5QKovYW"}, {"Field": "config_drive", "Value": ""}, {"Field": "created", "Value": "2015-08-18T19:53:17Z"}, {"Field": "flavor", "Value": "vps-ssd-1 (98c1e679-5f2c-4069-b4da-4a4f7179b758)"}, {"Field": "hostId", "Value": "643dffa5fd86216e17116ac0b2b145e2410835ccdba3e2f75fcc9cd5"}, {"Field": "id", "Value": "7f58dd70-4d2e-4e13-aa61-698fcee927c8"}, {"Field": "image", "Value": "teuthology-centos-7.0 (94967743-087d-44d3-a9bc-1bfe9481127b)"}, {"Field": "key_name", "Value": "teuthology"}, {"Field": "name", "Value": "target-7f58dd70-4d2e-4e13-aa61-698fcee927c8"}, {"Field": "os-extended-volumes:volumes_attached", "Value": []}, {"Field": "progress", "Value": 0}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"Field": "security_groups", "Value": [{"name": "teuthology"}]}, {"Field": "status", "Value": "ACTIVE"}, {"Field": "updated", "Value": "2015-08-18T19:53:50Z"}, {"Field": "user_id", "Value": "3a075820e5d24fda96cd340b87fd94e9"}]

2015-08-18T19:53:54.399 DEBUG:teuthology.misc:openstack server list -f json --long
2015-08-18T19:53:55.656 DEBUG:teuthology.misc:openstack server list -f json --long output [{"ID": "b26405dc-af10-492a-931c-6baca0275c94", "Name": "target-b26405dc-af10-492a-931c-6baca0275c94", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.152", "Availability Zone": "nova", "Host": "", "Properties": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"ID": "7f58dd70-4d2e-4e13-aa61-698fcee927c8", "Name": "target-7f58dd70-4d2e-4e13-aa61-698fcee927c8", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.153", "Availability Zone": "nova", "Host": "", "Properties": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"ID": "127d2f4d-bb50-4bbb-acb0-05ab8aa4f851", "Name": "teuthology", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.149", "Availability Zone": "nova", "Host": "", "Properties": ""}, {"ID": "018bc993-6944-4428-a057-6c2f3e472a33", "Name": "other", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.161.79", "Availability Zone": "nova", "Host": "", "Properties": ""}]

2015-08-18T19:53:55.657 DEBUG:teuthology.misc:openstack server show -f json b26405dc-af10-492a-931c-6baca0275c94
2015-08-18T19:53:57.427 DEBUG:teuthology.misc:openstack server show -f json b26405dc-af10-492a-931c-6baca0275c94 output [{"Field": "OS-DCF:diskConfig", "Value": "MANUAL"}, {"Field": "OS-EXT-AZ:availability_zone", "Value": "nova"}, {"Field": "OS-EXT-STS:power_state", "Value": 1}, {"Field": "OS-EXT-STS:task_state", "Value": null}, {"Field": "OS-EXT-STS:vm_state", "Value": "active"}, {"Field": "OS-SRV-USG:launched_at", "Value": "2015-08-18T19:53:50.000000"}, {"Field": "OS-SRV-USG:terminated_at", "Value": null}, {"Field": "accessIPv4", "Value": ""}, {"Field": "accessIPv6", "Value": ""}, {"Field": "addresses", "Value": "Ext-Net=149.202.170.152"}, {"Field": "config_drive", "Value": ""}, {"Field": "created", "Value": "2015-08-18T19:53:17Z"}, {"Field": "flavor", "Value": "vps-ssd-1 (98c1e679-5f2c-4069-b4da-4a4f7179b758)"}, {"Field": "hostId", "Value": "643dffa5fd86216e17116ac0b2b145e2410835ccdba3e2f75fcc9cd5"}, {"Field": "id", "Value": "b26405dc-af10-492a-931c-6baca0275c94"}, {"Field": "image", "Value": "teuthology-centos-7.0 (94967743-087d-44d3-a9bc-1bfe9481127b)"}, {"Field": "key_name", "Value": "teuthology"}, {"Field": "name", "Value": "target-b26405dc-af10-492a-931c-6baca0275c94"}, {"Field": "os-extended-volumes:volumes_attached", "Value": []}, {"Field": "progress", "Value": 0}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"Field": "security_groups", "Value": [{"name": "teuthology"}]}, {"Field": "status", "Value": "ACTIVE"}, {"Field": "updated", "Value": "2015-08-18T19:53:50Z"}, {"Field": "user_id", "Value": "3a075820e5d24fda96cd340b87fd94e9"}]

2015-08-18T19:53:57.429 DEBUG:teuthology.misc:openstack server set --name target170152 b26405dc-af10-492a-931c-6baca0275c94
2015-08-18T19:53:58.958 DEBUG:teuthology.misc:openstack server set --name target170152 b26405dc-af10-492a-931c-6baca0275c94 output
2015-08-18T19:54:00.013 INFO:teuthology.misc:try ssh_keyscan again for target170152.teuthology
2015-08-18T19:54:21.074 DEBUG:teuthology.openstack:cloud_init_wait target170152.teuthology
2015-08-18T19:54:21.868 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:22.477 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:07 localhost cloud-init: nameserver 149.202.170.149
Aug 18 19:54:07 localhost cloud-init: search teuthology
Aug 18 19:54:07 localhost cloud-init: target170152.teuthologyDefaults !requiretty
Aug 18 19:54:07 localhost cloud-init: Defaults visiblepw
Aug 18 19:54:08 localhost cloud-init: Cloud-init v. 0.7.5 running 'modules:config' at Tue, 18 Aug 2015 19:54:08 +0000. Up 13.71 seconds.
Aug 18 19:54:08 localhost cloud-init: Loaded plugins: fastestmirror
Aug 18 19:54:13 localhost cloud-init: Determining fastest mirrors
Aug 18 19:54:13 localhost cloud-init: * base: centos.quelquesmots.fr
Aug 18 19:54:13 localhost cloud-init: * extras: centos.quelquesmots.fr
Aug 18 19:54:13 localhost cloud-init: * updates: centos.crazyfrogs.org

==> /var/log/cloud-init-output.log <==
nameserver 149.202.170.149
search teuthology
target170152.teuthologyDefaults !requiretty
Defaults visiblepw
Cloud-init v. 0.7.5 running 'modules:config' at Tue, 18 Aug 2015 19:54:08 +0000. Up 13.71 seconds.
Loaded plugins: fastestmirror
Determining fastest mirrors
* base: centos.quelquesmots.fr
* extras: centos.quelquesmots.fr
* updates: centos.crazyfrogs.org

2015-08-18T19:54:22.478 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:24.714 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:24.889 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:24 localhost cloud-init: perl-threads x86_64 1.87-4.el7 base 49 k
Aug 18 19:54:24 localhost cloud-init: perl-threads-shared x86_64 1.43-6.el7 base 39 k
Aug 18 19:54:24 localhost cloud-init: Updating for dependencies:
Aug 18 19:54:24 localhost cloud-init: python-libs x86_64 2.7.5-18.el7_1.1 updates 5.6 M
Aug 18 19:54:24 localhost cloud-init: Transaction Summary
Aug 18 19:54:24 localhost cloud-init: ================================================================================
Aug 18 19:54:24 localhost cloud-init: Install 3 Packages (+33 Dependent packages)
Aug 18 19:54:24 localhost cloud-init: Upgrade 1 Package (+ 1 Dependent package)
Aug 18 19:54:24 localhost cloud-init: Total download size: 23 M
Aug 18 19:54:24 localhost cloud-init: Downloading packages:

==> /var/log/cloud-init-output.log <==
Updating for dependencies:
python-libs x86_64 2.7.5-18.el7_1.1 updates 5.6 M

Transaction Summary
================================================================================
Install 3 Packages (+33 Dependent packages)
Upgrade 1 Package (+ 1 Dependent package)

Total download size: 23 M
Downloading packages:

2015-08-18T19:54:24.889 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:27.141 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:27.318 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:24 localhost cloud-init: Transaction Summary
Aug 18 19:54:24 localhost cloud-init: ================================================================================
Aug 18 19:54:24 localhost cloud-init: Install 3 Packages (+33 Dependent packages)
Aug 18 19:54:24 localhost cloud-init: Upgrade 1 Package (+ 1 Dependent package)
Aug 18 19:54:24 localhost cloud-init: Total download size: 23 M
Aug 18 19:54:24 localhost cloud-init: Downloading packages:
Aug 18 19:54:24 localhost cloud-init: Delta RPMs disabled because /usr/bin/applydeltarpm not installed.
Aug 18 19:54:24 localhost cloud-init: warning: /var/cache/yum/x86_64/7/base/packages/autogen-libopts-5.18-5.el7.x86_64.rpm: Header V3 RSA/SHA256 Signature, key ID f4a80eb5: NOKEY
Aug 18 19:54:24 localhost cloud-init: Public key for autogen-libopts-5.18-5.el7.x86_64.rpm is not installed
Aug 18 19:54:24 localhost cloud-init: Public key for ntpdate-4.2.6p5-19.el7.centos.1.x86_64.rpm is not installed

==> /var/log/cloud-init-output.log <==
================================================================================
Install 3 Packages (+33 Dependent packages)
Upgrade 1 Package (+ 1 Dependent package)

Total download size: 23 M
Downloading packages:
Delta RPMs disabled because /usr/bin/applydeltarpm not installed.
warning: /var/cache/yum/x86_64/7/base/packages/autogen-libopts-5.18-5.el7.x86_64.rpm: Header V3 RSA/SHA256 Signature, key ID f4a80eb5: NOKEY
Public key for autogen-libopts-5.18-5.el7.x86_64.rpm is not installed
Public key for ntpdate-4.2.6p5-19.el7.centos.1.x86_64.rpm is not installed

2015-08-18T19:54:27.319 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:29.537 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:29.743 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:27 localhost cloud-init: Running transaction check
Aug 18 19:54:27 localhost cloud-init: Running transaction test
Aug 18 19:54:27 localhost cloud-init: Transaction test succeeded
Aug 18 19:54:27 localhost cloud-init: Running transaction
Aug 18 19:54:28 localhost cloud-init: Installing : 1:perl-parent-0.225-244.el7.noarch 1/40
Aug 18 19:54:28 localhost cloud-init: Installing : perl-HTTP-Tiny-0.033-3.el7.noarch 2/40
Aug 18 19:54:28 localhost cloud-init: Installing : perl-podlators-2.5.1-3.el7.noarch 3/40
Aug 18 19:54:28 localhost cloud-init: Installing : perl-Pod-Perldoc-3.20-4.el7.noarch 4/40
Aug 18 19:54:28 localhost cloud-init: Installing : 1:perl-Pod-Escapes-1.04-285.el7.noarch 5/40
Aug 18 19:54:29 localhost cloud-init: Installing : perl-Encode-2.51-7.el7.x86_64 6/40

==> /var/log/cloud-init-output.log <==
Running transaction test
Transaction test succeeded
Running transaction
Installing : 1:perl-parent-0.225-244.el7.noarch 1/40
Installing : perl-HTTP-Tiny-0.033-3.el7.noarch 2/40
Installing : perl-podlators-2.5.1-3.el7.noarch 3/40
Installing : perl-Pod-Perldoc-3.20-4.el7.noarch 4/40
Installing : 1:perl-Pod-Escapes-1.04-285.el7.noarch 5/40
Installing : perl-Encode-2.51-7.el7.x86_64 6/40
Installing : perl-Text-ParseWords-3.29-4.el7.noarch 7/40
2015-08-18T19:54:29.744 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:32.045 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:32.474 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:29 localhost cloud-init: Installing : perl-Scalar-List-Utils-1.27-248.el7.x86_64 16/40
Aug 18 19:54:29 localhost cloud-init: Installing : 4:perl-macros-5.16.3-285.el7.x86_64 17/40
Aug 18 19:54:30 localhost cloud-init: Installing : 1:perl-Pod-Simple-3.28-4.el7.noarch 18/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-Storable-2.45-3.el7.x86_64 19/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-File-Temp-0.23.01-3.el7.noarch 20/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-File-Path-2.09-2.el7.noarch 21/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-threads-shared-1.43-6.el7.x86_64 22/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-threads-1.87-4.el7.x86_64 23/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Aug 18 19:54:30 localhost cloud-init: Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40

==> /var/log/cloud-init-output.log <==
Installing : 4:perl-macros-5.16.3-285.el7.x86_64 17/40
Installing : 1:perl-Pod-Simple-3.28-4.el7.noarch 18/40
Installing : perl-Storable-2.45-3.el7.x86_64 19/40
Installing : perl-File-Temp-0.23.01-3.el7.noarch 20/40
Installing : perl-File-Path-2.09-2.el7.noarch 21/40
Installing : perl-threads-shared-1.43-6.el7.x86_64 22/40
Installing : perl-threads-1.87-4.el7.x86_64 23/40
Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40
Installing : perl-Getopt-Long-2.40-2.el7.noarch 26/40
2015-08-18T19:54:32.475 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:34.783 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:35.129 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:30 localhost cloud-init: Installing : perl-Storable-2.45-3.el7.x86_64 19/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-File-Temp-0.23.01-3.el7.noarch 20/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-File-Path-2.09-2.el7.noarch 21/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-threads-shared-1.43-6.el7.x86_64 22/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-threads-1.87-4.el7.x86_64 23/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Aug 18 19:54:30 localhost cloud-init: Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40
Aug 18 19:54:33 localhost cloud-init: Installing : perl-Getopt-Long-2.40-2.el7.noarch 26/40
Aug 18 19:54:33 localhost cloud-init: Installing : 4:perl-5.16.3-285.el7.x86_64 27/40
Aug 18 19:54:33 localhost cloud-init: Installing : 1:perl-Error-0.17020-2.el7.noarch 28/40

==> /var/log/cloud-init-output.log <==
Installing : perl-File-Temp-0.23.01-3.el7.noarch 20/40
Installing : perl-File-Path-2.09-2.el7.noarch 21/40
Installing : perl-threads-shared-1.43-6.el7.x86_64 22/40
Installing : perl-threads-1.87-4.el7.x86_64 23/40
Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40
Installing : perl-Getopt-Long-2.40-2.el7.noarch 26/40
Installing : 4:perl-5.16.3-285.el7.x86_64 27/40
Installing : 1:perl-Error-0.17020-2.el7.noarch 28/40
Installing : perl-TermReadKey-2.30-20.el7.x86_64 29/40
2015-08-18T19:54:35.129 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:37.415 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:37.689 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:30 localhost cloud-init: Installing : perl-threads-1.87-4.el7.x86_64 23/40
Aug 18 19:54:30 localhost cloud-init: Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Aug 18 19:54:30 localhost cloud-init: Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40
Aug 18 19:54:33 localhost cloud-init: Installing : perl-Getopt-Long-2.40-2.el7.noarch 26/40
Aug 18 19:54:33 localhost cloud-init: Installing : 4:perl-5.16.3-285.el7.x86_64 27/40
Aug 18 19:54:33 localhost cloud-init: Installing : 1:perl-Error-0.17020-2.el7.noarch 28/40
Aug 18 19:54:36 localhost cloud-init: Installing : perl-TermReadKey-2.30-20.el7.x86_64 29/40
Aug 18 19:54:36 localhost cloud-init: Updating : python-libs-2.7.5-18.el7_1.1.x86_64 30/40
Aug 18 19:54:36 localhost cloud-init: Updating : python-2.7.5-18.el7_1.1.x86_64 31/40
Aug 18 19:54:36 localhost cloud-init: Installing : libgnome-keyring-3.8.0-3.el7.x86_64 32/40

==> /var/log/cloud-init-output.log <==
Installing : perl-Filter-1.49-3.el7.x86_64 24/40
Installing : 4:perl-libs-5.16.3-285.el7.x86_64 25/40
Installing : perl-Getopt-Long-2.40-2.el7.noarch 26/40
Installing : 4:perl-5.16.3-285.el7.x86_64 27/40
Installing : 1:perl-Error-0.17020-2.el7.noarch 28/40
Installing : perl-TermReadKey-2.30-20.el7.x86_64 29/40
Updating : python-libs-2.7.5-18.el7_1.1.x86_64 30/40
Updating : python-2.7.5-18.el7_1.1.x86_64 31/40
Installing : libgnome-keyring-3.8.0-3.el7.x86_64 32/40
Installing : perl-Git-1.8.3.1-4.el7.noarch 33/40
2015-08-18T19:54:37.689 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:39.922 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:40.131 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:39 localhost cloud-init: Installing : ntp-4.2.6p5-19.el7.centos.1.x86_64 37/40
Aug 18 19:54:39 localhost cloud-init: Installing : wget-1.14-10.el7_0.1.x86_64 38/40
Aug 18 19:54:39 localhost cloud-init: Cleanup : python-2.7.5-16.el7.x86_64 39/40
Aug 18 19:54:39 localhost cloud-init: Cleanup : python-libs-2.7.5-16.el7.x86_64 40/40
Aug 18 19:54:39 localhost cloud-init: Verifying : perl-HTTP-Tiny-0.033-3.el7.noarch 1/40
Aug 18 19:54:39 localhost cloud-init: Verifying : perl-Git-1.8.3.1-4.el7.noarch 2/40
Aug 18 19:54:39 localhost cloud-init: Verifying : python-2.7.5-18.el7_1.1.x86_64 3/40
Aug 18 19:54:39 localhost cloud-init: Verifying : perl-threads-shared-1.43-6.el7.x86_64 4/40
Aug 18 19:54:39 localhost cloud-init: Verifying : autogen-libopts-5.18-5.el7.x86_64 5/40
Aug 18 19:54:39 localhost cloud-init: Verifying : perl-Exporter-5.68-3.el7.noarch 6/40

==> /var/log/cloud-init-output.log <==
Installing : wget-1.14-10.el7_0.1.x86_64 38/40
Cleanup : python-2.7.5-16.el7.x86_64 39/40
Cleanup : python-libs-2.7.5-16.el7.x86_64 40/40
Verifying : perl-HTTP-Tiny-0.033-3.el7.noarch 1/40
Verifying : perl-Git-1.8.3.1-4.el7.noarch 2/40
Verifying : python-2.7.5-18.el7_1.1.x86_64 3/40
Verifying : perl-threads-shared-1.43-6.el7.x86_64 4/40
Verifying : autogen-libopts-5.18-5.el7.x86_64 5/40
Verifying : perl-Exporter-5.68-3.el7.noarch 6/40
Verifying : perl-constant-1.27-2.el7.noarch 7/40
2015-08-18T19:54:40.131 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:42.343 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:42.500 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:41 localhost cloud-init: perl-podlators.noarch 0:2.5.1-3.el7
Aug 18 19:54:41 localhost cloud-init: perl-threads.x86_64 0:1.87-4.el7
Aug 18 19:54:41 localhost cloud-init: perl-threads-shared.x86_64 0:1.43-6.el7
Aug 18 19:54:41 localhost cloud-init: Updated:
Aug 18 19:54:41 localhost cloud-init: python.x86_64 0:2.7.5-18.el7_1.1
Aug 18 19:54:41 localhost cloud-init: Dependency Updated:
Aug 18 19:54:41 localhost cloud-init: python-libs.x86_64 0:2.7.5-18.el7_1.1
Aug 18 19:54:41 localhost cloud-init: Complete!
Aug 18 19:54:41 localhost cloud-init: Cloud-init v. 0.7.5 running 'modules:final' at Tue, 18 Aug 2015 19:54:41 +0000. Up 46.94 seconds.
Aug 18 19:54:41 localhost cloud-init: The system is finally up, after 47.10 seconds

==> /var/log/cloud-init-output.log <==

Updated:
python.x86_64 0:2.7.5-18.el7_1.1

Dependency Updated:
python-libs.x86_64 0:2.7.5-18.el7_1.1

Complete!
Cloud-init v. 0.7.5 running 'modules:final' at Tue, 18 Aug 2015 19:54:41 +0000. Up 46.94 seconds.
The system is finally up, after 47.10 seconds
/var/log/cloud-init.log:Aug 18 19:54:41 localhost cloud-init: The system is finally up, after 47.10 seconds
/var/log/cloud-init-output.log:The system is finally up, after 47.10 seconds

2015-08-18T19:54:42.500 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:54:42.501 DEBUG:teuthology.misc:openstack volume show -f json target170152-0
2015-08-18T19:54:43.741 ERROR:teuthology.misc:openstack volume show -f json target170152-0 error ERROR: openstack No volume with a name or ID of 'target170152-0' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170152-0' returned non-zero exit status 1
2015-08-18T19:54:43.742 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-0
2015-08-18T19:54:44.850 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-0 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:44.774544"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-0"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "7bcff9bf-d86f-421b-ab91-85934d61c562"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:44.850 DEBUG:teuthology.misc:openstack volume show -f json target170152-0
2015-08-18T19:54:46.228 DEBUG:teuthology.misc:openstack volume show -f json target170152-0 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:44.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-0"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "7bcff9bf-d86f-421b-ab91-85934d61c562"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:46.229 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-0
2015-08-18T19:54:48.570 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-0 output
2015-08-18T19:54:48.570 DEBUG:teuthology.misc:openstack volume show -f json target170152-1
2015-08-18T19:54:49.821 ERROR:teuthology.misc:openstack volume show -f json target170152-1 error ERROR: openstack No volume with a name or ID of 'target170152-1' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170152-1' returned non-zero exit status 1
2015-08-18T19:54:49.822 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-1
2015-08-18T19:54:51.075 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:50.957975"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "020f8c0e-db2b-4abc-b803-8b13b6a7efa4"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:51.075 DEBUG:teuthology.misc:openstack volume show -f json target170152-1
2015-08-18T19:54:52.349 DEBUG:teuthology.misc:openstack volume show -f json target170152-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:50.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "020f8c0e-db2b-4abc-b803-8b13b6a7efa4"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:52.350 INFO:teuthology.provision:volume target170152-1 not available yet
2015-08-18T19:54:54.352 DEBUG:teuthology.misc:openstack volume show -f json target170152-1
2015-08-18T19:54:55.595 DEBUG:teuthology.misc:openstack volume show -f json target170152-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:50.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "020f8c0e-db2b-4abc-b803-8b13b6a7efa4"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:55.596 INFO:teuthology.provision:volume target170152-1 not available yet
2015-08-18T19:54:57.598 DEBUG:teuthology.misc:openstack volume show -f json target170152-1
2015-08-18T19:54:58.738 DEBUG:teuthology.misc:openstack volume show -f json target170152-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:54:50.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "020f8c0e-db2b-4abc-b803-8b13b6a7efa4"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:54:58.739 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-1
2015-08-18T19:55:01.158 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-1 output
2015-08-18T19:55:01.158 DEBUG:teuthology.misc:openstack volume show -f json target170152-2
2015-08-18T19:55:02.313 ERROR:teuthology.misc:openstack volume show -f json target170152-2 error ERROR: openstack No volume with a name or ID of 'target170152-2' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170152-2' returned non-zero exit status 1
2015-08-18T19:55:02.313 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-2
2015-08-18T19:55:03.323 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170152-2 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:03.247825"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-2"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "a3b72f7a-f4fd-41ae-9fe4-78de27f4b130"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:03.323 DEBUG:teuthology.misc:openstack volume show -f json target170152-2
2015-08-18T19:55:04.358 DEBUG:teuthology.misc:openstack volume show -f json target170152-2 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:03.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170152-2"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "a3b72f7a-f4fd-41ae-9fe4-78de27f4b130"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:04.359 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-2
2015-08-18T19:55:06.380 DEBUG:teuthology.misc:openstack server add volume target170152 target170152-2 output
2015-08-18T19:55:06.380 DEBUG:teuthology.misc:openstack server show -f json 7f58dd70-4d2e-4e13-aa61-698fcee927c8
2015-08-18T19:55:08.173 DEBUG:teuthology.misc:openstack server show -f json 7f58dd70-4d2e-4e13-aa61-698fcee927c8 output [{"Field": "OS-DCF:diskConfig", "Value": "MANUAL"}, {"Field": "OS-EXT-AZ:availability_zone", "Value": "nova"}, {"Field": "OS-EXT-STS:power_state", "Value": 1}, {"Field": "OS-EXT-STS:task_state", "Value": null}, {"Field": "OS-EXT-STS:vm_state", "Value": "active"}, {"Field": "OS-SRV-USG:launched_at", "Value": "2015-08-18T19:53:50.000000"}, {"Field": "OS-SRV-USG:terminated_at", "Value": null}, {"Field": "accessIPv4", "Value": ""}, {"Field": "accessIPv6", "Value": ""}, {"Field": "addresses", "Value": "Ext-Net=149.202.170.153"}, {"Field": "config_drive", "Value": ""}, {"Field": "created", "Value": "2015-08-18T19:53:17Z"}, {"Field": "flavor", "Value": "vps-ssd-1 (98c1e679-5f2c-4069-b4da-4a4f7179b758)"}, {"Field": "hostId", "Value": "643dffa5fd86216e17116ac0b2b145e2410835ccdba3e2f75fcc9cd5"}, {"Field": "id", "Value": "7f58dd70-4d2e-4e13-aa61-698fcee927c8"}, {"Field": "image", "Value": "teuthology-centos-7.0 (94967743-087d-44d3-a9bc-1bfe9481127b)"}, {"Field": "key_name", "Value": "teuthology"}, {"Field": "name", "Value": "target-7f58dd70-4d2e-4e13-aa61-698fcee927c8"}, {"Field": "os-extended-volumes:volumes_attached", "Value": []}, {"Field": "progress", "Value": 0}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"Field": "security_groups", "Value": [{"name": "teuthology"}]}, {"Field": "status", "Value": "ACTIVE"}, {"Field": "updated", "Value": "2015-08-18T19:53:50Z"}, {"Field": "user_id", "Value": "3a075820e5d24fda96cd340b87fd94e9"}]

2015-08-18T19:55:08.173 DEBUG:teuthology.misc:openstack server set --name target170153 7f58dd70-4d2e-4e13-aa61-698fcee927c8
2015-08-18T19:55:09.615 DEBUG:teuthology.misc:openstack server set --name target170153 7f58dd70-4d2e-4e13-aa61-698fcee927c8 output
2015-08-18T19:55:24.920 DEBUG:teuthology.openstack:cloud_init_wait target170153.teuthology
2015-08-18T19:55:25.160 DEBUG:teuthology.openstack:cloud_init_wait tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:55:25.334 DEBUG:teuthology.openstack:cloud_init_wait stdout tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log ==> /var/log/cloud-init.log <==
Aug 18 19:54:39 localhost cloud-init: perl-podlators.noarch 0:2.5.1-3.el7
Aug 18 19:54:39 localhost cloud-init: perl-threads.x86_64 0:1.87-4.el7
Aug 18 19:54:39 localhost cloud-init: perl-threads-shared.x86_64 0:1.43-6.el7
Aug 18 19:54:39 localhost cloud-init: Updated:
Aug 18 19:54:39 localhost cloud-init: python.x86_64 0:2.7.5-18.el7_1.1
Aug 18 19:54:39 localhost cloud-init: Dependency Updated:
Aug 18 19:54:39 localhost cloud-init: python-libs.x86_64 0:2.7.5-18.el7_1.1
Aug 18 19:54:39 localhost cloud-init: Complete!
Aug 18 19:54:39 localhost cloud-init: Cloud-init v. 0.7.5 running 'modules:final' at Tue, 18 Aug 2015 19:54:39 +0000. Up 45.08 seconds.
Aug 18 19:54:39 localhost cloud-init: The system is finally up, after 45.23 seconds

==> /var/log/cloud-init-output.log <==

Updated:
python.x86_64 0:2.7.5-18.el7_1.1

Dependency Updated:
python-libs.x86_64 0:2.7.5-18.el7_1.1

Complete!
Cloud-init v. 0.7.5 running 'modules:final' at Tue, 18 Aug 2015 19:54:39 +0000. Up 45.08 seconds.
The system is finally up, after 45.23 seconds
/var/log/cloud-init.log:Aug 18 19:54:39 localhost cloud-init: The system is finally up, after 45.23 seconds
/var/log/cloud-init-output.log:The system is finally up, after 45.23 seconds

2015-08-18T19:55:25.334 DEBUG:teuthology.openstack:cloud_init_wait stderr tail /var/log/cloud-init*.log ; test -f /tmp/init.out && tail /tmp/init.out ; grep 'The system is finally up' /var/log/cloud-init*.log
2015-08-18T19:55:25.335 DEBUG:teuthology.misc:openstack volume show -f json target170153-0
2015-08-18T19:55:26.510 ERROR:teuthology.misc:openstack volume show -f json target170153-0 error ERROR: openstack No volume with a name or ID of 'target170153-0' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170153-0' returned non-zero exit status 1
2015-08-18T19:55:26.510 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-0
2015-08-18T19:55:27.683 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-0 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:27.606548"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-0"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "e6556acd-b4b7-4d96-90b5-98112b687cb5"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:27.684 DEBUG:teuthology.misc:openstack volume show -f json target170153-0
2015-08-18T19:55:28.967 DEBUG:teuthology.misc:openstack volume show -f json target170153-0 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:27.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-0"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "e6556acd-b4b7-4d96-90b5-98112b687cb5"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:28.968 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-0
2015-08-18T19:55:31.253 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-0 output
2015-08-18T19:55:31.253 DEBUG:teuthology.misc:openstack volume show -f json target170153-1
2015-08-18T19:55:32.520 ERROR:teuthology.misc:openstack volume show -f json target170153-1 error ERROR: openstack No volume with a name or ID of 'target170153-1' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170153-1' returned non-zero exit status 1
2015-08-18T19:55:32.520 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-1
2015-08-18T19:55:33.585 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:33.507077"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "5b0ffdea-29cf-45fe-b61d-3d8a1bf41e39"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:33.586 DEBUG:teuthology.misc:openstack volume show -f json target170153-1
2015-08-18T19:55:34.868 DEBUG:teuthology.misc:openstack volume show -f json target170153-1 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:33.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-1"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "5b0ffdea-29cf-45fe-b61d-3d8a1bf41e39"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:34.869 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-1
2015-08-18T19:55:37.385 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-1 output
2015-08-18T19:55:37.385 DEBUG:teuthology.misc:openstack volume show -f json target170153-2
2015-08-18T19:55:38.493 ERROR:teuthology.misc:openstack volume show -f json target170153-2 error ERROR: openstack No volume with a name or ID of 'target170153-2' exists.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/misc.py", line 1309, in sh
shell=True)
File "/usr/lib/python2.7/subprocess.py", line 573, in check_output
raise CalledProcessError(retcode, cmd, output=output)
CalledProcessError: Command 'openstack volume show -f json target170153-2' returned non-zero exit status 1
2015-08-18T19:55:38.494 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-2
2015-08-18T19:55:39.553 DEBUG:teuthology.misc:openstack volume create -f json --size 10 target170153-2 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:39.461757"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-2"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "8cd32233-9878-411d-808b-634d3e520904"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "creating"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:39.554 DEBUG:teuthology.misc:openstack volume show -f json target170153-2
2015-08-18T19:55:41.008 DEBUG:teuthology.misc:openstack volume show -f json target170153-2 output [{"Field": "attachments", "Value": []}, {"Field": "availability_zone", "Value": "nova"}, {"Field": "bootable", "Value": "false"}, {"Field": "created_at", "Value": "2015-08-18T19:55:39.000000"}, {"Field": "display_description", "Value": null}, {"Field": "display_name", "Value": "target170153-2"}, {"Field": "encrypted", "Value": false}, {"Field": "id", "Value": "8cd32233-9878-411d-808b-634d3e520904"}, {"Field": "os-volume-replication:driver_data", "Value": null}, {"Field": "os-volume-replication:extended_status", "Value": null}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": ""}, {"Field": "size", "Value": 10}, {"Field": "snapshot_id", "Value": null}, {"Field": "source_volid", "Value": null}, {"Field": "status", "Value": "available"}, {"Field": "type", "Value": "classic"}]

2015-08-18T19:55:41.009 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-2
2015-08-18T19:55:43.312 DEBUG:teuthology.misc:openstack server add volume target170153 target170153-2 output
2015-08-18T19:55:43.332 DEBUG:teuthology.lock:locked target170152.teuthology as scheduled_ubuntu@teuthology
2015-08-18T19:55:43.350 DEBUG:teuthology.lock:locked target170153.teuthology as scheduled_ubuntu@teuthology
2015-08-18T19:55:43.350 INFO:teuthology.task.internal:2 openstack machines locked this try, 2/2 locked so far
2015-08-18T19:55:43.351 INFO:teuthology.task.internal:Locked targets:
target170152.teuthology: null
target170153.teuthology: null
2015-08-18T19:55:43.351 DEBUG:teuthology.report:Pushing job info to http://localhost:8080/
2015-08-18T19:55:43.410 INFO:teuthology.run_tasks:Running task internal.save_config...
2015-08-18T19:55:43.411 INFO:teuthology.task.internal:Saving configuration
2015-08-18T19:55:43.424 INFO:teuthology.run_tasks:Running task internal.check_lock...
2015-08-18T19:55:43.424 INFO:teuthology.task.internal:Checking locks...
2015-08-18T19:55:43.439 DEBUG:teuthology.task.internal:machine status is {u'is_vm': True, u'locked': True, u'locked_since': u'2015-08-18 19:55:43.337292', u'locked_by': u'scheduled_ubuntu@teuthology', u'up': True, u'mac_address': None, u'name': u'target170153.teuthology', u'os_version': None, u'machine_type': u'openstack', u'vm_host': None, u'os_type': None, u'arch': None, u'ssh_pub_key': None, u'description': u'/usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1'}
2015-08-18T19:55:43.454 DEBUG:teuthology.task.internal:machine status is {u'is_vm': True, u'locked': True, u'locked_since': u'2015-08-18 19:55:43.319566', u'locked_by': u'scheduled_ubuntu@teuthology', u'up': True, u'mac_address': None, u'name': u'target170152.teuthology', u'os_version': None, u'machine_type': u'openstack', u'vm_host': None, u'os_type': None, u'arch': None, u'ssh_pub_key': None, u'description': u'/usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1'}
2015-08-18T19:55:43.454 INFO:teuthology.run_tasks:Running task internal.add_remotes...
2015-08-18T19:55:43.454 INFO:teuthology.task.internal:roles: ubuntu@target170153.teuthology - ['mon.a', 'mds.0', 'osd.0']
2015-08-18T19:55:43.454 INFO:teuthology.task.internal:roles: ubuntu@target170152.teuthology - ['osd.1', 'mon.b', 'client.0']
2015-08-18T19:55:43.454 INFO:teuthology.run_tasks:Running task internal.connect...
2015-08-18T19:55:43.454 INFO:teuthology.task.internal:Opening connections...
2015-08-18T19:55:43.454 DEBUG:teuthology.task.internal:connecting to ubuntu@target170153.teuthology
2015-08-18T19:55:43.455 INFO:teuthology.orchestra.connection:{'username': 'ubuntu', 'hostname': 'target170153.teuthology', 'timeout': 60}
2015-08-18T19:55:43.670 DEBUG:teuthology.task.internal:connecting to ubuntu@target170152.teuthology
2015-08-18T19:55:43.671 INFO:teuthology.orchestra.connection:{'username': 'ubuntu', 'hostname': 'target170152.teuthology', 'timeout': 60}
2015-08-18T19:55:43.884 INFO:teuthology.run_tasks:Running task internal.push_inventory...
2015-08-18T19:55:43.885 INFO:teuthology.orchestra.run.target170153:Running: 'uname -m'
2015-08-18T19:55:43.918 INFO:teuthology.orchestra.run.target170153:Running: "python -c 'import platform; print platform.linux_distribution()'"
2015-08-18T19:55:44.018 INFO:teuthology.lock:Updating target170153.teuthology on lock server
2015-08-18T19:55:44.038 INFO:teuthology.orchestra.run.target170152:Running: 'uname -m'
2015-08-18T19:55:44.070 INFO:teuthology.orchestra.run.target170152:Running: "python -c 'import platform; print platform.linux_distribution()'"
2015-08-18T19:55:44.172 INFO:teuthology.lock:Updating target170152.teuthology on lock server
2015-08-18T19:55:44.188 INFO:teuthology.run_tasks:Running task internal.serialize_remote_roles...
2015-08-18T19:55:44.192 INFO:teuthology.run_tasks:Running task internal.check_conflict...
2015-08-18T19:55:44.192 INFO:teuthology.task.internal:Checking for old test directory...
2015-08-18T19:55:44.193 INFO:teuthology.orchestra.run.target170152:Running: "test '!' -e /home/ubuntu/cephtest"
2015-08-18T19:55:44.229 INFO:teuthology.orchestra.run.target170153:Running: "test '!' -e /home/ubuntu/cephtest"
2015-08-18T19:55:44.377 INFO:teuthology.run_tasks:Running task internal.check_ceph_data...
2015-08-18T19:55:44.377 INFO:teuthology.task.internal:Checking for old /var/lib/ceph...
2015-08-18T19:55:44.378 INFO:teuthology.orchestra.run.target170152:Running: "test '!' -e /var/lib/ceph"
2015-08-18T19:55:44.384 INFO:teuthology.orchestra.run.target170153:Running: "test '!' -e /var/lib/ceph"
2015-08-18T19:55:44.470 INFO:teuthology.run_tasks:Running task internal.vm_setup...
2015-08-18T19:55:44.471 INFO:teuthology.run_tasks:Running task internal.base...
2015-08-18T19:55:44.471 INFO:teuthology.task.internal:Creating test directory...
2015-08-18T19:55:44.471 INFO:teuthology.orchestra.run.target170152:Running: 'mkdir -p -m0755 -- /home/ubuntu/cephtest'
2015-08-18T19:55:44.477 INFO:teuthology.orchestra.run.target170153:Running: 'mkdir -p -m0755 -- /home/ubuntu/cephtest'
2015-08-18T19:55:44.530 INFO:teuthology.run_tasks:Running task internal.archive...
2015-08-18T19:55:44.530 INFO:teuthology.task.internal:Creating archive directory...
2015-08-18T19:55:44.531 INFO:teuthology.orchestra.run.target170152:Running: 'install -d -m0755 -- /home/ubuntu/cephtest/archive'
2015-08-18T19:55:44.537 INFO:teuthology.orchestra.run.target170153:Running: 'install -d -m0755 -- /home/ubuntu/cephtest/archive'
2015-08-18T19:55:44.602 INFO:teuthology.run_tasks:Running task internal.coredump...
2015-08-18T19:55:44.602 INFO:teuthology.task.internal:Enabling coredump saving...
2015-08-18T19:55:44.603 INFO:teuthology.orchestra.run.target170152:Running: 'install -d -m0755 -- /home/ubuntu/cephtest/archive/coredump && sudo sysctl -w kernel.core_pattern=/home/ubuntu/cephtest/archive/coredump/%t.%p.core'
2015-08-18T19:55:44.609 INFO:teuthology.orchestra.run.target170153:Running: 'install -d -m0755 -- /home/ubuntu/cephtest/archive/coredump && sudo sysctl -w kernel.core_pattern=/home/ubuntu/cephtest/archive/coredump/%t.%p.core'
2015-08-18T19:55:44.647 INFO:teuthology.orchestra.run.target170152.stdout:kernel.core_pattern = /home/ubuntu/cephtest/archive/coredump/%t.%p.core
2015-08-18T19:55:44.711 INFO:teuthology.orchestra.run.target170153.stdout:kernel.core_pattern = /home/ubuntu/cephtest/archive/coredump/%t.%p.core
2015-08-18T19:55:44.713 INFO:teuthology.run_tasks:Running task internal.archive_upload...
2015-08-18T19:55:44.713 INFO:teuthology.run_tasks:Running task internal.sudo...
2015-08-18T19:55:44.714 INFO:teuthology.task.internal:Configuring sudo...
2015-08-18T19:55:44.714 INFO:teuthology.orchestra.run.target170152:Running: "sudo sed -i.orig.teuthology -e 's/^\\([^#]*\\) \\(requiretty\\)/\\1 !\\2/g' -e 's/^\\([^#]*\\) !\\(visiblepw\\)/\\1 \\2/g' /etc/sudoers"
2015-08-18T19:55:44.720 INFO:teuthology.orchestra.run.target170153:Running: "sudo sed -i.orig.teuthology -e 's/^\\([^#]*\\) \\(requiretty\\)/\\1 !\\2/g' -e 's/^\\([^#]*\\) !\\(visiblepw\\)/\\1 \\2/g' /etc/sudoers"
2015-08-18T19:55:44.783 INFO:teuthology.run_tasks:Running task internal.syslog...
2015-08-18T19:55:44.783 INFO:teuthology.task.internal:Starting syslog monitoring...
2015-08-18T19:55:44.784 INFO:teuthology.orchestra.run.target170152:Running: 'mkdir -p -m0755 -- /home/ubuntu/cephtest/archive/syslog'
2015-08-18T19:55:44.792 INFO:teuthology.orchestra.run.target170153:Running: 'mkdir -p -m0755 -- /home/ubuntu/cephtest/archive/syslog'
2015-08-18T19:55:44.848 INFO:teuthology.orchestra.run.target170153:Running: 'touch /home/ubuntu/cephtest/archive/syslog/kern.log'
2015-08-18T19:55:44.928 INFO:teuthology.orchestra.run.target170153:Running: 'sudo chcon system_u:object_r:var_log_t:s0 /home/ubuntu/cephtest/archive/syslog/kern.log'
2015-08-18T19:55:45.022 INFO:teuthology.orchestra.run.target170153:Running: 'touch /home/ubuntu/cephtest/archive/syslog/misc.log'
2015-08-18T19:55:45.106 INFO:teuthology.orchestra.run.target170153:Running: 'sudo chcon system_u:object_r:var_log_t:s0 /home/ubuntu/cephtest/archive/syslog/misc.log'
2015-08-18T19:55:45.195 INFO:teuthology.orchestra.run.target170153:Running: 'sudo python -c \'import shutil, sys; shutil.copyfileobj(sys.stdin, file(sys.argv[1], "wb"))\' /etc/rsyslog.d/80-cephtest.conf'
2015-08-18T19:55:45.312 INFO:teuthology.orchestra.run.target170152:Running: 'touch /home/ubuntu/cephtest/archive/syslog/kern.log'
2015-08-18T19:55:45.330 INFO:teuthology.orchestra.run.target170152:Running: 'sudo chcon system_u:object_r:var_log_t:s0 /home/ubuntu/cephtest/archive/syslog/kern.log'
2015-08-18T19:55:45.424 INFO:teuthology.orchestra.run.target170152:Running: 'touch /home/ubuntu/cephtest/archive/syslog/misc.log'
2015-08-18T19:55:45.504 INFO:teuthology.orchestra.run.target170152:Running: 'sudo chcon system_u:object_r:var_log_t:s0 /home/ubuntu/cephtest/archive/syslog/misc.log'
2015-08-18T19:55:45.597 INFO:teuthology.orchestra.run.target170152:Running: 'sudo python -c \'import shutil, sys; shutil.copyfileobj(sys.stdin, file(sys.argv[1], "wb"))\' /etc/rsyslog.d/80-cephtest.conf'
2015-08-18T19:55:45.713 INFO:teuthology.orchestra.run.target170152:Running: 'sudo service rsyslog restart'
2015-08-18T19:55:45.783 INFO:teuthology.orchestra.run.target170153:Running: 'sudo service rsyslog restart'
2015-08-18T19:55:45.820 INFO:teuthology.orchestra.run.target170153.stderr:Redirecting to /bin/systemctl restart rsyslog.service
2015-08-18T19:55:45.821 INFO:teuthology.orchestra.run.target170152.stderr:Redirecting to /bin/systemctl restart rsyslog.service
2015-08-18T19:55:45.850 INFO:teuthology.run_tasks:Running task internal.timer...
2015-08-18T19:55:45.850 INFO:teuthology.task.internal:Starting timer...
2015-08-18T19:55:45.850 INFO:teuthology.run_tasks:Running task selinux...
2015-08-18T19:55:45.873 INFO:teuthology.task.selinux:Excluding target170153: VMs are not yet supported
2015-08-18T19:55:45.890 INFO:teuthology.task.selinux:Excluding target170152: VMs are not yet supported
2015-08-18T19:55:45.890 DEBUG:teuthology.task.selinux:Getting current SELinux state
2015-08-18T19:55:45.890 DEBUG:teuthology.task.selinux:Existing SELinux modes: {}
2015-08-18T19:55:45.890 INFO:teuthology.task.selinux:Putting SELinux into permissive mode
2015-08-18T19:55:45.890 INFO:teuthology.run_tasks:Running task ansible.cephlab...
2015-08-18T19:55:45.891 INFO:teuthology.repo_utils:Cloning https://github.com/ceph/ceph-cm-ansible.git master from upstream
2015-08-18T19:55:47.611 INFO:teuthology.repo_utils:Resetting repo at /home/ubuntu/src/ceph-cm-ansible_master to branch master
2015-08-18T19:55:47.657 INFO:teuthology.task.ansible:Playbook: [{'include': 'ansible_managed.yml'}, {'include': 'teuthology.yml'}, {'include': 'testnodes.yml'}, {'include': 'cobbler.yml'}]
2015-08-18T19:55:47.657 DEBUG:teuthology.task.ansible:Running ansible-playbook -v --extra-vars '{"ansible_ssh_user": "ubuntu"}' -i /etc/ansible/hosts --limit target170153.teuthology,target170152.teuthology /home/ubuntu/src/ceph-cm-ansible_master/cephlab.yml
2015-08-18T19:55:51.435 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:51.436 INFO:teuthology.task.ansible.out:PLAY [all] ********************************************************************

2015-08-18T19:55:51.438 INFO:teuthology.task.ansible.out:
GATHERING FACTS ***************************************************************

2015-08-18T19:55:54.338 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology]

2015-08-18T19:55:54.341 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology]
2015-08-18T19:55:54.343 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.350 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.352 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Create the sudo group.] ******************************

2015-08-18T19:55:54.649 INFO:teuthology.task.ansible.out:changed: [target170152.teuthology] => {"changed": true, "gid": 1001, "name": "sudo", "state": "present", "system": false}
2015-08-18T19:55:54.650 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.652 INFO:teuthology.task.ansible.out:changed: [target170153.teuthology] => {"changed": true, "gid": 1001, "name": "sudo", "state": "present", "system": false}
2015-08-18T19:55:54.654 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.661 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.663 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Create the ansible user.] ****************************

2015-08-18T19:55:54.703 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:54.706 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.708 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:54.709 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.716 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.717 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Delete the ansible users password.] ******************

2015-08-18T19:55:54.756 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:54.757 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.760 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:54.761 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.767 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:54.769 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Ensure includedir is present in sudoers.] ************

2015-08-18T19:55:55.000 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology] => {"backup": "", "changed": false, "msg": ""}
2015-08-18T19:55:55.001 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.003 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {"backup": "", "changed": false, "msg": ""}
2015-08-18T19:55:55.004 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.015 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.016 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Create the cephlab_sudo sudoers.d file.] *************

2015-08-18T19:55:55.746 INFO:teuthology.task.ansible.out:changed: [target170152.teuthology] => {"changed": true, "checksum": "141b3b3617c6a8c42a9a178730d55a018eb4e41c", "dest": "/etc/sudoers.d/cephlab_sudo", "gid": 0, "group": "root", "md5sum": "8de73e0d6f6964e3804534eb57b3a85a", "mode": "0440", "owner": "root", "secontext": "system_u:object_r:etc_t:s0", "size": 255, "src": "/home/ubuntu/.ansible/tmp/ansible-tmp-1439927755.05-21190090095945/source", "state": "file", "uid": 0}
2015-08-18T19:55:55.748 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.860 INFO:teuthology.task.ansible.out:changed: [target170153.teuthology] => {"changed": true, "checksum": "141b3b3617c6a8c42a9a178730d55a018eb4e41c", "dest": "/etc/sudoers.d/cephlab_sudo", "gid": 0, "group": "root", "md5sum": "8de73e0d6f6964e3804534eb57b3a85a", "mode": "0440", "owner": "root", "secontext": "system_u:object_r:etc_t:s0", "size": 255, "src": "/home/ubuntu/.ansible/tmp/ansible-tmp-1439927755.18-183320115042797/source", "state": "file", "uid": 0}
2015-08-18T19:55:55.862 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.869 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.870 INFO:teuthology.task.ansible.out:TASK: [ansible-managed | Add authorized keys for the ansible user.] ***********

2015-08-18T19:55:55.913 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology] => (item=ansible_user_ssh_keys)
2015-08-18T19:55:55.915 INFO:teuthology.task.ansible.out:
skipping: [target170152.teuthology] => (item=ansible_user_ssh_keys)

2015-08-18T19:55:55.923 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:55.924 INFO:teuthology.task.ansible.out:PLAY [teuthology] *************************************************************

2015-08-18T19:55:55.930 INFO:teuthology.task.ansible.out:skipping: no hosts matched
2015-08-18T19:55:55.932 INFO:teuthology.task.ansible.out:

PLAY [testnodes] **************************************************************

2015-08-18T19:55:56.503 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.505 INFO:teuthology.task.ansible.out:GATHERING FACTS ***************************************************************

2015-08-18T19:55:56.918 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology]
2015-08-18T19:55:56.919 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.921 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology]
2015-08-18T19:55:56.923 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.930 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.931 INFO:teuthology.task.ansible.out:TASK: [users | Filter the managed_users list] *********************************

2015-08-18T19:55:56.967 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:56.968 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.969 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:56.971 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.976 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:56.978 INFO:teuthology.task.ansible.out:TASK: [users | Filter the managed_admin_users list] ***************************

2015-08-18T19:55:57.013 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.014 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.015 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:57.017 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.022 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.024 INFO:teuthology.task.ansible.out:TASK: [users | Create all admin users with sudo access.] **********************

2015-08-18T19:55:57.058 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.060 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.061 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]

2015-08-18T19:55:57.067 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.068 INFO:teuthology.task.ansible.out:TASK: [users | Create all users without sudo access.] *************************

2015-08-18T19:55:57.103 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.105 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.106 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]

2015-08-18T19:55:57.112 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.114 INFO:teuthology.task.ansible.out:TASK: [users | Update authorized_keys for each user.] *************************

2015-08-18T19:55:57.149 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.150 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.152 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:57.153 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.159 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.160 INFO:teuthology.task.ansible.out:TASK: [users | Filter the revoked_users list] *********************************

2015-08-18T19:55:57.195 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.196 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.198 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:57.199 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.205 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.206 INFO:teuthology.task.ansible.out:TASK: [users | Remove revoked users] ******************************************

2015-08-18T19:55:57.240 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.242 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.243 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]

2015-08-18T19:55:57.249 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.250 INFO:teuthology.task.ansible.out:TASK: [common | Log the OS name, version and release] *************************

2015-08-18T19:55:57.292 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {
2015-08-18T19:55:57.293 INFO:teuthology.task.ansible.out:
"msg": "Host target170152.teuthology is running RedHat 7.1.1503 (Core)"
}
ok: [target170153.teuthology] => {
2015-08-18T19:55:57.294 INFO:teuthology.task.ansible.out:
"msg": "Host target170153.teuthology is running RedHat 7.1.1503 (Core)"
}

2015-08-18T19:55:57.300 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.301 INFO:teuthology.task.ansible.out:TASK: [common | Including major version specific variables.] ******************

2015-08-18T19:55:57.344 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => (item=/home/ubuntu/src/ceph-cm-ansible_master/roles/common/vars/redhat_7.yml) => {"ansible_facts": {"rhsm_repos": ["rhel-7-server-rpms", "rhel-7-server-optional-rpms", "rhel-7-server-extras-rpms"]}, "item": "/home/ubuntu/src/ceph-cm-ansible_master/roles/common/vars/redhat_7.yml"}
2015-08-18T19:55:57.346 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.347 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology] => (item=/home/ubuntu/src/ceph-cm-ansible_master/roles/common/vars/redhat_7.yml) => {"ansible_facts": {"rhsm_repos": ["rhel-7-server-rpms", "rhel-7-server-optional-rpms", "rhel-7-server-extras-rpms"]}, "item": "/home/ubuntu/src/ceph-cm-ansible_master/roles/common/vars/redhat_7.yml"}
2015-08-18T19:55:57.348 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.354 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.355 INFO:teuthology.task.ansible.out:TASK: [common | Set entitlements_path] ****************************************

2015-08-18T19:55:57.396 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {"ansible_facts": {"entitlements_path": "/etc/ansible/secrets/entitlements.yml"}}
2015-08-18T19:55:57.398 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.399 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology] => {"ansible_facts": {"entitlements_path": "/etc/ansible/secrets/entitlements.yml"}}

2015-08-18T19:55:57.405 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.406 INFO:teuthology.task.ansible.out:TASK: [common | Include Red Hat encrypted variables.] *************************

2015-08-18T19:55:57.449 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {"censored": "results hidden due to no_log parameter"}
2015-08-18T19:55:57.451 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.452 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology] => {"censored": "results hidden due to no_log parameter"}
2015-08-18T19:55:57.454 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.459 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.460 INFO:teuthology.task.ansible.out:TASK: [common | Set have_entitlements] ****************************************

2015-08-18T19:55:57.502 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {"ansible_facts": {"have_entitlements": "False"}}
2015-08-18T19:55:57.504 INFO:teuthology.task.ansible.out:
ok: [target170153.teuthology] => {"ansible_facts": {"have_entitlements": "False"}}

2015-08-18T19:55:57.510 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.511 INFO:teuthology.task.ansible.out:TASK: [common | Determine if node is registered with subscription-manager.] ***

2015-08-18T19:55:57.751 INFO:teuthology.task.ansible.out:failed: [target170152.teuthology] => {"censored": "results hidden due to no_log parameter", "changed": false, "failed": true, "rc": 2}
2015-08-18T19:55:57.753 INFO:teuthology.task.ansible.out:
failed: [target170153.teuthology] => {"censored": "results hidden due to no_log parameter", "changed": false, "failed": true, "rc": 2}
...ignoring

2015-08-18T19:55:57.754 INFO:teuthology.task.ansible.out:...ignoring

2015-08-18T19:55:57.764 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.766 INFO:teuthology.task.ansible.out:TASK: [common | Set rhsm_registered] ******************************************

2015-08-18T19:55:57.811 INFO:teuthology.task.ansible.out:ok: [target170152.teuthology] => {"ansible_facts": {"rhsm_registered": "False"}}
2015-08-18T19:55:57.812 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.814 INFO:teuthology.task.ansible.out:ok: [target170153.teuthology] => {"ansible_facts": {"rhsm_registered": "False"}}

2015-08-18T19:55:57.820 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.821 INFO:teuthology.task.ansible.out:TASK: [common | Register with subscription-manager.] **************************

2015-08-18T19:55:57.859 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology] => (item={'skipped': True, 'censored': 'results hidden due to no_log parameter', 'changed': False})
2015-08-18T19:55:57.860 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.863 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology] => (item={'skipped': True, 'censored': 'results hidden due to no_log parameter', 'changed': False})
2015-08-18T19:55:57.864 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.870 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.871 INFO:teuthology.task.ansible.out:TASK: [common | Get list of enabled repos] ************************************

2015-08-18T19:55:57.909 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.910 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.912 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:57.914 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.919 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.921 INFO:teuthology.task.ansible.out:TASK: [common | Store list of enabled repos] **********************************

2015-08-18T19:55:57.958 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:57.959 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.961 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:57.963 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.969 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:57.970 INFO:teuthology.task.ansible.out:TASK: [common | Set replace_repos if rhsm_repos differs from repo_list] *******

2015-08-18T19:55:58.007 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:58.008 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.010 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:58.011 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.017 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.018 INFO:teuthology.task.ansible.out:TASK: [common | Set replace_repos if newly-subscribed] ************************

2015-08-18T19:55:58.056 INFO:teuthology.task.ansible.out:skipping: [target170152.teuthology]
2015-08-18T19:55:58.057 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.060 INFO:teuthology.task.ansible.out:skipping: [target170153.teuthology]
2015-08-18T19:55:58.061 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.067 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.068 INFO:teuthology.task.ansible.out:TASK: [common | Disable all rhsm repos] ***************************************

2015-08-18T19:55:58.105 INFO:teuthology.task.ansible.out:fatal: [target170152.teuthology] => error while evaluating conditional: replace_repos
2015-08-18T19:55:58.106 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.109 INFO:teuthology.task.ansible.out:fatal: [target170153.teuthology] => error while evaluating conditional: replace_repos
2015-08-18T19:55:58.111 INFO:teuthology.task.ansible.out:

2015-08-18T19:55:58.117 INFO:teuthology.task.ansible.out:
2015-08-18T19:55:58.118 INFO:teuthology.task.ansible.out:
FATAL: all hosts have already failed -- aborting

PLAY RECAP ********************************************************************
to retry, use: --limit @/home/ubuntu/cephlab.retry

target170152.teuthology : ok=13 changed=2 unreachable=1 failed=0
target170153.teuthology : ok=13 changed=2 unreachable=1 failed=0


2015-08-18T19:55:58.240 ERROR:teuthology.task.ansible:Failed to parse ansible failure log: /tmp/teuth_ansible_failures_DMzQDF
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/task/ansible.py", line 268, in _handle_failure
failures = yaml.safe_load(fail_log)
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/__init__.py", line 93, in safe_load
return load(stream, SafeLoader)
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/__init__.py", line 71, in load
return loader.get_single_data()
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/constructor.py", line 37, in get_single_data
node = self.get_single_node()
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/composer.py", line 39, in get_single_node
if not self.check_event(StreamEndEvent):
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/parser.py", line 98, in check_event
self.current_event = self.state()
File "/home/ubuntu/teuthology/virtualenv/local/lib/python2.7/site-packages/yaml/parser.py", line 174, in parse_document_start
self.peek_token().start_mark)
ParserError: expected '<document start>', but found '{'
in "/tmp/teuth_ansible_failures_DMzQDF", line 3, column 1
2015-08-18T19:55:58.241 INFO:teuthology.task.ansible:Archiving ansible failure log at: /usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1/ansible_failures.yaml
2015-08-18T19:55:58.241 ERROR:teuthology.run_tasks:Saw exception from tasks.
Traceback (most recent call last):
File "/home/ubuntu/teuthology/teuthology/run_tasks.py", line 56, in run_tasks
manager.__enter__()
File "/home/ubuntu/teuthology/teuthology/task/__init__.py", line 121, in __enter__
self.begin()
File "/home/ubuntu/teuthology/teuthology/task/ansible.py", line 231, in begin
self.execute_playbook()
File "/home/ubuntu/teuthology/teuthology/task/ansible.py", line 256, in execute_playbook
self._handle_failure(command, status)
File "/home/ubuntu/teuthology/teuthology/task/ansible.py", line 282, in _handle_failure
raise CommandFailedError(command, status)
CommandFailedError: Command failed with status 3: 'ansible-playbook -v --extra-vars \'{"ansible_ssh_user": "ubuntu"}\' -i /etc/ansible/hosts --limit target170153.teuthology,target170152.teuthology /home/ubuntu/src/ceph-cm-ansible_master/cephlab.yml'
2015-08-18T19:55:58.242 DEBUG:teuthology.run_tasks:Unwinding manager ansible.cephlab
2015-08-18T19:55:58.242 INFO:teuthology.task.ansible:Skipping ansible cleanup...
2015-08-18T19:55:58.242 DEBUG:teuthology.run_tasks:Unwinding manager selinux
2015-08-18T19:55:58.242 DEBUG:teuthology.run_tasks:Unwinding manager internal.timer
2015-08-18T19:55:58.242 INFO:teuthology.task.internal:Duration was 12.392468 seconds
2015-08-18T19:55:58.243 DEBUG:teuthology.run_tasks:Unwinding manager internal.syslog
2015-08-18T19:55:58.243 INFO:teuthology.task.internal:Shutting down syslog monitoring...
2015-08-18T19:55:58.243 INFO:teuthology.orchestra.run.target170152:Running: 'sudo rm -f -- /etc/rsyslog.d/80-cephtest.conf && sudo service rsyslog restart'
2015-08-18T19:55:58.249 INFO:teuthology.orchestra.run.target170153:Running: 'sudo rm -f -- /etc/rsyslog.d/80-cephtest.conf && sudo service rsyslog restart'
2015-08-18T19:55:58.291 INFO:teuthology.orchestra.run.target170152.stderr:Redirecting to /bin/systemctl restart rsyslog.service
2015-08-18T19:55:58.294 INFO:teuthology.orchestra.run.target170153.stderr:Redirecting to /bin/systemctl restart rsyslog.service
2015-08-18T19:55:58.328 INFO:teuthology.task.internal:Checking logs for errors...
2015-08-18T19:55:58.328 DEBUG:teuthology.task.internal:Checking ubuntu@target170153.teuthology
2015-08-18T19:55:58.328 INFO:teuthology.orchestra.run.target170153:Running: "egrep --binary-files=text '\\bBUG\\b|\\bINFO\\b|\\bDEADLOCK\\b' /home/ubuntu/cephtest/archive/syslog/*.log | grep -v 'task .* blocked for more than .* seconds' | grep -v 'lockdep is turned off' | grep -v 'trying to register non-static key' | grep -v 'DEBUG: fsize' | grep -v CRON | grep -v 'BUG: bad unlock balance detected' | grep -v 'inconsistent lock state' | grep -v '*** DEADLOCK ***' | grep -v 'INFO: possible irq lock inversion dependency detected' | grep -v 'INFO: NMI handler (perf_event_nmi_handler) took too long to run' | grep -v 'INFO: recovery required on readonly' | head -n 1"
2015-08-18T19:55:58.425 DEBUG:teuthology.task.internal:Checking ubuntu@target170152.teuthology
2015-08-18T19:55:58.425 INFO:teuthology.orchestra.run.target170152:Running: "egrep --binary-files=text '\\bBUG\\b|\\bINFO\\b|\\bDEADLOCK\\b' /home/ubuntu/cephtest/archive/syslog/*.log | grep -v 'task .* blocked for more than .* seconds' | grep -v 'lockdep is turned off' | grep -v 'trying to register non-static key' | grep -v 'DEBUG: fsize' | grep -v CRON | grep -v 'BUG: bad unlock balance detected' | grep -v 'inconsistent lock state' | grep -v '*** DEADLOCK ***' | grep -v 'INFO: possible irq lock inversion dependency detected' | grep -v 'INFO: NMI handler (perf_event_nmi_handler) took too long to run' | grep -v 'INFO: recovery required on readonly' | head -n 1"
2015-08-18T19:55:58.464 INFO:teuthology.task.internal:Compressing syslogs...
2015-08-18T19:55:58.464 INFO:teuthology.orchestra.run.target170152:Running: "find /home/ubuntu/cephtest/archive/syslog -name '*.log' -print0 | sudo xargs -0 --no-run-if-empty -- gzip --"
2015-08-18T19:55:58.534 INFO:teuthology.orchestra.run.target170153:Running: "find /home/ubuntu/cephtest/archive/syslog -name '*.log' -print0 | sudo xargs -0 --no-run-if-empty -- gzip --"
2015-08-18T19:55:58.565 DEBUG:teuthology.run_tasks:Unwinding manager internal.sudo
2015-08-18T19:55:58.565 INFO:teuthology.task.internal:Restoring /etc/sudoers...
2015-08-18T19:55:58.566 INFO:teuthology.orchestra.run.target170152:Running: 'sudo mv -f /etc/sudoers.orig.teuthology /etc/sudoers'
2015-08-18T19:55:58.656 INFO:teuthology.orchestra.run.target170153:Running: 'sudo mv -f /etc/sudoers.orig.teuthology /etc/sudoers'
2015-08-18T19:55:58.687 DEBUG:teuthology.run_tasks:Unwinding manager internal.archive_upload
2015-08-18T19:55:58.688 INFO:teuthology.task.internal:Not uploading archives.
2015-08-18T19:55:58.688 DEBUG:teuthology.run_tasks:Unwinding manager internal.coredump
2015-08-18T19:55:58.688 INFO:teuthology.orchestra.run.target170152:Running: 'sudo sysctl -w kernel.core_pattern=core && rmdir --ignore-fail-on-non-empty -- /home/ubuntu/cephtest/archive/coredump'
2015-08-18T19:55:58.701 INFO:teuthology.orchestra.run.target170153:Running: 'sudo sysctl -w kernel.core_pattern=core && rmdir --ignore-fail-on-non-empty -- /home/ubuntu/cephtest/archive/coredump'
2015-08-18T19:55:58.720 INFO:teuthology.orchestra.run.target170152.stdout:kernel.core_pattern = core
2015-08-18T19:55:58.761 INFO:teuthology.orchestra.run.target170153.stdout:kernel.core_pattern = core
2015-08-18T19:55:58.764 INFO:teuthology.orchestra.run.target170153:Running: "if test '!' -e /home/ubuntu/cephtest/archive/coredump ; then echo OK ; fi"
2015-08-18T19:55:58.848 INFO:teuthology.orchestra.run.target170152:Running: "if test '!' -e /home/ubuntu/cephtest/archive/coredump ; then echo OK ; fi"
2015-08-18T19:55:58.863 DEBUG:teuthology.run_tasks:Unwinding manager internal.archive
2015-08-18T19:55:58.864 INFO:teuthology.task.internal:Transferring archived files...
2015-08-18T19:55:58.864 DEBUG:teuthology.misc:Transferring archived files from target170153:/home/ubuntu/cephtest/archive to /usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1/remote/target170153
2015-08-18T19:55:58.865 INFO:teuthology.orchestra.run.target170153:Running: "python -c 'import os; import tempfile; import sys;(fd,fname) = tempfile.mkstemp();os.close(fd);sys.stdout.write(fname.rstrip());sys.stdout.flush()'"
2015-08-18T19:55:58.941 INFO:teuthology.orchestra.run.target170153:Running: 'sudo tar cz -f /tmp/tmpwv_KSe -C /home/ubuntu/cephtest/archive -- .'
2015-08-18T19:55:59.036 INFO:teuthology.orchestra.run.target170153:Running: 'sudo chmod 0666 /tmp/tmpwv_KSe'
2015-08-18T19:55:59.214 INFO:teuthology.orchestra.run.target170153:Running: 'rm -fr /tmp/tmpwv_KSe'
2015-08-18T19:55:59.234 DEBUG:teuthology.misc:Transferring archived files from target170152:/home/ubuntu/cephtest/archive to /usr/share/nginx/html/ubuntu-2015-08-18_19:53:06-ceph-deploy-wip-11881-multipath---basic-openstack/1/remote/target170152
2015-08-18T19:55:59.235 INFO:teuthology.orchestra.run.target170152:Running: "python -c 'import os; import tempfile; import sys;(fd,fname) = tempfile.mkstemp();os.close(fd);sys.stdout.write(fname.rstrip());sys.stdout.flush()'"
2015-08-18T19:55:59.273 INFO:teuthology.orchestra.run.target170152:Running: 'sudo tar cz -f /tmp/tmp5OTq7u -C /home/ubuntu/cephtest/archive -- .'
2015-08-18T19:55:59.368 INFO:teuthology.orchestra.run.target170152:Running: 'sudo chmod 0666 /tmp/tmp5OTq7u'
2015-08-18T19:55:59.555 INFO:teuthology.orchestra.run.target170152:Running: 'rm -fr /tmp/tmp5OTq7u'
2015-08-18T19:55:59.576 INFO:teuthology.task.internal:Removing archive directory...
2015-08-18T19:55:59.576 INFO:teuthology.orchestra.run.target170152:Running: 'rm -rf -- /home/ubuntu/cephtest/archive'
2015-08-18T19:55:59.646 INFO:teuthology.orchestra.run.target170153:Running: 'rm -rf -- /home/ubuntu/cephtest/archive'
2015-08-18T19:55:59.667 DEBUG:teuthology.run_tasks:Unwinding manager internal.base
2015-08-18T19:55:59.668 INFO:teuthology.task.internal:Tidying up after the test...
2015-08-18T19:55:59.668 INFO:teuthology.orchestra.run.target170152:Running: 'rmdir -- /home/ubuntu/cephtest'
2015-08-18T19:55:59.737 INFO:teuthology.orchestra.run.target170153:Running: 'rmdir -- /home/ubuntu/cephtest'
2015-08-18T19:55:59.755 DEBUG:teuthology.run_tasks:Unwinding manager internal.lock_machines
2015-08-18T19:55:59.756 DEBUG:teuthology.run_tasks:Exception was not quenched, exiting: CommandFailedError: Command failed with status 3: 'ansible-playbook -v --extra-vars \'{"ansible_ssh_user": "ubuntu"}\' -i /etc/ansible/hosts --limit target170153.teuthology,target170152.teuthology /home/ubuntu/src/ceph-cm-ansible_master/cephlab.yml'
2015-08-18T19:55:59.756 INFO:teuthology.nuke:Checking targets against current locks
2015-08-18T19:56:00.266 DEBUG:teuthology.provision:ProvisionOpenStack: {'machine': {'disk': 20, 'ram': 8000, 'cpus': 1}, 'subnet': '149.202.160.0/19', 'volumes': {'count': 0, 'size': 1}, 'user-data': 'teuthology/openstack/openstack-{os_type}-{os_version}-user-data.txt', 'ip': '149.202.170.149', 'flavor-select-regexp': '^(vps|eg)-', 'nameserver': '149.202.170.149'}
2015-08-18T19:56:00.266 DEBUG:teuthology.provision:ProvisionOpenStack:destroy target170153
2015-08-18T19:56:00.267 DEBUG:teuthology.misc:openstack server list -f json
2015-08-18T19:56:01.536 DEBUG:teuthology.misc:openstack server list -f json output [{"ID": "b26405dc-af10-492a-931c-6baca0275c94", "Name": "target170152", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.152"}, {"ID": "7f58dd70-4d2e-4e13-aa61-698fcee927c8", "Name": "target170153", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.153"}, {"ID": "127d2f4d-bb50-4bbb-acb0-05ab8aa4f851", "Name": "teuthology", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.149"}, {"ID": "018bc993-6944-4428-a057-6c2f3e472a33", "Name": "other", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.161.79"}]

2015-08-18T19:56:01.536 DEBUG:teuthology.misc:openstack server show -f json target170153
2015-08-18T19:56:03.440 DEBUG:teuthology.misc:openstack server show -f json target170153 output [{"Field": "OS-DCF:diskConfig", "Value": "MANUAL"}, {"Field": "OS-EXT-AZ:availability_zone", "Value": "nova"}, {"Field": "OS-EXT-STS:power_state", "Value": 1}, {"Field": "OS-EXT-STS:task_state", "Value": null}, {"Field": "OS-EXT-STS:vm_state", "Value": "active"}, {"Field": "OS-SRV-USG:launched_at", "Value": "2015-08-18T19:53:50.000000"}, {"Field": "OS-SRV-USG:terminated_at", "Value": null}, {"Field": "accessIPv4", "Value": ""}, {"Field": "accessIPv6", "Value": ""}, {"Field": "addresses", "Value": "Ext-Net=149.202.170.153"}, {"Field": "config_drive", "Value": ""}, {"Field": "created", "Value": "2015-08-18T19:53:17Z"}, {"Field": "flavor", "Value": "vps-ssd-1 (98c1e679-5f2c-4069-b4da-4a4f7179b758)"}, {"Field": "hostId", "Value": "643dffa5fd86216e17116ac0b2b145e2410835ccdba3e2f75fcc9cd5"}, {"Field": "id", "Value": "7f58dd70-4d2e-4e13-aa61-698fcee927c8"}, {"Field": "image", "Value": "teuthology-centos-7.0 (94967743-087d-44d3-a9bc-1bfe9481127b)"}, {"Field": "key_name", "Value": "teuthology"}, {"Field": "name", "Value": "target170153"}, {"Field": "os-extended-volumes:volumes_attached", "Value": [{"id": "e6556acd-b4b7-4d96-90b5-98112b687cb5"}, {"id": "5b0ffdea-29cf-45fe-b61d-3d8a1bf41e39"}, {"id": "8cd32233-9878-411d-808b-634d3e520904"}]}, {"Field": "progress", "Value": 0}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"Field": "security_groups", "Value": [{"name": "teuthology"}]}, {"Field": "status", "Value": "ACTIVE"}, {"Field": "updated", "Value": "2015-08-18T19:55:09Z"}, {"Field": "user_id", "Value": "3a075820e5d24fda96cd340b87fd94e9"}]

2015-08-18T19:56:03.442 DEBUG:teuthology.misc:openstack server delete --wait target170153
2015-08-18T19:56:15.821 DEBUG:teuthology.misc:openstack server delete --wait target170153 output

2015-08-18T19:56:15.822 DEBUG:teuthology.misc:openstack volume delete e6556acd-b4b7-4d96-90b5-98112b687cb5
2015-08-18T19:56:17.052 DEBUG:teuthology.misc:openstack volume delete e6556acd-b4b7-4d96-90b5-98112b687cb5 output
2015-08-18T19:56:17.053 DEBUG:teuthology.misc:openstack volume delete 5b0ffdea-29cf-45fe-b61d-3d8a1bf41e39
2015-08-18T19:56:18.188 DEBUG:teuthology.misc:openstack volume delete 5b0ffdea-29cf-45fe-b61d-3d8a1bf41e39 output
2015-08-18T19:56:18.189 DEBUG:teuthology.misc:openstack volume delete 8cd32233-9878-411d-808b-634d3e520904
2015-08-18T19:56:19.350 DEBUG:teuthology.misc:openstack volume delete 8cd32233-9878-411d-808b-634d3e520904 output
2015-08-18T19:56:19.354 DEBUG:teuthology.provision:ProvisionOpenStack: {'machine': {'disk': 20, 'ram': 8000, 'cpus': 1}, 'subnet': '149.202.160.0/19', 'volumes': {'count': 0, 'size': 1}, 'user-data': 'teuthology/openstack/openstack-{os_type}-{os_version}-user-data.txt', 'ip': '149.202.170.149', 'flavor-select-regexp': '^(vps|eg)-', 'nameserver': '149.202.170.149'}
2015-08-18T19:56:19.354 DEBUG:teuthology.provision:ProvisionOpenStack:destroy target170152
2015-08-18T19:56:19.354 DEBUG:teuthology.misc:openstack server list -f json
2015-08-18T19:56:20.711 DEBUG:teuthology.misc:openstack server list -f json output [{"ID": "b26405dc-af10-492a-931c-6baca0275c94", "Name": "target170152", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.152"}, {"ID": "127d2f4d-bb50-4bbb-acb0-05ab8aa4f851", "Name": "teuthology", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.170.149"}, {"ID": "018bc993-6944-4428-a057-6c2f3e472a33", "Name": "other", "Status": "ACTIVE", "Networks": "Ext-Net=149.202.161.79"}]

2015-08-18T19:56:20.712 DEBUG:teuthology.misc:openstack server show -f json target170152
2015-08-18T19:56:22.958 DEBUG:teuthology.misc:openstack server show -f json target170152 output [{"Field": "OS-DCF:diskConfig", "Value": "MANUAL"}, {"Field": "OS-EXT-AZ:availability_zone", "Value": "nova"}, {"Field": "OS-EXT-STS:power_state", "Value": 1}, {"Field": "OS-EXT-STS:task_state", "Value": null}, {"Field": "OS-EXT-STS:vm_state", "Value": "active"}, {"Field": "OS-SRV-USG:launched_at", "Value": "2015-08-18T19:53:50.000000"}, {"Field": "OS-SRV-USG:terminated_at", "Value": null}, {"Field": "accessIPv4", "Value": ""}, {"Field": "accessIPv6", "Value": ""}, {"Field": "addresses", "Value": "Ext-Net=149.202.170.152"}, {"Field": "config_drive", "Value": ""}, {"Field": "created", "Value": "2015-08-18T19:53:17Z"}, {"Field": "flavor", "Value": "vps-ssd-1 (98c1e679-5f2c-4069-b4da-4a4f7179b758)"}, {"Field": "hostId", "Value": "643dffa5fd86216e17116ac0b2b145e2410835ccdba3e2f75fcc9cd5"}, {"Field": "id", "Value": "b26405dc-af10-492a-931c-6baca0275c94"}, {"Field": "image", "Value": "teuthology-centos-7.0 (94967743-087d-44d3-a9bc-1bfe9481127b)"}, {"Field": "key_name", "Value": "teuthology"}, {"Field": "name", "Value": "target170152"}, {"Field": "os-extended-volumes:volumes_attached", "Value": [{"id": "7bcff9bf-d86f-421b-ab91-85934d61c562"}, {"id": "020f8c0e-db2b-4abc-b803-8b13b6a7efa4"}, {"id": "a3b72f7a-f4fd-41ae-9fe4-78de27f4b130"}]}, {"Field": "progress", "Value": 0}, {"Field": "project_id", "Value": "62cf1be03cec403c8ed8e64df55732ea"}, {"Field": "properties", "Value": "ownedby='149.202.170.149', teuthology='333a94d2ac741af4e6ec9ea2b246159c'"}, {"Field": "security_groups", "Value": [{"name": "teuthology"}]}, {"Field": "status", "Value": "ACTIVE"}, {"Field": "updated", "Value": "2015-08-18T19:53:58Z"}, {"Field": "user_id", "Value": "3a075820e5d24fda96cd340b87fd94e9"}]

2015-08-18T19:56:22.959 DEBUG:teuthology.misc:openstack server delete --wait target170152
2015-08-18T19:56:29.959 DEBUG:teuthology.misc:openstack server delete --wait target170152 output

2015-08-18T19:56:29.959 DEBUG:teuthology.misc:openstack volume delete 7bcff9bf-d86f-421b-ab91-85934d61c562
2015-08-18T19:56:31.127 DEBUG:teuthology.misc:openstack volume delete 7bcff9bf-d86f-421b-ab91-85934d61c562 output
2015-08-18T19:56:31.127 DEBUG:teuthology.misc:openstack volume delete 020f8c0e-db2b-4abc-b803-8b13b6a7efa4
2015-08-18T19:56:32.484 DEBUG:teuthology.misc:openstack volume delete 020f8c0e-db2b-4abc-b803-8b13b6a7efa4 output
2015-08-18T19:56:32.484 DEBUG:teuthology.misc:openstack volume delete a3b72f7a-f4fd-41ae-9fe4-78de27f4b130
2015-08-18T19:56:33.578 DEBUG:teuthology.misc:openstack volume delete a3b72f7a-f4fd-41ae-9fe4-78de27f4b130 output
2015-08-18T19:56:33.602 INFO:teuthology.lock:unlocked target170153.teuthology
2015-08-18T19:56:33.623 INFO:teuthology.lock:unlocked target170152.teuthology
2015-08-18T19:56:33.633 INFO:teuthology.run:Summary data:
{description: 'ceph-deploy/basic/{ceph-deploy-overrides/ceph_deploy_dmcrypt.yaml config_options/cephdeploy_conf.yaml
distros/centos_7.0.yaml tasks/ceph-deploy_hello_world.yaml}', duration: 12.392467975616455,
failure_reason: 'Command failed with status 3: ''ansible-playbook -v --extra-vars
\''{"ansible_ssh_user": "ubuntu"}\'' -i /etc/ansible/hosts --limit target170153.teuthology,target170152.teuthology
/home/ubuntu/src/ceph-cm-ansible_master/cephlab.yml''', owner: scheduled_ubuntu@teuthology,
status: fail, success: false}

2015-08-18T19:56:33.633 DEBUG:teuthology.report:Pushing job info to http://localhost:8080/
2015-08-18T19:56:33.668 INFO:teuthology.run:FAIL
(2-2/2)