glance api is tracebacking with "error: [Errno 32] Broken pipe"

[Joe Gordon]

127.0.0.1 - - [15/Jul/2014 10:55:39] code 400, message Bad request syntax ('0')
127.0.0.1 - - [15/Jul/2014 10:55:39] "0" 400 -
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl
    func(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 584, in process_request
    proto.__init__(socket, address, self)
  File "/usr/lib/python2.7/SocketServer.py", line 649, in __init__
    self.handle()
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 342, in handle
    self.handle_one_request()
  File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 247, in handle_one_request
    if not self.parse_request():
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 286, in parse_request
    self.send_error(400, "Bad request syntax (%r)" % requestline)
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 368, in send_error
    self.send_response(code, message)
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 395, in send_response
    self.send_header('Server', self.version_string())
  File "/usr/lib/python2.7/BaseHTTPServer.py", line 401, in send_header
    self.wfile.write("%s: %s\r\n" % (keyword, value))
  File "/usr/lib/python2.7/socket.py", line 324, in write
    self.flush()
  File "/usr/lib/python2.7/socket.py", line 303, in flush
    self._sock.sendall(view[write_offset:write_offset+buffer_size])
  File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 307, in sendall
    tail = self.send(data, flags)
  File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 293, in send
    total_sent += fd.send(data[total_sent:], flags)
error: [Errno 32] Broken pipe

http://logs.openstack.org/62/100162/3/check/check-tempest-dsvm-full/77badd4/logs/screen-g-api.txt.gz?level=INFO#_2014-07-15_10_55_39_729

Seen all over the gate. Seeing stacktraces like thi

[Kashyap Chamarthy (kashyapc)]

Last 24 hours, logstack query for the string "error: [Errno 32] Broken pipe"

  http://logstash.openstack.org/#eyJzZWFyY2giOiJcImVycm9yOiBbRXJybm8gMzJdIEJyb2tlbiBwaXBlXCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjE3MjgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0MDU0MjY0NTg1MjF9

[Kashyap Chamarthy (kashyapc)]

Err, the above comment is meant to read as "Last 48 hour", and it's 500 hits.

[Bob Ball (bob-ball)]

http://logstash.openstack.org/#eyJzZWFyY2giOiJcImVycm9yOiBbRXJybm8gMzJdIEJyb2tlbiBwaXBlXCIgQU5EIFwiQmFkIHJlcXVlc3Qgc3ludGF4ICgnMCcpXCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjE3MjgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0MDg1NDc2Mzg2ODh9 is a slightly tighter query that seems to show this.

In the last 48 hours it's seen 28,366 hits...

[Erno Kuvaja (jokke)]

Seems to be still going on.

[Yang Yu (yuyangbj)]

I also see this bug, what OS did you use? Ubuntu 12.04?

[Sabari Murugesan (smurugesan)]

The traceback can be attributed both to python-glanceclient & 'request' library.

python-glanceclient: During chunked http image upload, we create a chunk for EOF while reading image file. Glance-api treats this as the end of chunked transmission and sends a 201 response. But the 'requests' library also sends the last-chunk for which the server tries to respond with 400 but tracebacks because the client has already closed the socket. I have uploaded a patch to correct the behavior in python-glanceclient.

'requests': httplib checks chunk_size in request.body before sending over socket. If it's empty it assumes end-of-transmission and does not send to the server. But 'requests' doesn't seem to do so. I am planning to provide a pull-request to 'requests'.

[Sabari Murugesan (smurugesan)]

Forgot to mention, either of the fix will solve the issue.

[Sabari Murugesan (smurugesan)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/142952
Committed: https://git.openstack.org/cgit/openstack/python-glanceclient/commit/?id=e3600ad7beb7cb4a067038d750e530a64fd1e93a
Submitter: Jenkins
Branch: master

commit e3600ad7beb7cb4a067038d750e530a64fd1e93a
Author: Sabari Kumar Murugesan <email address hidden>
Date: Thu Dec 18 16:52:07 2014 -0800

    Fix broken-pipe seen in glance-api

    When file size is an exact multiple of chunk_size, glance client
    is processing EOF in image-data as a chunk and sends to
    glance-api. The server treats this as the end of chunked
    transmission and sends a http response.

    When the actual last chunk is sent by the 'requests' library, the
    server sends a 400 response and tracebacks with broken pipe
    as the client has already closed the socket.

    Closes-Bug: #1342080
    Change-Id: Icdbff838450db1c252ddc919a230a7d3ca16765f

[Sabari Murugesan (smurugesan)]

FYI: Also submitted a pull request to 'requests' library https://github.com/kennethreitz/requests/pull/2388. This will help other such clients sending empty chunks.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Dr. Jens Harbott (j-harbott)]

Still seeing this in Ubuntu Vivid with python-glanceclient=1:0.15.0-0ubuntu1, any chance to get this backported?

[James Page (james-page)]

Fixed in 0.16.0 - marking fix released for Wily (has 0.19.0).

[Rolf Leggewie (r0lf)]

utopic has seen the end of its life and is no longer receiving any updates. Marking the utopic task for this ticket as "Won't Fix".