Eventlet Log Spamming on Client Disconnect (Broken Pipe)

[Morgan Fainberg]

If a client makes a request to keystone, and then disconnects before keystone responds, it is possible to fill up the logs (INFO) with eventlet tracebacks due to broken pipe:

2014-06-24 23:30:29.729 31440 INFO eventlet.wsgi.server [-] 127.0.0.1 - - [24/Jun/2014 23:30:29] "POST /v3/auth/tokens HTTP/1.1" 201 0 100.313719
2014-06-24 23:30:29.731 31440 INFO eventlet.wsgi.server [-] Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 399, in handle_one_response
    write(''.join(towrite))
  File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 349, in write
    _writelines(towrite)
  File "/usr/lib/python2.7/socket.py", line 334, in writelines
    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

Example (900k line file) due to this [WARNING THIS LINK MIGHT KILL YOUR BROWSER]:
http://logs.openstack.org/66/99766/2/check/check-grenade-dsvm/9fd33e1/logs/old/screen-key.txt.gz?level=INFO

We should override the required HTTPProtocol class and gracefully handle the traceback. If we would like to keep the information, a single log-line per incident would be sufficient instead of ~14.

This should be considered for a backport to Icehouse to help limit log spam there as well.

[Morgan Fainberg (mdrnstm)]

This is being marked as Critical on request of the -infra team, this is causing issues in gate with excessive log-size.

[OpenStack Infra (hudson-openstack)]

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

[Morgan Fainberg (mdrnstm)]

Targeted to Icehouse based upon original request from -infra.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/102912

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/102680
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=2c389b9f389f1a8bb01ffad6489353bc9c23416b
Submitter: Jenkins
Branch: master

commit 2c389b9f389f1a8bb01ffad6489353bc9c23416b
Author: Morgan Fainberg <email address hidden>
Date: Wed Jun 25 17:45:24 2014 -0700

    Do not log 14+ INFO lines on a broken pipe error (eventlet)

    Under eventlet if the client disconnects while Keystone is trying
    to transmit data, approximately 14 lines of traceback are logged.

    This could result in massive logs if done repeatedly; worst case
    scenario could include a denial of service due to disk space being
    exhausted.

    Change-Id: Iaf14c64799daa7539d1bd85cb6c6457380c111d9
    Closes-Bug: #1334466

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/102912
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=2baae7855bea0e151931c15b161a4b0742650c14
Submitter: Jenkins
Branch: stable/icehouse

commit 2baae7855bea0e151931c15b161a4b0742650c14
Author: Morgan Fainberg <email address hidden>
Date: Wed Jun 25 17:45:24 2014 -0700

    Do not log 14+ INFO lines on a broken pipe error (eventlet)

    Under eventlet if the client disconnects while Keystone is trying
    to transmit data, approximately 14 lines of traceback are logged.

    This could result in massive logs if done repeatedly; worst case
    scenario could include a denial of service due to disk space being
    exhausted.

    Change-Id: Iaf14c64799daa7539d1bd85cb6c6457380c111d9
    Closes-Bug: #1334466

[OpenStack Infra (hudson-openstack)]

Change abandoned by Ryan Hsu (<email address hidden>) on branch: master
Review: https://review.openstack.org/121711
Reason: Testing