Open Stack

See <https://jenkins02.openstack.org/job/periodic-nova-python26-stable-folsom/17/>

------------------------------------------
[...truncated 4430 lines...]
nova.api.openstack.extensions: AUDIT: Loaded extension: os-simple-tenant-usage
nova.api.openstack.extensions: AUDIT: Loaded extension: os-cloudpipe
nova.api.openstack.extensions: AUDIT: Loaded extension: os-security-groups
nova.api.openstack.extensions: AUDIT: Loaded extension: os-server-diagnostics
nova.api.openstack.extensions: AUDIT: Loaded extension: os-flavor-access
nova.api.openstack.extensions: AUDIT: Loaded extension: os-create-server-ext
nova.api.openstack.extensions: AUDIT: Loaded extension: os-multiple-create
nova.api.openstack.extensions: AUDIT: Loaded extension: OS-FLV-DISABLED
nova.api.openstack.extensions: AUDIT: Loaded extension: os-instance_usage_audit_log
nova.api.openstack.extensions: AUDIT: Loaded extension: OS-SCH-HNT
nova.api.openstack.extensions: AUDIT: Loaded extension: os-aggregates
nova.api.openstack.extensions: AUDIT: Loaded extension: os-networks
nova.api.openstack.extensions: AUDIT: Loaded extension: os-quota-sets
nova.api.openstack.extensions: AUDIT: Loaded extension: OS-DCF
nova.api.openstack.extensions: AUDIT: Loaded extension: os-used-limits
nova.api.openstack.extensions: AUDIT: Loaded extension: OS-FLV-EXT-DATA
routes.middleware: DEBUG: Initialized with method overriding = True, and path info altering = True
nova.wsgi: INFO: osapi_compute listening on 127.0.0.1:37499
nova.tests.integrated.integrated_helpers: WARNING: http://127.0.0.1:37499/v2
nova.tests.integrated.api.client: INFO: Doing GET on /v2
nova.osapi_compute.wsgi.server: INFO: (29350) wsgi starting up on http://127.0.0.1:37499/

nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41574)

nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:02] "GET /v2 HTTP/1.1" 204 216 0.000731

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//images/detail
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41575)

routes.middleware: DEBUG: Matched GET /openstack/images/detail
routes.middleware: DEBUG: Route path: '/{project_id}/images/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xc4fe8d0>}
routes.middleware: DEBUG: Match dict: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xc4fe8d0>, 'project_id': u'openstack'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/images/detail
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/images/detail returned with HTTP 200
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:03] "GET /v2/openstack//images/detail HTTP/1.1" 200 4992 0.820500

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//flavors/detail
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41576)

routes.middleware: DEBUG: Matched GET /openstack/flavors/detail
routes.middleware: DEBUG: Route path: '/{project_id}/flavors/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xbf40dd0>}
routes.middleware: DEBUG: Match dict: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xbf40dd0>, 'project_id': u'openstack'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/flavors/detail
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/flavors/detail returned with HTTP 200
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:03] "GET /v2/openstack//flavors/detail HTTP/1.1" 200 2013 0.013708

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//servers/detail
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41577)

routes.middleware: DEBUG: Matched GET /openstack/servers/detail
routes.middleware: DEBUG: Route path: '/{project_id}/servers/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'detail', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/servers/detail
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/detail returned with HTTP 200
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:03] "GET /v2/openstack//servers/detail HTTP/1.1" 200 187 0.043466

nova.tests.integrated.api.client: INFO: Doing POST on /v2/openstack//servers
nova.tests.integrated.api.client: INFO: Body: {"server": {"flavorRef": "http://fake.server/1", "name": "serverIX2X2AUU", "imageRef": "http://fake.server/70a599e0-31e7-49b7-b260-868f441e862b"}}
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41578)

routes.middleware: DEBUG: Matched POST /openstack/servers
routes.middleware: DEBUG: Route path: '/{project_id}/servers', defaults: {'action': u'create', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'create', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack'}
nova.api.openstack.wsgi: INFO: POST http://127.0.0.1:37499/v2/openstack/servers
nova.compute.manager: AUDIT: Starting instance...
nova.compute.resource_tracker: AUDIT: Attempting claim: memory 512 MB, disk 0 GB, VCPUs 1
nova.compute.resource_tracker: AUDIT: Total memory: 8192 MB, used: 512 MB, free: 7680 MB
nova.compute.resource_tracker: AUDIT: Memory limit not specified, defaulting to unlimited
nova.compute.resource_tracker: AUDIT: Total disk: 1028 GB, used: 0 GB, free: 1028 GB
nova.compute.resource_tracker: AUDIT: Disk limit not specified, defaulting to unlimited
nova.compute.resource_tracker: AUDIT: Total VCPUs: 1, used: 0
nova.compute.resource_tracker: AUDIT: VCPU limit not specified, defaulting to unlimited
nova.compute.resource_tracker: INFO: Finishing claim: [Claim f0003e69-b882-4e35-93c0-69bd07dc5d9a: 512 MB memory, 0 GB disk, 1 VCPUS]
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers returned with HTTP 202
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:04] "POST /v2/openstack//servers HTTP/1.1" 202 659 0.542065

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.compute.resource_tracker: AUDIT: Free ram (MB): 7168
nova.compute.resource_tracker: AUDIT: Free disk (GB): 1028
nova.compute.resource_tracker: AUDIT: Free VCPUS: 0
nova.compute.resource_tracker: INFO: Compute_service record updated for 27956ac73df94b1fb456257bb44d901e 
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41579)

nova.compute.manager: INFO: Updating bandwidth usage cache
routes.middleware: DEBUG: Matched GET /openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
routes.middleware: DEBUG: Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack', 'id': u'f0003e69-b882-4e35-93c0-69bd07dc5d9a'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a returned with HTTP 200
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:04] "GET /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a HTTP/1.1" 200 1424 0.062518

nova.tests.integrated.api.client: INFO: Doing DELETE on /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41580)

routes.middleware: DEBUG: Matched DELETE /openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
routes.middleware: DEBUG: Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'delete', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'delete', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack', 'id': u'f0003e69-b882-4e35-93c0-69bd07dc5d9a'}
nova.api.openstack.wsgi: INFO: DELETE http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a returned with HTTP 204
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:04] "DELETE /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a HTTP/1.1" 204 179 0.288814

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41581)

routes.middleware: DEBUG: Matched GET /openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
routes.middleware: DEBUG: Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack', 'id': u'f0003e69-b882-4e35-93c0-69bd07dc5d9a'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a returned with HTTP 200
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:04] "GET /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a HTTP/1.1" 200 1415 0.069503

nova.tests.integrated.api.client: INFO: Doing POST on /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a/action
nova.tests.integrated.api.client: INFO: Body: {"restore": {}}
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41582)

routes.middleware: DEBUG: Matched POST /openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a/action
routes.middleware: DEBUG: Route path: '/{project_id}/servers/:(id)/action', defaults: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'action', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack', 'id': u'f0003e69-b882-4e35-93c0-69bd07dc5d9a'}
nova.api.openstack.wsgi: INFO: POST http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a/action
nova.compute.manager: INFO: Reclaiming deleted instance
nova.compute.manager: AUDIT: Terminating instance
nova.compute.manager: INFO: Updating host status
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a/action returned with HTTP 202
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:05] "POST /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a/action HTTP/1.1" 202 121 0.402131

nova.tests.integrated.api.client: INFO: Doing GET on /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.osapi_compute.wsgi.server: INFO: (29350) accepted ('127.0.0.1', 41583)

routes.middleware: DEBUG: Matched GET /openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
routes.middleware: DEBUG: Route path: '/{project_id}/servers/:(id)', defaults: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>}
routes.middleware: DEBUG: Match dict: {'action': u'show', 'controller': <nova.api.openstack.wsgi.Resource object at 0xa2f9b50>, 'project_id': u'openstack', 'id': u'f0003e69-b882-4e35-93c0-69bd07dc5d9a'}
nova.api.openstack.wsgi: INFO: GET http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a
nova.api.openstack.wsgi: INFO: HTTP exception thrown: The resource could not be found.
nova.api.openstack.wsgi: INFO: http://127.0.0.1:37499/v2/openstack/servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a returned with HTTP 404
nova.osapi_compute.wsgi.server: INFO: 127.0.0.1 - - [03/Sep/2013 06:15:05] "GET /v2/openstack//servers/f0003e69-b882-4e35-93c0-69bd07dc5d9a HTTP/1.1" 404 272 0.043317

--------------------- >> end captured logging << ---------------------

----------------------------------------------------------------------
XML: nosetests.xml
Slowest 5 tests took 33.15 secs:
    10.72    ComputeTestCase.test_state_revert
    7.05    CloudTestCase.test_instance_initiated_shutdown_behavior
    6.00    ServersTest.test_create_multiple_servers
    5.07    StorwizeSVCDriverTestCase.test_storwize_svc_flashcopy
    4.31    ServersTest.test_create_and_rebuild_server
----------------------------------------------------------------------
Ran 3729 tests in 831.289s

FAILED (SKIP=7, errors=1)
ERROR: InvocationError: '<https://jenkins02.openstack.org/job/periodic-nova-python26-stable-folsom/ws/.tox/py26/bin/nosetests'>
___________________________________ summary ____________________________________
ERROR:   py26: commands failed
+ result=1
+ echo 'Begin pip freeze output from test virtualenv:'
Begin pip freeze output from test virtualenv:
+ echo ======================================================================
======================================================================
+ .tox/py26/bin/pip freeze
Babel==1.3
Cheetah==2.4.4
Jinja2==2.7.1
Markdown==2.3.1
MarkupSafe==0.18
Paste==1.7.5.1
PasteDeploy==1.5.0
Pygments==1.6
Routes==1.12.3
SQLAlchemy==0.7.9
Sphinx==1.2b1
Tempita==0.5.1
WebOb==1.0.8
amqplib==0.6.1
anyjson==0.2.4
argparse==1.2.1
boto==2.1.1
cliff==1.4.4
cmd2==0.6.5.1
colorama==0.2.5
coverage==3.6
d2to1==0.2.11
decorator==3.4.0
distribute==0.7.3
docutils==0.10
eventlet==0.13.0
feedparser==5.1.3
greenlet==0.4.1
httplib2==0.8
iso8601==0.1.4
jsonpatch==1.1
jsonpointer==1.0
jsonschema==2.0.0
kombu==1.0.4
logilab-astng==0.24.3
logilab-common==0.60.0
lxml==2.3.5
mox==0.5.3
netaddr==0.7.10
nose==1.2.1
nosehtmloutput==0.0.5
nova==2012.2.5
openstack.nose-plugin==0.11
oslo.config==1.1.1
paramiko==1.11.0
pbr==0.5.21
pep8==1.1
prettytable==0.7.2
pyOpenSSL==0.13
pycrypto==2.6
pylint==0.25.2
pyparsing==1.5.7
python-cinderclient==1.0.5
python-glanceclient==0.11.0
python-keystoneclient==0.3.2
python-quantumclient==2.2.3
pytz==2013b
requests==1.2.2
setuptools-git==1.0
simplejson==3.3.0
six==1.4.1
sqlalchemy-migrate==0.7.2
suds==0.4
termcolor==1.1.0
unittest2==0.5.1
warlock==1.0.1
+ echo ======================================================================
======================================================================
+ '[' -d .testrepository ']'
+ sudo /usr/local/jenkins/slave_scripts/jenkins-sudo-grep.sh post
+ sudoresult=0
+ '[' 0 -ne 0 ']'
+ /usr/local/jenkins/slave_scripts/jenkins-oom-grep.sh post
+ oomresult=0
+ '[' 0 -ne 0 ']'
++ find . -name nose_results.html
+ htmlreport=./nova/tests/nose_results.html
+ '[' -f ./nova/tests/nose_results.html ']'
++ grep -c 'tr class=.passClass' ./nova/tests/nose_results.html
+ passcount=459
+ '[' 459 -eq 0 ']'
+ exit 1
+ rm -rf /tmp/tmp.xDidLuswuY
Build step 'Execute shell' marked build as failure
[SCP] Connecting to static.openstack.org
[SCP] Trying to create /srv/static/logs/periodic/periodic-nova-python26-stable-folsom/17
[SCP] uploading file: '/srv/static/logs/periodic/periodic-nova-python26-stable-folsom/17/nose_results.html'
[SCP] Connecting to static.openstack.org
[SCP] Trying to create /srv/static/logs/periodic/periodic-nova-python26-stable-folsom/centos6-4/17
[SCP] Copying console log.