Applying GraphQL schema times out

machship-mm · February 9, 2021, 6:33am

Report a GraphQL Bug

What edition and version of Dgraph are you using?

Edition:

SlashGraphQL
Dgraph (community edition/Dgraph Cloud)

If you are using the community edition or enterprise edition of Dgraph, please list the version:

Dgraph Version

$ dgraph version
 
[Decoder]: Using assembly version of decoder
Page Size: 4096

Dgraph version   : v20.11.1
Dgraph codename  : tchalla-1
Dgraph SHA-256   : cefdcc880c0607a92a1d8d3ba0beb015459ebe216e79fdad613eb0d00d09f134
Commit SHA-1     : 7153d13fe
Commit timestamp : 2021-01-28 15:59:35 +0530
Branch           : HEAD
Go version       : go1.15.5
jemalloc enabled : true

For Dgraph official documentation, visit https://dgraph.io/docs/.
For discussions about Dgraph     , visit http://discuss.dgraph.io.

Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
Copyright 2015-2020 Dgraph Labs, Inc.

Have you tried reproducing the issue with the latest release?

Yes, this is the latest release (to my knowledge) and this issue has persisted across versions

Steps to reproduce the issue (paste the query/schema if possible)

We have a relatively large GraphQL schema. When trying to apply it to an empty Dgraph instance, the process times out and the container dies with lots of errors, finishing with the following:

goroutine 134229 [semacquire]:
sync.runtime_SemacquireMutex(0x2bb779c, 0x0, 0x1)
	/usr/local/go/src/runtime/sema.go:71 +0x47
sync.(*Mutex).lockSlow(0x2bb7798)
	/usr/local/go/src/sync/mutex.go:138 +0x105
sync.(*Mutex).Lock(...)
	/usr/local/go/src/sync/mutex.go:81
github.com/golang/glog.(*loggingT).output(0x2bb7780, 0xc000000000, 0xc00510a150, 0x2759ae5, 0x8, 0x3ae, 0x0)
	/go/pkg/mod/github.com/golang/glog@v0.0.0-20160126235308-23def4e6c14b/glog.go:672 +0x6c5
github.com/golang/glog.(*loggingT).printf(0x2bb7780, 0x0, 0x1dbf852, 0x2e, 0xc010e13da8, 0x2, 0x2)
	/go/pkg/mod/github.com/golang/glog@v0.0.0-20160126235308-23def4e6c14b/glog.go:655 +0x153
github.com/golang/glog.Infof(...)
	/go/pkg/mod/github.com/golang/glog@v0.0.0-20160126235308-23def4e6c14b/glog.go:1073
github.com/dgraph-io/dgraph/posting.rebuildTokIndex(0x1f94940, 0xc004c44510, 0xc004c444b0, 0x1b4aa00, 0x1f3bd40)
	/ext-go/1/src/github.com/dgraph-io/dgraph/posting/index.go:942 +0x185
github.com/dgraph-io/dgraph/posting.(*IndexRebuild).BuildIndexes(0xc004c444b0, 0x1f94940, 0xc004c44510, 0x1f3bd40, 0x1b3c800)
	/ext-go/1/src/github.com/dgraph-io/dgraph/posting/index.go:798 +0x45
github.com/dgraph-io/dgraph/worker.runSchemaMutation.func2(0xc00f0f2850, 0xc00f08ae00, 0x1c, 0x1c, 0xc005072460, 0xc00f0f2850, 0xc0001a2000, 0xc001d96380)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:181 +0xd5
github.com/dgraph-io/dgraph/worker.runSchemaMutation.func3(0xc00f0f2850, 0xc00f08ae00, 0x1c, 0x1c, 0xc005072460, 0xc00f0f2850)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:208 +0x98
created by github.com/dgraph-io/dgraph/worker.runSchemaMutation
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:252 +0x65a

goroutine 133413 [runnable]:
bytes.makeSlice.func1()
	/usr/local/go/src/bytes/buffer.go:224 +0x6b
bytes.makeSlice(0xca, 0xc00eb86000, 0xca, 0xca)
	/usr/local/go/src/bytes/buffer.go:229 +0x96
bytes.(*Buffer).grow(0xc00516a2a0, 0x4a, 0x1d41c60)
	/usr/local/go/src/bytes/buffer.go:142 +0x156
bytes.(*Buffer).Write(0xc00516a2a0, 0xc00c80c700, 0x4a, 0x100, 0x0, 0x0, 0x0)
	/usr/local/go/src/bytes/buffer.go:172 +0xd0
fmt.Fprintf(0x1f640e0, 0xc00516a2a0, 0x1dbf852, 0x2e, 0xc002947da8, 0x2, 0x2, 0x1, 0xc002947d10, 0xa34539)
	/usr/local/go/src/fmt/print.go:205 +0xa5
github.com/golang/glog.(*loggingT).printf(0x2bb7780, 0x0, 0x1dbf852, 0x2e, 0xc002947da8, 0x2, 0x2)
	/go/pkg/mod/github.com/golang/glog@v0.0.0-20160126235308-23def4e6c14b/glog.go:651 +0xc5
github.com/golang/glog.Infof(...)
	/go/pkg/mod/github.com/golang/glog@v0.0.0-20160126235308-23def4e6c14b/glog.go:1073
github.com/dgraph-io/dgraph/posting.rebuildTokIndex(0x1f94940, 0xc004d603f0, 0xc002833710, 0x1b4aa00, 0x1f3bd40)
	/ext-go/1/src/github.com/dgraph-io/dgraph/posting/index.go:942 +0x185
github.com/dgraph-io/dgraph/posting.(*IndexRebuild).BuildIndexes(0xc002833710, 0x1f94940, 0xc004d603f0, 0x1f3bd40, 0x1b3c800)
	/ext-go/1/src/github.com/dgraph-io/dgraph/posting/index.go:798 +0x45
github.com/dgraph-io/dgraph/worker.runSchemaMutation.func2(0xc00f0f22a0, 0xc00f08aca0, 0x17, 0x1c, 0xc0050843f0, 0xc00f0f22a0, 0x0, 0x0)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:181 +0xd5
github.com/dgraph-io/dgraph/worker.runSchemaMutation.func3(0xc00f0f22a0, 0xc00f08aca0, 0x17, 0x1c, 0xc0050843f0, 0xc00f0f22a0)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:208 +0x98
created by github.com/dgraph-io/dgraph/worker.runSchemaMutation
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:252 +0x65a

goroutine 134918 [select]:
github.com/dgraph-io/badger/v3.(*levelsController).runCompactor(0xc0001a2000, 0x3, 0xc001f42ed0)
	/go/pkg/mod/github.com/dgraph-io/badger/v3@v3.2011.1/levels.go:494 +0x285
created by github.com/dgraph-io/badger/v3.(*levelsController).startCompact
	/go/pkg/mod/github.com/dgraph-io/badger/v3@v3.2011.1/levels.go:354 +0x89

goroutine 134919 [chan receive]:
github.com/dgraph-io/badger/v3.(*DB).flushMemtable(0xc0006c0c00, 0xc001f42f30, 0x0, 0x0)
	/go/pkg/mod/github.com/dgraph-io/badger/v3@v3.2011.1/db.go:1021 +0xa9
github.com/dgraph-io/badger/v3.(*DB).startMemoryFlush.func1(0xc0006c0c00)
	/go/pkg/mod/github.com/dgraph-io/badger/v3@v3.2011.1/db.go:1427 +0x34
created by github.com/dgraph-io/badger/v3.(*DB).startMemoryFlush
	/go/pkg/mod/github.com/dgraph-io/badger/v3@v3.2011.1/db.go:1426 +0xaf

goroutine 107140 [running]:
runtime.throw(0x1d8f4bb, 0x15)
	/usr/local/go/src/runtime/panic.go:1116 +0x72 fp=0xc00cd73d10 sp=0xc00cd73ce0 pc=0xa60af2
runtime.mapdelete_faststr(0x1bb4860, 0xc0004d3680, 0xc00efed2a0, 0xd)
	/usr/local/go/src/runtime/map_faststr.go:377 +0x34c fp=0xc00cd73d78 sp=0xc00cd73d10 pc=0xa3dc4c
github.com/dgraph-io/dgraph/schema.Load(0xc00efed2a0, 0xd, 0x0, 0x0)
	/ext-go/1/src/github.com/dgraph-io/dgraph/schema/schema.go:431 +0x8d fp=0xc00cd73e38 sp=0xc00cd73d78 pc=0x14d5e0d
github.com/dgraph-io/dgraph/worker.undoSchemaUpdate.func1(0xbc, 0x0)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:126 +0x33 fp=0xc00cd73e68 sp=0xc00cd73e38 pc=0x1787ad3
github.com/dgraph-io/dgraph/x.RetryUntilSuccess(0xa, 0x989680, 0xc00cd73ee8, 0xc000000002, 0xc00513e000)
	/ext-go/1/src/github.com/dgraph-io/dgraph/x/x.go:505 +0x54 fp=0xc00cd73ea0 sp=0xc00cd73e68 pc=0x12d2af4
github.com/dgraph-io/dgraph/worker.undoSchemaUpdate(0xc00efed2a0, 0xd)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:125 +0x86 fp=0xc00cd73f30 sp=0xc00cd73ea0 pc=0x174a626
github.com/dgraph-io/dgraph/worker.runSchemaMutation.func3(0xc00f01d7a0, 0xc00efed2a0, 0xd, 0x1c, 0xc004fd5340, 0xc00f01d7a0)
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:210 +0x125 fp=0xc00cd73fb0 sp=0xc00cd73f30 pc=0x1787fc5
runtime.goexit()
	/usr/local/go/src/runtime/asm_amd64.s:1374 +0x1 fp=0xc00cd73fb8 sp=0xc00cd73fb0 pc=0xa9a4e1
created by github.com/dgraph-io/dgraph/worker.runSchemaMutation
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/mutation.go:252 +0x65a
W0209 06:28:01.303786      43 pool.go:267] Connection lost with localhost:7080. Error: rpc error: code = Unavailable desc = transport is closing

Expected behaviour and actual result.

Expect the process to take less than a few minutes, but it times out and dies.

NB: due to privacy issues, I cannot post the schema publicly here, so I may need to email it to someone at Dgraph.

machship-mm · February 9, 2021, 6:34am

@machship-bsuryn FYI

machship-bsuryn · February 9, 2021, 6:37am

Thanks Mike I can link you the two topics I created today, 1 was with the limit the other is with trying to or on cascade subfields

rajas · February 9, 2021, 10:06am

Thanks @machship-mm for reporting this. I am marking this as accepted.

I will require the schema to reproduce and RCA this. You may email it to the following Email ID: rajas[at]dgraph[dot]io

rajas · February 9, 2021, 3:10pm

Thanks for providing schema, I am able to reproduce this on latest master.

rajas · February 9, 2021, 4:47pm

Hi @machship-mm,

While reproducing this issue locally, dgraph alpha process is failing with many errors similar to

E0209 20:37:49.798002  608780 mutation.go:209] error in building indexes, aborting :: error opening temp badger for reindexing: cannot open directory "t/dgraph_index_699789352" error: open t/dgraph_index_699789352: too many open files

I was able to get this to work with your schema by setting a higher limit (I set it to 10000) of open file descriptors using ulimit .

What limit have you set for maximum number of file descriptors on your setup ?

Relevant Dgraph docs: https://dgraph.io/docs//deploy/troubleshooting/#too-many-open-files

Do let us know if you face any other issues while setting Dgraph.

machship-mm · February 15, 2021, 2:06am

Thanks, I’ll take a look

Topic		Replies	Views
Panic on update schema GraphQL status:accepted , ticket:created	8	468	March 18, 2021
Missing data GraphQL dgraph , kind:bug	2	344	March 11, 2021
Update mutation removing connection between nodes in one field and setting the connection on a different field fails GraphQL kind:bug	9	835	November 30, 2022
dropData endpoint missing on dgraph (not on slash) Dgraph	10	492	September 7, 2021
Dgraph start to panic out of nowhere on Darwin Dgraph graphql , dgraph , kind:bug	7	908	December 31, 2020