fix: prevent concurrent map writes in LoadPolicyLine function #627

jamesjmurtagh · 2020-10-22T03:30:05Z

I managed to create an environment in which the LoadPolicyLine function regularly causes concurrent map writes panics. Added a global sync.Mutex object that is used exclusively within the LoadPolicyLine function. Have not encountered any locks or concurrent map writes since this addition.

fatal error: concurrent map writes

goroutine 2247 [running]:
runtime.throw(0xdd5620, 0x15)
        /usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc000175278 sp=0xc000175248 pc=0x43d8d2
runtime.mapassign_faststr(0xcfd340, 0xc0001db200, 0xc0004d7fa0, 0x19, 0xc0002d1818)
        /usr/local/go/src/runtime/map_faststr.go:291 +0x3d8 fp=0xc0001752e0 sp=0xc000175278 pc=0x41be78
github.com/casbin/casbin/v2/persist.LoadPolicyLine(0xc0004d7f20, 0x1e, 0xc0002a9ce0)
        /home/example/go/pkg/mod/github.com/casbin/casbin/v2@v2.13.1/persist/adapter.go:43 +0x547 fp=0xc000175470 sp=0xc0001752e0 pc=0x9fbcc7

…oadPolicyLine function. Signed-off-by: James <james.murtagh@vorteil.io>

Signed-off-by: James <james.murtagh@vorteil.io>

nodece · 2020-10-22T04:56:44Z

@jamesjmurtagh Do you use the NewSyncedEnforcer?

nodece · 2020-10-22T05:03:38Z

I also did same things: #625.

hsluoyz · 2020-10-25T15:36:24Z

@jamesjmurtagh any update?

jamesjmurtagh · 2020-10-26T00:05:43Z

@nodece No; but I will do. Thanks!
@hsluoyz What would you like to know?

hsluoyz · 2020-10-26T01:08:36Z

@jamesjmurtagh you can try if NewSyncedEnforcer works for you.

jamesjmurtagh · 2020-10-28T01:16:51Z

I can confirm that this error still occurs when using SyncedEnforcer + gormadapter.

fatal error: concurrent map writes

goroutine 16 [running]:
runtime.throw(0xdec547, 0x15)
	/usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc000787178 sp=0xc000787148 pc=0x43d752
runtime.mapassign_faststr(0xd120a0, 0xc000696d20, 0xc0003fe0f0, 0x22, 0xc0001c79b8)
	/usr/local/go/src/runtime/map_faststr.go:211 +0x3f1 fp=0xc0007871e0 sp=0xc000787178 pc=0x41be51
github.com/casbin/casbin/v2/persist.LoadPolicyLine(0xc0003fe060, 0x27, 0xc0001add10)
	/home/example/go/pkg/mod/github.com/casbin/casbin/v2@v2.14.2/persist/adapter.go:43 +0x547 fp=0xc000787370 sp=0xc0007871e0 pc=0xa89907
github.com/casbin/gorm-adapter/v3.loadPolicyLine(0x0, 0x0, 0x0, 0x0, 0xc0005ac140, 0x1, 0xc0005ac141, 0xd, 0xc0005ac150, 0xe, ...)
	/home/example/go/pkg/mod/github.com/casbin/gorm-adapter/v3@v3.0.3/adapter.go:301 +0x18c fp=0xc000787428 sp=0xc000787370 pc=0xb3a78c
github.com/casbin/gorm-adapter/v3.(*Adapter).LoadPolicy(0xc000182000, 0xc0001add10, 0xd53f80, 0xdb6b00)
	/home/example/go/pkg/mod/github.com/casbin/gorm-adapter/v3@v3.0.3/adapter.go:312 +0x148 fp=0xc000787580 sp=0xc000787428 pc=0xb3aaa8
github.com/casbin/casbin/v2.(*Enforcer).LoadPolicy(0xc0001820e0, 0x7fdd6c16f200, 0xc000182000)
	/home/example/go/pkg/mod/github.com/casbin/casbin/v2@v2.14.2/enforcer.go:247 +0x53 fp=0xc0007875c0 sp=0xc000787580 pc=0xa8f053
github.com/casbin/casbin/v2.(*Enforcer).InitWithModelAndAdapter(0xc0001820e0, 0xc0001add10, 0x7fdd6c16f2b8, 0xc000182000, 0xc000182000, 0x7fdd969aee98)
	/home/example/go/pkg/mod/github.com/casbin/casbin/v2@v2.14.2/enforcer.go:158 +0xea fp=0xc000787600 sp=0xc0007875c0 pc=0xa8ea2a
github.com/casbin/casbin/v2.NewEnforcer(0xc000787718, 0x2, 0x2, 0xc000182000, 0x0, 0x0)
	/home/example/go/pkg/mod/github.com/casbin/casbin/v2@v2.14.2/enforcer.go:95 +0x3ce fp=0xc000787698 sp=0xc000787600 pc=0xa8e4ae
github.com/casbin/casbin/v2.NewSyncedEnforcer(0xc000787718, 0x2, 0x2, 0x0, 0x5cd391006e18, 0x472300)

go.mod file:

github.com/casbin/casbin/v2 v2.14.2
github.com/casbin/gorm-adapter/v3 v3.0.3

In this case, when created a new SyncedEnforcer, the adapter (gorm-adapter, in this case) will ultimately call github.com/casbin/casbin/v2/persist.LoadPolicyLine which panics due to a concurrent map write. With the changes proposed in this pull request, I am able to avoid the issue.

hsluoyz · 2020-10-28T01:25:43Z

LoadPolicyLine() is called in a for loop in a single thread way:

https://github.com/casbin/gorm-adapter/blob/dcbefd9ab8a71b76ce1c4e078878c861a36e63b2/adapter.go#L301-L313

Why does it cause contention?

jamesjmurtagh · 2020-10-28T01:30:35Z

In my case, the logic that is calling NewSyncedEnforcer is triggered by a REST request; perhaps multiple requests being called simultaneously is the cause. The proposed solution should mitigate the chances of simultaneous calls triggering the panic while not affecting single-threaded performance, I think.

hsluoyz · 2020-10-28T01:35:09Z

It's a bad way to load policy for each RESTful call. Please load policy at initial time only once.

jamesjmurtagh · 2020-10-28T01:39:00Z

I call NewSyncedEnforcer (not LoadPolicy directly) because I need to provide the gorm transaction (in case the operation needs to be rolled back or committed) at that time. I'm not sure what the alternative is.

Edit: I've noticed that the Enforcer has a SetAdapater function, which I could use to pass it a gormadapter that uses the correct transaction, but that sounds like it has the potential to introduce new thread-safety issues if multiple requests are being received simultaneously.

nodece · 2020-10-28T07:16:24Z

@jamesjmurtagh Casbin will call LoadPolicy automatically when you call NewSyncedEnforcer.

hsluoyz · 2020-10-28T11:08:08Z

@jamesjmurtagh can you provide a full minimized reproducible example code repo?

Glitchfix · 2021-06-22T21:21:22Z

I had the same issue, found out that I was using p_type column name in my table while it was trying to pick it from ptype

Paxa · 2021-07-06T07:43:50Z

I've got this error too, when sending multiple requests to our app at once

Glitchfix · 2021-07-06T09:38:13Z

@Paxa can you check if the column names are as intended, I had a column name mismatch earlier.

hsluoyz · 2021-07-07T01:34:23Z

@Paxa @Glitchfix which adapter (github repo) and version tag do you use?

hsluoyz · 2021-07-07T01:34:37Z

@closetool @tangyang9464

Paxa · 2021-07-09T07:57:11Z

github.com/casbin/casbin/v2 v2.28.2

hsluoyz · 2021-07-09T08:51:39Z

@Paxa which adapter? (and version tag)

Paxa · 2021-07-09T16:01:27Z

I use github.com/casbin/gorm-adapter/v3 latest version, in our web application we use one object of enforcer in process and call enforcer.LoadPolicy() on each request (because permissions in database can change at any moment)

enforcer.LoadPolicy can have race condition when it's called multiple times at once. At this line:

casbin/persist/adapter.go

Line 43 in 277c1a2

    
           m[sec][key].PolicyMap[strings.Join(tokens[1:], model.DefaultSep)] = len(m[sec][key].Policy) - 1

runtime.throw(0x206cbb6, 0x15)
	/usr/local/Cellar/go/1.15.3/libexec/src/runtime/panic.go:1116 +0x72 fp=0xc000f03208 sp=0xc000f031d8 pc=0x1039132
runtime.mapassign_faststr(0x1e8d780, 0xc000b10a20, 0xc001309d20, 0xf, 0xc0000cd8e8)
	/usr/local/Cellar/go/1.15.3/libexec/src/runtime/map_faststr.go:211 +0x3f1 fp=0xc000f03270 sp=0xc000f03208 pc=0x1016b31
github.com/casbin/casbin/v2/persist.LoadPolicyLine(0xc000a47140, 0x14, 0xc0002a3d70)
	/Users/pavel/go/pkg/mod/github.com/casbin/casbin/v2@v2.28.3/persist/adapter.go:43 +0x547 fp=0xc000f03400 sp=0xc000f03270 pc=0x1552667
github.com/casbin/gorm-adapter/v3.loadPolicyLine(0x4, 0x2a5bfc0, 0x1, 0xc000c1a068, 0x5, 0xc000c1a070, 0x5, 0xc000c1a075, 0x3, 0x0, ...)
	/Users/pavel/go/pkg/mod/github.com/casbin/gorm-adapter/v3@v3.3.1/adapter.go:417 +0x18c fp=0xc000f034b8 sp=0xc000f03400 pc=0x17a3f4c
github.com/casbin/gorm-adapter/v3.(*Adapter).LoadPolicy(0xc000a282a0, 0xc0002a3d70, 0x2, 0xc000e9e004)
	/Users/pavel/go/pkg/mod/github.com/casbin/gorm-adapter/v3@v3.3.1/adapter.go:428 +0x191 fp=0xc000f035e0 sp=0xc000f034b8 pc=0x17a42b1
github.com/casbin/casbin/v2.(*Enforcer).LoadPolicy(0xc000b09280, 0xc0007da690, 0xc000ba22d0)
	/Users/pavel/go/pkg/mod/github.com/casbin/casbin/v2@v2.28.3/enforcer.go:275 +0x53 fp=0xc000f03620 sp=0xc000f035e0 pc=0x1559553
my-repo.io/my-app/service.(*accessService).GetRolesForUser(0xc000118540, 0xc000ac6180, 0x10, 0x1e8b500, 0xc0010bc450, 0x0)

But I think casbin solution doesn't fit our needs because it always loads all policies in memory and it takes ~180ms (with current data), and I expect the time to load will increase when we have more users in database. Or we need to think of additional mechanism to maintain in-memory cache updated. Also other race condition when 1 request is reloading policies while other request use enforcer for validation (may be I'm using it wrong, please suggest how to make it better)

hsluoyz · 2021-07-09T16:11:32Z

@Paxa you can use watcher and filters to optimize your case, see: https://casbin.org/docs/en/performance

hsluoyz · 2021-07-09T16:13:04Z

Edit: I've noticed that the Enforcer has a SetAdapater function, which I could use to pass it a gormadapter that uses the correct transaction, but that sounds like it has the potential to introduce new thread-safety issues if multiple requests are being received simultaneously.

You should init the enforcer at your program start.

hsluoyz · 2021-07-09T16:15:20Z

I had the same issue, found out that I was using p_type column name in my table while it was trying to pick it from ptype

@Glitchfix for gorm adapter, we have changed the column name from p_type to ptype from v3.1.0 in this PR: casbin/gorm-adapter#67

hsluoyz · 2021-07-09T16:17:10Z

@Glitchfix @Paxa I think our discussion has deviated from the topic of this PR. This PR will be closed for now. And plz make new issues to the correct repos if you still have any questions.

James added 3 commits October 22, 2020 13:30

Add a sync.Mutex object to prevent concurrent map writes within the L…

6ffc779

…oadPolicyLine function. Signed-off-by: James <james.murtagh@vorteil.io>

fix: prevent concurrent map writes in LoadPolicyLine function

be9a9fb

Signed-off-by: James <james.murtagh@vorteil.io>

fix: prevent concurrent map writes in LoadPolicyLine function

fd5d03c

Signed-off-by: James <james.murtagh@vorteil.io>

hsluoyz closed this Jul 9, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: prevent concurrent map writes in LoadPolicyLine function #627

fix: prevent concurrent map writes in LoadPolicyLine function #627

jamesjmurtagh commented Oct 22, 2020

nodece commented Oct 22, 2020

nodece commented Oct 22, 2020

hsluoyz commented Oct 25, 2020

jamesjmurtagh commented Oct 26, 2020

hsluoyz commented Oct 26, 2020

jamesjmurtagh commented Oct 28, 2020 •

edited

hsluoyz commented Oct 28, 2020

jamesjmurtagh commented Oct 28, 2020

hsluoyz commented Oct 28, 2020

jamesjmurtagh commented Oct 28, 2020 •

edited

nodece commented Oct 28, 2020

hsluoyz commented Oct 28, 2020

Glitchfix commented Jun 22, 2021

Paxa commented Jul 6, 2021

Glitchfix commented Jul 6, 2021

hsluoyz commented Jul 7, 2021

hsluoyz commented Jul 7, 2021

Paxa commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

Paxa commented Jul 9, 2021 •

edited

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

fix: prevent concurrent map writes in LoadPolicyLine function #627

fix: prevent concurrent map writes in LoadPolicyLine function #627

Conversation

jamesjmurtagh commented Oct 22, 2020

nodece commented Oct 22, 2020

nodece commented Oct 22, 2020

hsluoyz commented Oct 25, 2020

jamesjmurtagh commented Oct 26, 2020

hsluoyz commented Oct 26, 2020

jamesjmurtagh commented Oct 28, 2020 • edited

hsluoyz commented Oct 28, 2020

jamesjmurtagh commented Oct 28, 2020

hsluoyz commented Oct 28, 2020

jamesjmurtagh commented Oct 28, 2020 • edited

nodece commented Oct 28, 2020

hsluoyz commented Oct 28, 2020

Glitchfix commented Jun 22, 2021

Paxa commented Jul 6, 2021

Glitchfix commented Jul 6, 2021

hsluoyz commented Jul 7, 2021

hsluoyz commented Jul 7, 2021

Paxa commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

Paxa commented Jul 9, 2021 • edited

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

hsluoyz commented Jul 9, 2021

jamesjmurtagh commented Oct 28, 2020 •

edited

jamesjmurtagh commented Oct 28, 2020 •

edited

Paxa commented Jul 9, 2021 •

edited