Skip to content

sync: Pool example suggests incorrect usage #23199

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

Open
dsnet opened this issue Dec 20, 2017 · 36 comments
Open

sync: Pool example suggests incorrect usage #23199

dsnet opened this issue Dec 20, 2017 · 36 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. Documentation Issues describing a change to documentation. help wanted NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@dsnet
Copy link
Member

dsnet commented Dec 20, 2017

The operation of sync.Pool assumes that the memory cost of each element is approximately the same in order to be efficient. This property can be seen by the fact that Pool.Get returns you a random element, and not the one that has "the greatest capacity" or what not. In other words, from the perspective of the Pool, all elements are more or less the same.

However, the Pool example stores bytes.Buffer objects, which have an underlying []byte of varying capacity depending on how much of the buffer is actually used.

Dynamically growing an unbounded buffers can cause a large amount of memory to be pinned and never be freed in a live-lock situation. Consider the following:

pool := sync.Pool{New: func() interface{} { return new(bytes.Buffer) }}

processRequest := func(size int) {
	b := pool.Get().(*bytes.Buffer)
	time.Sleep(500 * time.Millisecond) // Simulate processing time
	b.Grow(size)
	pool.Put(b)
	time.Sleep(1 * time.Millisecond) // Simulate idle time
}

// Simulate a set of initial large writes.
for i := 0; i < 10; i++ {
	go func() {
		processRequest(1 << 28) // 256MiB
	}()
}

time.Sleep(time.Second) // Let the initial set finish

// Simulate an un-ending series of small writes.
for i := 0; i < 10; i++ {
	go func() {
		for {
			processRequest(1 << 10) // 1KiB
		}
	}()
}

// Continually run a GC and track the allocated bytes.
var stats runtime.MemStats
for i := 0; ; i++ {
	runtime.ReadMemStats(&stats)
	fmt.Printf("Cycle %d: %dB\n", i, stats.Alloc)
	time.Sleep(time.Second)
	runtime.GC()
}

Depending on timing, the above snippet takes around 35 GC cycles for the initial set of large requests (2.5GiB) to finally be freed, even though each of the subsequent writes only use around 1KiB. This can happen in a real server handling lots of small requests, where large buffers allocated by some prior request end up being pinned for a long time since they are not in Pool long enough to be collected.

The example claims to be based on fmt usage, but I'm not convinced that fmt's usage is correct. It is susceptible to the live-lock problem described above. I suspect this hasn't been an issue in most real programs since fmt.PrintX is typically not used to write very large strings. However, other applications of sync.Pool may certainly have this issue.

I suggest we fix the example to store elements of fixed size and document this.

\cc @kevinburke @LMMilewski @bcmills

@dsnet
Copy link
Member Author

dsnet commented Dec 20, 2017

I should also note that if #22950 is done, then usages like this will cause large buffers to be pinned forever since this example has a steady state of Pool usage, so the GC would never clear the pool.

@dsnet
Copy link
Member Author

dsnet commented Dec 20, 2017

Here's an even worse situation than earlier (suggested by @bcmills):

pool := sync.Pool{New: func() interface{} { return new(bytes.Buffer) }}

processRequest := func(size int) {
	b := pool.Get().(*bytes.Buffer)
	time.Sleep(500 * time.Millisecond) // Simulate processing time
	b.Grow(size)
	pool.Put(b)
	time.Sleep(1 * time.Millisecond) // Simulate idle time
}

// Simulate a steady stream of infrequent large requests.
go func() {
	for {
		processRequest(1 << 28) // 256MiB
	}
}()

// Simulate a storm of small requests.
for i := 0; i < 1000; i++ {
	go func() {
		for {
			processRequest(1 << 10) // 1KiB
		}
	}()
}

// Continually run a GC and track the allocated bytes.
var stats runtime.MemStats
for i := 0; ; i++ {
	runtime.ReadMemStats(&stats)
	fmt.Printf("Cycle %d: %dB\n", i, stats.Alloc)
	time.Sleep(time.Second)
	runtime.GC()
}

Rather than a single one-off large request, let there be a steady stream of occasional large requests intermixed with a large number of small requests. As this snippet runs, the heap keeps growing over time. The large request is "poisoning" the pool such that most of the small requests eventually pin a large capacity buffer under the hood.

@dsnet dsnet added the Documentation Issues describing a change to documentation. label Dec 20, 2017
@kevinburke
Copy link
Contributor

Yikes. My goal in adding the example was to try to show the easiest-to-understand use case for a Pool. fmt was the best one I could find in the standard library.

@ulikunitz
Copy link
Contributor

The solution is of course to put only buffers with small byte slices back into the pool.

if b.Cap() <= 1<<12 {
         pool.put(b)
}

@dsnet
Copy link
Member Author

dsnet commented Dec 21, 2017

Alternatively, you could use an array of sync.Pools to bucketize the items by size: https://github.com/golang/go/blob/7e394a2/src/net/http/h2_bundle.go#L998-L1043

@bcmills
Copy link
Contributor

bcmills commented Dec 21, 2017

The solution is of course …

There are many possible solutions: the important thing is to apply one of them.

A related problem can arise with goroutine stacks in conjunction with “worker pools”, depending on when and how often the runtime reclaims large stacks. (IIRC that has changed several times over the lifetime of the Go runtime, so I'm not sure what the current behavior is.) If you have a pool of worker goroutines executing callbacks that can vary significantly in stack usage, you can end up with all of the workers consuming very large stacks even if the overall fraction of large tasks remains very low.

@kevinburke
Copy link
Contributor

kevinburke commented Dec 21, 2017

Do you have any suggestions for better use cases we could include in the example, that are reasonably compact?

Maybe the solution is not to recommend a sync.Pool at all anymore? This is my understanding from a comment I read about how GC makes this more or less useless

@jzelinskie
Copy link
Contributor

Would changing the example to use an array (fixed size) rather than a slice solve this problem?
In Chihaya, this is how we've used sync.Pool and our implementation before it was in the standard library.

Maybe the solution is not to recommend a sync.Pool at all anymore?

I legitimately don't think there ever was a time to generally recommend sync.Pool. I find it a pretty contentious add to the standard library because of how careful and knowledgable of the runtime you need to be in order to use it effectively. If you need optimization at this level, you probably know how to implement this best for your own use case.

Sorry to interject randomly, but I saw this thread on Twitter and have strong opinions on this feature.

@aclements
Copy link
Member

Maybe the solution is not to recommend a sync.Pool at all anymore? This is my understanding from a comment I read about how GC makes this more or less useless

We would certainly like to get to this point, and the GC has improved a lot, but for high-churn allocations with obvious lifetimes and no need for zeroing, sync.Pool can still be a significant optimization. As @RLH likes to say, every use of sync.Pool is a bug report on the GC. But we're still taking those bug reports. :)

I should also note that if #22950 is done, then usages like this will cause large buffers to be pinned forever since this example has a steady state of Pool usage, so the GC would never clear the pool.

That's clearly true, but even right now it's partly by chance that these examples are eventually dropping the large buffers. And in the more realistic stochastic mix example, it's not clear to me that #22950 would make it any better or worse.

I agree with @dsnet's original point that we should document that sync.Pool treats all objects interchangeably, so they should all have roughly the same "weight". And it would be good to provide some suggestions for what to do in situations where this isn't the case, and perhaps some concrete examples of poor sync.Pool usage.

@FMNSSun
Copy link

FMNSSun commented Jul 22, 2018

We've used sync.Pool for dealing with network packets and others do too (such as lucas-clemente/quic-go) because for those use cases you gain performance when using them. However, in those cases []byte is used instead of bytes.Buffer and they all have the same capacity and are re-sliced as needed. Before putting them back they are re-sliced to MaxPacketSize and before reading you Get a new []byte and re-slice it to the size of the network packet.

The same we did even for structs such as when parsing packets to a struct func ParsePacket([]byte data) *Packet (which overwrites all fields in a struct anyway) which means instead of allocating/freeing thousands of new structs each second they can be re-used using sync.Pool which makes things a little bit faster.

@FMNSSun
Copy link

FMNSSun commented Jul 23, 2018

I guess a minimal example of such a usage would be:

package main

import (
	"sync"
	"net"
)

const MaxPacketSize = 4096

var bufPool = sync.Pool {
	New: func() interface{} {
		return make([]byte, MaxPacketSize)
	},
}

func process(outChan chan []byte) {
	for data := range outChan {
		// process data

		// Re-slice to maximum capacity and return it
		// for re-use. This is important to guarantee that
		// all calls to Get() will return a buffer of
		// length MaxPacketSize.
		bufPool.Put(data[:MaxPacketSize])
	}
}

func reader(conn net.PacketConn, outChan chan []byte) {
	for {
		data := bufPool.Get().([]byte)
		
		n, _, err := conn.ReadFrom(data)
		
		if err != nil {
			break
		}
		
		outChan <- data[:n]
	}
	
	close(outChan)
}

func main() {
	N := 3
	var wg sync.WaitGroup
	
	outChan := make(chan []byte, N)
	
	wg.Add(N)
	
	for i := 0; i < N; i++ {
		go func() {
			process(outChan)
			wg.Done()
		}()
	}
	
	wg.Add(1)

	conn, err := net.ListenPacket("udp", "localhost:10001")

	if err != nil {
		panic(err.Error())
	}
	
	go func() {
		reader(conn, outChan)
		wg.Done()
	}()
	
	wg.Wait()
}

but of course... whether this is going to be faster than the GC depends on how many packets per second you have to deal with and what exactly you do with the data etc. In real world you'd benchmark with GC/sync.Pool and compare the two. At the time we wrote our code there was a significant time spent allocating new stuff and using a scheme as above we've managed to increase the throughput. Of course, one should re-benchmark this with every update to the GC.

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/136035 mentions this issue: encoding/json: fix usage of sync.Pool

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/136115 mentions this issue: sync: clarify proper Pool usage for dynamically sized buffers

@gopherbot
Copy link
Contributor

Change https://golang.org/cl/136116 mentions this issue: fmt: fix usage of sync.Pool

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/455236 mentions this issue: encoding/json: implement more intelligent encoder buffer pooling

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/464344 mentions this issue: log: reduce lock contention

gopherbot pushed a commit that referenced this issue Feb 3, 2023
Logger.Log methods are called in a highly concurrent manner in many servers.
Acquiring a lock in each method call results in high lock contention,
especially since each lock covers a non-trivial amount of work
(e.g., formatting the header and outputting to the writer).

Changes made:
* Modify the Logger to use atomics so that the header formatting
  can be moved out of the critical lock section.
  Acquiring the flags does not occur in the same critical section
  as outputting to the underlying writer, so this introduces
  a very slight consistency instability where concurrently calling
  multiple Logger.Output along with Logger.SetFlags may cause
  the older flags to be used by some ongoing Logger.Output calls
  even after Logger.SetFlags has returned.
* Use a sync.Pool to buffer the intermediate buffer.
  This approach is identical to how fmt does it,
  with the same max cap mitigation for #23199.
* Only protect outputting to the underlying writer with a lock
  to ensure serialized ordering of output.

Performance:
	name           old time/op  new time/op  delta
	Concurrent-24  19.9µs ± 2%   8.3µs ± 1%  -58.37%  (p=0.000 n=10+10)

Updates #19438

Change-Id: I091beb7431d8661976a6c01cdb0d145e37fe3d22
Reviewed-on: https://go-review.googlesource.com/c/go/+/464344
TryBot-Result: Gopher Robot <[email protected]>
Run-TryBot: Joseph Tsai <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Reviewed-by: Bryan Mills <[email protected]>
johanbrandhorst pushed a commit to Pryz/go that referenced this issue Feb 12, 2023
Logger.Log methods are called in a highly concurrent manner in many servers.
Acquiring a lock in each method call results in high lock contention,
especially since each lock covers a non-trivial amount of work
(e.g., formatting the header and outputting to the writer).

Changes made:
* Modify the Logger to use atomics so that the header formatting
  can be moved out of the critical lock section.
  Acquiring the flags does not occur in the same critical section
  as outputting to the underlying writer, so this introduces
  a very slight consistency instability where concurrently calling
  multiple Logger.Output along with Logger.SetFlags may cause
  the older flags to be used by some ongoing Logger.Output calls
  even after Logger.SetFlags has returned.
* Use a sync.Pool to buffer the intermediate buffer.
  This approach is identical to how fmt does it,
  with the same max cap mitigation for golang#23199.
* Only protect outputting to the underlying writer with a lock
  to ensure serialized ordering of output.

Performance:
	name           old time/op  new time/op  delta
	Concurrent-24  19.9µs ± 2%   8.3µs ± 1%  -58.37%  (p=0.000 n=10+10)

Updates golang#19438

Change-Id: I091beb7431d8661976a6c01cdb0d145e37fe3d22
Reviewed-on: https://go-review.googlesource.com/c/go/+/464344
TryBot-Result: Gopher Robot <[email protected]>
Run-TryBot: Joseph Tsai <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Reviewed-by: Bryan Mills <[email protected]>
@gopherbot
Copy link
Contributor

Change https://go.dev/cl/471200 mentions this issue: encoding/json: improve Marshal memory utilization

eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
Logger.Log methods are called in a highly concurrent manner in many servers.
Acquiring a lock in each method call results in high lock contention,
especially since each lock covers a non-trivial amount of work
(e.g., formatting the header and outputting to the writer).

Changes made:
* Modify the Logger to use atomics so that the header formatting
  can be moved out of the critical lock section.
  Acquiring the flags does not occur in the same critical section
  as outputting to the underlying writer, so this introduces
  a very slight consistency instability where concurrently calling
  multiple Logger.Output along with Logger.SetFlags may cause
  the older flags to be used by some ongoing Logger.Output calls
  even after Logger.SetFlags has returned.
* Use a sync.Pool to buffer the intermediate buffer.
  This approach is identical to how fmt does it,
  with the same max cap mitigation for golang#23199.
* Only protect outputting to the underlying writer with a lock
  to ensure serialized ordering of output.

Performance:
	name           old time/op  new time/op  delta
	Concurrent-24  19.9µs ± 2%   8.3µs ± 1%  -58.37%  (p=0.000 n=10+10)

Updates golang#19438

Change-Id: I091beb7431d8661976a6c01cdb0d145e37fe3d22
Reviewed-on: https://go-review.googlesource.com/c/go/+/464344
TryBot-Result: Gopher Robot <[email protected]>
Run-TryBot: Joseph Tsai <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Reviewed-by: Bryan Mills <[email protected]>
eric pushed a commit to fancybits/go that referenced this issue Sep 7, 2023
Logger.Log methods are called in a highly concurrent manner in many servers.
Acquiring a lock in each method call results in high lock contention,
especially since each lock covers a non-trivial amount of work
(e.g., formatting the header and outputting to the writer).

Changes made:
* Modify the Logger to use atomics so that the header formatting
  can be moved out of the critical lock section.
  Acquiring the flags does not occur in the same critical section
  as outputting to the underlying writer, so this introduces
  a very slight consistency instability where concurrently calling
  multiple Logger.Output along with Logger.SetFlags may cause
  the older flags to be used by some ongoing Logger.Output calls
  even after Logger.SetFlags has returned.
* Use a sync.Pool to buffer the intermediate buffer.
  This approach is identical to how fmt does it,
  with the same max cap mitigation for golang#23199.
* Only protect outputting to the underlying writer with a lock
  to ensure serialized ordering of output.

Performance:
	name           old time/op  new time/op  delta
	Concurrent-24  19.9µs ± 2%   8.3µs ± 1%  -58.37%  (p=0.000 n=10+10)

Updates golang#19438

Change-Id: I091beb7431d8661976a6c01cdb0d145e37fe3d22
Reviewed-on: https://go-review.googlesource.com/c/go/+/464344
TryBot-Result: Gopher Robot <[email protected]>
Run-TryBot: Joseph Tsai <[email protected]>
Reviewed-by: Ian Lance Taylor <[email protected]>
Reviewed-by: Bryan Mills <[email protected]>
@mitar
Copy link
Contributor

mitar commented Oct 21, 2023

I think one issue is that bytes.Buffer does not have Shrink() method to make the underlying buffer smaller. It could be used as a middle ground between retaining full buffer and dropping it completely. Then one could shrink the buffer to an acceptable size before returning it to the pool.

@puellanivis
Copy link

So I believe, capping the length or capacity of a slice does not actually reduce the size of the underlying backing array. So, this would not actually save or restore any more memory than stuffing the whole buffer anyways. The only way to truly shrink the memory usage of a slice would be to reallocate it at a smaller size, and then copy the data into… but at that point, in this particular use case, that means we would be better off just dropping the whole slice on the ground, and letting the GC clean it up.

@zigo101
Copy link

zigo101 commented Oct 22, 2023

For the buffer specific problem, it would be great to support a new Buffer type with multiple underlying (same-capacity) slices, so that we can instead put the underlying slices in Pool.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. Documentation Issues describing a change to documentation. help wanted NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Development

No branches or pull requests