Golang map len() reports > 0 when map is empty

Short story:

I'm having an issue where a map that previously had data but should now be empty is reporting a len() of > 0 even though it appears to be empty, and I have no idea why.

Longer story:

I need to process a number of devices at a time. Each device can have a number of messages. The concurrency of Go seemed like an obvious place to begin, so I wrote up some code to handle it and it seems to be going mostly very well. However...

I started a single goroutine for each device. In the main() function I have a map that contains each of the devices. When a message comes in I check to see whether the device already exists and if not I create it, store it in the map, and then pass the message into the device's receiving buffered channel.

This works great, and each device is being processed nicely. However, I need the device (and its goroutine) to terminate when it doesn't receive any messages for a preset amount of time. I've done this by checking in the goroutine itself how much time has passed since the last message was received, and if the goroutine is considered stale then the receiving channel is closed. But how to remove from the map?

So I passed in a pointer to the map, and I have the goroutine delete the device from the map and close the receiving channel before returning. The problem though is that at the end I'm finding that the len() function returns a value > 0, but when I output the map itself I see that it's empty.

I've written up a toy example to try to replicate the fault, and indeed I'm seeing that len() is reporting > 0 when the map is apparently empty. The last time I tried it I saw 10. The time before that 14. The time before that one, 53.

So I can replicate the fault, but I'm not sure whether the fault is with me or with Go. How is len() reporting > 0 when there are apparently no items in it?

Here's an example of how I've been able to replicate. I'm using Go v1.5.1 windows/amd64

There are two things here, as far as I'm concerned:

1. Am I managing the goroutines properly (probably not) and
2. Why does len(m) report > 0 when there are no items in it?

Thanks all

Example Code:

package main
import (
"log"
"os"
"time"
)
const (
chBuffSize        = 100             // How large the thing's channel buffer should be
thingIdleLifetime = time.Second * 5 // How long things can live for when idle
thingsToMake      = 1000            // How many things and associated goroutines to make
thingMessageCount = 10              // How many messages to send to the thing
)
// The thing that we'll be passing into a goroutine to process -----------------
type thing struct {
id string
ch chan bool
}
// Go go gadget map test -------------------------------------------------------
func main() {
// Make all of the things!
things := make(map[string]thing)
for i := 0; i < thingsToMake; i++ {
t := thing{
id: string(i),
ch: make(chan bool, chBuffSize),
}
things[t.id] = t
// Pass the thing into it's own goroutine
go doSomething(t, &things)
// Send (thingMessageCount) messages to the thing
go func(t thing) {
for x := 0; x < thingMessageCount; x++ {
t.ch <- true
}
}(t)
}
// Check the map of things to see whether we're empty or not
size := 0
for {
if size == len(things) && size != thingsToMake {
log.Println("Same number of items in map as last time")
log.Println(things)
os.Exit(1)
}
size = len(things)
log.Printf("Map size: %d\n", size)
time.Sleep(time.Second)
}
}
// Func for each goroutine to run ----------------------------------------------
//
// Takes two arguments:
// 1) the thing that it is working with
// 2) a pointer to the map of things
//
// When this goroutine is ready to terminate, it should remove the associated
// thing from the map of things to clean up after itself
func doSomething(t thing, things *map[string]thing) {
lastAccessed := time.Now()
for {
select {
case <-t.ch:
// We received a message, so extend the lastAccessed time
lastAccessed = time.Now()
default:
// We haven't received a message, so check if we're allowed to continue
n := time.Now()
d := n.Sub(lastAccessed)
if d > thingIdleLifetime {
// We've run for >thingIdleLifetime, so close the channel, delete the
// associated thing from the map and return, terminating the goroutine
close(t.ch)
delete(*things, string(t.id))
return
}
}
// Just sleep for a second in each loop to prevent the CPU being eaten up
time.Sleep(time.Second)
}
}

Just to add; in my original code this is looping forever. The program is designed to listen for TCP connections and receive and process the data, so the function that is checking the map count is running in it's own goroutine. However, this example has exactly the same symptom even though the map len() check is in the main() function and it is designed to handle an initial burst of data and then break out of the loop.

UPDATE 2015/11/23 15:56 UTC

I've refactored my example below. I'm not sure if I've misunderstood @RobNapier or not but this works much better. However, if I change thingsToMake to a larger number, say 100000, then I get lots of errors like this:

goroutine 199734 [select]:
main.doSomething(0xc0d62e7680, 0x4, 0xc0d64efba0, 0xc082016240)
C:/Users/anttheknee/go/src/maptest/maptest.go:83 +0x144
created by main.main
C:/Users/anttheknee/go/src/maptest/maptest.go:46 +0x463

I'm not sure if the problem is that I'm asking Go to do too much, or if I've made a hash of understanding the solution. Any thoughts?

package main
import (
"log"
"os"
"time"
)
const (
chBuffSize        = 100             // How large the thing's channel buffer should be
thingIdleLifetime = time.Second * 5 // How long things can live for when idle
thingsToMake      = 10000           // How many things and associated goroutines to make
thingMessageCount = 10              // How many messages to send to the thing
)
// The thing that we'll be passing into a goroutine to process -----------------
type thing struct {
id   string
ch   chan bool
done chan string
}
// Go go gadget map test -------------------------------------------------------
func main() {
// Make all of the things!
things := make(map[string]thing)
// Make a channel to receive completion notification on
doneCh := make(chan string, chBuffSize)
log.Printf("Making %d things\n", thingsToMake)
for i := 0; i < thingsToMake; i++ {
t := thing{
id:   string(i),
ch:   make(chan bool, chBuffSize),
done: doneCh,
}
things[t.id] = t
// Pass the thing into it's own goroutine
go doSomething(t)
// Send (thingMessageCount) messages to the thing
go func(t thing) {
for x := 0; x < thingMessageCount; x++ {
t.ch <- true
time.Sleep(time.Millisecond * 10)
}
}(t)
}
log.Printf("All %d things made\n", thingsToMake)
// Receive on doneCh when the goroutine is complete and clean the map up
for {
id := <-doneCh
close(things[id].ch)
delete(things, id)
if len(things) == 0 {
log.Printf("Map: %v", things)
log.Println("All done. Exiting")
os.Exit(0)
}
}
}
// Func for each goroutine to run ----------------------------------------------
//
// Takes two arguments:
// 1) the thing that it is working with
// 2) the channel to report that we're done through
//
// When this goroutine is ready to terminate, it should remove the associated
// thing from the map of things to clean up after itself
func doSomething(t thing) {
timer := time.NewTimer(thingIdleLifetime)
for {
select {
case <-t.ch:
// We received a message, so extend the timer
timer.Reset(thingIdleLifetime)
case <-timer.C:
// Timer returned so we need to exit now
t.done <- t.id
return
}
}
}

UPDATE 2015/11/23 16:41 UTC

The completed code that appears to be working properly. Do feel free to let me know if there are any improvements that could be made, but this works (sleeps are deliberate to see progress as it's otherwise too fast!)

package main
import (
"log"
"os"
"strconv"
"time"
)
const (
chBuffSize        = 100             // How large the thing's channel buffer should be
thingIdleLifetime = time.Second * 5 // How long things can live for when idle
thingsToMake      = 100000          // How many things and associated goroutines to make
thingMessageCount = 10              // How many messages to send to the thing
)
// The thing that we'll be passing into a goroutine to process -----------------
type thing struct {
id       string
receiver chan bool
done     chan string
}
// Go go gadget map test -------------------------------------------------------
func main() {
// Make all of the things!
things := make(map[string]thing)
// Make a channel to receive completion notification on
doneCh := make(chan string, chBuffSize)
log.Printf("Making %d things\n", thingsToMake)
for i := 0; i < thingsToMake; i++ {
t := thing{
id:       strconv.Itoa(i),
receiver: make(chan bool, chBuffSize),
done:     doneCh,
}
things[t.id] = t
// Pass the thing into it's own goroutine
go doSomething(t)
// Send (thingMessageCount) messages to the thing
go func(t thing) {
for x := 0; x < thingMessageCount; x++ {
t.receiver <- true
time.Sleep(time.Millisecond * 100)
}
}(t)
}
log.Printf("All %d things made\n", thingsToMake)
// Check the `len()` of things every second and exit when empty
go func() {
for {
time.Sleep(time.Second)
m := things
log.Printf("Map length: %v", len(m))
if len(m) == 0 {
log.Printf("Confirming empty map: %v", things)
log.Println("All done. Exiting")
os.Exit(0)
}
}
}()
// Receive on doneCh when the goroutine is complete and clean the map up
for {
id := <-doneCh
close(things[id].receiver)
delete(things, id)
}
}
// Func for each goroutine to run ----------------------------------------------
//
// When this goroutine is ready to terminate it should respond through t.done to
// notify the caller that it has finished and can be cleaned up. It will wait
// for `thingIdleLifetime` until it times out and terminates on it's own
func doSomething(t thing) {
timer := time.NewTimer(thingIdleLifetime)
for {
select {
case <-t.receiver:
// We received a message, so extend the timer
timer.Reset(thingIdleLifetime)
case <-timer.C:
// Timer expired so we need to exit now
t.done <- t.id
return
}
}
}

map is not thread-safe. You cannot access a map on multiple goroutines safely. You can corrupt the map, as you're seeing in this case.

Rather than allow the goroutine to modify the map, the goroutine should write their identifier to a channel before returning. The main loop should watch that channel, and when an identifier comes back, should remove that element from the map.

You'll probably want to read up on Go concurrency patterns. In particular, you may want to look at Fan-out/Fan-in. Look at the links at the bottom. The Go blog has a lot of information on concurrency.

Note that your goroutine is busy waiting to check for timeout. There's no reason for that. The fact that you "sleep(1 second)") should be a clue that there's a mistake. Instead, look at time.Timer which will give you a chan that will receive a value after some time, which you can reset.

Your problem is how you're converting numbers to strings:

        id:   string(i),

That creates a string using i as a rune (int32). For example string(65) is A. Some unequal Runes resolve to equal strings. You get a collision and close the same channel twice. See http://play.golang.org/p/__KpnfQc1V

You meant this:

		id:   strconv.Itoa(i),