Skip to content

Race using WithLazy #1426

Open
Open
@markuspeloquin

Description

Describe the bug
A race exists in the WithLazy implementation. lazyWithCore's own methods are protected from it, but since Core is embedded, methods from Core (in this case, Enabled()) do an unsynchronized read.

zap/zapcore/lazy_with.go

Lines 41 to 43 in fcf8ee5

d.Once.Do(func() {
d.Core = d.Core.With(d.fields)
})

The trace below is for v1.27.0.

==================
WARNING: DATA RACE
Read at 0x00c0092f6d80 by goroutine 29644:
  go.uber.org/zap/zapcore.(*lazyWithCore).Enabled()
      <autogenerated>:1 +0x35
  go.uber.org/zap/zapcore.(*lazyWithCore).Enabled()
      <autogenerated>:1 +0x4c
  go.uber.org/zap.(*Logger).check()
      [...]/go.uber.org/zap/logger.go:331 +0x90
  go.uber.org/zap.(*Logger).Error()
      [...]/go.uber.org/zap/logger.go:262 +0x4e
  [...]

Previous write at 0x00c0092f6d80 by goroutine 29645:
  go.uber.org/zap/zapcore.(*lazyWithCore).With.(*lazyWithCore).initOnce.func1()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:42 +0x91
  sync.(*Once).doSlow()
      /home/markusp/.local/go1.22.1/src/sync/once.go:74 +0xf0
  sync.(*Once).Do()
      /home/markusp/.local/go1.22.1/src/sync/once.go:65 +0x44
  go.uber.org/zap/zapcore.(*lazyWithCore).initOnce()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:41 +0x77
  go.uber.org/zap/zapcore.(*lazyWithCore).With()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:47 +0x30
  go.uber.org/zap/zapcore.(*lazyWithCore).Check.(*lazyWithCore).initOnce.func1()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:42 +0x7d
  sync.(*Once).doSlow()
      /home/markusp/.local/go1.22.1/src/sync/once.go:74 +0xf0
  sync.(*Once).Do()
      /home/markusp/.local/go1.22.1/src/sync/once.go:65 +0x44
  go.uber.org/zap/zapcore.(*lazyWithCore).initOnce()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:41 +0x92
  go.uber.org/zap/zapcore.(*lazyWithCore).Check()
      [...]/go.uber.org/zap/zapcore/lazy_with.go:52 +0x3a
  go.uber.org/zap.(*Logger).check()
      [...]/go.uber.org/zap/logger.go:343 +0x21e
  go.uber.org/zap.(*Logger).Error()
      [...]/go.uber.org/zap/logger.go:262 +0x4e
  [...]
==================

To Reproduce
Create a logger using WithLazy, then use it in multiple goroutines in parallel.

Expected behavior
No race.

Additional context
Personally I would fix by replacing the embedded Core with an atomic.Pointer (as gross as these are for holding interfaces).

type lazyWithCore struct {
    corePtr atomic.Pointer[Core]
    once sync.Once
    fields []Field
}
func NewLazyWith(core Core, fields []Field) Core {
    d := lazyWithCore{fields: fields}
    d.corePtr.Store(&core)
    return d
}
func (d *lazyWithCore) initOnce() Core { // Returning Core here to avoid a repeated Load and to contain the ugliness
    core := *d.corePtr.Load()
    d.once.Do(func() {
        core = core.With(d.fields)
        d.corePtr.Store(&core)
    })
    return core
}
func (d *lazyWithCore) Enabled() bool {
    // Init not needed
    return (*d.corePtr.Load()).Enabled()
}
func (d *lazyWithCore) Sync() error {
    // Init needed
    return d.initOnce().Sync()
}

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions