Amazon IAM CreatePolicy Request Error

[guo-sj]

Discussed in #2622

^{Originally posted by guo-sj January 27, 2022}
When I post a iam CreatePolicy request, I got the following error message:

$ aws --endpoint-url http://193.160.63.154:8111 iam create-policy --policy-name my-policy --policy-document file://my-policy.json

Error message from iam server:

E0127 18:49:50 27268 iamapi_management_handlers.go:413] CreatePolicy:  filer: no entry is found in filer store

Then I found that the reason why the error occurred is that, when iam server gets a CreatePolicy request, the function GetPolicies() will be called to lookup file /etc/iam/policies.json in filer server; If not found policies.json, iam server will complain filer: no entry is found in filer store.

But after I uploaded a empty policies.json file to filer server, then send a iam CreatePolicy request again, I sadly got that the iam server was been killed with error message fatal error: runtime: out of memory.

$ curl -F "filename=@policies.json" "http://193.160.63.154:8888/etc/iam"

Complete logs of iam server:

I0127 18:40:17 27268 iam.go:56] IAM read filer configuration: masters:"193.160.63.154:9333" max_mb:4 dir_buckets:"/buckets" signature:-620079281 metrics_interval_sec:15 version:"30GB 2.86 "
I0127 18:40:17 27268 iam.go:63] connected to filer localhost:8888 grpc address localhost:18888
I0127 18:40:17 27268 iam.go:76] NewIamApiServer created
I0127 18:40:17 27268 iam.go:89] Start Seaweed IAM API Server 30GB 2.86  at http port 8111
E0127 18:49:50 27268 iamapi_management_handlers.go:413] CreatePolicy:  filer: no entry is found in filer store
fatal error: runtime: out of memory

runtime stack:
runtime.throw({0x24657eb, 0x200000000})
        /usr/local/go/src/runtime/panic.go:1198 +0x71
runtime.sysMap(0xc201000000, 0x437dc0, 0x7f6f68701d58)
        /usr/local/go/src/runtime/mem_linux.go:169 +0x96
runtime.(*mheap).grow(0x3f63a00, 0x100000)
        /usr/local/go/src/runtime/mheap.go:1393 +0x225
runtime.(*mheap).allocSpan(0x3f63a00, 0x100000, 0x0, 0x1)
        /usr/local/go/src/runtime/mheap.go:1179 +0x165
runtime.(*mheap).alloc.func1()
        /usr/local/go/src/runtime/mheap.go:913 +0x69
runtime.systemstack()
        /usr/local/go/src/runtime/asm_amd64.s:383 +0x49

goroutine 39 [running]:
runtime.systemstack_switch()
        /usr/local/go/src/runtime/asm_amd64.s:350 fp=0xc000612708 sp=0xc000612700 pc=0x475420
runtime.(*mheap).alloc(0x200000000, 0x100000, 0x38, 0x0)
        /usr/local/go/src/runtime/mheap.go:907 +0x73 fp=0xc000612758 sp=0xc000612708 pc=0x4340f3
runtime.(*mcache).allocLarge(0x0, 0x1fffffc00, 0x0, 0x1)
        /usr/local/go/src/runtime/mcache.go:227 +0x89 fp=0xc0006127b8 sp=0xc000612758 pc=0x424d69
runtime.mallocgc(0x1fffffc00, 0x1f90e80, 0x1)
        /usr/local/go/src/runtime/malloc.go:1088 +0x5c5 fp=0xc000612838 sp=0xc0006127b8 pc=0x41b125
runtime.makeslice(0x0, 0x0, 0x0)
        /usr/local/go/src/runtime/slice.go:98 +0x52 fp=0xc000612860 sp=0xc000612838 pc=0x45b412
bytes.makeSlice(0x1fffffc00)
        /usr/local/go/src/bytes/buffer.go:229 +0x65 fp=0xc0006128b0 sp=0xc000612860 pc=0x506f65
bytes.(*Buffer).grow(0xc000d3ed50, 0x400)
        /usr/local/go/src/bytes/buffer.go:142 +0x11f fp=0xc0006128f8 sp=0xc0006128b0 pc=0x50691f
bytes.(*Buffer).Write(0xc000d3ed50, {0xc000b68000, 0x400, 0x400})
        /usr/local/go/src/bytes/buffer.go:172 +0x66 fp=0xc000612928 sp=0xc0006128f8 pc=0x506b86
github.com/chrislusf/seaweedfs/weed/filer.writeZero({0x28dfcc0, 0xc000d3ed50}, 0x7fffffffffffffff)
        /root/Documents/guo-sj/github/seaweedfs/weed/filer/stream.go:124 +0x8e fp=0xc000612968 sp=0xc000612928 pc=0xe6328e
github.com/chrislusf/seaweedfs/weed/filer.StreamContent({0x28e32c0, 0xc0000fad20}, {0x28dfcc0, 0xc000d3ed50}, {0x0, 0x0, 0x0}, 0x0, 0x7fffffffffffffff)
        /root/Documents/guo-sj/github/seaweedfs/weed/filer/stream.go:108 +0xa55 fp=0xc000612cd8 sp=0xc000612968 pc=0xe630d5
github.com/chrislusf/seaweedfs/weed/filer.ReadEntry(0x3f47aa0, {0x2984a08, 0xc000c56840}, {0x24417f3, 0x8}, {0x244bc13, 0xd}, 0x2107f80)
        /root/Documents/guo-sj/github/seaweedfs/weed/filer/read_write.go:27 +0x14b fp=0xc000612d40 sp=0xc000612cd8 pc=0xe5d22b
github.com/chrislusf/seaweedfs/weed/iamapi.IamS3ApiConfigure.GetPolicies.func1({0x2984a08, 0xc000c56840})
        /root/Documents/guo-sj/github/seaweedfs/weed/iamapi/iamapi_server.go:116 +0x5a fp=0xc000612d98 sp=0xc000612d40 pc=0x1ad46da
github.com/chrislusf/seaweedfs/weed/pb.WithGrpcFilerClient.func1(0xc0008edc00)
        /root/Documents/guo-sj/github/seaweedfs/weed/pb/grpc_client_server.go:244 +0x6f fp=0xc000612dc0 sp=0xc000612d98 pc=0xb2632f
github.com/chrislusf/seaweedfs/weed/pb.WithGrpcClient(0xaa, 0xc000612ee0, {0xc00025f180, 0xf}, {0xc000612ed0, 0x0, 0x0})
        /root/Documents/guo-sj/github/seaweedfs/weed/pb/grpc_client_server.go:124 +0x2ed fp=0xc000612e90 sp=0xc000612dc0 pc=0xb256ed
github.com/chrislusf/seaweedfs/weed/pb.WithGrpcFilerClient(0x80, {0x244dcaa, 0x3e55820}, {0x28e8d80, 0xc000010ff8}, 0xc000612f58)
        /root/Documents/guo-sj/github/seaweedfs/weed/pb/grpc_client_server.go:242 +0xa7 fp=0xc000612f00 sp=0xc000612e90 pc=0xb26267
github.com/chrislusf/seaweedfs/weed/iamapi.IamS3ApiConfigure.GetPolicies({0xc000358200, 0xc0000fad20}, 0xc0001263e0)
        /root/Documents/guo-sj/github/seaweedfs/weed/iamapi/iamapi_server.go:115 +0xc8 fp=0xc000612f90 sp=0xc000612f00 pc=0x1ad4548
github.com/chrislusf/seaweedfs/weed/iamapi.(*IamS3ApiConfigure).GetPolicies(0xc000d44150, 0x17)
        <autogenerated>:1 +0x3c fp=0xc000612fb8 sp=0xc000612f90 pc=0x1ad5c1c
github.com/chrislusf/seaweedfs/weed/iamapi.(*IamApiServer).CreatePolicy(0xc000122a08, 0x26d847ba2e046b1e, 0xc000d3e780)
        /root/Documents/guo-sj/github/seaweedfs/weed/iamapi/iamapi_management_handlers.go:180 +0x370 fp=0xc0006130a0 sp=0xc000612fb8 pc=0x1acfff0
github.com/chrislusf/seaweedfs/weed/iamapi.(*IamApiServer).DoActions(0xc000122a08, {0x2913988, 0xc0001d22a0}, 0xc00057c400)
        /root/Documents/guo-sj/github/seaweedfs/weed/iamapi/iamapi_management_handlers.go:411 +0x7eb fp=0xc0006138c0 sp=0xc0006130a0 pc=0x1ad2e8b
github.com/chrislusf/seaweedfs/weed/iamapi.(*IamApiServer).DoActions-fm({0x2913988, 0xc0001d22a0}, 0xc00025ea90)
        /root/Documents/guo-sj/github/seaweedfs/weed/iamapi/iamapi_management_handlers.go:363 +0x3c fp=0xc0006138f0 sp=0xc0006138c0 pc=0x1ad4a7c
github.com/chrislusf/seaweedfs/weed/s3api.(*IdentityAccessManagement).Auth.func1({0x2913988, 0xc0001d22a0}, 0xc00057c400)
        /root/Documents/guo-sj/github/seaweedfs/weed/s3api/auth_credentials.go:194 +0x271 fp=0xc000613970 sp=0xc0006138f0 pc=0x1aa1c71
net/http.HandlerFunc.ServeHTTP(0xc00057c300, {0x2913988, 0xc0001d22a0}, 0xc0000879f8)
        /usr/local/go/src/net/http/server.go:2047 +0x2f fp=0xc000613998 sp=0xc000613970 pc=0x6df7ef
github.com/gorilla/mux.(*Router).ServeHTTP(0xc000d48000, {0x2913988, 0xc0001d22a0}, 0xc00057c200)
        /root/go/pkg/mod/github.com/gorilla/mux@v1.7.4/mux.go:210 +0x1cf fp=0xc000613ac0 sp=0xc000613998 pc=0x72882f
net/http.serverHandler.ServeHTTP({0x2908170}, {0x2913988, 0xc0001d22a0}, 0xc00057c200)
        /usr/local/go/src/net/http/server.go:2879 +0x43b fp=0xc000613b80 sp=0xc000613ac0 pc=0x6e321b
net/http.(*conn).serve(0xc0009960a0, {0x292e060, 0xc000c514d0})
        /usr/local/go/src/net/http/server.go:1930 +0xb08 fp=0xc000613fb8 sp=0xc000613b80 pc=0x6de8c8
net/http.(*Server).Serve·dwrap·87()
        /usr/local/go/src/net/http/server.go:3034 +0x2e fp=0xc000613fe0 sp=0xc000613fb8 pc=0x6e3b6e
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:1581 +0x1 fp=0xc000613fe8 sp=0xc000613fe0 pc=0x477641
created by net/http.(*Server).Serve
        /usr/local/go/src/net/http/server.go:3034 +0x4e8

goroutine 1 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7f6f66e84d78, 0x72)
        /usr/local/go/src/runtime/netpoll.go:234 +0x89
internal/poll.(*pollDesc).wait(0xc000c5b800, 0x100065000, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc000c5b800)
        /usr/local/go/src/internal/poll/fd_unix.go:402 +0x22c
net.(*netFD).accept(0xc000c5b800)
        /usr/local/go/src/net/fd_unix.go:173 +0x35
net.(*TCPListener).accept(0xc000122a80)
        /usr/local/go/src/net/tcpsock_posix.go:140 +0x28
net.(*TCPListener).Accept(0xc000122a80)
        /usr/local/go/src/net/tcpsock.go:262 +0x3d
github.com/chrislusf/seaweedfs/weed/util.(*Listener).Accept(0xc0000d9120)
        /root/Documents/guo-sj/github/seaweedfs/weed/util/net_timeout.go:19 +0x2d
net/http.(*Server).Serve(0xc000c62380, {0x290ad48, 0xc0000d9120})
        /usr/local/go/src/net/http/server.go:3002 +0x394
github.com/chrislusf/seaweedfs/weed/command.(*IamOptions).startIamServer(0x3f42720)
        /root/Documents/guo-sj/github/seaweedfs/weed/command/iam.go:90 +0x72d
github.com/chrislusf/seaweedfs/weed/command.runIam(0x3e63358, {0xc00012a010, 0x0, 0x0})
        /root/Documents/guo-sj/github/seaweedfs/weed/command/iam.go:42 +0x25
main.main()
        /root/Documents/guo-sj/github/seaweedfs/weed/weed.go:78 +0x3a3

goroutine 35 [chan receive]:
github.com/chrislusf/seaweedfs/weed/glog.(*loggingT).flushDaemon(0x0)
        /root/Documents/guo-sj/github/seaweedfs/weed/glog/glog.go:883 +0x6a
created by github.com/chrislusf/seaweedfs/weed/glog.init.0
        /root/Documents/guo-sj/github/seaweedfs/weed/glog/glog.go:410 +0x1c5

goroutine 4 [syscall, 27 minutes]:
os/signal.signal_recv()
        /usr/local/go/src/runtime/sigqueue.go:169 +0x98
os/signal.loop()
        /usr/local/go/src/os/signal/signal_unix.go:24 +0x19
created by os/signal.Notify.func1.1
        /usr/local/go/src/os/signal/signal.go:151 +0x2c

goroutine 52 [chan receive, 27 minutes]:
github.com/chrislusf/seaweedfs/weed/util/grace.init.0.func1()
        /root/Documents/guo-sj/github/seaweedfs/weed/util/grace/signal_handling.go:30 +0x45
created by github.com/chrislusf/seaweedfs/weed/util/grace.init.0
        /root/Documents/guo-sj/github/seaweedfs/weed/util/grace/signal_handling.go:29 +0x145

goroutine 57 [runnable]:
go.opencensus.io/stats/view.(*worker).start(0xc00028e180)
        /root/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:276 +0xb9
created by go.opencensus.io/stats/view.init.0
        /root/go/pkg/mod/go.opencensus.io@v0.23.0/stats/view/worker.go:34 +0x92

goroutine 67 [select, 1 minutes]:
github.com/chrislusf/seaweedfs/weed/stats.(*ServerStats).Start(0xc000720e80)
        /root/Documents/guo-sj/github/seaweedfs/weed/stats/stats.go:92 +0x205
created by github.com/chrislusf/seaweedfs/weed/server.init.0
        /root/Documents/guo-sj/github/seaweedfs/weed/server/common.go:35 +0x87

goroutine 68 [select, 27 minutes]:
google.golang.org/grpc.(*ccBalancerWrapper).watcher(0xc0001419a0)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/balancer_conn_wrappers.go:71 +0xa5
created by google.golang.org/grpc.newCCBalancerWrapper
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/balancer_conn_wrappers.go:62 +0x246

goroutine 69 [chan receive, 27 minutes]:
google.golang.org/grpc.(*addrConn).resetTransport(0xc0008a18c0)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/clientconn.go:1219 +0x48f
created by google.golang.org/grpc.(*addrConn).connect
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/clientconn.go:849 +0x147

goroutine 74 [select, 1 minutes]:
google.golang.org/grpc/internal/transport.(*http2Client).keepalive(0xc0002da960)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:1569 +0x169
created by google.golang.org/grpc/internal/transport.newHTTP2Client
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:350 +0x18a5

goroutine 75 [IO wait]:
internal/poll.runtime_pollWait(0x7f6f66e84e60, 0x72)
        /usr/local/go/src/runtime/netpoll.go:234 +0x89
internal/poll.(*pollDesc).wait(0xc0001d6d80, 0xc00053c000, 0x0)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
        /usr/local/go/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0001d6d80, {0xc00053c000, 0x8000, 0x8000})
        /usr/local/go/src/internal/poll/fd_unix.go:167 +0x25a
net.(*netFD).Read(0xc0001d6d80, {0xc00053c000, 0x60100000000, 0x8})
        /usr/local/go/src/net/fd_posix.go:56 +0x29
net.(*conn).Read(0xc000011960, {0xc00053c000, 0x446827, 0xc000d33c40})
        /usr/local/go/src/net/net.go:183 +0x45
bufio.(*Reader).Read(0xc000129da0, {0xc0004a6038, 0x9, 0xc0000b20c0})
        /usr/local/go/src/bufio/bufio.go:227 +0x1b4
io.ReadAtLeast({0x28dfc60, 0xc000129da0}, {0xc0004a6038, 0x9, 0x9}, 0x9)
        /usr/local/go/src/io/io.go:328 +0x9a
io.ReadFull(...)
        /usr/local/go/src/io/io.go:347
golang.org/x/net/http2.readFrameHeader({0xc0004a6038, 0x9, 0x203000}, {0x28dfc60, 0xc000129da0})
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20210813160813-60bc85c4be6d/http2/frame.go:237 +0x6e
golang.org/x/net/http2.(*Framer).ReadFrame(0xc0004a6000)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20210813160813-60bc85c4be6d/http2/frame.go:492 +0x95
google.golang.org/grpc/internal/transport.(*http2Client).reader(0xc0002da960)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:1495 +0x41f
created by google.golang.org/grpc/internal/transport.newHTTP2Client
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:355 +0x18ef

goroutine 76 [select]:
google.golang.org/grpc/internal/transport.(*controlBuffer).get(0xc0000b4550, 0x1)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/controlbuf.go:406 +0x11b
google.golang.org/grpc/internal/transport.(*loopyWriter).run(0xc000129e60)
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/controlbuf.go:533 +0x85
google.golang.org/grpc/internal/transport.newHTTP2Client.func3()
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:405 +0x65
created by google.golang.org/grpc/internal/transport.newHTTP2Client
        /root/go/pkg/mod/google.golang.org/grpc@v1.40.0/internal/transport/http2_client.go:403 +0x1f45

Is that a bug? Or I did something incorrect?

I'm confused about this problem, and any help will be appreciated.

[guo-sj]

After some exploration, I located this statement weed/filer/read_write.go:line 26:

	return StreamContent(masterClient, byteBuffer, respLookupEntry.Entry.Chunks, 0, math.MaxInt64)

I tried to change fifth parameter (math.MaxInt64) to 0, then the problem disappeared.

Anyone could explain that what does function StreamContent mean?

[guo-sj]

Hi, chrislusf @chrislusf
Besides the problem mentioned above, I found that there are three similar problems, which will cause fatal errors:

1. weed/shell/command_fs_cat.go: line 60:
   If you execute command cat test in weed shell and file test is empty, weed shell will stall.
2. weed/filer/filer_on_meta_event.go: line 60:
   If you create an empty file /etc/seaweedfs/filer.conf, filer server will read that file and then crash.
3. weed/command/filer_cat.go: line 118:
   If you upload an empty file /etc/iam/test and execute command ./weed filer.cat http:localhost:8888/etc/iam/test, then you will get no response in a very long time.