State.commit is out of range

Issues Dgraph
1

Report a Dgraph Bug

What version of Dgraph are you using?

Dgraph Version 
$ dgraph version
 
alpha_1  | Dgraph version   : v20.11.0
alpha_1  | Dgraph codename  : tchalla
alpha_1  | Dgraph SHA-256   : 8acb886b24556691d7d74929817a4ac7d9db76bb8b77de00f44650931a16b6ac
alpha_1  | Commit SHA-1     : c4245ad55
alpha_1  | Commit timestamp : 2020-12-16 15:55:40 +0530
alpha_1  | Branch           : HEAD
alpha_1  | Go version       : go1.15.5
alpha_1  | jemalloc enabled : true

Have you tried reproducing the issue with the latest release?

yes

What is the hardware spec (RAM, OS)?

Macbook Pro 2020; MAC OS X 10.15.7; 16 GB; via Docker environment

Steps to reproduce the issue (command/config used to run Dgraph).

Unknown. I think it is a problem after a computer kernel panic.

What’s the best way to fix this issue?
I deleted the folder w in the mounted docker volume. It’s on the same level like data. And it works again. But I can verify if it’s the best solution.

Expected behaviour and actual result.

Result from docker logs

alpha_1  | Page Size: 4096
alpha_1  | I0214 20:37:28.261683       1 util_ee.go:126] KeyReader instantiated of type <nil>
alpha_1  | I0214 20:37:28.393551       1 init.go:107]
alpha_1  |
alpha_1  | Dgraph version   : v20.11.0
alpha_1  | Dgraph codename  : tchalla
alpha_1  | Dgraph SHA-256   : 8acb886b24556691d7d74929817a4ac7d9db76bb8b77de00f44650931a16b6ac
alpha_1  | Commit SHA-1     : c4245ad55
alpha_1  | Commit timestamp : 2020-12-16 15:55:40 +0530
alpha_1  | Branch           : HEAD
alpha_1  | Go version       : go1.15.5
alpha_1  | jemalloc enabled : true
alpha_1  |
alpha_1  | For Dgraph official documentation, visit https://dgraph.io/docs/.
alpha_1  | For discussions about Dgraph     , visit http://discuss.dgraph.io.
alpha_1  |
alpha_1  | Licensed variously under the Apache Public License 2.0 and Dgraph Community License.
alpha_1  | Copyright 2015-2020 Dgraph Labs, Inc.
alpha_1  |
alpha_1  |
alpha_1  | I0214 20:37:28.393599       1 run.go:696] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000 MutationsNQuadLimit:1000000 PollInterval:1s GraphqlExtension:true GraphqlDebug:false GraphqlLambdaUrl:}
alpha_1  | I0214 20:37:28.393629       1 run.go:697] x.WorkerConfig: {TmpDir:t ExportPath:export NumPendingProposals:256 Tracing:0.01 MyAddr:alpha:7080 ZeroAddr:[zero:5080] TLSClientConfig:<nil> TLSServerConfig:<nil> RaftId:0 WhiteListedIPRanges:[] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2021-02-14 20:37:28.1419036 +0000 UTC m=+0.032640401 LudicrousMode:false LudicrousConcurrency:2000 EncryptionKey:**** LogRequest:0 HardSync:false}
alpha_1  | I0214 20:37:28.393690       1 run.go:698] worker.Config: {PostingDir:p PostingDirCompression:1 PostingDirCompressionLevel:0 WALDir:w MutationsMode:0 AuthToken: PBlockCacheSize:697932185 PIndexCacheSize:375809638 WalCache:0 HmacSecret:**** AccessJwtTtl:0s RefreshJwtTtl:0s CachePercentage:0,65,35,0 CacheMb:0}
alpha_1  | I0214 20:37:28.395977       1 log.go:295] Found file: 1 First Index: 1
alpha_1  | I0214 20:37:28.397194       1 storage.go:132] Init Raft Storage with snap: 43, first: 44, last: 5637
alpha_1  | I0214 20:37:28.397924       1 server_state.go:76] Setting Posting Dir Compression Level: 0
alpha_1  | I0214 20:37:28.397974       1 server_state.go:120] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x2dffcb8 Compression:1 InMemory:false MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 ValueThreshold:1024 NumMemtables:5 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 DetectConflicts:false managedTxns:false maxBatchCount:0 maxBatchSize:0}
alpha_1  | I0214 20:37:28.431898       1 log.go:34] All 3 tables opened in 2ms
alpha_1  | I0214 20:37:28.433482       1 log.go:34] Discard stats nextEmptySlot: 0
alpha_1  | I0214 20:37:28.433609       1 log.go:34] Set nextTxnTs to 14
alpha_1  | I0214 20:37:28.436718       1 log.go:34] Deleting empty file: p/000124.vlog
alpha_1  | E0214 20:37:28.476320       1 groups.go:1143] Error during SubscribeForUpdates for prefix "\x00\x00\vdgraph.cors\x00": Unable to find any servers for group: 1. closer err: <nil>
alpha_1  | I0214 20:37:28.477918       1 groups.go:99] Current Raft Id: 0x1
alpha_1  | I0214 20:37:28.477828       1 worker.go:104] Worker listening at address: [::]:7080
alpha_1  | I0214 20:37:28.480243       1 run.go:519] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql
alpha_1  | I0214 20:37:28.480294       1 run.go:520] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin
alpha_1  | I0214 20:37:28.480378       1 run.go:552] gRPC server started.  Listening on port 9080
alpha_1  | I0214 20:37:28.480409       1 run.go:553] HTTP server started.  Listening on port 8080
alpha_1  | E0214 20:37:28.480605       1 groups.go:1143] Error during SubscribeForUpdates for prefix "\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: <nil>
alpha_1  | I0214 20:37:28.580764       1 pool.go:162] CONNECTING to zero:5080
zero_1   | I0214 20:37:28.586880       1 zero.go:432] Got connection request: cluster_info_only:true
zero_1   | I0214 20:37:28.587678       1 zero.go:450] Connected: cluster_info_only:true
zero_1   | I0214 20:37:28.590105       1 zero.go:432] Got connection request: id:1 addr:"alpha:7080"
zero_1   | I0214 20:37:28.590983       1 zero.go:566] Connected: id:1 addr:"alpha:7080"
alpha_1  | I0214 20:37:28.592223       1 groups.go:127] Connected to group zero. Assigned group: 0
alpha_1  | I0214 20:37:28.592285       1 groups.go:129] Raft Id after connection to Zero: 0x1
alpha_1  | I0214 20:37:28.592330       1 draft.go:230] Node ID: 0x1 with GroupID: 1
alpha_1  | I0214 20:37:28.592512       1 node.go:152] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00003e0a0 Applied:43 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x2dffcb8 DisableProposalForwarding:false}
alpha_1  | I0214 20:37:28.593792       1 node.go:310] Found Snapshot.Metadata: {ConfState:{Nodes:[1] Learners:[] XXX_unrecognized:[]} Index:43 Term:2 XXX_unrecognized:[]}
alpha_1  | I0214 20:37:28.593860       1 node.go:321] Found hardstate: {Term:5 Vote:1 Commit:5638 XXX_unrecognized:[]}
alpha_1  | I0214 20:37:28.597167       1 node.go:326] Group 1 found 5637 entries
alpha_1  | I0214 20:37:28.597241       1 draft.go:1689] Restarting node for group: 1
alpha_1  | I0214 20:37:28.597261       1 node.go:189] Setting conf state to nodes:1
alpha_1  | 2021/02/14 20:37:28 1 state.commit 5638 is out of range [43, 5637]
alpha_1  | panic: 1 state.commit 5638 is out of range [43, 5637]
alpha_1  |
alpha_1  | goroutine 41 [running]:
alpha_1  | log.Panicf(0x1dae9fb, 0x2b, 0xc00056e780, 0x4, 0x4)
alpha_1  | 	/usr/local/go/src/log/log.go:358 +0xc5
alpha_1  | github.com/dgraph-io/dgraph/x.(*ToGlog).Panicf(0x2dffcb8, 0x1dae9fb, 0x2b, 0xc00056e780, 0x4, 0x4)
alpha_1  | 	/ext-go/1/src/github.com/dgraph-io/dgraph/x/log.go:40 +0x53
alpha_1  | go.etcd.io/etcd/raft.(*raft).loadState(0xc000146140, 0x5, 0x1, 0x1606, 0x0, 0x0, 0x0)
alpha_1  | 	/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/raft.go:1475 +0x1c4
alpha_1  | go.etcd.io/etcd/raft.newRaft(0xc0003f2420, 0x180)
alpha_1  | 	/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/raft.go:377 +0xd55
alpha_1  | go.etcd.io/etcd/raft.RestartNode(0xc0003f2420, 0x1, 0xc00038e060)
alpha_1  | 	/go/pkg/mod/go.etcd.io/etcd@v0.0.0-20190228193606-a943ad0ee4c9/raft/node.go:242 +0x45
alpha_1  | github.com/dgraph-io/dgraph/worker.(*node).InitAndStartNode(0xc000214100)
alpha_1  | 	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/draft.go:1708 +0x437
alpha_1  | github.com/dgraph-io/dgraph/worker.StartRaftNodes(0xc00003e0a0, 0x1)
alpha_1  | 	/ext-go/1/src/github.com/dgraph-io/dgraph/worker/groups.go:147 +0x745
alpha_1  | github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run.func4(0xc00018e090)
alpha_1  | 	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:760 +0x3c
alpha_1  | created by github.com/dgraph-io/dgraph/dgraph/cmd/alpha.run
alpha_1  | 	/ext-go/1/src/github.com/dgraph-io/dgraph/dgraph/cmd/alpha/run.go:759 +0x12c5
dgraph_alpha_1 exited with code 2

Thanks Ron

2

This looks like a common problem that happens when you mix old files with new ones. The only way to fix this is to start from scratch.

3

Thanks for your anwer.

I don’t mixed old and new files. It was a blank installation. No data was set.
In this case, it’s not a problem to start from scratch.

Is there a documentation about the content of the directories?

4

It was just an example. If you do several tries, sometimes the volume is reused and without noticing it happens. I have seen this several times, it is a matter of attention sometimes.

Go for me, always starting from scratch helps when you don’t know the source of the issue. If that doesn’t solve the case. Then we have a problem.

Not in special, just mentions.