logrus icon indicating copy to clipboard operation
logrus copied to clipboard

fix for "fatal error: concurrent map iteration and map write"

Open javarange opened this issue 7 years ago • 16 comments

I've seen race condition issue during testing logrus with hook.

So to isolate the issue, I've made a test program that can cause "fatal error", and add PR for fixing it.

Thanks.

=========== logrus_fatalerror.go.txt

_fatal error: concurrent map iteration and map write

goroutine 6 [running]: runtime.throw(0x10f4c35, 0x26) /usr/local/go/src/runtime/panic.go:605 +0x95 fp=0xc420071c48 sp=0xc420071c28 pc=0x1027a65 runtime.mapiternext(0xc420071de8) /usr/local/go/src/runtime/hashmap.go:778 +0x6f1 fp=0xc420071ce0 sp=0xc420071c48 pc=0x1009251 github.com/Sirupsen/logrus.(*JSONFormatter).Format(0xc42000a080, 0xc420084730, 0xc42000a060, 0x10e7a20, 0xc420092000, 0x0, 0x0) /Users/javarange/GOLANG/src/github.com/Sirupsen/logrus/json_formatter.go:51 +0xe5 fp=0xc420071e58 sp=0xc420071ce0 pc=0x10b28e5 github.com/Sirupsen/logrus.Entry.log(0xc420084190, 0xc42007c2d0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x4, ...) /Users/javarange/GOLANG/src/github.com/Sirupsen/logrus/entry.go:109 +0x22c fp=0xc420071f28 sp=0xc420071e58 pc=0x10b1e2c github.com/Sirupsen/logrus.(*Entry).Info(0xc420084230, 0xc420071fb8, 0x1, 0x1) /Users/javarange/GOLANG/src/github.com/Sirupsen/logrus/entry.go:144 +0xac fp=0xc420071f98 sp=0xc420071f28 pc=0x10b22ec main.(*Mystruct).f2(0xc42000a0a0) /Users/javarange/Work/FM/logrus_panic/logrus_fatalerror.go:91 +0x75 fp=0xc420071fd8 sp=0xc420071f98 pc=0x10b6045_

javarange avatar Nov 07 '17 23:11 javarange

Is this fix still valid? I'm getting these panics fairly often. When I look at the current version of entry.go it's quite different that this version. Any other help with this panics???

rickw avatar May 21 '18 02:05 rickw

Yes, I tried and it is valid. Working without any errors. Good Job

nishitm avatar Jun 18 '18 03:06 nishitm

Have this issue with the latest release.

krasoffski avatar Apr 13 '20 12:04 krasoffski

I'm also experiencing this with 1.7.0

sjurtf avatar Oct 16 '20 10:10 sjurtf

Experiencing this too, would be nice to have this PR merged! :)

cmaster11 avatar Nov 11 '20 13:11 cmaster11

Just noticed this today. Any luck getting this merged if it's updated?

epelc avatar Jan 20 '21 04:01 epelc

Same issue here, could it be merged ?

ArkaGPL avatar Apr 14 '21 17:04 ArkaGPL

i have the same issue, please merge

MarcelEdmundFranke avatar Apr 27 '21 18:04 MarcelEdmundFranke

@sirupsen please review

MarcelEdmundFranke avatar Apr 27 '21 18:04 MarcelEdmundFranke

Hello? :)

MarcelEdmundFranke avatar May 06 '21 15:05 MarcelEdmundFranke

The root cause that cause this on my side was logging and concurrently modifying the data (d'oh, I could've read that in the error message!). It was a very rare bug, but it ultimately reared its head in forms other than logging. The erroneous code looked something like this:

func process(b []byte) {
    var modifierMap map[string]interface{}
    _ = json.Unmarshal(b, &modifierMap)
    go func() {
        logrus.WithField("incoming map", modifierMap).Info("started processing A")
        // ... further processing
    }()
    modifierMap["ID"] = "bar" // or new UUID or some similar edit
   
    // ... any further processing
}

My solution was to deep copy the map before handing it off to a goroutine that read/logged it, basically the same as this PR suggests. IMO this is an acceptable tradeoff for clients to make and I'm not sure the logging framework should impose the penalty of deep copying a map within itself.

raidancampbell avatar May 07 '21 01:05 raidancampbell

@sirupsen could you please pay attention to this bug? cause it's really important, looks like all stuff related to thread safety in logrus with this bug is unusable at all.

quenbyako avatar May 14 '21 13:05 quenbyako

@quenbyako the code has changed a lot since this MR. The latest v1.8.1 should contain fixes for this kind of issue. Do you have a reproducible test case which exhibits the issue.

dgsb avatar May 15 '21 08:05 dgsb

this is happening to me as well in version 1.8.1

OrlandoBitencourt avatar Jul 28 '22 19:07 OrlandoBitencourt

@dgsb

OrlandoBitencourt avatar Jul 28 '22 19:07 OrlandoBitencourt

Is there no other way of solving this that doesn't require a full copy of the map? Can you still reproduce it?

sirupsen avatar Jul 29 '22 13:07 sirupsen