Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"fatal error: concurrent map writes" panic, unable to reproduce #551

Closed
AlbinoDrought opened this issue Oct 6, 2020 · 1 comment · Fixed by #552
Closed

"fatal error: concurrent map writes" panic, unable to reproduce #551

AlbinoDrought opened this issue Oct 6, 2020 · 1 comment · Fixed by #552
Assignees
@aeneasr
Labels
bug Something is not working. corp/m2 Up for M2 at Ory Corp.
Milestone
v0.39.0

Comments

@AlbinoDrought
Copy link
Contributor

Describe the bug

Oathkeeper crashed with the message "fatal error: concurrent map writes". This crash happened in a dev environment two requests after container boot. Oathkeeper was being used in proxy mode.

Reproducing the bug

Steps to reproduce the behavior:

I have not been able to reproduce this issue reliably. I am hoping the stack trace is useful enough to diagnose and resolve the issue. If not and it keeps happening, I will report back.

Server logs

time=2020-10-06T23:10:04Z level=info msg=Config file loaded successfully. audience=application path=/oathkeeper-dev/config.yaml service_name=oathkeeper service_version=
Thank you for using ORY Oathkeeper master!

Take security seriously and subscribe to the ORY Security Newsletter. Stay on top of new patches and security insights.                                                                                                

>> Subscribe now: http://eepurl.com/di390P <<
time=2020-10-06T23:10:04Z level=info msg=No tracer configured - skipping tracing setup audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:04Z level=info msg=Listening on http://:9000 audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:04Z level=info msg=TLS has not been configured for api, skipping audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:04Z level=info msg=Listening on http://:4456 audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:04Z level=info msg=TLS has not been configured for proxy, skipping audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:04Z level=info msg=Listening on http://:4455 audience=application service_name=ORY Oathkeeper service_version=master
time=2020-10-06T23:10:39Z level=info msg=started handling request http_request=map[headers:map[accept:application/json, text/plain, */* accept-encoding:gzip, deflate accept-language:en-US,en;q=0.5 cookie:snip referer:http://localhost:8080/ user-agent:Mozilla/5.0 (X11; Linux x86_64; rv:81.0) Gecko/20100101 Firefox/81.0 x-forwarded-for:127.0.0.1 x-forwarded-proto:http] host:localhost method:GET path:/api/v1/ecu/makes/BMW/years query:<nil> remote:172.18.0.1:32968 scheme:http]
time=2020-10-06T23:10:39Z level=info msg=started handling request http_request=map[headers:map[accept:application/json, text/plain, */* accept-encoding:gzip, deflate accept-language:en-US,en;q=0.5 cookie:snip referer:http://localhost:8080/ user-agent:Mozilla/5.0 (X11; Linux x86_64; rv:81.0) Gecko/20100101 Firefox/81.0 x-forwarded-for:127.0.0.1 x-forwarded-proto:http] host:localhost method:GET path:/api/v1/ecu/makes query:<nil> remote:172.18.0.1:32970 scheme:http]
fatal error: concurrent map writes
fatal error: concurrent map writes

goroutine 479 [running]:
runtime.throw(0xec17be, 0x15)
	/usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc0007ae3a0 sp=0xc0007ae370 pc=0x42f532
runtime.mapassign_faststr(0xd7b680, 0xc0004a0990, 0xc00057a460, 0x20, 0x16c9de0)
	/usr/local/go/src/runtime/map_faststr.go:291 +0x3fe fp=0xc0007ae408 sp=0xc0007ae3a0 pc=0x41338e
text/template.(*Template).associate(0xc0003f36c0, 0xc0003f36c0, 0xc00032d000, 0xc000119201)
	/usr/local/go/src/text/template/template.go:226 +0xb7 fp=0xc0007ae448 sp=0xc0007ae408 pc=0x7b0b27
text/template.(*Template).AddParseTree(0xc0003f36c0, 0xc00057a460, 0x20, 0xc00032d000, 0x0, 0x0, 0x0)
	/usr/local/go/src/text/template/template.go:132 +0xf9 fp=0xc0007ae498 sp=0xc0007ae448 pc=0x7afe59
text/template.(*Template).Parse(0xc0003f36c0, 0xc0008ca280, 0x47, 0x20, 0x16c9de0, 0x0)
	/usr/local/go/src/text/template/template.go:207 +0x1df fp=0xc0007ae598 sp=0xc0007ae498 pc=0x7b085f
github.com/ory/oathkeeper/pipeline/mutate.(*MutatorIDToken).Mutate(0xc0004cc3c0, 0xc00032cd00, 0xc0003f2f40, 0x0, 0x0, 0x0, 0x1026d00, 0xc000538380, 0x0, 0x0)
	/app/pipeline/mutate/mutator_id_token.go:155 +0xe61 fp=0xc0007ae770 sp=0xc0007ae598 pc=0xc20071
github.com/ory/oathkeeper/proxy.(*RequestHandler).HandleRequest(0xc000a0c9a0, 0xc00032cd00, 0xc000538380, 0x1002d18, 0xdebfe0, 0xc000538380)
	/app/proxy/request_handler.go:318 +0x8d7 fp=0xc0007aec40 sp=0xc0007ae770 pc=0xc88607
github.com/ory/oathkeeper/proxy.(*Proxy).Director(0xc000124000, 0xc00032cd00)
	/app/proxy/proxy.go:134 +0x559 fp=0xc0007af380 sp=0xc0007aec40 pc=0xc84e79
github.com/ory/oathkeeper/proxy.(*Proxy).Director-fm(0xc00032cd00)
	/app/proxy/proxy.go:125 +0x34 fp=0xc0007af3a0 sp=0xc0007af380 pc=0xc97054
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc000656050, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/usr/local/go/src/net/http/httputil/reverseproxy.go:206 +0x149 fp=0xc0007af660 sp=0xc0007af3a0 pc=0x9f4549
github.com/urfave/negroni.Wrap.func1(0x7faee7c77320, 0xc0005a8038, 0xc00032cc00, 0xc000a0c860)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:46 +0x4d fp=0xc0007af690 sp=0xc0007af660 pc=0xb1baad
github.com/urfave/negroni.HandlerFunc.ServeHTTP(0xc000364200, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00, 0xc000a0c860)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:29 +0x4e fp=0xc0007af6c0 sp=0xc0007af690 pc=0xb1a52e
github.com/urfave/negroni.middleware.ServeHTTP(0x101e8e0, 0xc000364200, 0xc000364300, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007af6f8 sp=0xc0007af6c0 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007af738 sp=0xc0007af6f8 pc=0xb1be3a
github.com/ory/x/reqlog.(*Middleware).ServeHTTP(0xc0000fe460, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00, 0xc000a0c7e0)
	/go/pkg/mod/github.com/ory/[email protected]/reqlog/middleware.go:138 +0x308 fp=0xc0007af800 sp=0xc0007af738 pc=0xb43088
github.com/urfave/negroni.middleware.ServeHTTP(0x101cd00, 0xc0000fe460, 0xc000364260, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007af838 sp=0xc0007af800 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007af878 sp=0xc0007af838 pc=0xb1be3a
github.com/ory/oathkeeper/metrics.(*Middleware).ServeHTTP(0xc000656140, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00, 0xc000a0c7c0)
	/app/metrics/middleware.go:88 +0xa1 fp=0xc0007af910 sp=0xc0007af878 pc=0xc91f01
github.com/urfave/negroni.middleware.ServeHTTP(0x101cbc0, 0xc000656140, 0xc000364240, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007af948 sp=0xc0007af910 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007af988 sp=0xc0007af948 pc=0xb1be3a
github.com/ory/x/metricsx.(*Service).ServeHTTP(0xc00045a910, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00, 0xc000a0c7a0)
	/go/pkg/mod/github.com/ory/[email protected]/metricsx/middleware.go:261 +0x92 fp=0xc0007afb80 sp=0xc0007af988 pc=0xb41892
github.com/urfave/negroni.middleware.ServeHTTP(0x101ccc0, 0xc00045a910, 0xc000364220, 0x7faee7c77320, 0xc0005a8038, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007afbb8 sp=0xc0007afb80 pc=0xb1a5dc
github.com/urfave/negroni.(*Negroni).ServeHTTP(0xc000012c30, 0x1031500, 0xc0005380e0, 0xc00032cc00)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:96 +0xeb fp=0xc0007afc18 sp=0xc0007afbb8 pc=0xb1a99b
net/http.serverHandler.ServeHTTP(0xc000538000, 0x1031500, 0xc0005380e0, 0xc00032cc00)
	/usr/local/go/src/net/http/server.go:2831 +0xa4 fp=0xc0007afc48 sp=0xc0007afc18 pc=0x6f41d4
net/http.(*conn).serve(0xc0007a61e0, 0x1034b80, 0xc0003f2540)
	/usr/local/go/src/net/http/server.go:1919 +0x875 fp=0xc0007affc8 sp=0xc0007afc48 pc=0x6efb75
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0007affd0 sp=0xc0007affc8 pc=0x45efd1
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2957 +0x384

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc0002f4aa8)
	/usr/local/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc0002f4aa0)
	/usr/local/go/src/sync/waitgroup.go:130 +0x64
github.com/ory/oathkeeper/cmd/server.RunServe.func1(0x168f5a0, 0xc0005d2a20, 0x0, 0x2)
	/app/cmd/server/server.go:245 +0xa8f
github.com/ory/oathkeeper/cmd.glob..func8(0x168f5a0, 0xc0005d2a20, 0x0, 0x2)
	/app/cmd/serve.go:49 +0xe9
github.com/spf13/cobra.(*Command).execute(0x168f5a0, 0xc0005d29e0, 0x2, 0x2, 0x168f5a0, 0xc0005d29e0)
	/go/pkg/mod/github.com/spf13/[email protected]/command.go:846 +0x2aa
github.com/spf13/cobra.(*Command).ExecuteC(0x1690800, 0xeb756f, 0x9, 0x0)
	/go/pkg/mod/github.com/spf13/[email protected]/command.go:950 +0x349
github.com/spf13/cobra.(*Command).Execute(...)
	/go/pkg/mod/github.com/spf13/[email protected]/command.go:887
github.com/ory/oathkeeper/cmd.Execute()
	/app/cmd/root.go:51 +0x31
main.main()
	/app/main.go:31 +0x5a

goroutine 18 [select]:
github.com/dgraph-io/ristretto.(*defaultPolicy).processItems(0xc0001217a0)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:96 +0xbe
created by github.com/dgraph-io/ristretto.newDefaultPolicy
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:80 +0x129

goroutine 7 [syscall]:
os/signal.signal_recv(0x6e6f697470697263)
	/usr/local/go/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
	/usr/local/go/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
	/usr/local/go/src/os/signal/signal_unix.go:29 +0x41

goroutine 47 [chan receive]:
github.com/ory/graceful.Graceful.func1(0xc00053c000, 0xc00009f0e0, 0xc00053c060)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:62 +0xc8
created by github.com/ory/graceful.Graceful
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:59 +0x98

goroutine 472 [IO wait]:
internal/poll.runtime_pollWait(0x7faee7c33570, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00049a018, 0x72, 0x0, 0x0, 0xeb60da)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc00049a000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc00049a000, 0xc000625ab0, 0xc000282380, 0x7faeea090b28)
	/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00000c060, 0xc000625ae0, 0x40c9a8, 0x30)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc00000c060, 0xe2f860, 0xc0001941b0, 0xd87380, 0x1683c40)
	/usr/local/go/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc000520000, 0x1031240, 0xc00000c060, 0x0, 0x0)
	/usr/local/go/src/net/http/server.go:2925 +0x280
net/http.(*Server).ListenAndServe(0xc000520000, 0x4, 0xec21b2)
	/usr/local/go/src/net/http/server.go:2854 +0xb7
github.com/ory/oathkeeper/cmd/server.runAPI.func1.1(0x18, 0xf084e8)
	/app/cmd/server/server.go:112 +0x185
github.com/ory/graceful.Graceful(0xc000625f30, 0xc0002840c0, 0xc000033a40, 0x0)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:76 +0xa2
github.com/ory/oathkeeper/cmd/server.runAPI.func1()
	/app/cmd/server/server.go:106 +0xa3d
github.com/ory/oathkeeper/cmd/server.RunServe.func1.1(0xc0002f4aa0, 0xc000213560)
	/app/cmd/server/server.go:242 +0x57
created by github.com/ory/oathkeeper/cmd/server.RunServe.func1
	/app/cmd/server/server.go:240 +0xa70

goroutine 467 [select]:
github.com/dgraph-io/ristretto.(*Cache).processItems(0xc0005da240)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:299 +0xed
created by github.com/dgraph-io/ristretto.NewCache
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:162 +0x22a

goroutine 239 [syscall]:
syscall.Syscall6(0xe8, 0x9, 0xc0006c1bec, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/syscall/asm_linux_amd64.s:44 +0x5
golang.org/x/sys/unix.EpollWait(0x9, 0xc0006c1bec, 0x7, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x0)
	/go/pkg/mod/golang.org/x/[email protected]/unix/zsyscall_linux_amd64.go:76 +0x72
github.com/fsnotify/fsnotify.(*fdPoller).wait(0xc0000364e0, 0x0, 0x0, 0x0)
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify_poller.go:86 +0x91
github.com/fsnotify/fsnotify.(*Watcher).readEvents(0xc00045a000)
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify.go:192 +0x1f8
created by github.com/fsnotify/fsnotify.NewWatcher
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify.go:59 +0x1a5

goroutine 466 [select]:
github.com/dgraph-io/ristretto.(*defaultPolicy).processItems(0xc00014ecc0)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:96 +0xbe
created by github.com/dgraph-io/ristretto.newDefaultPolicy
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:80 +0x129

goroutine 413 [select]:
github.com/dgraph-io/ristretto.(*defaultPolicy).processItems(0xc00014d2c0)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:96 +0xbe
created by github.com/dgraph-io/ristretto.newDefaultPolicy
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:80 +0x129

goroutine 431 [semacquire]:
sync.runtime_Semacquire(0xc00045df88)
	/usr/local/go/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc00045df80)
	/usr/local/go/src/sync/waitgroup.go:130 +0x64
github.com/ory/viper.(*Viper).WatchConfig.func1(0xc0000e6840, 0xc00045df40)
	/go/pkg/mod/github.com/ory/[email protected]/viper.go:445 +0x33a
created by github.com/ory/viper.(*Viper).WatchConfig
	/go/pkg/mod/github.com/ory/[email protected]/viper.go:384 +0x75

goroutine 124 [select]:
github.com/dgraph-io/ristretto.(*Cache).processItems(0xc0000c67e0)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:299 +0xed
created by github.com/dgraph-io/ristretto.(*Cache).Clear
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:293 +0xc9

goroutine 432 [syscall]:
syscall.Syscall6(0xe8, 0x5, 0xc00063dbec, 0x7, 0xffffffffffffffff, 0x0, 0x0, 0x73646f6874656d5f, 0x4556524553223a22, 0x432e59584f52502e)
	/usr/local/go/src/syscall/asm_linux_amd64.s:44 +0x5
golang.org/x/sys/unix.EpollWait(0x5, 0xc00063dbec, 0x7, 0x7, 0xffffffffffffffff, 0x574f4c4c412e5352, 0x494749524f5f4445, 0x657322202c22534e)
	/go/pkg/mod/golang.org/x/[email protected]/unix/zsyscall_linux_amd64.go:76 +0x72
github.com/fsnotify/fsnotify.(*fdPoller).wait(0xc0004e1520, 0x432e59584f525000, 0x4f5058452e53524f, 0x444145485f444553)
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify_poller.go:86 +0x91
github.com/fsnotify/fsnotify.(*Watcher).readEvents(0xc0000338b0)
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify.go:192 +0x1f8
created by github.com/fsnotify/fsnotify.NewWatcher
	/go/pkg/mod/github.com/fsnotify/[email protected]/inotify.go:59 +0x1a5

goroutine 433 [select]:
github.com/ory/viper.(*Viper).WatchConfig.func1.1(0xc0000338b0, 0xc00045df80, 0x7ffcd467cf31, 0x1b, 0x7ffcd467cf31, 0x1b, 0xc000372fb0, 0xc0000e6840)
	/go/pkg/mod/github.com/ory/[email protected]/viper.go:406 +0xe6
created by github.com/ory/viper.(*Viper).WatchConfig.func1
	/go/pkg/mod/github.com/ory/[email protected]/viper.go:404 +0x2e6

goroutine 434 [select]:
github.com/ory/oathkeeper/rule.(*FetcherDefault).watch(0xc0003d8380, 0x1034bc0, 0xc0000c0058, 0xc00045a000, 0xc000436180, 0xc000591f01, 0xc000120690)
	/app/rule/fetcher_default.go:221 +0x258
github.com/ory/oathkeeper/rule.(*FetcherDefault).Watch(0xc0003d8380, 0x1034bc0, 0xc0000c0058, 0x0, 0x0)
	/app/rule/fetcher_default.go:182 +0xf0
github.com/ory/oathkeeper/driver.(*RegistryMemory).Init.func1(0xc0000e8780)
	/app/driver/registry_memory.go:69 +0x5b
created by github.com/ory/oathkeeper/driver.(*RegistryMemory).Init
	/app/driver/registry_memory.go:68 +0x43

goroutine 450 [select]:
github.com/ory/analytics-go/v4.(*client).loop(0xc00054c000)
	/go/pkg/mod/github.com/ory/analytics-go/[email protected]/analytics.go:370 +0x2a1
created by github.com/ory/analytics-go/v4.NewWithConfig
	/go/pkg/mod/github.com/ory/analytics-go/[email protected]/analytics.go:92 +0x286

goroutine 125 [chan receive]:
github.com/ory/analytics-go/v4.(*executor).loop(0xc00043c0c0)
	/go/pkg/mod/github.com/ory/analytics-go/[email protected]/executor.go:39 +0x86
created by github.com/ory/analytics-go/v4.newExecutor
	/go/pkg/mod/github.com/ory/analytics-go/[email protected]/executor.go:17 +0x95

goroutine 473 [IO wait]:
internal/poll.runtime_pollWait(0x7faee7c334a0, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0003f0118, 0x72, 0x0, 0x0, 0xeb60da)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0003f0100, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc0003f0100, 0xc00079fae8, 0x6f5164, 0xc0005380a0)
	/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc0003ead60, 0x5f7cf96f, 0xc00079fae8, 0x4c9626)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc0003ead60, 0xc00079fb38, 0x18, 0xc00059a900, 0x6f4694)
	/usr/local/go/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc000538000, 0x1031240, 0xc0003ead60, 0x0, 0x0)
	/usr/local/go/src/net/http/server.go:2925 +0x280
net/http.(*Server).ListenAndServe(0xc000538000, 0x4, 0xec21b2)
	/usr/local/go/src/net/http/server.go:2854 +0xb7
github.com/ory/oathkeeper/cmd/server.runProxy.func1.1(0x18, 0xf084e8)
	/app/cmd/server/server.go:70 +0x185
github.com/ory/graceful.Graceful(0xc00079ff30, 0xc00009f0e0, 0xc000033a40, 0x0)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:76 +0xa2
github.com/ory/oathkeeper/cmd/server.runProxy.func1()
	/app/cmd/server/server.go:64 +0x8c8
github.com/ory/oathkeeper/cmd/server.RunServe.func1.1(0xc0002f4aa0, 0xc000213590)
	/app/cmd/server/server.go:242 +0x57
created by github.com/ory/oathkeeper/cmd/server.RunServe.func1
	/app/cmd/server/server.go:240 +0xa70

goroutine 474 [IO wait]:
internal/poll.runtime_pollWait(0x7faee7c33640, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc000412698, 0x72, 0x0, 0x0, 0xeb60da)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc000412680, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc000412680, 0xc000487b60, 0xc000478a80, 0x7faeea08f6d0)
	/usr/local/go/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00039bc60, 0xc000487b90, 0x40c9a8, 0x30)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc00039bc60, 0xe2f860, 0xc0002a4060, 0xd87380, 0x1683c40)
	/usr/local/go/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc0001340e0, 0x1031240, 0xc00039bc60, 0x0, 0x0)
	/usr/local/go/src/net/http/server.go:2925 +0x280
net/http.(*Server).ListenAndServe(0xc0001340e0, 0x4, 0xec21b2)
	/usr/local/go/src/net/http/server.go:2854 +0xb7
github.com/ory/oathkeeper/cmd/server.runPrometheus.func1.1(0x18, 0xf084e8)
	/app/cmd/server/server.go:135 +0xbf
github.com/ory/graceful.Graceful(0xc0000a4f48, 0xc000497630, 0x8, 0x101ec80)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:76 +0xa2
github.com/ory/oathkeeper/cmd/server.runPrometheus.func1()
	/app/cmd/server/server.go:133 +0x383
github.com/ory/oathkeeper/cmd/server.RunServe.func1.1(0xc0002f4aa0, 0xc0002135c0)
	/app/cmd/server/server.go:242 +0x57
created by github.com/ory/oathkeeper/cmd/server.RunServe.func1
	/app/cmd/server/server.go:240 +0xa70

goroutine 477 [chan receive]:
github.com/ory/graceful.Graceful.func1(0xc0004363c0, 0xc000497630, 0xc000436420)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:62 +0xc8
created by github.com/ory/graceful.Graceful
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:59 +0x98

goroutine 132 [chan receive]:
github.com/ory/graceful.Graceful.func1(0xc0006f81e0, 0xc0002840c0, 0xc0006f8240)
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:62 +0xc8
created by github.com/ory/graceful.Graceful
	/go/pkg/mod/github.com/ory/[email protected]/http_graceful.go:59 +0x98

goroutine 435 [select]:
github.com/dgraph-io/ristretto.(*Cache).processItems(0xc000320ba0)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:299 +0xed
created by github.com/dgraph-io/ristretto.NewCache
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:162 +0x22a

goroutine 436 [select]:
github.com/dgraph-io/ristretto.(*defaultPolicy).processItems(0xc0004a0a80)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:96 +0xbe
created by github.com/dgraph-io/ristretto.newDefaultPolicy
	/go/pkg/mod/github.com/dgraph-io/[email protected]/policy.go:80 +0x129

goroutine 437 [select]:
github.com/dgraph-io/ristretto.(*Cache).processItems(0xc000320d20)
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:299 +0xed
created by github.com/dgraph-io/ristretto.NewCache
	/go/pkg/mod/github.com/dgraph-io/[email protected]/cache.go:162 +0x22a

goroutine 478 [running]:
	goroutine running on other thread; stack unavailable
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2957 +0x384

goroutine 480 [IO wait]:
internal/poll.runtime_pollWait(0x7faee7c33300, 0x72, 0xffffffffffffffff)
	/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00065c098, 0x72, 0x0, 0x1, 0xffffffffffffffff)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00065c080, 0xc0001b8131, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc00065c080, 0xc0001b8131, 0x1, 0x1, 0x202020202020200a, 0x202020200a2c7d20, 0x78616d2220202020)
	/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0005a8018, 0xc0001b8131, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:184 +0x68
net/http.(*connReader).backgroundRead(0xc0001b8120)
	/usr/local/go/src/net/http/server.go:688 +0x58
created by net/http.(*connReader).startBackgroundRead
	/usr/local/go/src/net/http/server.go:684 +0xd4

goroutine 438 [IO wait]:
internal/poll.runtime_pollWait(0x7faee7c333d0, 0x72, 0xffffffffffffffff)
	/usr/local/go/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc00065c018, 0x72, 0x0, 0x1, 0xffffffffffffffff)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00065c000, 0xc0001329a1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc00065c000, 0xc0001329a1, 0x1, 0x1, 0x756d222020202020, 0x664f656c7069746c, 0x2020200a7b203a22)
	/usr/local/go/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0005a8010, 0xc0001329a1, 0x1, 0x1, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:184 +0x68
net/http.(*connReader).backgroundRead(0xc000132990)
	/usr/local/go/src/net/http/server.go:688 +0x58
created by net/http.(*connReader).startBackgroundRead
	/usr/local/go/src/net/http/server.go:684 +0xd4

goroutine 497 [select]:
net/http/httputil.(*ReverseProxy).ServeHTTP.func1(0xc0008c63f0, 0xc00040c440, 0x1034b80, 0xc0003f2f00)
	/usr/local/go/src/net/http/httputil/reverseproxy.go:190 +0xb7
created by net/http/httputil.(*ReverseProxy).ServeHTTP
	/usr/local/go/src/net/http/httputil/reverseproxy.go:189 +0x1469

goroutine 439 [select]:
net/http/httputil.(*ReverseProxy).ServeHTTP.func1(0xc00093b0a0, 0xc0004f3190, 0x1034b80, 0xc0006d95c0)
	/usr/local/go/src/net/http/httputil/reverseproxy.go:190 +0xb7
created by net/http/httputil.(*ReverseProxy).ServeHTTP
	/usr/local/go/src/net/http/httputil/reverseproxy.go:189 +0x1469

goroutine 478 [running]:
runtime.throw(0xec17be, 0x15)
	/usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc0007aa3a0 sp=0xc0007aa370 pc=0x42f532
runtime.mapassign_faststr(0xd7b680, 0xc0004a0990, 0xc000506320, 0x20, 0x16c9de0)
	/usr/local/go/src/runtime/map_faststr.go:291 +0x3fe fp=0xc0007aa408 sp=0xc0007aa3a0 pc=0x41338e
text/template.(*Template).associate(0xc000788200, 0xc000788200, 0xc000778100, 0xc0002e2601)
	/usr/local/go/src/text/template/template.go:226 +0xb7 fp=0xc0007aa448 sp=0xc0007aa408 pc=0x7b0b27
text/template.(*Template).AddParseTree(0xc000788200, 0xc000506320, 0x20, 0xc000778100, 0x0, 0x0, 0x0)
	/usr/local/go/src/text/template/template.go:132 +0xf9 fp=0xc0007aa498 sp=0xc0007aa448 pc=0x7afe59
text/template.(*Template).Parse(0xc000788200, 0xc000034370, 0x47, 0x20, 0x16c9de0, 0x0)
	/usr/local/go/src/text/template/template.go:207 +0x1df fp=0xc0007aa598 sp=0xc0007aa498 pc=0x7b085f
github.com/ory/oathkeeper/pipeline/mutate.(*MutatorIDToken).Mutate(0xc0004cc3c0, 0xc000108300, 0xc000788000, 0x0, 0x0, 0x0, 0x1026d00, 0xc0005201c0, 0x0, 0x0)
	/app/pipeline/mutate/mutator_id_token.go:155 +0xe61 fp=0xc0007aa770 sp=0xc0007aa598 pc=0xc20071
github.com/ory/oathkeeper/proxy.(*RequestHandler).HandleRequest(0xc000a0c9a0, 0xc000108300, 0xc0005201c0, 0x1002d18, 0xdebfe0, 0xc0005201c0)
	/app/proxy/request_handler.go:318 +0x8d7 fp=0xc0007aac40 sp=0xc0007aa770 pc=0xc88607
github.com/ory/oathkeeper/proxy.(*Proxy).Director(0xc000124000, 0xc000108300)
	/app/proxy/proxy.go:134 +0x559 fp=0xc0007ab380 sp=0xc0007aac40 pc=0xc84e79
github.com/ory/oathkeeper/proxy.(*Proxy).Director-fm(0xc000108300)
	/app/proxy/proxy.go:125 +0x34 fp=0xc0007ab3a0 sp=0xc0007ab380 pc=0xc97054
net/http/httputil.(*ReverseProxy).ServeHTTP(0xc000656050, 0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/usr/local/go/src/net/http/httputil/reverseproxy.go:206 +0x149 fp=0xc0007ab660 sp=0xc0007ab3a0 pc=0x9f4549
github.com/urfave/negroni.Wrap.func1(0x7faee7c77320, 0xc0004180d8, 0xc000108100, 0xc0004e9ec0)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:46 +0x4d fp=0xc0007ab690 sp=0xc0007ab660 pc=0xb1baad
github.com/urfave/negroni.HandlerFunc.ServeHTTP(0xc000364200, 0x7faee7c77320, 0xc0004180d8, 0xc000108100, 0xc0004e9ec0)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:29 +0x4e fp=0xc0007ab6c0 sp=0xc0007ab690 pc=0xb1a52e
github.com/urfave/negroni.middleware.ServeHTTP(0x101e8e0, 0xc000364200, 0xc000364300, 0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007ab6f8 sp=0xc0007ab6c0 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007ab738 sp=0xc0007ab6f8 pc=0xb1be3a
github.com/ory/x/reqlog.(*Middleware).ServeHTTP(0xc0000fe460, 0x7faee7c77320, 0xc0004180d8, 0xc000108100, 0xc0004e9e40)
	/go/pkg/mod/github.com/ory/[email protected]/reqlog/middleware.go:138 +0x308 fp=0xc0007ab800 sp=0xc0007ab738 pc=0xb43088
github.com/urfave/negroni.middleware.ServeHTTP(0x101cd00, 0xc0000fe460, 0xc000364260, 0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007ab838 sp=0xc0007ab800 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007ab878 sp=0xc0007ab838 pc=0xb1be3a
github.com/ory/oathkeeper/metrics.(*Middleware).ServeHTTP(0xc000656140, 0x7faee7c77320, 0xc0004180d8, 0xc000108100, 0xc0004e9e20)
	/app/metrics/middleware.go:88 +0xa1 fp=0xc0007ab910 sp=0xc0007ab878 pc=0xc91f01
github.com/urfave/negroni.middleware.ServeHTTP(0x101cbc0, 0xc000656140, 0xc000364240, 0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007ab948 sp=0xc0007ab910 pc=0xb1a5dc
github.com/urfave/negroni.middleware.ServeHTTP-fm(0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:37 +0x5a fp=0xc0007ab988 sp=0xc0007ab948 pc=0xb1be3a
github.com/ory/x/metricsx.(*Service).ServeHTTP(0xc00045a910, 0x7faee7c77320, 0xc0004180d8, 0xc000108100, 0xc0004e9e00)
	/go/pkg/mod/github.com/ory/[email protected]/metricsx/middleware.go:261 +0x92 fp=0xc0007abb80 sp=0xc0007ab988 pc=0xb41892
github.com/urfave/negroni.middleware.ServeHTTP(0x101ccc0, 0xc00045a910, 0xc000364220, 0x7faee7c77320, 0xc0004180d8, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:38 +0x9c fp=0xc0007abbb8 sp=0xc0007abb80 pc=0xb1a5dc
github.com/urfave/negroni.(*Negroni).ServeHTTP(0xc000012c30, 0x1031500, 0xc000134380, 0xc000108100)
	/go/pkg/mod/github.com/urfave/[email protected]/negroni.go:96 +0xeb fp=0xc0007abc18 sp=0xc0007abbb8 pc=0xb1a99b
net/http.serverHandler.ServeHTTP(0xc000538000, 0x1031500, 0xc000134380, 0xc000108100)
	/usr/local/go/src/net/http/server.go:2831 +0xa4 fp=0xc0007abc48 sp=0xc0007abc18 pc=0x6f41d4
net/http.(*conn).serve(0xc0007a6000, 0x1034b80, 0xc0006d9440)
	/usr/local/go/src/net/http/server.go:1919 +0x875 fp=0xc0007abfc8 sp=0xc0007abc48 pc=0x6efb75
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0007abfd0 sp=0xc0007abfc8 pc=0x45efd1
created by net/http.(*Server).Serve
	/usr/local/go/src/net/http/server.go:2957 +0x384

Server configuration

config.yaml

access_rules:
  repositories:
    - file:///oathkeeper-dev/access-rules.json
serve:
  proxy:
    port: 4455
  api:
    port: 4456
authenticators:
  anonymous:
    enabled: true
    config:
      subject: anonymous
  unauthorized:
    enabled: true
  cookie_session:
    enabled: true
    config:
      check_session_url: http://oathkeeper-subject:3000/oathkeeper/subject
      preserve_path: true
      only:
        - oathkeeper-dev
authorizers:
  allow:
    enabled: true
  deny:
    enabled: true
mutators:
  id_token:
    enabled: true
    config:
      issuer_url: http://oathkeeper
      jwks_url: file:///run/secrets/jwks.json
      claims: '{"aud":["api://audience"],"lup":"{{ print .Extra.last_updated }}"}'
  header:
    enabled: true
    config:
      headers:
        X-User-ID: '{{ print .Subject }}'
        X-User-LastUpdated: '{{ print .Extra.last_updated }}'

access_rules.json

[
  {
    "id": "public-site",
    "upstream": {
      "url": "http://web",
      "preserve_host": true
    },
    "match": {
      "methods": ["GET", "HEAD", "POST", "PUT", "PATCH", "DELETE", "CONNECT", "OPTIONS"],
      "url": "<.*>"
    },
    "authenticators": [
      { "handler": "cookie_session" },
      { "handler": "anonymous" }
    ],
    "authorizer": {
      "handler": "allow"
    },
    "mutators": [
      { "handler": "id_token" }
    ],
    "errors": [
      { "handler": "json" }
    ]
  }
]

Expected behavior

No crash and hopefully no concurrent map writes or panic.

Environment

  • Version: v0.38.3-beta.1
  • Environment: Docker

Additional context
@AlbinoDrought
Copy link
Contributor Author

AlbinoDrought commented Oct 7, 2020 •
edited
Loading

At a glance, I am assuming two goroutines enter this branch at the same time: https://github.com/ory/oathkeeper/blob/v0.38.3-beta.1/pipeline/mutate/mutator_id_token.go#L155

See also https://golang.org/pkg/text/template/#Template.New :

Because associated templates share underlying data, template construction cannot be done safely in parallel. Once the templates are constructed, they can be executed in parallel.

AlbinoDrought added a commit to AlbinoDrought/oathkeeper that referenced this issue Oct 7, 2020
@AlbinoDrought
fix: never construct id token claim templates in parallel
a0ba9ec 
Fixes ory#551
@AlbinoDrought AlbinoDrought mentioned this issue Oct 7, 2020
Merged
5 tasks
@aeneasr aeneasr added bug Something is not working. corp/m2 Up for M2 at Ory Corp. labels Oct 7, 2020
@aeneasr aeneasr self-assigned this Oct 7, 2020
@aeneasr aeneasr added this to the v0.39.0 milestone Oct 7, 2020
aeneasr pushed a commit that referenced this issue Oct 11, 2020
@AlbinoDrought
fix: never construct id token claim templates in parallel (#552)
4f504d9 
Closes #551
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@aeneasr aeneasr

Labels
bug Something is not working. corp/m2 Up for M2 at Ory Corp.
Projects
None yet
Milestone
v0.39.0
Development

Successfully merging a pull request may close this issue.

fix: never construct id token claim templates in parallel AlbinoDrought/oathkeeper
2 participants
@AlbinoDrought @aeneasr