Wrong output when piping to less #2713
Comments
asterite
added
kind:bug
|
#triage Redirecting stderr to stdout produces the expected result: (also So is there some part of the output that is getting sent to stderr instead of stdout? |
|
I dug into this further, and using Using the I haven't been able to find the reasoning for 1024 being the buffer limit on OSX, other than some references being based on fcntl kernel default settings. I got lost in digging through how it all ties together... |
|
Another reference: http://www.pixelbeat.org/programming/stdio_buffering/ |
|
# add in IO::FileDescriptor def self.blocking(fd) fcntl(fd, LibC::F_GETFL) & LibC::O_NONBLOCK == 0 end
STDIN = IO::FileDescriptor.new(0, blocking: IO::FileDescriptor.blocking(0))
STDOUT = (IO::FileDescriptor.new(1, blocking: IO::FileDescriptor.blocking(1))).tap { |f| f.flush_on_newline = true }
STDERR = (IO::FileDescriptor.new(2, blocking: IO::FileDescriptor.blocking(2))).tap { |f| f.flush_on_newline = true }
## comment out following lines
#STDIN = IO::FileDescriptor.new(0, blocking: LibC.isatty(0) == 0)
#STDOUT = (IO::FileDescriptor.new(1, blocking: LibC.isatty(1) == 0)).tap { |f| f.flush_on_newline = true }
#STDERR = (IO::FileDescriptor.new(2, blocking: LibC.isatty(2) == 0)).tap { |f| f.flush_on_newline = true }
Ahh, now I see what is bugging you guys. |
|
The main issue is that we want to have non-blocking IO for stdin/stdout/stderr. For example this should work well: spawn do
loop do
puts 1
sleep 1
end
end
spawn do
loop do
while line = gets
puts line
end
end
end
sleepSo |
|
Some more links with others running into this problem: https://twistedmatrix.com/trac/ticket/3442
So setting O_NONBLOCK on stdin/stdout/stderr is wrong. |
|
It seems that all crystal programs still modify the behavior of STDIO. Even if I compile an empty crystal program (one which is nothing but comments), if I type in STDIN.blocking = trueas mentioned in #3674, then the problem does not happen. @asterite mentioned "So setting O_NONBLOCK on stdin/stdout/stderr is wrong". Does that mean that crystal sets blocking on all three of the standard descriptors? |
|
Yes. It shouldn't, otherwise accessible standard descriptors would block the event loop. We must rework |
|
A little add-on trivia: If you're trying to write a single source-file which works in both Ruby and crystal without any changes, and if this issue causes some grief for you, here's a slight change to the command. This should work-around the issue in crystal without causing any errors in ruby: STDIN.blocking = true if STDIN.class != IO(or at least it worked for me, using Crystal 0.21.1 and macOS) |
|
Some progress on this issue? Currently I'm using some hacks shown in above comments. |
|
@asterite Do you think we can fix this before next release ? 😅 Are some other issues blocking this in particular ? |
|
@faustinoaq To implement this we need to implement STDIN, STDOUT and STDERR as blocking, but when they block, fire a Thread and wait there. So that kinda involves parallelism. And I'm not in charge of that, so I don't think this will be fixed soon. |
|
Isn't it possible to reset blocking state of the fd when the program exits? |
|
Why not just make writing to stdout blocking? It's a simple fix, which has some other benefits. Such as using puts/p/pp doesn't change the execution of the program. If for some reason using blocking stdout is a major performance problem, they can get the current behaviour with 1 line of code. I don't see too many cases where it'd be a problem through. |
|
@RX14 What about this? spawn do
loop do
puts 1
sleep 1
end
end
spawn do
loop do
while line = gets
puts line
end
end
end
sleep |
|
What about if it was a busy loop instead of puts? What if stdout and stdin are extremely fast C applications which always empty/fill the buffer faster than we can fill/empty it? What if they're files and never block? Until we have preemptive scheduling we can't solve all these problems, so I suggest we don't try to. |
|
until we double fault, or just kill -9 will do it |
What do you have to handle a SIGKILL? :-) |
Not much, but if you SIGKILL your program, it's difficult to expect the programs interacting with it to not have problems ^^ And if you need to SIGKILL your program, I bet you have other problems more important than the blocking state of the outputs! |
|
lol I have to sigkill something or another almost every week, it's not rare in any sense. For example, if you get your crystal program stuck into a tight loop, SIGINT etc will never work since the signal handles are processed in the event loop which never gets reached since you're in a tight loop. |
|
Ok now we need a scheduler that handle priority or sth like that, to make sure the signal handler's fiber is checked once in a while.. 😛 |
|
The problem is not scheduling the problem is preemption. |
|
@martinos Ruby stdin is blocking. If you do gets, it will block the entire thread. I think printing to stdout and stderr is blocking too in Ruby. |
|
@asterite stdout is non-blocking by default, data is being buffered and flushed after a while. I have been bitten with that multiple times before. http://ruby-doc.org/core-2.3.1/IO.html#method-i-sync even when there was no system threading support. I don't know much about system programming, sorry if I say stuff that don't make sense. |
|
@martinos buffering is totally different to nonblocking, let me explain: Buffering is a solution to the problem of many little writes. Calling into the kernel to perform a Nonblocking IO is a different solution to a different problem. When you're doing network or file IO, the system can spend a lot of time waiting on hardware: for example waiting 10ms to fetch something from the database or 30ms to fetch something from disk. Wouldn't it be great if your computer could do something else while that was happening? Well, that's what threads are for. Threads are the OS's solution to this problem, you can spawn a bunch of threads and one thread can do work while another is waiting (blocks) on IO. However, it turns out that threads have some performance problems of their own on modern machines. Switching between threads involves a lot of housekeeping in the kernel, so there's an alternative that operates entirely in userland called green threads. They're similar to threads but have a lot less features but are a lot lot faster. So back to IO: when you make a You can set a flag on the file descriptor called This bug is caused by crystal setting the There are two clear solutions:
The former has better performance and changes current behaviour the least, but the second option is far more robust. This is because running some code when your application exits isn't always possible in every single scenario (i.e. Hope that helps! |
|
@RX14, that was a great explanation! I really appreciate. I would say that in when Ruby was 1.8 it only had green threads and I have never had issues when using |
|
Please take what I say with a grain of salt, I'm not really confident in these matters but I'm trying to analyze the situation and possible scenarios to proceed. Correct me if I'm wrong. Of these two solutions mentioned by @RX14, number 2 can only be implemented with parallelism and if done so, it will be slightly less performant. It would be the cleaner and standards compliant solution, but unfortunately, it can't be implemented until Crystal supports parallelism. Now, the first question is, what should be the final goal to solve this? Should standard streams be blocking or might it be worth to avoid the performance impact and stay with non-blocking IO even if we have parallelism? The second question is about the immediate solution. SIG_KILL is only meant as a last resort and since it stops the process immediately, one cannot expect that it terminates cleanly. This should usually not leave non-blocking standard streams, but this seems like a worthy trade-off at least as an intermediary solution. |
|
The problem is that when you run your program in the shell, the real file descriptors for stdin, stdout and stderr are sometimes shared (can't remember where in stack overflow I read this, I think there's a link somewhere in this github issue). So changing one to be blocking or non blocking will change the other one too. It's a little mess. In short, it seems it's never safe to modify the state of these things, so the only good solution is to have them be blocking (the default) and use threads. This is what Go does. |
|
Maybe this one: https://cr.yp.to/unix/nonblock.html (From your comment @asterite) |
simply incorrect. We would only need threads to simulate nonblocking IO on a blocking FD. Just don't do that just make it block like all |
|
Right, I had it in mind but forgot when writing it down explicitly: Number 2 can only be implemented with parallelism if it is to be non-blocking for the crystal program. |
|
I did the following test: added 280 lines to test on the top of this thread and some spacing to the lines to see any changes in output and it was working just fine. then I added code from Ary and executed them together. I stated to see weird behaviour. So data is not lost. Here is my short version of the code: string = <<-EOF 1000.times do |i| |
|
Interesting effect is with chains like this: ./test_bug | tee test_bug.log file content is good and as expected but screen output is crazy ./test_bug | cat shows little bit of output and then crashes with stack trace. I think it can help you understand what is going on. |
|
Yay! Looks like this issue is fixed on v0.25.0 🎉 |
|
Maybe I'm missing something,can you just select on stdin before reading from it to make that non-blocking and not have to change state, perhaps? |
|
@RX14 @ysbaddaden @straight-shoota @Timbus Is this issue fixed by #6518 ? |
|
I can test when I get home (can't build master at work), but in theory this should definitely be fixed. Will confirm in ~7hrs if needed. |
|
Yeah, I ran nearly every test case in this thread and it seems to be fixed in master. |
Extracted from Google Groups
A consistent way to reproduce it:
Then:
The issue seems to be related to using
fcntlwith stdin/stdout/stderr in a shell. I found this but I can't seem to understand what's going on in this case.The text was updated successfully, but these errors were encountered: