golang: net.Conn Read very slow?

Question

I am using net.Listen("tcp", addr) for a small server program which is to accept data and STORE it on the server. On the client side, I have a c++ program and I have simply written 4096000 BYTES to the socket (connected to my server program) The write on the client side finishes in less than a second. When using the Read() functions of the connection net.Conn, the read happens very slow.

Following is the Read() for loop :

  // Handle the reads
  var tbuf [81920]byte

  for {

    n, err := c.rwc.Read(tbuf[0:])

    // Was there an error in reading ?
    if err != nil {
        log.Printf("Could not read packet : %s", err.Error())
        break
    }

    log.Println(n)

}

return

c.rwc is of type net.Conn

The output of the above code is as follows :

2012/12/29 13:45:12 16384
2012/12/29 13:45:12 16018
2012/12/29 13:45:12 16384
2012/12/29 13:45:12 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:13 16016
2012/12/29 13:45:13 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:14 16384
2012/12/29 13:45:14 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:15 16016
2012/12/29 13:45:15 16384
2012/12/29 13:45:16 16016
2012/12/29 13:45:16 16384
2012/12/29 13:45:16 16016
2012/12/29 13:45:16 16384
2012/12/29 13:45:16 16016
2012/12/29 13:45:16 16384
2012/12/29 13:45:16 16016
2012/12/29 13:45:16 16384
2012/12/29 13:45:16 16016
2012/12/29 13:45:18 16384
2012/12/29 13:45:18 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:19 16016
2012/12/29 13:45:19 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:20 16384
2012/12/29 13:45:20 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:21 16016
2012/12/29 13:45:21 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:22 16384
2012/12/29 13:45:22 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:23 16384
2012/12/29 13:45:23 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:24 16016
2012/12/29 13:45:24 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:25 16016
2012/12/29 13:45:25 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:26 16384
2012/12/29 13:45:26 16016
2012/12/29 13:45:27 16384
2012/12/29 13:45:27 16016
2012/12/29 13:45:27 16384
2012/12/29 13:45:27 16016
2012/12/29 13:45:27 16384
2012/12/29 13:45:27 16016
2012/12/29 13:45:27 16384
2012/12/29 13:45:27 16016
2012/12/29 13:45:27 16384
2012/12/29 13:45:28 16016
2012/12/29 13:45:28 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:29 16016
2012/12/29 13:45:29 16384
2012/12/29 13:45:30 16016
2012/12/29 13:45:30 16384
2012/12/29 13:45:30 16016
2012/12/29 13:45:30 16384
2012/12/29 13:45:30 16016
2012/12/29 13:45:30 16384
2012/12/29 13:45:30 16016
2012/12/29 13:45:30 16384
2012/12/29 13:45:30 16016
2012/12/29 13:45:31 16384
2012/12/29 13:45:31 16016
2012/12/29 13:45:31 16384
2012/12/29 13:45:31 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:32 16016
2012/12/29 13:45:32 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:33 16016
2012/12/29 13:45:33 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:34 16016
2012/12/29 13:45:34 16384
2012/12/29 13:45:35 16016
2012/12/29 13:45:35 16384
2012/12/29 13:45:35 16016
2012/12/29 13:45:35 16384
2012/12/29 13:45:35 16016
2012/12/29 13:45:35 16384
2012/12/29 13:45:35 16016
2012/12/29 13:45:36 16384
2012/12/29 13:45:36 16016
2012/12/29 13:45:36 16384
2012/12/29 13:45:36 16016
2012/12/29 13:45:37 16384
2012/12/29 13:45:37 16016
2012/12/29 13:45:37 16384
2012/12/29 13:45:37 16016
2012/12/29 13:45:37 16384
2012/12/29 13:45:37 16016
2012/12/29 13:45:37 16384
2012/12/29 13:45:37 16016
2012/12/29 13:45:37 16384
2012/12/29 13:45:37 16016
2012/12/29 13:45:37 4048

As you can see the read operation is taking nearly 21-25 seconds to read 4096000 bytes, which is very slow as the server and the client are on the same computer. Is the read operation wrong ? I am unable to understand why is this so slow ?

Answer 1

I took your example and made it into a complete examples for client and server in go. Testing it on Linux it transfers the data in 20ms or thereabouts with no unexpected pauses.

Do you get the same results if you try it on your computer? If so then suspect the C++ part of your system. If get the same pauses as your original post then suspect your setup.

server code

package main

import (
    "io"
    "log"
    "net"
    "time"
)

func handle(c net.Conn) {
    // Handle the reads
    start := time.Now()
    tbuf := make([]byte, 81920)
    totalBytes := 0

    for {
        n, err := c.Read(tbuf)
        totalBytes += n
        // Was there an error in reading ?
        if err != nil {
            if err != io.EOF {
                log.Printf("Read error: %s", err)
            }
            break
        }
        log.Println(n)
    }
    log.Printf("%d bytes read in %s", totalBytes, time.Now().Sub(start))
    c.Close()
}

func main() {
    srv, err := net.Listen("tcp", ":2000")
    if err != nil {
        log.Fatal(err)
    }
    log.Println("Listening on localhost:2000")
    for {
        conn, err := srv.Accept()
        if err != nil {
            log.Fatal(err)
        }
        go handle(conn)
    }
}

client code

package main

import (
    "log"
    "net"
    "time"
)

func handle(c net.Conn) {
    start := time.Now()
    tbuf := make([]byte, 4096)
    totalBytes := 0
    for i := 0; i < 1000; i++ {
        n, err := c.Write(tbuf)
        totalBytes += n
        // Was there an error in writing?
        if err != nil {
            log.Printf("Write error: %s", err)
            break
        }
        log.Println(n)
    }
    log.Printf("%d bytes written in %s", totalBytes, time.Now().Sub(start))
    c.Close()
}

func main() {
    conn, err := net.Dial("tcp", ":2000")
    if err != nil {
        log.Fatal(err)
    }
    log.Println("Sending to localhost:2000")
    handle(conn)
}