0

I am trying to understand the behavior of bufio ReadBytes when it receives large packets. I am running a simple Golang TCP server on eth0 of a unix machine with MTU=9001. The client is a separate machine (not directly connected to the server) is running a python client program on eth0 with MTU=1500. My client python program is trying to send some large sized packets, which gets fragmented in the client machine as expected, and is sent out in IP packets with max TCP MSS=1440. Uptil this, all is good. The packets arrive on the server machine, and I would expect the server machine to reassemble the packet at OSI Layer4. So, to my understanding, my Golang socket buffer should get 1 large size packet (already reassembled). My Golang server program using bufio.ReadBytes('\x04') to read till EOT character in the message. My client program explicitly adds an EOT character to the end of each packet's payload.

In the server, I see packets being received with inconsistent sizes. Per the official documentation of ReadBytes(), it should read all data in the input buffer until the 'delim' character is read in. I am not able to understand the max. buffer capacity in the bufio package used for reader objects, and would appreciate any help from anyone.

My client program snippet:

while True:
    l = random.randint(1400, 10000)
    data=("t"*l + '\x04').encode()
    try:
        if sock.send(data)==0:
            print("Server closed connection")
        else:
            print("Data send done. Intended length=", l, " bytes")
    except:
       print ("Exception when sending data. Trace=" + traceback.format_exc())
    time.sleep(10)
    sock.close()

Server program snippet:

reader := bufio.NewReader(conn)
readbuf := make([]byte, 1500)
err := io.EOF
for sockConnected {
    conn.SetReadDeadline(time.Now().Add(10 * time.Millisecond))
    readbuf, err = reader.ReadBytes('\x04')
    switch {
    case err == io.EOF || err == io.ErrUnexpectedEOF:
        log.Println("Socket closed. EOF / ErrUnexpectedEOF read in")
        sockConnected = false
    case err == nil:
        //log.Println("No error on read")
    case strings.HasSuffix(err.Error(), "i/o timeout"):
        //log.Println("Timed out read")
    default:
        log.Println("Some other error occurred.Reason=" + err.Error())
    }
    if len(readbuf) == 0 {
        continue
    } else {
        //log.Printf("Received from client=%v", string(readbuf))
        log.Printf("Recvd Bytes count=%v", len(readbuf))
    }
}

One sample packet sent from the client to the server:

  1. from the client :

    Data send done. Intended length= 8267 bytes

    => 8268 bytes including trailing EOT char.

  2. on the server :

    2017/11/08 21:55:42.551604 Recvd Bytes count=1440

    2017/11/08 21:55:42.561897 Recvd Bytes count=4096

    2017/11/08 21:55:42.569405 Recvd Bytes count=2732

    => 3 different ReadBytes() got triggered to consume 8268 bytes.

    => the first and second calls returned different sizes of data. I was hoping them to be the same, if there was 1 single constant buffer being used as the input buffer for bufio.

Any help here please ?

mkopriva
  • 35,176
  • 4
  • 57
  • 71
AnirbanMukherjee
  • 379
  • 1
  • 5
  • 14
  • 2
    This is TCP? With TCP, from a user-space application perspective, **there are no packets**. The network stack can and will deliver TCP data to your application in **any** number of bytes, regardless of how you **think** the packets are arranged. – Zan Lynx Nov 08 '17 at 23:49
  • 2
    Also, if you do a lot of network programming you should get used to using Wireshark or Ethereal or other network analyzers. For example in this case I bet you're hitting your 10 ms timeout because of TCP slow start, MSS discovery, etc. Like here: https://en.wikipedia.org/wiki/Path_MTU_Discovery – Zan Lynx Nov 09 '17 at 00:00

1 Answers1

1

The amount of data read by the ReadBytes method is not limited by the size of the bufio.Reader's read buffer.

The problem is not with buffering, but with i/o timeouts. The ReadBytes function reads until the delimiter is found or read on the underlying io.Reader returns an error. In the example given in the question, ReadBytes returned twice with i/o timeout errors before reading the entire message:

ReadBytes 
  read 1440 bytes
  timeout on read to underlying io.Reader, return error
ReadBytes
  read 4096 bytes
  timeout on read to underlying i.Reader, return error
ReadBytes
  read 2732 bytes to EOT
  return success

Fix the problem by increasing or eliminating the read deadline. For example:

conn.SetReadDeadline(time.Now().Add(time.Second))

Here's a simpler version of the server application that works as expected. The read deadline is removed in this example.

func main() {
    ln, err := net.Listen("tcp", ":8080")
    if err != nil {
        log.Fatal(err)
    }
    conn, err := ln.Accept()
    if err != nil {
        log.Fatal(err)
    }
    reader := bufio.NewReader(conn)
    for {
        buf, err := reader.ReadBytes('\x04')
        if err != nil {
            log.Fatal(err)
        }
        log.Printf("Received %d bytes\n", len(buf))
    }
}
Charlie Tumahai
  • 113,709
  • 12
  • 249
  • 242
  • Hi, thanks for the answer. I am trying to make a non-blocking i/o server. So I need to timeout the read as soon as possible. @zan lynx mentioned aptly that the reason for 10msec timeout could be tcp slow start. Mss discovery may be not because the packet I am checking is part of an existing tcp session. So mss discovery should not happen again for this packet. Do you have an alternate suggestion so that I could still have a non blocking read () ? – AnirbanMukherjee Nov 09 '17 at 08:28
  • There is no inherently non-blocking IO in Go, but you can do asynchronous IO in order to not block other parts of the program. See [this answer](https://stackoverflow.com/a/36117724/7426) for a good explanation. – Adrian Nov 09 '17 at 14:52
  • @AnirbanMukherjee Use goroutines to create servers that do not block on i/o of a single connection. This answers your question as stated. Perhaps ask a different question about the design of your server. – Charlie Tumahai Nov 09 '17 at 14:59