New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Python 3: wsgi doesn't handle correctly partial write of socket send() when using writelines() #295

Closed
vstinner opened this Issue Feb 3, 2016 · 37 comments

Comments

Projects
None yet
5 participants
@vstinner
Contributor

vstinner commented Feb 3, 2016

The wsgi module uses "wfile = conn.makefile('wb', self.wbufsize)" to get a file-like API and then call wfile.writelines(lines) to write data. If a socket send() is a partial write, writelines() doesn't retry and simply try to write the next line. In this case, the HTTP client is stuck and wait forever. See the following message for a script to reproduce the bug:
#274 (comment)

raylu wrote that it's a bug in CPython, but I don't think so. On Python 3, SocketIO.write() is clear on how it handles partial write:

    """Write the given bytes or bytearray object *b* to the socket
    and return the number of bytes written.  This can be less than
    len(b) if not all data could be written.  If the socket is
    non-blocking and no bytes could be written None is returned.
    """

Moreover, socket.makefile() doc of Python 3 says "The socket must be in blocking mode":
https://docs.python.org/dev/library/socket.html#socket.socket.makefile

eventlet monkey-patching should do something to use its own GreenPipe object. Hack to workaround this bug:

diff --git a/eventlet/greenio/base.py b/eventlet/greenio/base.py
index 5f0108c..204e6f0 100644
--- a/eventlet/greenio/base.py
+++ b/eventlet/greenio/base.py
@@ -289,8 +289,10 @@ class GreenSocket(object):
         return newsock

     if six.PY3:
-        def makefile(self, *args, **kwargs):
-            return _original_socket.makefile(self, *args, **kwargs)
+        def makefile(self, mode, *args, **kwargs):
+            from eventlet.greenio.py3 import GreenFileIO
+            fd = os.dup(self.fileno())
+            return GreenFileIO(fd, mode, *args, **kwargs)
     else:
         def makefile(self, *args, **kwargs):
             dupped = self.dup()

I don't think that this patch is correct because I'm not sure that it creates a buffered reader/writer, nor that it's the best design to duplicate the file descriptor of the socket.

On Python 2, makefile() creates a socket._filesocket object. This object calls sendall() and not send() in its flush() method. It works because sendall() is an eventlet method which handles partial write and retries to ensure that all bytes are written.

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 3, 2016

Contributor

I confirm that reverting the commit bc4d1b5 works around the issue. Try using following patch:

diff --git a/eventlet/greenio/base.py b/eventlet/greenio/base.py
index 5f0108c..7d8d7d8 100644
--- a/eventlet/greenio/base.py
+++ b/eventlet/greenio/base.py
@@ -355,29 +355,31 @@ class GreenSocket(object):
     def recvfrom_into(self, buffer, nbytes=0, flags=0):
         return self._recv_loop(self.fd.recvfrom_into, buffer, nbytes, flags)

-    def _send_loop(self, send_method, data, *args):
+    def send(self, data, flags=0):
+        fd = self.fd
         if self.act_non_blocking:
-            return send_method(data, *args)
+            return fd.send(data, flags)

+        # blocking socket behavior - sends all, blocks if the buffer is full
+        total_sent = 0
+        len_data = len(data)
         while 1:
             try:
-                return send_method(data, *args)
+                total_sent += fd.send(data[total_sent:], flags)
             except socket.error as e:
-                eno = get_errno(e)
-                if eno == errno.ENOTCONN or eno not in SOCKET_BLOCKING:
+                if get_errno(e) not in SOCKET_BLOCKING:
                     raise

+            if total_sent == len_data:
+                break
+
             try:
                 self._trampoline(self.fd, write=True, timeout=self.gettimeout(),
                                  timeout_exc=socket.timeout("timed out"))
             except IOClosed:
                 raise socket.error(errno.ECONNRESET, 'Connection closed by another thread')

-    def send(self, data, flags=0):
-        return self._send_loop(self.fd.send, data, flags)
-
-    def sendto(self, data, *args):
-        return self._send_loop(self.fd.sendto, data, *args)
+        return total_sent

     def sendall(self, data, flags=0):
         tail = self.send(data, flags)
@@ -385,6 +387,10 @@ class GreenSocket(object):
         while tail < len_data:
             tail += self.send(data[tail:], flags)

+    def sendto(self, *args):
+        self._trampoline(self.fd, write=True)
+        return self.fd.sendto(*args)
+
     def setblocking(self, flag):
         if flag:
             self.act_non_blocking = False

The old behaviour was to retry on partial write directly in send(), whereas the new behaviour gives up on partial write and let the caller to handler this case.

Sorry, it's still unclear to me what is the expected behaviour in eventlet with monkey-patching... But I have the feeling that eventlet was hiding bugs before. It's just that the bugs were more rare before?

Contributor

vstinner commented Feb 3, 2016

I confirm that reverting the commit bc4d1b5 works around the issue. Try using following patch:

diff --git a/eventlet/greenio/base.py b/eventlet/greenio/base.py
index 5f0108c..7d8d7d8 100644
--- a/eventlet/greenio/base.py
+++ b/eventlet/greenio/base.py
@@ -355,29 +355,31 @@ class GreenSocket(object):
     def recvfrom_into(self, buffer, nbytes=0, flags=0):
         return self._recv_loop(self.fd.recvfrom_into, buffer, nbytes, flags)

-    def _send_loop(self, send_method, data, *args):
+    def send(self, data, flags=0):
+        fd = self.fd
         if self.act_non_blocking:
-            return send_method(data, *args)
+            return fd.send(data, flags)

+        # blocking socket behavior - sends all, blocks if the buffer is full
+        total_sent = 0
+        len_data = len(data)
         while 1:
             try:
-                return send_method(data, *args)
+                total_sent += fd.send(data[total_sent:], flags)
             except socket.error as e:
-                eno = get_errno(e)
-                if eno == errno.ENOTCONN or eno not in SOCKET_BLOCKING:
+                if get_errno(e) not in SOCKET_BLOCKING:
                     raise

+            if total_sent == len_data:
+                break
+
             try:
                 self._trampoline(self.fd, write=True, timeout=self.gettimeout(),
                                  timeout_exc=socket.timeout("timed out"))
             except IOClosed:
                 raise socket.error(errno.ECONNRESET, 'Connection closed by another thread')

-    def send(self, data, flags=0):
-        return self._send_loop(self.fd.send, data, flags)
-
-    def sendto(self, data, *args):
-        return self._send_loop(self.fd.sendto, data, *args)
+        return total_sent

     def sendall(self, data, flags=0):
         tail = self.send(data, flags)
@@ -385,6 +387,10 @@ class GreenSocket(object):
         while tail < len_data:
             tail += self.send(data[tail:], flags)

+    def sendto(self, *args):
+        self._trampoline(self.fd, write=True)
+        return self.fd.sendto(*args)
+
     def setblocking(self, flag):
         if flag:
             self.act_non_blocking = False

The old behaviour was to retry on partial write directly in send(), whereas the new behaviour gives up on partial write and let the caller to handler this case.

Sorry, it's still unclear to me what is the expected behaviour in eventlet with monkey-patching... But I have the feeling that eventlet was hiding bugs before. It's just that the bugs were more rare before?

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 5, 2016

Contributor

See my comment here: #274 (comment)

Contributor

jstasiak commented Feb 5, 2016

See my comment here: #274 (comment)

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 5, 2016

Contributor

jstasiak: "See my comment here: #274 (comment)"

Since I consider that writlines() issue is not directly related to #274, I prefer to discuss it here. Copy of your comment:

@raylu @haypo I'll just leave this here for reference: https://mail.python.org/pipermail/python-dev/2012-August/121396.html

Considering the above I'm inclined to say the wsgi module only worked before because GreenSocket.send was broken too and was working like sendall internally therefore the fix is to stop using writelines().

Contributor

vstinner commented Feb 5, 2016

jstasiak: "See my comment here: #274 (comment)"

Since I consider that writlines() issue is not directly related to #274, I prefer to discuss it here. Copy of your comment:

@raylu @haypo I'll just leave this here for reference: https://mail.python.org/pipermail/python-dev/2012-August/121396.html

Considering the above I'm inclined to say the wsgi module only worked before because GreenSocket.send was broken too and was working like sendall internally therefore the fix is to stop using writelines().

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 5, 2016

Contributor

@raylu @haypo I'll just leave this here for reference: https://mail.python.org/pipermail/python-dev/2012-August/121396.html

Oh, nice catch. I reported a bug to Python to decide what to do for writelines() on the io module: http://bugs.python.org/issue26292

Considering the above I'm inclined to say the wsgi module only worked before because GreenSocket.send was broken too and was working like sendall internally therefore the fix is to stop using writelines().

I see 3 options:

  • (1) modify again eventlet send() to always work like sendall()
  • (2) modify eventlet writlines() to retry on partial write
  • (3) modify eventlet wsgi to use sendall()

Options (1) and (2) are exclusive, but (3) can be done anyway.

I don't know the rules of eventlet monkey-patching, but I guess that it should not change too much the Python semantics. On regular Python blocking socket, send() can use partial write, it's a common and known well issue of send(). That's why Python has sendall().

It's unclear to me if eventlet applications are relying or not on the fact that eventlet send() worked as sendall() on eventlet < 0.18. If they do, is it better to ask users to replace send() with sendall() in their code (like option 3 inside eventlet), or to restore the previous behaviour? (option 1)

Contributor

vstinner commented Feb 5, 2016

@raylu @haypo I'll just leave this here for reference: https://mail.python.org/pipermail/python-dev/2012-August/121396.html

Oh, nice catch. I reported a bug to Python to decide what to do for writelines() on the io module: http://bugs.python.org/issue26292

Considering the above I'm inclined to say the wsgi module only worked before because GreenSocket.send was broken too and was working like sendall internally therefore the fix is to stop using writelines().

I see 3 options:

  • (1) modify again eventlet send() to always work like sendall()
  • (2) modify eventlet writlines() to retry on partial write
  • (3) modify eventlet wsgi to use sendall()

Options (1) and (2) are exclusive, but (3) can be done anyway.

I don't know the rules of eventlet monkey-patching, but I guess that it should not change too much the Python semantics. On regular Python blocking socket, send() can use partial write, it's a common and known well issue of send(). That's why Python has sendall().

It's unclear to me if eventlet applications are relying or not on the fact that eventlet send() worked as sendall() on eventlet < 0.18. If they do, is it better to ask users to replace send() with sendall() in their code (like option 3 inside eventlet), or to restore the previous behaviour? (option 1)

@raylu

This comment has been minimized.

Show comment
Hide comment
@raylu

raylu Feb 6, 2016

Contributor

IMO, the writelines behavior is wrong/unexpected anyway, regardless of whether it's correct per the documentation. Fixing that has no real downsides and happens to solve our problem.

Doing the opposite of option 1 is how we got here in the first place and I assume it was done to deal with some other issue. Option 3 is alright and it is odd that we use writelines in eventlet.wsgi, but even then I still say option 2 should happen regardless.

Contributor

raylu commented Feb 6, 2016

IMO, the writelines behavior is wrong/unexpected anyway, regardless of whether it's correct per the documentation. Fixing that has no real downsides and happens to solve our problem.

Doing the opposite of option 1 is how we got here in the first place and I assume it was done to deal with some other issue. Option 3 is alright and it is odd that we use writelines in eventlet.wsgi, but even then I still say option 2 should happen regardless.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 7, 2016

Member
  • We're not restoring send-like-sendall unless critical mass of external applications depend on it.
  • wsgi writelines -> sendall high priority.
  • green writelines retry low priority.
Member

temoto commented Feb 7, 2016

  • We're not restoring send-like-sendall unless critical mass of external applications depend on it.
  • wsgi writelines -> sendall high priority.
  • green writelines retry low priority.

@temoto temoto added this to the v0.19 milestone Feb 7, 2016

@temoto temoto self-assigned this Feb 7, 2016

temoto added a commit that referenced this issue Feb 7, 2016

wsgi: writelines() doesn't handle partial writes
Instead, use `socket.sendall()` for any wsgi network writing operations.

#295

Upstream CPython bug:

http://bugs.python.org/issue26292

temoto added a commit that referenced this issue Feb 7, 2016

wsgi: writelines() doesn't handle partial writes
Instead, use `socket.sendall()` for any wsgi network writing operations.

#295

Upstream CPython bug:

http://bugs.python.org/issue26292
@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 8, 2016

Member

Either my fix is wrong, or wsgi or BaseHTTPServer is more dependant on file interface than I initially thought. Could use a fresh head for review here.

Member

temoto commented Feb 8, 2016

Either my fix is wrong, or wsgi or BaseHTTPServer is more dependant on file interface than I initially thought. Could use a fresh head for review here.

@fake-name

This comment has been minimized.

Show comment
Hide comment
@fake-name

fake-name Feb 8, 2016

I spent all morning tracking down a bug that wound up being caused by this issue (Flask-Assets served files above a certain size would never finish transfer).

Since this seems pretty broken, could you folks remove v0.18 from PyPi until it's sorted out? Rolling back to 0.17.4 fixes it.

I spent all morning tracking down a bug that wound up being caused by this issue (Flask-Assets served files above a certain size would never finish transfer).

Since this seems pretty broken, could you folks remove v0.18 from PyPi until it's sorted out? Rolling back to 0.17.4 fixes it.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 8, 2016

Member

Yes, 0.18.* are hidden on pypi now.

Member

temoto commented Feb 8, 2016

Yes, 0.18.* are hidden on pypi now.

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 8, 2016

Contributor
Contributor

vstinner commented Feb 8, 2016

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 9, 2016

Contributor

I agree with @haypo that it should be fixed instead of hiding the release(s), I'll have a fix ready shortly.

Contributor

jstasiak commented Feb 9, 2016

I agree with @haypo that it should be fixed instead of hiding the release(s), I'll have a fix ready shortly.

jstasiak added a commit that referenced this issue Feb 9, 2016

jstasiak added a commit that referenced this issue Feb 9, 2016

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 9, 2016

Contributor

@temoto I went for the minimal solution needed to make this work, see f011f78.

@raylu @fake-name Do you mind testing if that commit works for you?

Contributor

jstasiak commented Feb 9, 2016

@temoto I went for the minimal solution needed to make this work, see f011f78.

@raylu @fake-name Do you mind testing if that commit works for you?

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

@haypo

  • thanks for adding project maintenance perspective, I agree it's bad
  • even with removed releases, pip install -r req failure is far easier to debug than this

@jstasiak

  • no trampoline = CPU burn
  • your test does not create partial write condition, there's a test in c3da8eb that ensures partial write
  • there are more writelines() in wsgi
  • thanks for activity
Member

temoto commented Feb 9, 2016

@haypo

  • thanks for adding project maintenance perspective, I agree it's bad
  • even with removed releases, pip install -r req failure is far easier to debug than this

@jstasiak

  • no trampoline = CPU burn
  • your test does not create partial write condition, there's a test in c3da8eb that ensures partial write
  • there are more writelines() in wsgi
  • thanks for activity
@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 9, 2016

Contributor

Thanks for the feedback @temoto, no problem.

There should be no noticeably increased CPU usage (at least not compared to the solution using sendall() which would do the same thing basically), the partial write condition is actually created (I made sure the tests fail before I fixed it, see https://travis-ci.org/eventlet/eventlet/builds/107921835) and the remaining write() calls are covered by c31b3cb f473cad (writelines-fix branch).

Contributor

jstasiak commented Feb 9, 2016

Thanks for the feedback @temoto, no problem.

There should be no noticeably increased CPU usage (at least not compared to the solution using sendall() which would do the same thing basically), the partial write condition is actually created (I made sure the tests fail before I fixed it, see https://travis-ci.org/eventlet/eventlet/builds/107921835) and the remaining write() calls are covered by c31b3cb f473cad (writelines-fix branch).

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

There is trampoline somewhere down the path of fd.write?

Member

temoto commented Feb 9, 2016

There is trampoline somewhere down the path of fd.write?

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 9, 2016

Contributor

As far as I understand write() will proxy to socket's send() method which will trampoline if it can't send anything.

Updated my comment above, made a silly bug, the actual commit changing write() calls is f473cad.

Contributor

jstasiak commented Feb 9, 2016

As far as I understand write() will proxy to socket's send() method which will trampoline if it can't send anything.

Updated my comment above, made a silly bug, the actual commit changing write() calls is f473cad.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

I mean your test did not create partial write. There was no code that enforces partial write.
It may experience partial write in default environment, but when buffer size or something else is changed, then it won't catch bug anymore.

As far as I remember, socket.send lost it's sendall behavior and does not trampoline now.

Member

temoto commented Feb 9, 2016

I mean your test did not create partial write. There was no code that enforces partial write.
It may experience partial write in default environment, but when buffer size or something else is changed, then it won't catch bug anymore.

As far as I remember, socket.send lost it's sendall behavior and does not trampoline now.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

In other words, partial write may happen on each byte of each line, just writing big buffer is not a way to test for partial write.

Member

temoto commented Feb 9, 2016

In other words, partial write may happen on each byte of each line, just writing big buffer is not a way to test for partial write.

jstasiak added a commit that referenced this issue Feb 9, 2016

wsgi: Fix handling partial writes on Python 3
Closes #295 (in the wsgi
module we use a custom writelines implementation now).

Those write() calls might write only part of the data (and even if they
don't - it's more readable to make sure all data is written
explicitly).

I changed the test code so that the write() implementation returns the
number of characters logged and it cooperates nicely with writeall()
now.
@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 9, 2016

Contributor

While I think the patch is good enough I agree in principle, see commit b7380fd where I simulate the conditions described (a build with just the test added fails, https://travis-ci.org/eventlet/eventlet/builds/107984564, a build with test + patch works: https://travis-ci.org/eventlet/eventlet/builds/107987655).

Feel free to merge if it works for you.

Contributor

jstasiak commented Feb 9, 2016

While I think the patch is good enough I agree in principle, see commit b7380fd where I simulate the conditions described (a build with just the test added fails, https://travis-ci.org/eventlet/eventlet/builds/107984564, a build with test + patch works: https://travis-ci.org/eventlet/eventlet/builds/107987655).

Feel free to merge if it works for you.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

Yeah, your new test is awesome!

Few more comments:

  • all this must be commented as temporary solution, proper is either use sendall in wsgi or fix makefile().writelines() without touching wsgi module.
  • get rid of if six.PY2 (that's a mystical hope that PY2 means fd.write has sendall behavior). We must provide proper semantics, no matter if upstream implementation is valid or not.
  • from support import safe_writelines, writeall doesn't play with patching, bad practice. Only ever import modules.
  • if b: b = b[0:1] is identical to b = b[:1]

I'm waiting if you are willing to change something with these comments, if not, I merge and release b7380fd .

Member

temoto commented Feb 9, 2016

Yeah, your new test is awesome!

Few more comments:

  • all this must be commented as temporary solution, proper is either use sendall in wsgi or fix makefile().writelines() without touching wsgi module.
  • get rid of if six.PY2 (that's a mystical hope that PY2 means fd.write has sendall behavior). We must provide proper semantics, no matter if upstream implementation is valid or not.
  • from support import safe_writelines, writeall doesn't play with patching, bad practice. Only ever import modules.
  • if b: b = b[0:1] is identical to b = b[:1]

I'm waiting if you are willing to change something with these comments, if not, I merge and release b7380fd .

@temoto temoto assigned jstasiak and unassigned temoto Feb 9, 2016

@temoto temoto closed this in b7380fd Feb 9, 2016

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

Jakub's fix is merged into master and released on PyPi.
Previous releases 0.18 and 0.18.1 are deleted from PyPi.

Member

temoto commented Feb 9, 2016

Jakub's fix is merged into master and released on PyPi.
Previous releases 0.18 and 0.18.1 are deleted from PyPi.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 9, 2016

Member

Maybe proper fix is to just inherit GreenFileIO from BufferedIOBase. I will try it and encourage everyone to try it too.

Member

temoto commented Feb 9, 2016

Maybe proper fix is to just inherit GreenFileIO from BufferedIOBase. I will try it and encourage everyone to try it too.

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 10, 2016

Contributor

Hey, I don't have time to do it right now but feel free to apply those comments (different code for Python 2/Python 3 may need to stay in one form or the other though, at least the builtin write() method just returns None so the code would break).

Contributor

jstasiak commented Feb 10, 2016

Hey, I don't have time to do it right now but feel free to apply those comments (different code for Python 2/Python 3 may need to stay in one form or the other though, at least the builtin write() method just returns None so the code would break).

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 11, 2016

Member

Guys, I'm a fool. I'm sorry. It's so ridiculous in the end. :)

  • eventlet.wsgi tries to reuse stdlib code.
  • stdlib BaseHTTPServer.BaseHTTPRequestHandler inherits from StreamRequestHandler which defines rbufsize = -1 (buffered, default size), but wbufsize = 0 (unbuffered).
  • writelines() doesn't check what each lines' write() returned, but that's not a problem in case file object is buffered, next line is just added to buffer and buffer is flushed when required.
  • writelines() + unbuffered file is a problem.
  • So the solution is to make wsgi wfile buffered (and also flush it).

@haypo you may update related CPython bug http://bugs.python.org/issue26292 . RawIOBase.writelines may be wrong, but stdlib socket.makefile() file-object is very well buffered, in fact. It's implementation is beautiful.

Member

temoto commented Feb 11, 2016

Guys, I'm a fool. I'm sorry. It's so ridiculous in the end. :)

  • eventlet.wsgi tries to reuse stdlib code.
  • stdlib BaseHTTPServer.BaseHTTPRequestHandler inherits from StreamRequestHandler which defines rbufsize = -1 (buffered, default size), but wbufsize = 0 (unbuffered).
  • writelines() doesn't check what each lines' write() returned, but that's not a problem in case file object is buffered, next line is just added to buffer and buffer is flushed when required.
  • writelines() + unbuffered file is a problem.
  • So the solution is to make wsgi wfile buffered (and also flush it).

@haypo you may update related CPython bug http://bugs.python.org/issue26292 . RawIOBase.writelines may be wrong, but stdlib socket.makefile() file-object is very well buffered, in fact. It's implementation is beautiful.

temoto added a commit that referenced this issue Feb 12, 2016

wsgi: use buffered wfile
Fix the root cause of makefile().writelines() data loss.
#295

Also wsgi.log.write can break file-object API and not return number of bytes again.
#296

temoto added a commit that referenced this issue Feb 12, 2016

wsgi: use buffered wfile
Fix the root cause of makefile().writelines() data loss.
#295

Also wsgi.log.write can break file-object API and not return number of bytes again.
#296
@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@haypo @fake-name @jstasiak please, run master (f66ab29) with actual application to verify that buffered wsgi resolves the problem.

Member

temoto commented Feb 12, 2016

@haypo @fake-name @jstasiak please, run master (f66ab29) with actual application to verify that buffered wsgi resolves the problem.

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 12, 2016

Contributor
Contributor

vstinner commented Feb 12, 2016

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@haypo do you mean logger.write int+None issue or do you have a test that verifies for partial writes?

Member

temoto commented Feb 12, 2016

@haypo do you mean logger.write int+None issue or do you have a test that verifies for partial writes?

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 12, 2016

Contributor

@haypo do you mean logger.write int+None issue or do you have a test that verifies for partial writes?

I'm talking about the bug #296: write() method which returns None in Keystone. It now works again.

Contributor

vstinner commented Feb 12, 2016

@haypo do you mean logger.write int+None issue or do you have a test that verifies for partial writes?

I'm talking about the bug #296: write() method which returns None in Keystone. It now works again.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@haypo ah, that's good, but please run master with application that exposed partial write problem. It's now fixed without safe_writelines, by using buffered wfile in wsgi.

Member

temoto commented Feb 12, 2016

@haypo ah, that's good, but please run master with application that exposed partial write problem. It's now fixed without safe_writelines, by using buffered wfile in wsgi.

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 12, 2016

Contributor
Contributor

vstinner commented Feb 12, 2016

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 12, 2016

Contributor

@temoto I won't be able to test this right now, if the tests pass it should be fine. There's something not covered by the tests and f66ab29 introduces a regression in this regard - log.write() call may very well result in a partial write and not testing its return value means we can lose logs. I stand by my position that a write method returning None is an issue in the client code.

Contributor

jstasiak commented Feb 12, 2016

@temoto I won't be able to test this right now, if the tests pass it should be fine. There's something not covered by the tests and f66ab29 introduces a regression in this regard - log.write() call may very well result in a partial write and not testing its return value means we can lose logs. I stand by my position that a write method returning None is an issue in the client code.

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@jstasiak I also stand you are correct, log.write() returning None is an issue in the client code, but releasing that equals breaking a lot of poorly written custom loggers without a good reason. I mean log loss is not nearly as important as HTTP response loss.

So here's the plan on wsgi logger:

  • eventlet.net must contain description of problem, script to verify codebase for invalid loggers, solution
  • on wsgi.Server start, verify their logger returns None for 0 or 1 byte
  • notify developers via Python warnings and also via separate message in logs
  • notification must contain inline description how to fix the problem
  • wait 6 months
  • remove support for invalid loggers
Member

temoto commented Feb 12, 2016

@jstasiak I also stand you are correct, log.write() returning None is an issue in the client code, but releasing that equals breaking a lot of poorly written custom loggers without a good reason. I mean log loss is not nearly as important as HTTP response loss.

So here's the plan on wsgi logger:

  • eventlet.net must contain description of problem, script to verify codebase for invalid loggers, solution
  • on wsgi.Server start, verify their logger returns None for 0 or 1 byte
  • notify developers via Python warnings and also via separate message in logs
  • notification must contain inline description how to fix the problem
  • wait 6 months
  • remove support for invalid loggers
@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@jstasiak I think a good start is to test that their logger not isinstance(io.BufferedWriter).

Member

temoto commented Feb 12, 2016

@jstasiak I think a good start is to test that their logger not isinstance(io.BufferedWriter).

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@haypo excellent, thanks for testing. I'm a bit lost, if #274 and #295 are two symptoms of same issue? Previously I was talking about #295 the makefile('w').writelines() issue. Do you have an application that exposes partial writelines problem?

Member

temoto commented Feb 12, 2016

@haypo excellent, thanks for testing. I'm a bit lost, if #274 and #295 are two symptoms of same issue? Previously I was talking about #295 the makefile('w').writelines() issue. Do you have an application that exposes partial writelines problem?

@temoto

This comment has been minimized.

Show comment
Hide comment
@temoto

temoto Feb 12, 2016

Member

@raylu you seem to run applications affected by this issue, please test if they not show symptoms of partial writelines in master f66ab29 .

Member

temoto commented Feb 12, 2016

@raylu you seem to run applications affected by this issue, please test if they not show symptoms of partial writelines in master f66ab29 .

@jstasiak

This comment has been minimized.

Show comment
Hide comment
@jstasiak

jstasiak Feb 12, 2016

Contributor

@temoto I want to agree with you but I know there are some industries where complete and accurate logs are a legal requirement. In those losing logs can be more of an issue than losing parts of HTTP responses.

Contributor

jstasiak commented Feb 12, 2016

@temoto I want to agree with you but I know there are some industries where complete and accurate logs are a legal requirement. In those losing logs can be more of an issue than losing parts of HTTP responses.

@vstinner

This comment has been minimized.

Show comment
Hide comment
@vstinner

vstinner Feb 12, 2016

Contributor
Contributor

vstinner commented Feb 12, 2016

@temoto temoto removed this from the v0.19 milestone Feb 13, 2016

openstack-gerrit pushed a commit to openstack/deb-python-eventlet that referenced this issue Sep 2, 2016

wsgi: Fix handling partial writes on Python 3
Closes eventlet/eventlet#295 (in the wsgi
module we use a custom writelines implementation now).

Those write() calls might write only part of the data (and even if they
don't - it's more readable to make sure all data is written
explicitly).

I changed the test code so that the write() implementation returns the
number of characters logged and it cooperates nicely with writeall()
now.

openstack-gerrit pushed a commit to openstack/deb-python-eventlet that referenced this issue Sep 2, 2016

wsgi: use buffered wfile
Fix the root cause of makefile().writelines() data loss.
eventlet/eventlet#295

Also wsgi.log.write can break file-object API and not return number of bytes again.
eventlet/eventlet#296
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment