Race(?) with Mutex - corrupt data in map

Question

In a project I want to use a cache to store things like a hash. However, it happens from time to time that the stored value in the cache changes to the key. Usually around 4 characters from the key are taken over:

<- Set hash::helloworldtest = abcdef0123456789
-> Get hash::helloworldtest = testef0123456789

This is roughly how my cache is structured:

type node struct {
    expires nodeExpiration
    value   interface{}
}

// ...

func (c *Cache) Set(key string, value interface{}, expiration time.Duration) {
    c.mu.Lock()
    c.val[key] = &node{
        expires: c.expiration(expiration),
        value:   value,
    }
    // fmt.Println( ... )
    c.mu.Unlock()
}

func (c *Cache) Get(key string) (interface{}, bool) {
    c.mu.Lock()
    if v, o := c.val[key]; o && v != nil {
        if !v.expires.IsExpired() {
            // fmt.Println( ... )
            c.mu.Unlock()
            return v.value, true
        }
    }
    c.mu.Unlock()
    return nil, false
}

// Cache Backend
func (b *CacheBackend) GetHash(key string) (res string, err error) {
    return b.get("hash::" + key)
}
func (b *CacheBackend) get(key string) (res string, err error) {
    if v, ok := b.cache.Get(key); ok {
        if s, ok := v.(string); ok {
            return s, nil
        }
        return "", b.errCast
    }
    return "", nil
}

// go-fiber Route
func (s *WebServer) handleGetHashAnywhere(ctx *fiber.Ctx) (err error) {
    path := ctx.Params("anywhere")
    var res string
    if res, err = s.Backend.GetHash(path); err != nil {
        return
    }
    if res == "" {
        ctx.Status(404)
    } else {
        ctx.Status(200)
    }
    return ctx.SendString(res)
}

I was using a sync.RWMutex before, but replaced it with a sync.Mutex, thinking that might be where the problem was. But same with sync.Mutex.

The Get and Set methods are called in a goroutine by go-fiber to then return these values.

Does anyone have any idea how something like this can happen?

EDIT 1: Saving []byte instead of string works fine.

Are you sure there's no other go routines accessing the cache and setting the value? I would guess this is not an issue with the kind of mutex you're using — kolaente, Apr 03 '21 at 11:05
@kolaente Yes, I have included extra debug messages (as visible in the image) when the Get or Set method is called. — Daniel, Apr 03 '21 at 11:12
What does your map look like, just a regular `map[string]interface{}`? — kolaente, Apr 03 '21 at 11:20
@kolaente Yes. Here is my cache.go file: https://gist.github.com/df7a7bda169e9814a4a6272437494a1d — Daniel, Apr 03 '21 at 11:24
Could it be a pointer issue where the value you're putting in the new `node.value` is a point to some value elsewhere which then gets changed? — kolaente, Apr 03 '21 at 11:33
I actually just write a string to the cache, which is why I don't assume it. But I'll change the type of node from `interface{}` to `string`. I'll get back to you in a moment. // EDIT: Same error when using string as the node type... https://gist.github.com/darmiel/1217661c18e215f9b7fe817011d3916a — Daniel, Apr 03 '21 at 11:35
@Daniel do you see the issue only in debug logs or do you see it also in the client that communicates with your go-fiber app? If you see the issue *only* when logging to stdout then that might be the problem, printing to stdout should not be considered safe for concurrency. See here: https://stackoverflow.com/questions/14694088/is-it-safe-for-more-than-one-goroutine-to-print-to-stdout. Another thing I'm wondering is whether or not you still see the issue if you disable the janitor. — mkopriva, Apr 03 '21 at 12:25
@mkopriva Yes, the problem also appears with the client. I rewrite the program again and disable the Janitor. I'll get back to you in a moment. // EDIT: Disabling janitor does not affect this issue. — Daniel, Apr 03 '21 at 12:54
@Daniel have you tried building the app with [the race detector](https://golang.org/doc/articles/race_detector)? i.e. `go build -race mycmd`. — mkopriva, Apr 03 '21 at 14:06

score 2 · Accepted Answer · answered May 09 '21 at 10:57

Thanks to @majodev the problem was finally fixed properly.

The problem is described in the documentation under Zero Allocation. An excerpt:

Because fiber is optimized for high-performance, values returned from fiber.Ctx are not immutable by default and will be re-used across requests. [...] As soon as you return from the handler, any values you have obtained from the context will be re-used in future requests and will change below your feet.

So the context values must be copied, or the "Immutable" flag must be passed in the fiber config.

1st Solution:
New buffer from read values and copy its contents

buf := bytes.NewBufferString(ctx.Params("hash"))
hash := string(buf.Bytes())

2nd Solution:
Use builtin function utils#CopyString(string) described here.

hash := utils.CopyString(ctx.Params("hash"))

3rd Solution:
Immutable config flag

cfg := &fiber.Config{Immutable: true}

then everything works.

Race(?) with Mutex - corrupt data in map

1 Answers1