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

76% of time are runtime.goexit #141

Open
oliveagle opened this issue Jul 28, 2015 · 11 comments
Open

76% of time are runtime.goexit #141

oliveagle opened this issue Jul 28, 2015 · 11 comments

Comments

@oliveagle
Copy link

consuming too slow compare to java client.

on the same machine. java client process 250k messages per second in snappy encoding each thread, 3 threads in total. but this client can only reach 30k at maximum. on a better machine this client can reach 70k per second.

(pprof) top -cum
3.61s of 25.42s total (14.20%)
Dropped 165 nodes (cum <= 0.13s)
Showing top 10 nodes out of 139 (cum >= 2.85s)
      flat  flat%   sum%        cum   cum%
     0.02s 0.079% 0.079%     19.47s 76.59%  runtime.goexit
     0.11s  0.43%  0.51%      6.15s 24.19%  github.com/stealthly/go_kafka_client                    .func·047
     0.16s  0.63%  1.14%      4.94s 19.43%  main.func·003
         0     0%  1.14%      4.62s 18.17%  System
         0     0%  1.14%      4.07s 16.01%  github.com/rcrowley/go-metrics.(*Sta                    ndardTimer).Time
     0.16s  0.63%  1.77%      3.40s 13.38%  github.com/stealthly/go_kafka_client                    .func·037
     0.04s  0.16%  1.93%      3.32s 13.06%  github.com/stealthly/go_kafka_client                    .Tracef
     0.10s  0.39%  2.32%      3.16s 12.43%  github.com/stealthly/go_kafka_client                    .(*WorkerManager).processBatch
     2.67s 10.50% 12.82%      3.14s 12.35%  runtime.mallocgc
     0.35s  1.38% 14.20%      2.85s 11.21%  reflect.Select
@edgefox
Copy link
Contributor

edgefox commented Jul 28, 2015

Hi! Unfortunately, current implementation of Snappy and GZip encoding showed itself quite bad while testing on big data volumes due to inefficient CPU usage. The only way I see is to change them to something that performs better. Though, I haven't seen any options available so far.

@serejja
Copy link
Contributor

serejja commented Jul 28, 2015

One more thing worth to mention here is that this consumer uses completely different approach than the Java consumer and this affects performance because of workers and acknowledgements handling. I agree there is place for optimizations but roughly this consumer won't be that fast as standard Java consumer.

@oliveagle
Copy link
Author

compare to the performance of lower level kafka lib

% user time on windows. (average: 0.35)
image

40k+ messages per second.
image

image

package main

import (
    "fmt"
    "github.com/stealthly/siesta"
    "time"
)

func main() {
    config := siesta.NewConnectorConfig()
    config.BrokerList = []string{"localhost:9092"}
    config.KeepAlive = true
    connector, err := siesta.NewDefaultConnector(config)
    if err != nil {
        fmt.Println("failed to create default connector: ", err)
    }

    max_offset := int64(12902921)

    tick := time.Tick(time.Second)

    cnt := int64(0)

    diff_offset_ch := make(chan int64, 1)
    go func() {
        for {
            prev_offset := max_offset
            response, err := connector.Fetch("test3", 1, max_offset)
            if err != nil {
                fmt.Println(err)
            }
            messages, err := response.GetMessages()
            for _, m := range messages {
                if m.Offset > max_offset {
                    max_offset = m.Offset
                }
            }
            diff_offset_ch <- (max_offset - prev_offset)
        }
    }()

    for {
        select {
        case t := <-tick:
            fmt.Println(t, cnt)
            cnt = 0
        case offset := <-diff_offset_ch:
            cnt += offset
        }
    }

}

@serejja
Copy link
Contributor

serejja commented Jul 28, 2015

@oliveagle umm so you say siesta is doing 40k snappy encoded messages/sec while java client does 250k? This shouldn't definitely happen. I understand if this happens on go_kafka_client level but definitely not on siesta level.

What is average message size in the topic? Can you also check performance for non-compressed messages?
Thanks!

@oliveagle
Copy link
Author

low level lib, on 1Gbps nic machine. lower level lib can reach 200k/second. no compression.

image

image

@oliveagle
Copy link
Author

@serejja

150B per message.

compression is not the problem here. maybe too many goroutine should be blamed.

150B per message.  no compression

                               100MbpsNIC ,                   1GbpsNIC
go_kafka_client       cpu: 80%,  50k/s               cpu: 100%, 50k/s
siesta                cpu: 1%,  50k/s                cpu: 20%,  200k+/s

@serejja
Copy link
Contributor

serejja commented Jul 28, 2015

@oliveagle ok so if I understand you correctly the performance problem appears on siesta level and only with compressed messages?

@oliveagle
Copy link
Author

@serejja, no, siesta don't have performance problem. go_kafka_client does. no matter compressed or not.

@serejja
Copy link
Contributor

serejja commented Jul 28, 2015

@oliveagle we've just discussed this with Ivan and have an assumption how to fix this. Will try to create a PR for this soon. Thanks!

@edgefox
Copy link
Contributor

edgefox commented Jul 28, 2015

@oliveagle please try #142 PR and tell whether it solves your issue or not. Thanks!

@oliveagle
Copy link
Author

no compression, 150B/msg, 50K messages per second . 95% network io of a 100Mbytes Nic,

CPU is still very high. compare to siesta

image

image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants