Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

net: tiny i/o is slower than in C #5643

Closed
gopherbot opened this issue Jun 5, 2013 · 11 comments

Comments

Projects
None yet
5 participants
@gopherbot
Copy link

commented Jun 5, 2013

by steve.wangbin:

Before filing a bug, please check whether it has been fixed since the
latest release. Search the issue tracker and check that you're running the
latest version of Go:

Run "go version" and compare against
http://golang.org/doc/devel/release.html  If a newer version of Go exists,
install it and retry what you did to reproduce the problem.

Thanks.

What steps will reproduce the problem?
If possible, include a link to a program on play.golang.org.
Run the server for the clients written in C++ and Go. The source files have been
attached.
=====================
build:
$ g++ -o server_cpp server.cpp 
$ g++ -o client_cpp client.cpp
$ go build -o client_go client.go

=====================
run server and cpp client:
$ ./server_cpp
recv system call times: 998808
recv bytes: 20000000

$ time ./client_cpp
real    0m3.678s
user    0m0.224s
sys 0m3.440s

=====================
run server and go client:
$ ./server_cpp
recv system call times: 8877231
recv bytes: 20000000

$ time ./client_go
begin send...
client done!

real    0m23.028s
user    0m5.036s
sys 0m17.929s

What is the expected output?
Not too bad performance compared with C++.


What do you see instead?
10 times slower.

Which compiler are you using (5g, 6g, 8g, gccgo)?
6g

Which operating system are you using?
ubuntu 12.04 64bit

Which version are you using?  (run 'go version')
1.1

Please provide any additional information below.
See the attachment.
And it was discussed here:
https://groups.google.com/forum/?fromgroups=#!topic/golang-nuts/E-kMSkXMXM0

Attachments:

  1. client.go (486 bytes)
  2. client.cpp (797 bytes)
  3. server.cpp (828 bytes)
@bradfitz

This comment has been minimized.

Copy link
Member

commented Jun 5, 2013

Comment 1:

Per the mailing list thread on this, the issue is that Go is TCP_NODELAY by default,
where your C++ client has Nagel on by default.

Status changed to Invalid.

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Jun 5, 2013

Comment 2:

If you use DialTCP instead of Dial, you will get a TCPConn, and then you can call
SetNoDelay(false).
@gopherbot

This comment has been minimized.

Copy link
Author

commented Jun 5, 2013

Comment 3 by steve.wangbin:

The go client is still 3x slower even though NoDelay is false.
====
$ time ./client_go
real    0m10.202s
user    0m3.808s
sys 0m6.368s
$ time ./client_cpp
real    0m3.366s
user    0m0.220s
sys 0m3.132s
@gopherbot

This comment has been minimized.

Copy link
Author

commented Jun 5, 2013

Comment 4 by steve.wangbin:

And the server still have to invoke function recv() much more times.
for cpp client:
$ ./server_cpp
recv system call times: 986183
recv bytes: 20000000
for go client:
$ ./server_cpp
recv system call times: 4951222
recv bytes: 20000000
@bradfitz

This comment has been minimized.

Copy link
Member

commented Jun 5, 2013

Comment 5:

Attach a pcap file (from e.g. tcpdump or wireshark) & strace -f output of the Go binary.

Labels changed: removed priority-triage.

Status changed to WaitingForReply.

@gopherbot

This comment has been minimized.

Copy link
Author

commented Jun 5, 2013

Comment 6 by vladislav.chugunov:

strace -f shows
[pid 30088] write(3, "ab", 2 <unfinished ...>
[pid 30087] <... select resumed> )      = 0 (Timeout)
[pid 30088] <... write resumed> )       = 2
[pid 30087] select(0, NULL, NULL, NULL, {0, 10000} <unfinished ...>
after every random small amount(70 - 120 on my laptop) of 
[pid 30088] write(3, "ab", 2)           = 2
@gopherbot

This comment has been minimized.

Copy link
Author

commented Jun 5, 2013

Comment 7 by steve.wangbin:

The files got from tcpdump and strace are too large to upload because of the maximum
size of attachment.
So I upload the revised files with NoDelay being false.
I believe this issue is quite easy to reproduce.
There is one thing I have not mentioned is that I just ran these programs on
localhost(127.0.0.1), and I'm not sure whether it matters.

Attachments:

  1. client.cpp (797 bytes)
  2. client.go (525 bytes)
  3. server.cpp (765 bytes)
@gopherbot

This comment has been minimized.

Copy link
Author

commented Jun 5, 2013

Comment 8 by steve.wangbin:

Here is strace.txt.tar.gz.
The file created by tcpdump is too big to attach.

Attachments:

  1. strace.txt.tar.gz (74479 bytes)
@kylelemons

This comment has been minimized.

Copy link
Contributor

commented Jun 6, 2013

Comment 9:

I can't reproduce on darwin/amd64.
dtraces:
https://gist.github.com/kylelemons/5719397
The only thing that happens is that as you disable nodelay and switch to C, a higher
proportion of the server's writes are fast enough to be read by the same read syscall. 
It doesn't take much in such a tight loop to balloon the run time, so the difference
between the C and Go version (+17%) and between the nagle and nodelay version (+25%)
doesn't seem extraordinary, especially since in any real program the delay between
writes will be dominated by other processing time (and writes won't be two-bytes
each...).
@rsc

This comment has been minimized.

Copy link
Contributor

commented Jul 25, 2013

Comment 10:

I'm not sure there's much to do here. Go has the overhead of the select loop and such,
but those can't be removed.
@rsc

This comment has been minimized.

Copy link
Contributor

commented Jul 30, 2013

Comment 11:

Status changed to Unfortunate.

@golang golang locked and limited conversation to collaborators Jun 24, 2016

This issue was closed.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.