Badger in Alpha panics on startup "Error while creating badger KV posting store" (v20.07.0)

Issues
1

Component: Alpha
Environment: Kubernetes (GKE)
Version: v20.07.0 and v.20.07.0-beta (June)

Alpha fails during startup and exits with panic in badger and showing the error “Error while creating badger KV posting store”.

++ hostname -f
+ dgraph alpha --my=dgraph-alpha-0.dgraph-alpha-headless.parser.svc.cluster.local:7080 --lru_mb 24576 --zero dgraph-zero-0.dgraph-zero-headless.parser.svc.cluster.local:5080
[Decoder]: Using assembly version of decoder
[Sentry] 2020/08/08 11:27:48 Integration installed: ContextifyFrames
[Sentry] 2020/08/08 11:27:48 Integration installed: Environment
[Sentry] 2020/08/08 11:27:48 Integration installed: Modules
[Sentry] 2020/08/08 11:27:48 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
[Sentry] 2020/08/08 11:27:49 Integration installed: ContextifyFrames
[Sentry] 2020/08/08 11:27:49 Integration installed: Environment
[Sentry] 2020/08/08 11:27:49 Integration installed: Modules
[Sentry] 2020/08/08 11:27:49 Integration installed: IgnoreErrors
I0808 11:27:49.218938      16 sentry_integration.go:48] This instance of Dgraph will send anonymous reports of panics back to Dgraph Labs via Sentry. No confidential information is sent. These reports help improve Dgraph. To opt-out, restart your instance with the --enable_sentry=false flag. For more info, see https://dgraph.io/docs/howto/#data-handling.
I0808 11:27:49.219876      16 util_ee.go:126] KeyReader instantiated of type <nil>
I0808 11:27:49.384018      16 init.go:102] 

Dgraph version   : v20.07.0
Dgraph codename  : shuri
Dgraph SHA-256   : 4cd320fc6eab163ab68602a5122a6c82c8467c2ed5ac93478d5f40d44eec71c4
Commit SHA-1     : d65e20530
Commit timestamp : 2020-07-28 15:31:37 -0700
Branch           : HEAD
Go version       : go1.14.4

For Dgraph official documentation, visit https://dgraph.io/docs/.
For discussions about Dgraph     , visit http://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

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


I0808 11:27:49.384050      16 run.go:654] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000 PollInterval:1s GraphqlExtension:true}
I0808 11:27:49.384113      16 run.go:655] x.WorkerConfig: {ExportPath:export NumPendingProposals:256 Tracing:0.01 MyAddr:dgraph-alpha-0.dgraph-alpha-headless.parser.svc.cluster.local:7080 ZeroAddr:[dgraph-zero-0.dgraph-zero-headless.parser.svc.cluster.local:5080] RaftId:0 WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2020-08-08 11:27:48.856334089 +0000 UTC m=+0.018546974 LudicrousMode:false EncryptionKey:**** LogRequest:0}
I0808 11:27:49.384169      16 run.go:656] worker.Config: {PostingDir:p BadgerTables:mmap BadgerVlog:mmap BadgerCompressionLevel:3 WALDir:w MutationsMode:0 AuthToken: AllottedMemory:24576 HmacSecret:**** AccessJwtTtl:0s RefreshJwtTtl:0s AclRefreshInterval:0s}
I0808 11:27:49.394093      16 server_state.go:78] Setting Badger Compression Level: 3
I0808 11:27:49.394131      16 server_state.go:87] Setting Badger table load option: mmap
I0808 11:27:49.394138      16 server_state.go:99] Setting Badger value log load option: mmap
I0808 11:27:49.394150      16 server_state.go:144] Opening write-ahead log BadgerDB with options: {Dir:w ValueDir:w SyncWrites:false TableLoadingMode:1 ValueLogLoadingMode:2 NumVersionsToKeep:1 ReadOnly:false Truncate:true Logger:0x2bcf318 Compression:2 InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1048576 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:false MaxCacheSize:10485760 MaxBfCacheSize:0 LoadBloomsOnOpen:false NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:10000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:3 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 DetectConflicts:false KeepBlockIndicesInCache:false KeepBlocksInCache:false managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0808 11:27:50.104722      16 log.go:34] All 10 tables opened in 639ms
I0808 11:27:50.118481      16 log.go:34] Replaying file id: 5548 at offset: 33141
I0808 11:27:54.364175      16 log.go:34] Replay took: 4.245657072s
I0808 11:27:54.367771      16 log.go:34] Replaying file id: 5549 at offset: 0
I0808 11:27:54.370167      16 log.go:34] Replay took: 2.365382ms
I0808 11:27:54.373417      16 server_state.go:78] Setting Badger Compression Level: 3
I0808 11:27:54.373439      16 server_state.go:87] Setting Badger table load option: mmap
I0808 11:27:54.373445      16 server_state.go:99] Setting Badger value log load option: mmap
I0808 11:27:54.373452      16 server_state.go:168] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false TableLoadingMode:2 ValueLogLoadingMode:2 NumVersionsToKeep:2147483647 ReadOnly:false Truncate:true Logger:0x2bcf318 Compression:2 InMemory:false MaxTableSize:67108864 LevelSizeMultiplier:10 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 KeepL0InMemory:false MaxCacheSize:1073741824 MaxBfCacheSize:524288000 LoadBloomsOnOpen:false NumLevelZeroTables:5 NumLevelZeroTablesStall:10 LevelOneSize:268435456 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:2 CompactL0OnClose:true LogRotatesToFlush:2 ZSTDCompressionLevel:3 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 DetectConflicts:false KeepBlockIndicesInCache:true KeepBlocksInCache:true managedTxns:false maxBatchCount:0 maxBatchSize:0}
I0808 11:27:57.578592      16 log.go:34] 110 tables out of 856 opened in 3.046s
I0808 11:28:00.614519      16 log.go:34] 182 tables out of 856 opened in 6.082s
I0808 11:28:03.551259      16 log.go:34] 256 tables out of 856 opened in 9.018s
I0808 11:28:06.548770      16 log.go:34] 316 tables out of 856 opened in 12.016s
I0808 11:28:09.543198      16 log.go:34] 385 tables out of 856 opened in 15.01s
I0808 11:28:12.534750      16 log.go:34] 454 tables out of 856 opened in 18.002s
I0808 11:28:15.534953      16 log.go:34] 524 tables out of 856 opened in 21.002s
I0808 11:28:18.552130      16 log.go:34] 595 tables out of 856 opened in 24.019s
I0808 11:28:21.557925      16 log.go:34] 666 tables out of 856 opened in 27.025s
I0808 11:28:24.534517      16 log.go:34] 737 tables out of 856 opened in 30.002s
I0808 11:28:27.606511      16 log.go:34] 803 tables out of 856 opened in 33.074s
I0808 11:28:30.573340      16 log.go:34] All 856 tables opened in 36.04s
[Sentry] 2020/08/08 11:28:30 Sending fatal event [0b01a03d08bb4d4cba75e206d77834b5] to o318308.ingest.sentry.io project: 1805390
2020/08/08 11:28:30 Inter: Biggest(j-1) 
00000000  00 00 10 73 70 65 63 2e  73 69 6d 63 56 65 72 73  |...spec.simcVers|
00000010  69 6f 6e 00 00 00 00 00  02 bc b5 79 ff ff ff ff  |ion........y....|
00000020  fb fb 4e d2                                       |..N.|

 vs Smallest(j): 
00000000  00 00 0e 6d 65 74 61 64  61 74 61 2e 72 65 66 49  |...metadata.refI|
00000010  64 00 00 00 00 00 00 28  aa 00 ff ff ff ff fc 6e  |d......(.......n|
00000020  67 5d                                             |g]|

: level=2 j=42 numTables=116
github.com/dgraph-io/badger/v2.(*levelHandler).validate
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/util.go:55
github.com/dgraph-io/badger/v2.(*levelsController).validate
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/util.go:33
github.com/dgraph-io/badger/v2.newLevelsController
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/levels.go:191
github.com/dgraph-io/badger/v2.Open
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/db.go:357
github.com/dgraph-io/badger/v2.OpenManaged
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/managed_db.go:26
github.com/dgraph-io/dgraph/worker.(*ServerState).initStorage
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:171
github.com/dgraph-io/dgraph/worker.InitServerState
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:54
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:658
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.init.2.func1
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:95
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
github.com/dgraph-io/dgraph/dgraph/cmd.Execute
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/root.go:70
main.main
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/main.go:78
runtime.main
	/usr/local/go/src/runtime/proc.go:203
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1373
Levels Controller
github.com/dgraph-io/badger/v2.(*levelsController).validate
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/util.go:34
github.com/dgraph-io/badger/v2.newLevelsController
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/levels.go:191
github.com/dgraph-io/badger/v2.Open
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/db.go:357
github.com/dgraph-io/badger/v2.OpenManaged
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/managed_db.go:26
github.com/dgraph-io/dgraph/worker.(*ServerState).initStorage
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:171
github.com/dgraph-io/dgraph/worker.InitServerState
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:54
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:658
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.init.2.func1
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:95
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
github.com/dgraph-io/dgraph/dgraph/cmd.Execute
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/root.go:70
main.main
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/main.go:78
runtime.main
	/usr/local/go/src/runtime/proc.go:203
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1373
Level validation
github.com/dgraph-io/badger/v2.newLevelsController
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/levels.go:193
github.com/dgraph-io/badger/v2.Open
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/db.go:357
github.com/dgraph-io/badger/v2.OpenManaged
	/go/pkg/mod/github.com/dgraph-io/badger/v2@v2.0.1-rc1.0.20200718033852-37ee16d8ad1c/managed_db.go:26
github.com/dgraph-io/dgraph/worker.(*ServerState).initStorage
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:171
github.com/dgraph-io/dgraph/worker.InitServerState
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:54
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:658
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.init.2.func1
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:95
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
github.com/dgraph-io/dgraph/dgraph/cmd.Execute
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/root.go:70
main.main
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/main.go:78
runtime.main
	/usr/local/go/src/runtime/proc.go:203
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1373
Error while creating badger KV posting store
github.com/dgraph-io/dgraph/x.Checkf
	/ext-go/1/src/github.com/dgraph-io/dgraph/x/error.go:51
github.com/dgraph-io/dgraph/worker.(*ServerState).initStorage
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:172
github.com/dgraph-io/dgraph/worker.InitServerState
	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/server_state.go:54
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:658
github.com/dgraph-io/dgraph/dgraph/cmd/alpha.init.2.func1
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:95
github.com/spf13/cobra.(*Command).execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:830
github.com/spf13/cobra.(*Command).ExecuteC
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:914
github.com/spf13/cobra.(*Command).Execute
	/go/pkg/mod/github.com/spf13/cobra@v0.0.5/command.go:864
github.com/dgraph-io/dgraph/dgraph/cmd.Execute
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/root.go:70
main.main
	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/main.go:78
runtime.main
	/usr/local/go/src/runtime/proc.go:203
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1373
2

@christian-roggia There was an issue in the earlier release of dgraph (because of badger) which wrote incorrect badger data. You can try to re-import your data in dgraph v20.07 and this error should go away.

In case you cannot re-import the data, there is a workaround (requires changing badger code) which can be used. Let me know if the re-import does not work and I’ll help you fix this badger directory.

3

@ibrahim thank you for the clarification, we can run a new import and we will do so short-term. I wanted to verify that this was a known and solved bug, otherwise running a new import might’ve eventually led to the database in the same broken state. Thank you!

1 Like
4

@christian-roggia Please do try import on v20.07 and let me know how it goes.