I've run into an insidious issue.

The log package writes to the standard error. However, at least on linux, 
if stderr is redirected to a pipe and the other end of that pipe is not 
drained, then the kernel buffer associated with that pipe eventually gets 
full, and once that happens, subsequent write calls to stderr will block 
indefinitely. The problem is exacerbated by the fact that the log package 
uses a mutex to ensure that messages don't get mixed up on output - but 
because the of the blocked write call the mutex is never unlocked, so any 
subsequent call to any output function of the log package, from anywhere in 
the program, will block.

Demonstration: the following program, when ran in itself, prints several 
dummy strings to stderr then exits with a panic message.

//////////////////////
package main

import (
    "log"
    "time"
)

func spam(id int) {
    max := 10000
    for i := 0; i < max; i++ {
        log.Printf("%d\t%06d\t%10s", id, i, "")
    }
}

func main() {
    go spam(1)
    go spam(2)
    time.Sleep(1 * time.Second)
    panic("exiting")
}
//////////////////////////

However, when ran through the following script, which redirects the 
standard error of its child process but purposely doesn't read from it, the 
program hangs.

########################
#!/usr/bin/perl

use strict;
use warnings;
use IPC::Open3;
use Symbol 'gensym';

my($wtr, $rdr, $err);
$err = gensym;
my $pid = open3($wtr, $rdr, $err, @ARGV);

waitpid( $pid, 0 );
##########################

(Compile the above go program as `child`, save this script as runner.pl, 
then run it as `perl runner.pl ./child`.)
If you run it with strace, you can see that it can't even panic, because it 
blocks on one of the many write calls that produce the panic message.


The question of "but why would you do that" may arise - of course I would 
not *want* to do this. The issue came up in an environment where a go 
program somewhat more complex than the one above is run by supervisord, and 
I use supervisord's output redirection facility to forward the go program's 
stderr to a remote syslog sink. And, for some reason I don't yet 
understand, supervisord stopped reading the stderr pipe mid-run.
So I don't say that this is a bug in go, I'm not sure that you could even 
do anything about it, I just find the issue particularly annoying, because 
it's hard to detect and hard to work around.
Perhaps a note in the log package's documentation about possible dangers of 
redirecting stderr may be useful.

best regards,
Peter Juhasz

-- 
You received this message because you are subscribed to the Google Groups 
"golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to golang-nuts+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/golang-nuts/83a396b3-41c1-453d-b604-3640ba58bdb0%40googlegroups.com.

Reply via email to