net/http: client is slow

[gopherbot]

by hk.yuhe:

I have a web API written in Golang.
The API fetch data from redis(http://redis.io/) using
Go-redis(https://github.com/alphazero/Go-Redis),do some iter computation and return.

When I run benchmark with http_load,the result is not that good.
The result is as follows:

[yugaohe@localhost test]$ http_load -p 100 -s 60 t.txt
459810 fetches, 100 max parallel, 7.44892e+07 bytes, in 60.0004 seconds
162 mean bytes/connection
7663.45 fetches/sec, 1.24148e+06 bytes/sec
msecs/connect: 0.523986 mean, 3000.81 max, 0.069 min
msecs/first-response: 12.3115 mean, 1041.64 max, 0.51 min
HTTP response codes:
  code 200 -- 459810

I do some profile work following this
blog(http://blog.golang.org/2011/06/profiling-go-programs.html)
And find it is SCANBLOCK that stucks!

I make several images about this:

http://yugaohe.sinaapp.com/rtdeAnalysis.html
http://yugaohe.sinaapp.com/rtdeAnalysis2.html

Does Golang really do bad in Garbage Collection?
And how can I optimize my golang program?


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

I use 6g

Which operating system are you using?

cat /proc/version
Linux version 2.6.18-274.17.1.el5 (mockbuild@builder10.centos.org) (gcc version 4.1.2
20080704 (Red Hat 4.1.2-51)) #1 SMP Tue Jan 10 17:25:58 EST 2012

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

go version go1.0.3

Attachments:

1. pprof.png (23967 bytes)

[remyoudompheng]

Comment 1:

You should optimize your program. Use memory profiling and pprof --alloc_objects to look
for extra calls to malloc in your code.

[rsc]

Comment 2:

Please show us the client code; otherwise, there's nothing we can do to help.

Labels changed: added priority-later, removed priority-triage.

Status changed to WaitingForReply.

[rsc]

Comment 3:

Labels changed: removed go1.1.

[gopherbot]

Comment 4 by hk.yuhe:

the redis package refers to https://github.com/alphazero/Go-Redis
the mmsego package refers to https://github.com/Codefor/MMSEGO
the config package refers to https://github.com/kless/goconfig
the darts package refers to https://github.com/awsong/go-darts
the code tree outputs like this:
.
|-- config
|   |-- all_test.go
|   |-- config.go
|   |-- error.go
|   |-- option.go
|   |-- read.go
|   |-- section.go
|   |-- type.go
|   `-- write.go
|-- darts
|   |-- darts.go
|   `-- dawg.go
|-- data
|   |-- all.gob
|   |-- brandId2Name.txt
|   |-- brandName2Id.txt
|   |-- brandNames.txt
|   |-- cid2name.txt
|   |-- cid2path.txt
|   |-- cid2tags.txt
|   |-- data.tar.gz
|   |-- id2newid.txt
|   |-- mmseg.so.64
|   |-- pid2tags.txt
|   |-- pidsinfo.txt
|   |-- t.py
|   |-- tag2pids.txt
|   |-- tagName2Id.txt
|   |-- words.dic
|   |-- words.dic.bak
|   `-- words.lib
|-- mmsego
|   `-- mmsego.go
|-- rtde//the most important package
|   |-- dataSet.go
|   |-- ddurl.go
|   |-- result.go
|   |-- step.go
|   `-- userIntention.go
|-- rtde.cfg//the config file
|-- test
|   |-- fetch_perm_ids.py
|   |-- perm_id.txt
|   |-- redis_bench
|   |-- redis_bench.go
|   |-- redis_bench.py
|   `-- redis_bench_avg.py
`-- userIntentionAPI.go//the main script

Attachments:

1. dataSet.go (11891 bytes)
2. ddurl.go (2363 bytes)
3. result.go (2595 bytes)
4. userIntentionAPI.go (12536 bytes)
5. step.go (2971 bytes)
6. userIntention.go (19808 bytes)

[gopherbot]

Comment 5 by hk.yuhe:

Is anybody there? @rsc@golang.org

[rsc]

Comment 6:

The way to optimize your program is to remove sources of allocation from the profiles.
Your profile http://yugaohe.sinaapp.com/rtdeAnalysis.html is actually a good source of
data. 
For example redis's CreateRequestBytes should probably be passed in a destination buffer
to append to, so that it can be reused. It could then also use AppendInt instead of
Itoa, saving a few more allocations.
I don't believe the client is that slow. I think you're just exercising the code by
allocating a lot. I don't think there's a runtime bug here. 
You might want to try mailing the golang-nuts@googlegroups.com mailing list and point
them to this issue so they can look at the graphs and code and make suggestions.

Status changed to WorkingAsIntended.