Eventlistener protocol "len" header changed in Supervisor 4

[mnaberez]

@plockaby wrote comments of issue #1235:

Migrating from version 3 to version 4, my event listeners read from supervisor over stdin using a byte stream and then did the conversion to utf8 and chose to "backslashreplace" undecodable utf8 data. When I went to version 4 I expected to continue to get a byte stream that I could convert myself to whatever encoding I knew the data to be in. It was really unexpected to discover that supervisor was doing the conversion for me and then telling me the number of characters to read off of stdin and not the number of bytes.

cc: @vsajip

[mnaberez]

Description eventlistener header tokens:

len | An integer indicating the number of bytes in the event payload, aka the PAYLOAD_LENGTH

From above, it sounds like the meaning of the len header unintentionally changed from bytes to characters. This is something we should probably investigate. There are a lot of existing eventlisteners.

[plockaby]

Thanks for making this. I put my issue over there because it looked related to doing byte->string conversion in an unexpected place to me but you're right, I think, that the recipient of the converted data is different.

[vsajip]

According to the docs,

In the below list, we indicate that some event types have a “body” which is a a token set. A token set consists of a set of charaters with space-separated tokens. Each token represents a key-value pair. The key and value are separated by a colon.

It's not clear to me why you would be seeing arbitrary (not utf-8 decodable) binary data in the event listener. Which event types are being listening for where the problem is seen?

[plockaby]

Also according to the docs:

len | An integer indicating the number of bytes in the event payload, aka the PAYLOAD_LENGTH

And:

Directly following the linefeed character in the header is the event payload. It consists of PAYLOAD_LENGTH bytes representing a serialization of the event data. See Event Types for the specific event data serialization definitions.

And:

Once it has processed the header, the event listener implementation should read PAYLOAD_LENGTH bytes from its stdin, perform an arbitrary action based on the values in the header and the data parsed out of the serialization.

When Supervisor3 was running under Python2 the payload length did indeed represent the number of bytes to read. In Supervisor4 the payload length now represents characters. My event listener was listening for bytes under Supervisor3 and when I upgraded to Supervisor4 my event listener stopped working because the stream now came as characters and not bytes.

[plockaby]

Sorry I misspoke in the last sentence. The stream might have always come as characters and not bytes (not sure tbh) but in Supervisor3 under Python2 that didn't matter because Python didn't really distinguish between bytes and characters very effectively and the payload length represented bytes to read. In Supervisor4 under Python3 the payload length definitely changed to represent characters. So the docs are wrong in the sense that it says bytes when it is actually characters.

I'd actually argue that it'd be better if the supervisor event listener protocol changes to NOT do utf8 conversions and just gives event listeners raw data so that I can decide what the encoding is in my event listener rather than get messages that literally say "indecipherable".

[plockaby]

And since you asked but I have yet to answer this is happening on log events. Sorry I didn't say that sooner and for replying to this thread so many times.

[vsajip]

Well, the bytes vs. chars thing in the documentation could be addressed just by changing the documentation to say "characters" rather than "bytes". I'm not sure it was really intended to mean bytes, specifically, since in Python 2.x the distinction was somewhat loose. Note that most of the output of events (input to event listeners) is actually logically text rather than binary.

For programs interacting with Supervisor, it would seem that their stdout and stderr should logically be text streams - are you saying they are not? TBF, the output in the "indecipherable" case is Undecodable: followed by the binary data in repr format, which certainly allows it to be recovered.

I'll leave it to Mike to decide how this should be handled, from a policy point of view. I'm not sure what's best at this point, but I would want to see how many people are running into problems with arbitrary binary data in log streams (to understand the use cases better) before deciding what the best fix is.

[plockaby]

If the documentation is changed you should also change the upgrade guide for 3->4 to indicate a breaking change. As I'm sure you know, sys.stdin and sys.stdout in Python3 are byte streams and not text streams. I had to change my code from this:

stdin = sys.stdin.buffer

to this:

stdin = io.TextIOWrapper(sys.stdin.buffer, encoding="utf-8", newline='\n')

in order to make .read(PAYLOAD_LENGTH) return the correct data since without that change .read would read bytes and not characters and when my log lines contained UTF-8 data the number of bytes did not match the number of characters.

I guess what I'm saying is that this policy is backwards incompatible and should either change to be backwards compatible or the docs should be updated to say "hey we made this breaking change in the migration from 3 to 4." But what I'd strongly prefer is that the documentation and functionality from version 3 stay the same. I say that because (1) it's what the docs say, (2) it's probably how a lotof event listeners were implemented, and (3) it's a better interface to let the receiver of the event listener decide what encoding their log lines are in rather than deciding for them.

I appreciate you taking the time to understand the issue that I'm facing.

[vsajip]

As I'm sure you know, sys.stdin and sys.stdout in Python3 are byte streams and not text streams.

Which version of Python 3 are you running?

$ python3
Python 3.7.3+ (heads/3.7:0ff08b061b, May 11 2019, 09:27:05) 
[GCC 7.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.stdin
<_io.TextIOWrapper name='<stdin>' mode='r' encoding='UTF-8'>
>>> sys.stdout
<_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
>>> sys.stderr
<_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>

$ python3.6
Python 3.6.7 (default, Oct 22 2018, 11:32:17) 
[GCC 8.2.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.stdin
<_io.TextIOWrapper name='<stdin>' mode='r' encoding='UTF-8'>
>>> sys.stdout
<_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
>>> sys.stderr
<_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>

$ python3.5
Python 3.5.7+ (heads/3.5:2bb327816d, May 11 2019, 08:47:36) 
[GCC 7.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.stdin
<_io.TextIOWrapper name='<stdin>' mode='r' encoding='UTF-8'>
>>> sys.stdout
<_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
>>> sys.stderr
<_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>

$ python3.4
Python 3.4.10 (default, May 11 2019, 08:42:05) 
[GCC 7.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import sys
>>> sys.stdin
<_io.TextIOWrapper name='<stdin>' mode='r' encoding='UTF-8'>
>>> sys.stdout
<_io.TextIOWrapper name='<stdout>' mode='w' encoding='UTF-8'>
>>> sys.stderr
<_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>

[plockaby]

Ah, you're right, sys.stdin is a character stream. But in my example I use sys.stdin.buffer which is a byte stream of type io.BufferedReader. The reason I use the byte stream wrapped in the character stream is because, by default, TextIOWrapper implements universal newlines which means that when my log lines have "\r\n" in them (which happens) the "\r\n" gets turned into "\n" and then my calls to .read(PAYLOAD_SIZE) wait for an extra character that will never come.

[vsajip]

means that when my log lines have "\r\n" in them (which happens)

How come, if you're not on Windows? This is a different problem to what you described earlier (which related to arbitrary encodings, not utf-8).