I'm using the libchan
library by docker. Their example goes like this:
// client.go
package main
import (
"log"
"io"
"net"
"os"
"github.com/docker/libchan"
"github.com/docker/libchan/spdy"
)
type RemoteCommand struct {
Cmd string
Args []string
Stdin io.Writer
Stdout io.Reader
Stderr io.Reader
StatusChan libchan.Sender
}
type CommandResponse struct {
Status int
}
func main() {
var client net.Conn
client, err := net.Dial("tcp", "127.0.0.1:9323")
if err != nil {
log.Fatal(err)
}
p, err := spdy.NewSpdyStreamProvider(client, false)
transport := spdy.NewTransport(p)
sender, err := transport.NewSendChannel()
if err != nil {
log.Fatal(err)
}
receiver, remoteSender := libchan.Pipe()
command := &RemoteCommand{
Cmd: os.Args[1],
Args: os.Args[2:],
Stdin: os.Stdin,
Stdout: os.Stdout,
Stderr: os.Stderr,
StatusChan: remoteSender,
}
err = sender.Send(command)
if err != nil {
log.Fatal(err)
}
response := &CommandResponse{}
err = receiver.Receive(response)
if err != nil {
log.Fatal(err)
}
os.Exit(response.Status)
}
And this is the server:
// server.go
package main
import (
"log"
"net"
"io"
"os/exec"
"syscall"
"github.com/docker/libchan"
"github.com/docker/libchan/spdy"
)
type RemoteReceivedCommand struct {
Cmd string
Args []string
Stdin io.Reader
Stdout io.WriteCloser
Stderr io.WriteCloser
StatusChan libchan.Sender
}
type CommandResponse struct {
Status int
}
func main() {
var listener net.Listener
var err error
listener, err = net.Listen("tcp", "localhost:9323")
if err != nil {
log.Fatal(err)
}
for {
c, err := listener.Accept()
if err != nil {
log.Print("listener accept error")
log.Print(err)
break
}
p, err := spdy.NewSpdyStreamProvider(c, true)
if err != nil {
log.Print("spdy stream error")
log.Print(err)
break
}
t := spdy.NewTransport(p)
go func() {
for {
receiver, err := t.WaitReceiveChannel()
if err != nil {
log.Print("receiver error")
log.Print(err)
break
}
log.Print("about to spawn receive proc")
go func() {
for {
command := &RemoteReceivedCommand{}
err := receiver.Receive(command)
log.Print("received command")
log.Print(command)
if err != nil {
log.Print("command error")
log.Print(err)
break
}
cmd := exec.Command(command.Cmd, command.Args...)
cmd.Stdout = command.Stdout
cmd.Stderr = command.Stderr
stdin, err := cmd.StdinPipe()
if err != nil {
log.Print("stdin error")
log.Print(err)
break
}
go func() {
io.Copy(stdin, command.Stdin)
stdin.Close()
}()
log.Print("about to run the command")
res := cmd.Run()
command.Stdout.Close()
command.Stderr.Close()
returnResult := &CommandResponse{}
if res != nil {
if exiterr, ok := res.(*exec.ExitError); ok {
returnResult.Status = exiterr.Sys().(syscall.WaitStatus).ExitStatus()
} else {
log.Print("res")
log.Print(res)
returnResult.Status = 10
}
}
err = command.StatusChan.Send(returnResult)
if err != nil {
log.Print(err)
}
}
}()
}
}()
}
}
When I run the server and send a message with the client:
$ ./client /bin/echo "hello"
I see this output in the server logs:
2018/06/18 23:13:56 about to spawn receive proc
2018/06/18 23:13:56 received command
2018/06/18 23:13:56 &{/bin/echo [hello] 0xc4201201b0 0xc42023c030 0xc42023c090 0xc420186080}
2018/06/18 23:13:56 about to run the command
2018/06/18 23:13:56 received command
2018/06/18 23:13:56 &{ [] <nil> <nil> <nil> <nil>}
2018/06/18 23:13:56 command error
2018/06/18 23:13:56 EOF
My server receives the message with the echo
command and executes it successfully. However, it also receives an empty command and then throws an EOF:
2018/06/18 23:13:56 &{ [] <nil> <nil> <nil> <nil>}
2018/06/18 23:13:56 command error
2018/06/18 23:13:56 EOF
Why is the command an empty string?
My suspicion is that the client exits and then sends an exit
signal. But if that was the case, why would the command be blank? Please help me understand what's going on.
It seems it is an attempted try to decode FIN ACK TCP packet coming from the client on exiting. The TCP connection is being closed, and at the server side we try to read this. We get EOF error because there is no more input to read. It seems to be a behaviour as specified in documentation:
EOF is the error returned by Read when no more input is available. Functions should return EOF only to signal a graceful end of input. If the EOF occurs unexpectedly in a structured data stream, the appropriate error is either ErrUnexpectedEOF or some other error giving more detail.
Under the hood, libchan spdy uses msgpack encoder and decoder (source code) that, in order to read this TCP packet will call bufio ReadByte() function (source code), that returns error when no more data is there to be read (and that's the case when TCP connection was closed).
// ReadByte reads and returns a single byte.
// If no byte is available, returns an error.
func (b *Reader) ReadByte() (byte, error) {
...
You can see the TCP packet exchange running sudo tcpdump -i lo dst port 9323
. The FIN ACK TCP packet that is causing this EOF error:
18:28:23.782337 IP localhost.47574 > localhost.9323: Flags [F.], seq 272, ack 166, win 342, options [nop,nop,TS val 73397258 ecr 73397258], length 0
I think that this behaviour is normal and EOF error should be handled in the code. The command is blank, because client is not sending any specific command, just the stream is being closed.
Also - from the io.Reader documentation:
When Read encounters an error or end-of-file condition after successfully reading n > 0 bytes, it returns the number of bytes read. It may return the (non-nil) error from the same call or return the error (and n == 0) from a subsequent call. An instance of this general case is that a Reader returning a non-zero number of bytes at the end of the input stream may return either err == EOF or err == nil. The next Read should return 0, EOF.
Callers should always process the n > 0 bytes returned before considering the error err. Doing so correctly handles I/O errors that happen after reading some bytes and also both of the allowed EOF behaviors.
[EDIT] To answer more specifically what's happening behind the scenes with libchan:
If you look in the code, you'll see that spdy.NewSpdyStreamProvider(c, true)
creates new spdystream connection and then runs Serve on that connection in a separate goroutine. Serve function of spdstream tries to read received FIN ACK packet and receives EOF (as specified in go documentation cited above). Then, it exits the main Loop of the function and closes channels. Then, we get our EOF error on Receive here.
In order to see in more detail what's happening, you can set env variable DEBUG=true
$ export DEBUG=true
$ ./server
The output:
127.0.0.1:57652
2018/06/22 12:24:12 (0xc4200a42c0) Add stream frame: 1
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c000) Stream added, broadcasting: 1
2018/06/22 12:24:12 (0xc4200a42c0) Add stream frame: 3
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c0a0) Stream added, broadcasting: 3
2018/06/22 12:24:12 (0xc4200a42c0) Add stream frame: 5
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c140) Stream added, broadcasting: 5
2018/06/22 12:24:12 (0xc4200a42c0) Add stream frame: 7
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c1e0) Stream added, broadcasting: 7
2018/06/22 12:24:12 about to spawn receive proc
2018/06/22 12:24:12 trying to receive
2018/06/22 12:24:12 (0xc4200a42c0) Add stream frame: 9
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c280) Stream added, broadcasting: 9
2018/06/22 12:24:12 (0xc4200a42c0) Data frame received for 1
2018/06/22 12:24:12 (0xc42016c000) (1) Data frame handling
2018/06/22 12:24:12 (0xc42016c000) (1) Data frame sent
2018/06/22 12:24:12 received command
2018/06/22 12:24:12 &{/bin/echo [hello] 0xc420156570 0xc4201565a0 0xc420156120 0xc42013c4a0}
2018/06/22 12:24:12 about to run the command
2018/06/22 12:24:12 (0xc42016c140) (5) Writing data frame
2018/06/22 12:24:12 (0xc42016c140) (5) Writing data frame
2018/06/22 12:24:12 (0xc42016c1e0) (7) Writing data frame
2018/06/22 12:24:12 (0xc42016c280) (9) Writing data frame
2018/06/22 12:24:12 trying to receive
2018/06/22 12:24:12 (0xc4200a42c0) EOF received
2018/06/22 12:24:12 (0xc4200a42c0) (0xc42016c000) Stream removed, broadcasting: 1
2018/06/22 12:24:12 (0xc42016c000) (1) Writing data frame
2018/06/22 12:24:12 received command
2018/06/22 12:24:12 &{ [] <nil> <nil> <nil> <nil>}
2018/06/22 12:24:12 command error
2018/06/22 12:24:12 EOF