FAQ
the socket read code :

         headerBuf := make([]byte, 4)
         t1 := time.Now().UnixNano()
         _, err := reader.Read(headerBuf)
         t2 := time.Now().UnixNano()
         if err != nil {
                 mylog.Warning("Warning: read header failed - %s",
err.Error())
                 return nil, myerror.New(err.Error(),
myerror.ERR_CLIENT_NET_READ)
         }
         mylog.Warning("%d", t2-t1)

from log, one read cost almost 50ms

--
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+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Search Discussions

  • Péter Szilágyi at May 13, 2014 at 3:53 pm
    Hi,

       Please provide some more details (Go is fast, 50ms is enormous and I'm
    almost sure there's something wrong there). A working source code would be
    nice. Additionally, are you sure it's milliseconds that you see, and not
    nanoseconds or microseconds?

    Cheers,
       Peter

    On Tue, May 13, 2014 at 3:06 PM, wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Chensi_04 at May 14, 2014 at 2:39 am
    it's milliseconds actually.
    A client continue to send request packet to the server, and the server
    using the above code to read.

    在 2014年5月13日星期二UTC+8下午11时53分15秒,Péter Szilágyi写道:
    Hi,

    Please provide some more details (Go is fast, 50ms is enormous and I'm
    almost sure there's something wrong there). A working source code would be
    nice. Additionally, are you sure it's milliseconds that you see, and not
    nanoseconds or microseconds?

    Cheers,
    Peter

    On Tue, May 13, 2014 at 3:06 PM, <chen...@126.com <javascript:>> wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms

    --
    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...@googlegroups.com <javascript:>.
    For more options, visit https://groups.google.com/d/optout.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Chensi_04 at May 14, 2014 at 3:14 am
    client server model
    first request packet recv is fast
    but the ack of the reponse(go server) arrives 40milliseconds after the
    response is send,
    SO the question is not recv request slow, is the client recv response slow.
    Using wireshark:
    4 0.042124 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query
    5 0.042134 10.XX.XX.XX 10.XX.XX.XX TCP 66 distinct > 53069 [ACK] Seq=1
    Ack=71 Win=14592 Len=0 TSval=4286666284 TSecr=3266982894
    6 0.210450 10.XX.XX.XX 10.XX.XX.XX MONGO 153 Response : Reply
    7 0.251994 10.XX.XX.XX 10.XX.XX.XX TCP 66 53069 > distinct [ACK] Seq=71
    Ack=88 Win=5888 Len=0 TSval=3266983104 TSecr=4286666452
    8 0.252058 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query

    the delay is between packet 6 and 7.
    So why the ACK of the go reply comes so slowly?

    在 2014年5月13日星期二UTC+8下午11时53分15秒,Péter Szilágyi写道:
    Hi,

    Please provide some more details (Go is fast, 50ms is enormous and I'm
    almost sure there's something wrong there). A working source code would be
    nice. Additionally, are you sure it's milliseconds that you see, and not
    nanoseconds or microseconds?

    Cheers,
    Peter

    On Tue, May 13, 2014 at 3:06 PM, <chen...@126.com <javascript:>> wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms

    --
    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...@googlegroups.com <javascript:>.
    For more options, visit https://groups.google.com/d/optout.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Gé Weijers at May 15, 2014 at 2:11 pm
    You can try to disable the "Nagle Algorithm" for your TCP connections, in
    both client and server. On Unix that's done using the TCP_NODELAY socket
    option.

    --


    On May 13, 2014, at 20:14, "chensi_04@126.com" wrote:

    client server model
    first request packet recv is fast
    but the ack of the reponse(go server) arrives 40milliseconds after the
    response is send,
    SO the question is not recv request slow, is the client recv response slow.
    Using wireshark:
    4 0.042124 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query
    5 0.042134 10.XX.XX.XX 10.XX.XX.XX TCP 66 distinct > 53069 [ACK] Seq=1
    Ack=71 Win=14592 Len=0 TSval=4286666284 TSecr=3266982894
    6 0.210450 10.XX.XX.XX 10.XX.XX.XX MONGO 153 Response : Reply
    7 0.251994 10.XX.XX.XX 10.XX.XX.XX TCP 66 53069 > distinct [ACK] Seq=71
    Ack=88 Win=5888 Len=0 TSval=3266983104 TSecr=4286666452
    8 0.252058 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query

    the delay is between packet 6 and 7.
    So why the ACK of the go reply comes so slowly?

    在 2014年5月13日星期二UTC+8下午11时53分15秒,Péter Szilágyi写道:
    Hi,

    Please provide some more details (Go is fast, 50ms is enormous and I'm
    almost sure there's something wrong there). A working source code would be
    nice. Additionally, are you sure it's milliseconds that you see, and not
    nanoseconds or microseconds?

    Cheers,
    Peter

    On Tue, May 13, 2014 at 3:06 PM, <chen...@126.com <javascript:>> wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms

    --
    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...@googlegroups.com <javascript:>.
    For more options, visit https://groups.google.com/d/optout.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Gé Weijers at May 15, 2014 at 2:22 pm
    Maybe I should elaborate: the TCP ack packet had no payload, it's sent by
    the kernel after a delay, the app did not send it. The kernel waits a
    little just in case the app sends a reply quickly, and will piggy-back the
    ack on that reply. In some cases you may not want that, but usually there's
    an app problem if it responds slowly. Make sure that you send any
    requests/replies using a single write/send system call. The TCP_NODELAY
    setting is probably not the issue.

    --


    On May 15, 2014, at 7:11, "Gé Weijers" wrote:

    You can try to disable the "Nagle Algorithm" for your TCP connections, in
    both client and server. On Unix that's done using the TCP_NODELAY socket
    option.

    --


    On May 13, 2014, at 20:14, "chensi_04@126.com" wrote:

    client server model
    first request packet recv is fast
    but the ack of the reponse(go server) arrives 40milliseconds after the
    response is send,
    SO the question is not recv request slow, is the client recv response slow.
    Using wireshark:
    4 0.042124 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query
    5 0.042134 10.XX.XX.XX 10.XX.XX.XX TCP 66 distinct > 53069 [ACK] Seq=1
    Ack=71 Win=14592 Len=0 TSval=4286666284 TSecr=3266982894
    6 0.210450 10.XX.XX.XX 10.XX.XX.XX MONGO 153 Response : Reply
    7 0.251994 10.XX.XX.XX 10.XX.XX.XX TCP 66 53069 > distinct [ACK] Seq=71
    Ack=88 Win=5888 Len=0 TSval=3266983104 TSecr=4286666452
    8 0.252058 10.XX.XX.XX 10.XX.XX.XX MONGO 136 Request : Query

    the delay is between packet 6 and 7.
    So why the ACK of the go reply comes so slowly?

    在 2014年5月13日星期二UTC+8下午11时53分15秒,Péter Szilágyi写道:
    Hi,

    Please provide some more details (Go is fast, 50ms is enormous and I'm
    almost sure there's something wrong there). A working source code would be
    nice. Additionally, are you sure it's milliseconds that you see, and not
    nanoseconds or microseconds?

    Cheers,
    Peter

    On Tue, May 13, 2014 at 3:06 PM, <chen...@126.com <javascript:>> wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms

    --
    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...@googlegroups.com <javascript:>.
    For more options, visit https://groups.google.com/d/optout.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Konstantin Khomoutov at May 13, 2014 at 4:12 pm

    On Tue, 13 May 2014 05:06:52 -0700 (PDT) chensi_04@126.com wrote:

    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano() [...]
    from log, one read cost almost 50ms
    time.Now() is a syscall as well, so you basically measure time to make
    two syscalls, the time each syscall spends in the kernel to do its work
    plus the time the read() syscall might wait until the data to read
    becomes available (because in Go, all syscalls are blocking).

    So, for a start, are you sure the data is available in the in-kernel
    socket's buffer at the time reader.Read() hits the kernel?

    Another thing to consider is that nothing prevents your code from being
    suspended in reader.Read() to make another goroutine do its work.

    From your example, it's not clear whether your setup guarantees there's
    exactly one goroutine and the data is 100% available by the time it's
    about to be read so I'm unable to guess further.

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Voidlogic at May 13, 2014 at 9:18 pm
    My understanding is time.Now() is not usually a syscall. It was in the old
    days, but most systems store the current time in a chunk of read only
    memory that is mapped to processes and then the process (usually by its
    runtime or C library) reads this memory location when it needs the time.
    Maybe I am wrong and Go actually uses a syscall... but I doubt it.
    On Tuesday, May 13, 2014 9:11:39 AM UTC-7, Konstantin Khomoutov wrote:

    On Tue, 13 May 2014 05:06:52 -0700 (PDT)
    chen...@126.com <javascript:> wrote:
    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano() [...]
    from log, one read cost almost 50ms
    time.Now() is a syscall as well, so you basically measure time to make
    two syscalls, the time each syscall spends in the kernel to do its work
    plus the time the read() syscall might wait until the data to read
    becomes available (because in Go, all syscalls are blocking).

    So, for a start, are you sure the data is available in the in-kernel
    socket's buffer at the time reader.Read() hits the kernel?

    Another thing to consider is that nothing prevents your code from being
    suspended in reader.Read() to make another goroutine do its work.

    From your example, it's not clear whether your setup guarantees there's
    exactly one goroutine and the data is 100% available by the time it's
    about to be read so I'm unable to guess further.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Steven Hartland at May 13, 2014 at 9:49 pm
    ----- Original Message -----
    From: "voidlogic" <voidlogic7@gmail.com>

    My understanding is time.Now() is not usually a syscall. It was in the old
    days, but most systems store the current time in a chunk of read only
    memory that is mapped to processes and then the process (usually by its
    runtime or C library) reads this memory location when it needs the time.
    Maybe I am wrong and Go actually uses a syscall... but I doubt it.
    Thats really dependent on implementation, not something that should be
    relied on tbh.

         Regards
         Steve

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Sanjay at May 13, 2014 at 10:10 pm
    That source code seems to imply that you're getting 50 nanoseconds, not
    milliseconds.

    Sanjay
    On Tuesday, May 13, 2014 5:48:44 PM UTC-4, Steven Hartland wrote:

    ----- Original Message -----
    From: "voidlogic" <voidl...@gmail.com <javascript:>>

    My understanding is time.Now() is not usually a syscall. It was in the old
    days, but most systems store the current time in a chunk of read only
    memory that is mapped to processes and then the process (usually by its
    runtime or C library) reads this memory location when it needs the time.
    Maybe I am wrong and Go actually uses a syscall... but I doubt it.
    Thats really dependent on implementation, not something that should be
    relied on tbh.

    Regards
    Steve
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Chensi_04 at May 14, 2014 at 2:39 am
    46126889 in nanoseconds

    在 2014年5月14日星期三UTC+8上午6时10分38秒,Sanjay写道:
    That source code seems to imply that you're getting 50 nanoseconds, not
    milliseconds.

    Sanjay
    On Tuesday, May 13, 2014 5:48:44 PM UTC-4, Steven Hartland wrote:

    ----- Original Message -----
    From: "voidlogic" <voidl...@gmail.com>

    My understanding is time.Now() is not usually a syscall. It was in the old
    days, but most systems store the current time in a chunk of read only
    memory that is mapped to processes and then the process (usually by its
    runtime or C library) reads this memory location when it needs the time.
    Maybe I am wrong and Go actually uses a syscall... but I doubt it.
    Thats really dependent on implementation, not something that should be
    relied on tbh.

    Regards
    Steve
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Voidlogic at May 15, 2014 at 3:51 pm
    By the way everyone, Go does indeed use a vsyscall for time (vDSO
    clock_gettime(2)) as I suspected.
    On Tuesday, May 13, 2014 2:48:44 PM UTC-7, Steven Hartland wrote:

    ----- Original Message -----
    From: "voidlogic" <voidl...@gmail.com <javascript:>>

    My understanding is time.Now() is not usually a syscall. It was in the old
    days, but most systems store the current time in a chunk of read only
    memory that is mapped to processes and then the process (usually by its
    runtime or C library) reads this memory location when it needs the time.
    Maybe I am wrong and Go actually uses a syscall... but I doubt it.
    Thats really dependent on implementation, not something that should be
    relied on tbh.

    Regards
    Steve
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Chensi_04 at May 14, 2014 at 3:23 am
    The question is clear now. client and server in different IDC, the TTL is
    40ms.
    glad for all of your replies.

    Thank you!

    在 2014年5月13日星期二UTC+8下午8时06分52秒,chen...@126.com写道:
    the socket read code :

    headerBuf := make([]byte, 4)
    t1 := time.Now().UnixNano()
    _, err := reader.Read(headerBuf)
    t2 := time.Now().UnixNano()
    if err != nil {
    mylog.Warning("Warning: read header failed - %s",
    err.Error())
    return nil, myerror.New(err.Error(),
    myerror.ERR_CLIENT_NET_READ)
    }
    mylog.Warning("%d", t2-t1)

    from log, one read cost almost 50ms
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupgolang-nuts @
categoriesgo
postedMay 13, '14 at 3:44p
activeMay 15, '14 at 3:51p
posts13
users7
websitegolang.org

People

Translate

site design / logo © 2021 Grokbase