log
log copied to clipboard
fatal error: concurrent map iteration and map write
We experienced a crash today that I'm having trouble diagnosing. The error occurred when calling logger.Info
inside a goroutine. There were several parallel tasks, all which log when they complete. This code has been running, unchanged for months and I don't believe we've had any issues before.
Are logger.WithField
and logger.WithError
intended to be threadsafe?
Thanks in advance.
The error occurs at line 155 in (e *Entry) mergedFields
151 func (e *Entry) mergedFields() Fields {
152 f := Fields{}
153
154 for _, fields := range e.fields {
155 for k, v := range fields {
156 f[k] = v
157 }
158 }
159
160 return f
161 }
/usr/lib/golang/src/runtime/panic.go:617 +0x72 fp=0xc001167d48 sp=0xc001167d18 pc=0x43a112
runtime.mapiternext(0xc001167e28)
/usr/lib/golang/src/runtime/map.go:860 +0x597 fp=0xc001167dd0 sp=0xc001167d48 pc=0x41ccd7
vendor/github.com/apex/log.(*Entry).mergedFields(0xc00017d260, 0x14)
/go/src/vendor/github.com/apex/log/entry.go:155 +0x6c fp=0xc001167e98 sp=0xc001167dd0 pc=0x77aeac
vendor/github.com/apex/log.(*Entry).finalize(0xc00017d260, 0x1, 0x1779ed3, 0x1c, 0x0)
/go/src/vendor/github.com/apex/log/entry.go:167 +0x2f fp=0xc001167ee0 sp=0xc001167e98 pc=0x77afef
vendor/github.com/apex/log.(*Logger).log(0x2978830, 0x1, 0xc00017d260, 0x1779ed3, 0x1c)
/go/src/vendor/github.com/apex/log/logger.go:146 +0x5c fp=0xc001167f28 sp=0xc001167ee0 pc=0x77c31c
vendor/github.com/apex/log.(*Entry).Info(...)
hmm yea definitely should be, sounds like a bug to me, thanks for reporting!
Just an FYI that we're seeing this regularly now. A refinement on the original data, the code is essentially calling logger.Info("...")
from multiple goroutines.
I have some more info about how this bug occurs:
- We have a function that calls
logger.WithFields(fields)
in order to create thelogger
instance that is shared between multiple goroutines. - Calls to
logger.Info(...)
may then run concurrently with other code that writes additional keys/values to thatfields
instance. - Since
fields
is alog.Fields
, which is implemented with a map underneath, if a read and a write collide, we can get this error. It's not safe to concurrently read from and write to a map (as I learned today while investigating this).
We can address this in our own code by ensuring that fields
is never written to after it's used to make a logger
(by copying it).
But I wonder if it would also make sense to prevent this type of mistake at the apex/log level?
- Perhaps
func (f Fields) Fields() Fields
should make a shallow copy of the underlying map instead of just returning theFields
struct? - Or perhaps
func (e *Entry) WithFields(fields Fielder) *Entry
should make a copy offields.Fields()
before appending it to the list of fields objects?
Either of those options would ensure that no further writes to a fields map can occur that would be concurrent with a call to log something.
Hi, opening a PR to fix the issue, please let me know if there's anything to improve there :)