Socket leak on proxy->obj when HTTPRequestedRangeNotSatisfiable with erasure code

Bug #1738804 reported by Romain LE DISEZ
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Object Storage (swift)
Fix Released
High
Samuel Merritt

Bug Description

Issue:
proxy-server does not close connections with object-servers when the client requested a range that is not satisfiable for an object on an erasure code policy (no issue with replica policy)

How to reproduce on a SAIO:
eval $(swift -A http://127.0.0.1:8080/auth/v1.0 -U test:tester -K testing auth)

curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec -X PUT -H "X-Storage-Policy: ec42"
curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec/obj -X PUT -d "1234"
for i in $(seq 1 10); do curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec/obj -H "Range: bytes=10-20"; echo; done

netstat -tpn | grep -E "127.0.0.1:[0-9]+ +127.0.0.1:60[0-9][0-9] "
# => many CLOSE_WAIT that will never be closed

Revision history for this message
Romain LE DISEZ (rledisez) wrote :

After few more tests, it seems the range value is important.

If the range begin is lower than 1M (1024*1024), it leaks:
for i in $(seq 1 10); do curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec/obj -H "Range: bytes=1048575-1048580"; echo; done

If the range begin is greater or equal than 1M, it does not leak:
for i in $(seq 1 10); do curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec/obj -H "Range: bytes=1048576-1048580"; echo; done

Revision history for this message
Romain LE DISEZ (rledisez) wrote :

FWIW, probably not the right way to do it so i'm not submitting a patch, but it does the job: http://paste.openstack.org/show/629232/

Revision history for this message
clayg (clay-gerrard) wrote :

ubuntu@saio:~$ sudo netstat -tpn | grep -i close_wait
tcp 0 0 127.0.0.1:54264 127.0.0.3:6037 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:54278 127.0.0.3:6037 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:39970 127.0.0.1:6016 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:46518 127.0.0.1:6017 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:39960 127.0.0.1:6016 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:46508 127.0.0.1:6017 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:47166 127.0.0.2:6026 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:44300 127.0.0.4:6047 CLOSE_WAIT 21011/python
ubuntu@saio:~$ curl -H "X-Auth-Token: $OS_AUTH_TOKEN" $OS_STORAGE_URL/range_leak_ec/obj -H "Range: bytes=10-20"
<html><h1>Requested Range Not Satisfiable</h1><p>The Range requested is not available.</p></html>ubuntu@saio:~$
ubuntu@saio:~$ sudo netstat -tpn | grep -i close_wait
tcp 0 0 127.0.0.1:54288 127.0.0.3:6037 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:41524 127.0.0.2:6027 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:44310 127.0.0.4:6047 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:54264 127.0.0.3:6037 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:39980 127.0.0.1:6016 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:54278 127.0.0.3:6037 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:39970 127.0.0.1:6016 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:46518 127.0.0.1:6017 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:39960 127.0.0.1:6016 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:46508 127.0.0.1:6017 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:47166 127.0.0.2:6026 CLOSE_WAIT 21011/python
tcp 0 0 127.0.0.1:44300 127.0.0.4:6047 CLOSE_WAIT 21011/python

Changed in swift:
status: New → Confirmed
importance: Undecided → High
Changed in swift:
assignee: nobody → Samuel Merritt (torgomatic)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to swift (master)

Fix proposed to branch: master
Review: https://review.openstack.org/530411

Changed in swift:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to swift (master)

Reviewed: https://review.openstack.org/530411
Committed: https://git.openstack.org/cgit/openstack/swift/commit/?id=f709eed41b9579cf5a8ca9180143301a2b452d47
Submitter: Zuul
Branch: master

commit f709eed41b9579cf5a8ca9180143301a2b452d47
Author: Samuel Merritt <email address hidden>
Date: Thu Dec 28 14:56:08 2017 -0800

    Fix socket leak on 416 EC GET responses.

    Sometimes, when handling an EC GET request with a Range header, the
    object servers reply 206 to the proxy, but the proxy (correctly)
    replies 416 to the client[1]. In that case, the connections to the object
    servers were not being closed. This was due to improper error handling
    in ECAppIter.

    Since ECAppIter is intended to be a WSGI iterable, it expects to have
    its close() method called when the caller is done with it. In this
    particular case, the caller (ECAppIter.kickoff()) was not calling
    close() when an exception was raised. Now it is.

    [1] consider a 4+2 EC policy with segment size 1024, an 20 byte
    object, and a request with "Range: bytes=21-50". The proxy needs whole
    fragments to decode, so it asks the object server for "Range:
    bytes=0-255" [2], the object server says 206, and then the proxy
    realizes that the client's request is unsatisfiable and tells the
    client 416.

    [2] segment size 1024 and 4 data fragments means the fragments have
    size 1024 / 4 = 256, hence "bytes=0-255" asks for the first whole
    fragment

    Change-Id: Ide2edf8c449c97d45f48c2dbbbff7aebefa4b158
    Closes-Bug: 1738804

Changed in swift:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to swift (feature/s3api)

Fix proposed to branch: feature/s3api
Review: https://review.openstack.org/535623

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to swift (feature/s3api)
Download full text (33.3 KiB)

Reviewed: https://review.openstack.org/535623
Committed: https://git.openstack.org/cgit/openstack/swift/commit/?id=271b80d0f51078719de35bf6f75b7e06ac3e5b91
Submitter: Zuul
Branch: feature/s3api

commit 88eea33ccd1875af811b59d15df55e2bffa27f77
Author: Clay Gerrard <email address hidden>
Date: Thu Jan 11 13:36:09 2018 -0800

    Recenter builder test expectation around random variance

    ... in order to make the test pass with more seeds and fail less
    frequently in the gate.

    Change-Id: I059e80af87fd33a3b6c0731fbad62e035215eca5

commit d924fa759967b7cdca0d91f21112725f6099a254
Author: Samuel Merritt <email address hidden>
Date: Tue Jan 16 22:19:09 2018 -0800

    Remove old post-as-copy leftovers from tests.

    Since commit 1e79f828, we don't need to test with post_as_copy=True
    any more since we haven't got post_as_copy at all.

    Change-Id: I9c96ce0b812d877bbe11bdb50eb160d6ffa5933d

commit dfa0c4e604fb931d232395599bd0e7b0f11441ee
Author: Alistair Coles <email address hidden>
Date: Wed Jan 17 12:04:45 2018 +0000

    Preserve expiring object behaviour with old proxy-server

    The related change [1] causes expiring object records to no longer be
    created if the X-Delete-At-Container header is not sent to the object
    server, but old proxies prior to [2] (i.e. releases prior to 1.9.0)
    did not send this header.

    The goal of [1] can be alternatively achieved by making expiring
    object record creation be conditional on the X-Delete-At-Host header.

    [1] Related-Change: I20fc2f42f590fda995814a2fa7ba86019f9fddc1
    [2] Related-Change: Id0873a3f2198ce285fe0b0c777738eff38bc2438

    Change-Id: Ia0081693f01631d3f2a59612308683e939ced76a

commit d707fc7b6d0ceb4556dddfc258c5de8c4baff05c
Author: Clay Gerrard <email address hidden>
Date: Tue Jan 16 16:30:13 2018 -0800

    DRY out tests until the stone bleeds

    Can we go deeper!?

    Change-Id: Ibd3b06542aa1bfcbcb71cc98e6bb21a6a67c12f4

commit ba8f1b1c3786df4e79fc3f9e4747d7cfb9072b6f
Author: Alistair Coles <email address hidden>
Date: Wed Jan 17 15:25:33 2018 +0000

    Fix intermittent unit test failure

    test_check_delete_headers_removes_delete_after was
    failing intermittently due to rounding of float time
    values.

    Change-Id: Ia126ad6988f387bbd2d1f5ddff0a56d457a1fc9b
    Closes-Bug: #1743804

commit e747f94313f315fdf8d8fc01fb0c5aac60c33897
Author: Kota Tsuyuzaki <email address hidden>
Date: Wed Dec 27 14:37:29 2017 +0900

    Fix InternalClient to drain response body if the request fails

    If we don't drain the body, the proxy logging in the internal client
    pipeline will log 499 client disconnect instead of actual error response
    code.

    For error responses, we try to do the most helpful thing using swob's
    closing and caching response body attribute. For non-error responses
    which are returned to the client, we endeavour to keep the app_iter
    intact and unconsumed, trusting expecting the caller to do the right
    thing is the only reasonable interface. We must cleanly close any WSGI
    app_iter which we do not return to the client rega...

tags: added: in-feature-s3api
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to swift (feature/deep)

Fix proposed to branch: feature/deep
Review: https://review.openstack.org/535990

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to swift (feature/deep)
Download full text (32.4 KiB)

Reviewed: https://review.openstack.org/535990
Committed: https://git.openstack.org/cgit/openstack/swift/commit/?id=3122895118111b2b11f5ef9d0b3410b337624b1b
Submitter: Zuul
Branch: feature/deep

commit ddb13aa5eab03b6993887eb02260b4bc0b256922
Author: vxlinux <email address hidden>
Date: Sat Jan 20 17:23:35 2018 +0800

    Remove redundant blank space in README.rst

    Change-Id: If347476e3b9185921ff174d3f8170a1c4d0622e8

commit 12f874534925b52f9d1c91580794eb9e5e9a4589
Author: vxlinux <email address hidden>
Date: Fri Jan 19 16:54:26 2018 +0800

    Add Docstrings to validate_replicas_by_tier

    New common functions should have Docstrings

    Change-Id: Icbb3cdf38509fd6d034cbb2271786559780a7b68

commit d2034cd7b6946829a7d95c4d2c71d4322f80e855
Author: Clay Gerrard <email address hidden>
Date: Tue Jan 16 17:03:38 2018 -0800

    Keep object-updater stats logging consistent

    If we're going to encapsulate the stats tracking it seems reasonable if
    we ever add any more metrics we can reduce the number of places we need
    to update log messages.

    Change-Id: I187cf6cfec1e0a9138b709fa298e1991aa809ec4

commit cd2c73fd955317a3f40758cef45ee48bef8fbc79
Author: Tim Burke <email address hidden>
Date: Tue Jan 16 01:07:35 2018 +0000

    internal_client: Don't retry when we expect the same reponse

    This boils down to 404, 412, or 416; or 409 when we provided an
    X-Timestamp.

    This means, among other things, that the expirer won't issue 3 DELETEs
    every cycle for every stale work item.

    Related-Change: Icd63c80c73f864d2561e745c3154fbfda02bd0cc
    Change-Id: Ie5f2d3824e040bbc76d511a54d1316c4c2503732

commit 222df9185782f59ffdc96c3534afaa2fb1361235
Author: chengebj5238 <email address hidden>
Date: Thu Jan 18 17:03:11 2018 +0800

    Modify redirection URL and broken URL

    Change-Id: I9a04cb2fbe61e1fbd8185ab2fac9abbcea4d55cc

commit d1656e334959e09d13eea98c2696e58c77e4ab91
Author: Tim Burke <email address hidden>
Date: Fri Jan 12 13:17:45 2018 -0800

    slo: Send ETag header in 206 responses

    Why weren't we doing that before?? The etag should be the same as for
    GET/HEAD, and by sending it, we can assure resuming clients that they're
    downlading the same object even if they didn't include an If-Match
    header.

    Change-Id: I4ccbd1ae3a909ecb4606ef18211d1b868f5cad86
    Related-Change: Ic11662eb5c7176fbf422a6fc87a569928d6f85a1

commit 88eea33ccd1875af811b59d15df55e2bffa27f77
Author: Clay Gerrard <email address hidden>
Date: Thu Jan 11 13:36:09 2018 -0800

    Recenter builder test expectation around random variance

    ... in order to make the test pass with more seeds and fail less
    frequently in the gate.

    Change-Id: I059e80af87fd33a3b6c0731fbad62e035215eca5

commit f64c00b00aa8df31a937448917421891904abdc8
Author: Samuel Merritt <email address hidden>
Date: Fri Jan 12 07:17:18 2018 -0800

    Improve object-updater's stats logging

    The object updater has five different stats, but its logging only told
    you two of them (successes and failures), and it only told you after
    finishing all the async_pendings for a device. If y...

tags: added: in-feature-deep
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/swift 2.17.0

This issue was fixed in the openstack/swift 2.17.0 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to swift (stable/pike)

Fix proposed to branch: stable/pike
Review: https://review.openstack.org/585342

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to swift (stable/pike)

Reviewed: https://review.openstack.org/585342
Committed: https://git.openstack.org/cgit/openstack/swift/commit/?id=8ff69e69bf4be0a0085916339003dc1368b7c703
Submitter: Zuul
Branch: stable/pike

commit 8ff69e69bf4be0a0085916339003dc1368b7c703
Author: Samuel Merritt <email address hidden>
Date: Thu Dec 28 14:56:08 2017 -0800

    Fix socket leak on 416 EC GET responses.

    Sometimes, when handling an EC GET request with a Range header, the
    object servers reply 206 to the proxy, but the proxy (correctly)
    replies 416 to the client[1]. In that case, the connections to the object
    servers were not being closed. This was due to improper error handling
    in ECAppIter.

    Since ECAppIter is intended to be a WSGI iterable, it expects to have
    its close() method called when the caller is done with it. In this
    particular case, the caller (ECAppIter.kickoff()) was not calling
    close() when an exception was raised. Now it is.

    [1] consider a 4+2 EC policy with segment size 1024, an 20 byte
    object, and a request with "Range: bytes=21-50". The proxy needs whole
    fragments to decode, so it asks the object server for "Range:
    bytes=0-255" [2], the object server says 206, and then the proxy
    realizes that the client's request is unsatisfiable and tells the
    client 416.

    [2] segment size 1024 and 4 data fragments means the fragments have
    size 1024 / 4 = 256, hence "bytes=0-255" asks for the first whole
    fragment

    Change-Id: Ide2edf8c449c97d45f48c2dbbbff7aebefa4b158
    Closes-Bug: 1738804

tags: added: in-stable-pike
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/swift 2.15.2

This issue was fixed in the openstack/swift 2.15.2 release.

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

Other bug subscribers

Remote bug watches

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