tempest.tests.compute.servers.test_server_rescue.ServerRescueTestJSON fail with badstatusline in ha mode

Bug #1312440 reported by Jerry Zhao
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Compass
Fix Committed
Undecided
Jerry Zhao

Bug Description

When running tempest full smoke test, each time tempest.tests.compute.servers.test_server_rescue.ServerRescueTestJSON and tempest.tests.compute.servers.test_server_rescue.ServerRescueTestXML would get an BadStatusLine error when delete a floating ip.
Did a packet capture and found out that ha proxy sent tcp rst on receiving the deleting the floating ip request.
However, it can not be reproduced by running the particular test manually. Need more haproxy log for investigation.
2014-04-24 10:50:50.509 | ======================================================================
2014-04-24 10:50:50.509 | ERROR: test suite for <class 'tempest.tests.compute.servers.test_server_rescue.ServerRescueTestJSON'>
2014-04-24 10:50:50.509 | ----------------------------------------------------------------------
2014-04-24 10:50:50.509 | Traceback (most recent call last):
2014-04-24 10:50:50.509 | File "/usr/lib/python2.6/site-packages/nose/suite.py", line 227, in run
2014-04-24 10:50:50.510 | self.tearDown()
2014-04-24 10:50:50.510 | File "/usr/lib/python2.6/site-packages/nose/suite.py", line 350, in tearDown
2014-04-24 10:50:50.510 | self.teardownContext(ancestor)
2014-04-24 10:50:50.510 | File "/usr/lib/python2.6/site-packages/nose/suite.py", line 366, in teardownContext
2014-04-24 10:50:50.510 | try_run(context, names)
2014-04-24 10:50:50.510 | File "/usr/lib/python2.6/site-packages/nose/util.py", line 469, in try_run
2014-04-24 10:50:50.510 | return func()
2014-04-24 10:50:50.510 | File "/tmp/tempest/tempest/tests/compute/servers/test_server_rescue.py", line 96, in tearDownClass
2014-04-24 10:50:50.511 | cls.floating_ips_client.delete_floating_ip(cls.floating_ip_id)
2014-04-24 10:50:50.511 | File "/tmp/tempest/tempest/services/compute/json/floating_ips_client.py", line 60, in delete_floating_ip
2014-04-24 10:50:50.511 | resp, body = self.delete(url)
2014-04-24 10:50:50.511 | File "/tmp/tempest/tempest/common/rest_client.py", line 177, in delete
2014-04-24 10:50:50.511 | return self.request('DELETE', url, headers)
2014-04-24 10:50:50.511 | File "/tmp/tempest/tempest/common/rest_client.py", line 283, in request
2014-04-24 10:50:50.511 | headers=headers, body=body)
2014-04-24 10:50:50.511 | File "/tmp/tempest/tempest/common/rest_client.py", line 266, in _request
2014-04-24 10:50:50.511 | headers=headers, body=body)
2014-04-24 10:50:50.512 | File "/usr/lib/python2.6/site-packages/httplib2/__init__.py", line 1570, in request
2014-04-24 10:50:50.512 | (response, content) = self._request(conn, authority, uri, request_uri, method, body, headers, redirections, cachekey)
2014-04-24 10:50:50.512 | File "/usr/lib/python2.6/site-packages/httplib2/__init__.py", line 1317, in _request
2014-04-24 10:50:50.512 | (response, content) = self._conn_request(conn, request_uri, method, body, headers)
2014-04-24 10:50:50.512 | File "/usr/lib/python2.6/site-packages/httplib2/__init__.py", line 1286, in _conn_request
2014-04-24 10:50:50.512 | response = conn.getresponse()
2014-04-24 10:50:50.512 | File "/usr/lib64/python2.6/httplib.py", line 990, in getresponse
2014-04-24 10:50:50.512 | response.begin()
2014-04-24 10:50:50.512 | File "/usr/lib64/python2.6/httplib.py", line 391, in begin
2014-04-24 10:50:50.513 | version, status, reason = self._read_status()
2014-04-24 10:50:50.513 | File "/usr/lib64/python2.6/httplib.py", line 355, in _read_status
2014-04-24 10:50:50.513 | raise BadStatusLine(line)
2014-04-24 10:50:50.513 | BadStatusLine:
2014-04-24 10:50:50.513 | -------------------- >> begin captured logging << --------------------
2014-04-24 10:50:50.513 | 2014-04-24 03:41:29,516 Request: DELETE http://172.16.0.253:8774/v2/c94f3211595d46a9a167b70028c0afcc/os-floating-ips/52621fb0-888f-43d5-b379-e9bd38cf5003
2014-04-24 10:50:50.513 | 2014-04-24 03:41:29,516 Request Headers: {'X-Auth-Token': '<Token omitted>'}

Revision history for this message
Jerry Zhao (zhaoxinyu) wrote :
Revision history for this message
Jerry Zhao (zhaoxinyu) wrote :

haproxy closes the tcp connection after client timeout, which was 50s, so later when tempest/httplib2 sent floating ip delete request, the tcp connection was not there, hence the tcp rst.
Try increasing the timeout to 100s to see what happens.

Changed in compass:
assignee: nobody → Jerry Zhao (zhaoxinyu)
Revision history for this message
Jerry Zhao (zhaoxinyu) wrote :

https://bugs.launchpad.net/tempest/+bug/1215804
https://review.openstack.org/#/c/43390/

Increasing haproxy timeout fixed the issue but it is in fact a bug in tempest after all because tempest http client should not keep the tcp connection around until it finishes one test. The bug above reported in havana is caused by the same behavior, so tempest later use a new connection for each request and closes the old connection.

Jerry Zhao (zhaoxinyu)
Changed in compass:
status: New → Fix Committed
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Bug attachments

Remote bug watches

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