You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Alan Conway (JIRA)" <ji...@apache.org> on 2018/08/07 15:04:00 UTC
[jira] [Commented] (PROTON-1764) Slow performance seen when running
Go client
[ https://issues.apache.org/jira/browse/PROTON-1764?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16571807#comment-16571807 ]
Alan Conway commented on PROTON-1764:
-------------------------------------
On reading around, CGO is well known to have very high per-call overhead - the Go binding was not written with that in mind, it is a very thin wrapper around the C library. There are two short-term paths to improvement:
* re-write minor C functionality Go where possible.
* re-write critical Go code, esp. code that calls C in a loop in C.
Both of these may be challenging.
Longer term I would like to rewrite the entire codec in Go, using the C codec is not really providing any benefits as the pn_data_t is pretty much equally hard to use as parsing AMQP bytes directly.
There may be low-hanging fruit in Message, see PROTON-1910
> Slow performance seen when running Go client
> --------------------------------------------
>
> Key: PROTON-1764
> URL: https://issues.apache.org/jira/browse/PROTON-1764
> Project: Qpid Proton
> Issue Type: Bug
> Components: go-binding
> Affects Versions: proton-c-0.18.1
> Reporter: Aaron Smith
> Assignee: Alan Conway
> Priority: Major
> Labels: perf
>
> Slower than expected message deliver rate seen while running simple benchmarking test. Setup:
> Client(Go) Sender -> QPID Router -> Client Receiver(Go)
> Profiling of reveals that a large percentage of time is spent in wrapper call from Go to c.
> Not sure if the call to C from Go is the issue.
>
> Here's the pointer for sender/receiver (both uses qpid go-binding).
> Sender (with '-limit' option, it sends AMQP messages in 10sec for benchmarking):
> [https://github.com/redhat-nfvpe/service-assurance-poc/tree/master/tools/sa-bench]
> Receiver (based on electron sample):
> [http://kagaribi.s1061123.net/receive.go]
> Here are the results:
> {noformat}
> [root@nfvha-comp-01 sa-bench]# ./sa-bench -mode limit amqp://127.0.0.1:5672/collectd/telemetry
> sending AMQP in 10 seconds...Done!
> Total: 171908 sent (duration:10.000103521s, mesg/sec: 17190.62204096157)
> [root@nfvha-comp-01 electron_sample]# ./receive -prefetch 12 amqp://127.0.0.1:5672/collectd/telemetry
> Listening on 1 connections
> ^C2018/02/15 01:44:51 Total: 171908 received.
> 2018/02/15 01:44:51 captured interrupt, stopping profiler and exiting...
> {noformat}
> Both program can collect profile data using '-pprofile' option as following:
> {noformat}
> [root@nfvha-comp-01 sa-bench]# ./sa-bench -mode limit -pprofile profile.out amqp://127.0.0.1:5672/collectd/telemetry
> sending AMQP in 10 seconds...Done!
> Total: 189305 sent (duration:10.000111611s, mesg/sec: 18930.2887171546)
> [root@nfvha-comp-01 sa-bench]# go tool pprof sa-bench profile.out
> File: sa-bench
> Build ID: 7ffec7b98a532892d7b9932b70b7451866cd4e5e
> Type: cpu
> Time: Feb 15, 2018 at 1:49am (EST)
> Duration: 10.11s, Total samples = 15.75s (155.79%)
> Entering interactive mode (type "help" for commands, "o" for options)
> (pprof) top5
> Showing nodes accounting for 9990ms, 63.43% of 15750ms total
> Dropped 200 nodes (cum <= 78.75ms)
> Showing top 5 nodes out of 144
> flat flat% sum% cum cum%
> 6750ms 42.86% 42.86% 7080ms 44.95% runtime.cgocall /usr/local/go/src/runtime/cgocall.go
> 1570ms 9.97% 52.83% 1590ms 10.10% syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
> 800ms 5.08% 57.90% 800ms 5.08% runtime.futex /usr/local/go/src/runtime/sys_linux_amd64.s
> 440ms 2.79% 60.70% 770ms 4.89% runtime.runqgrab /usr/local/go/src/runtime/proc.go
> 430ms 2.73% 63.43% 1070ms 6.79% runtime.selectgo /usr/local/go/src/runtime/select.go
> [root@nfvha-comp-01 electron_sample]# ./receive -prefetch 12 -pprofile profile.out amqp://127.0.0.1:5672/collectd/telemetry
> Listening on 1 connections
> ^C2018/02/15 01:49:25 Total: 181422 received.
> 2018/02/15 01:49:25 captured interrupt, stopping profiler and exiting...
> [root@nfvha-comp-01 electron_sample]# go tool pprof receive profile.out
> File: receive
> Build ID: 66addd89d429ca678cbd6e336872bc604406f83e
> Type: cpu
> Time: Feb 15, 2018 at 1:49am (EST)
> Duration: 14.78s, Total samples = 16.60s (112.31%)
> Entering interactive mode (type "help" for commands, "o" for options)
> (pprof) top 5
> Showing nodes accounting for 10620ms, 63.98% of 16600ms total
> Dropped 160 nodes (cum <= 83ms)
> Showing top 5 nodes out of 124
> flat flat% sum% cum cum%
> 5730ms 34.52% 34.52% 5960ms 35.90% runtime.cgocall /usr/local/go/src/runtime/cgocall.go
> 2190ms 13.19% 47.71% 2220ms 13.37% syscall.Syscall /usr/local/go/src/syscall/asm_linux_amd64.s
> 1070ms 6.45% 54.16% 1070ms 6.45% runtime.epollwait /usr/local/go/src/runtime/sys_linux_amd64.s
> 860ms 5.18% 59.34% 4430ms 26.69% runtime.findrunnable /usr/local/go/src/runtime/proc.go
> 770ms 4.64% 63.98% 1130ms 6.81% runtime.runqgrab /usr/local/go/src/runtime/proc.go
> (pprof) {noformat}
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org