Issue with some responses

Question

Issue with some responses

Opened this issue 4 years ago · 6 comments

Hi, I found the following issue in my log. Any idea how this can be solved? After googling I think it has to do with my program returning some utf-8 chars?

** (ArgumentError) argument error
(stdlib 3.12) :io.put_chars(:standard_error, :unicode, <<104, 97, 102, 116, 46, 32, 78, 111, 99, 104, 32, 98, 101, 115, 115, 101, 114, 44, 32, 108, 105, 101, 98, 101, 32, 66, 108, 111, 99, 107, 112, 97, 114, 116, 101, 105, 101, 110, 44, 32, 104, 195, 164, 116, 116, 101, 110, 32, 83, 105, ...>>)
(rambo 0.3.2) lib/rambo.ex:255: Rambo.receive_result/3
(rambo 0.3.2) lib/rambo.ex:176: Rambo.run/3

Answer 1 · 2020-12-01T13:37:24.000Z

I was able to prevent this crash by setting log: false. Seems that IO.write does not work well with utf8 chars.

Answer 2 · 2020-12-03T14:07:03.000Z

Can you paste a UTF-8 binary that doesn’t work for me to try out? I do use Rambo to print fancy characters daily without issues.

Answer 3 · 2020-12-11T08:06:40.000Z

Hi, I just tried to run the command with the same input again and couldn't reproduce it on MacOS. It happened in the production environment where we are running it as an Elixir Release (Version 1.10) and Alpine Linux. I'll try to reproduce it in that environment.

Answer 4 · 2021-02-16T14:32:38.000Z

I think I'm experiencing the same thing, the command I'm running prints some borders among other characters...

While this hasn't been an issue using log: true|false, even giving it a function works... That is until something else logs inbetween that commands lines...

Given this example I lifted out of some tests I was messing with:

iex(3)> a = <<128, 226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128,
...(3)>       226, 148, 128, 226, 149, 175, 10>>
iex(4)> String.graphemes(a)
[<<128>>, "─", "─", "─", "─", "─", "╯", "\n"]
iex(5)> IO.inspect(<<226, 148, 128>>)
"─"

For the context of the command I'm running, I know that specific log line is too short...
So my hunch is that if you try and print out a log line that has these kinds of UTF-8 characters (without some kind of buffer) they can't be displayed...

I've also managed to at least kinda prove this theory by jamming some IO.inspects in the receive_result/3 function:

      {^port, {:data, @stdout <> stdout}} ->
        IO.inspect(stdout, label: "stdout")      <---
        maybe_log(:stdout, stdout, log)
        result = Map.update(result, :out, [], &[&1 | stdout])
        receive_result(port, result, log)

stdout: "mon/package.json\n"
stdout: <<226, 149, 173, 226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128,
  226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128,
  226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128, 226, 148, 128,
  226, 148, 128, 226, 148, ...>>

So you can see above, in the lines that are 'complete' or convertable in one go print just fine - but the lines with characters that require more than one item in the binary. (But if you don't jam a label or some other output inbetween - everything looks fine)

Long story short - I don't think this is actually a bug, as much as it is a painful reality of UTF-8 and buffers...

Answer 5 · 2021-02-23T16:45:47.000Z

Thanks for the detailed investigations! Here’s how I reproduced it.

iex> Rambo.run("echo", [String.duplicate(".", 64) <> "💣"], log: :stdout)
................................................................💣
iex> Rambo.run("echo", [String.duplicate(".", 63) <> "💣"], log: :stdout)
** (ArgumentError) argument error
    (stdlib 3.13.2) :io.put_chars(:standard_io, :unicode, <<46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, 46, ...>>)
    (rambo 0.3.3) lib/rambo.ex:250: Rambo.receive_result/3
    (rambo 0.3.3) lib/rambo.ex:176: Rambo.run/3

So Rambo streams exactly what your program outputs, it’s not UTF-8 aware or anything. On my machine, echo chunks every 64 bytes but it can likely be your system pipe buffer size too. If a chunk happens to split a multi-byte UTF-8 character, then IO.write fails.

In our app using Rambo, I do send logs off to a GenServer that buffers before display and we never had issues. Rambo’s default :log implementations are definitely too naive but shipping GenServers would be too heavy.

However IO.write and therefore :io.put_chars requires UTF-8 input. I need to find a workaround.

Answer 6 · 2021-02-24T09:04:28.000Z

@jayjun thats awesome! Thanks for confirming!

I mean - the naive log implementation makes sense to me in this case. And like beefing it up is imo is out of scope for Rambo no (or at least the current log: fn... interface)?
Or maybe something that does the chunking around maybe_log, but then again - we're back at a tangled mess at calling log: fn... later when the binary is a valid string...

Using a GenServer call is exactly what I'm doing as well.
However I suspect my server at least in it's uncommitted form is insufficient to deal with this..

What would your advice for buffering these log line messages to in an attempt to make them readable?
I can't think of anything other than a hacky solution testing for validity in a reducer...