Why channel latency depends on CPU utilization?

[Sergey Kurenkov]

I am trying to understand why higher CPU utilization leads to longer latency in reading from channels in golang. Could you help me with this question?

I wrote a test that reads from channels and measure latency between writing to a channel and reading from the channel. It shows that the latency depends on CPU utulization. When one of functions looks like this

func (c *Connection) imitateEncodeAndSend() {
   onFinish := time.Now().Add(8 * time.Microsecond)
   for time.Now().Before(onFinish) {
     runtime.Gosched()
   }
}

the average latency of reading from 5 channels is 1,5 microseconds.When runtime.Gosched() is commented the average latency is 10 microseconds. Why latency depends so much on CPU utilization even though there are a lot of CPU available on the host where I test? Could you suggest anything to improve latency when runtime.Gosched() is commented?

I have included the test. It has 156 LOC.

Test with not commented runtime.Gosched() :
$ N=100000 C=5 go run ./multiplex.go
connections: 5, a.iterations: 100000, duration: 1.352864833s, average broadcasting latency: 720ns, average receive latency: 1.504µs, rate: 73917

Test with commented runtime.Gosched():

$ N=100000 C=5 go run ./multiplex.go
connections: 5, a.iterations: 100000, duration: 2.860448459s, average broadcasting latency: 569ns, average receive latency: 10.655µs, rate: 34960

[Ian Lance Taylor]

On Mon, Oct 31, 2022 at 1:34 PM Sergey Kurenkov
<sergey.a...@gmail.com> wrote:
>
> I am trying to understand why higher CPU utilization leads to longer latency in reading from channels in golang. Could you help me with this question?
>
> I wrote a test that reads from channels and measure latency between writing to a channel and reading from the channel. It shows that the latency depends on CPU utulization. When one of functions looks like this
>
> func (c *Connection) imitateEncodeAndSend() {
> onFinish := time.Now().Add(8 * time.Microsecond)
> for time.Now().Before(onFinish) {
> runtime.Gosched()
> }
> }

You should make sure that you are testing CPU utilization itself,
rather than heavy scheduler use. Sending a value on a channel
generally requires a trip through the scheduler, to pick up the
receiving goroutine and start running it. Often the scheduler can
find the next job without acquiring the global scheduler lock, but not
always. Your sample code above is entering the scheduler
continuously, which is not a typical characteristic of a real program
that has heavy CPU usage. It's possible that what you are seeing is
contention on the scheduler lock.

Ian

[Robert Engels]

github.com/robaho/go-currency-test has some investigation on this

> On Oct 31, 2022, at 3:53 PM, Ian Lance Taylor <ia...@golang.org> wrote:
>
> On Mon, Oct 31, 2022 at 1:34 PM Sergey Kurenkov

> --
> 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.
> To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CAOyqgcVRZyMzOcN4UfiPkKLPGVmAtifVetpnCBJBgrdAWF6AJw%40mail.gmail.com.

[Sergey Kurenkov]

> Your sample code above is entering the scheduler
continuously, which is not a typical characteristic of a real program
that has heavy CPU usage. It's possible that what you are seeing is

contention on the scheduler lock.

Ian,

Don't understand your point. The sample code above actually has better latency in my test even though it is is entering the scheduler
continuously according to you:

func (c *Connection) imitateEncodeAndSend() {
   onFinish := time.Now().Add(8 * time.Microsecond)
   for time.Now().Before(onFinish) {
     runtime.Gosched()
   }
}

And this code has 10 times worse latency in my test:

func (c *Connection) imitateEncodeAndSend() {
   onFinish := time.Now().Add(8 * time.Microsecond)
   for time.Now().Before(onFinish) {

     // runtime.Gosched()
   }
}

[Robert Engels]

Entering the scheduler continuously will improve performance - it is known as “keeping things hot”. Waking a thread is usually about 6-7 usecs. So if you never “sleep” you get much lower latency. 

On Oct 31, 2022, at 4:55 PM, Sergey Kurenkov <sergey.a...@gmail.com> wrote:



--

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.

To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/7497264f-d407-423e-8b51-9567bc1fbd21n%40googlegroups.com.

[Ian Lance Taylor]

> Ian,
>
> Don't understand your point. The sample code above actually has better latency in my test even though it is is entering the scheduler
> continuously according to you:

Ah, sorry for misunderstanding the code.

> func (c *Connection) imitateEncodeAndSend() {
> onFinish := time.Now().Add(8 * time.Microsecond)
> for time.Now().Before(onFinish) {
> runtime.Gosched()
> }
> }
>

> And this code has 10 times worse latency in my test:
>

> func (c *Connection) imitateEncodeAndSend() {
> onFinish := time.Now().Add(8 * time.Microsecond)
> for time.Now().Before(onFinish) {

> // runtime.Gosched()
> }
> }

The Go scheduler doesn't behave that well with tight loops. It may be
preempting this loop using a signal, which is naturally slower.

I'm just guessing, though.

Ian