Dgraph cluster not initialize on v20.11.0 and v20.11.1

Pod logs

alpha-0
++ hostname -f
++ awk '{gsub(/\.$/,""); print $0}'
+ dgraph alpha --my=dgraph-alpha-0.dgraph-alpha-headless.production-services.svc.cluster.local:7080 --zero dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080,dgraph-zero-1.dgraph-zero-headless.production-services.svc.cluster.local:5080,dgraph-zero-2.dgraph-zero-headless.production-services.svc.cluster.local:5080 --whitelist 192.168.0.0:192.168.255.255
[Decoder]: Using assembly version of decoder
Page Size: 4096
[Sentry] 2021/02/05 08:14:57 Integration installed: ContextifyFrames
[Sentry] 2021/02/05 08:14:57 Integration installed: Environment
[Sentry] 2021/02/05 08:14:57 Integration installed: Modules
[Sentry] 2021/02/05 08:14:57 Integration installed: IgnoreErrors
[Decoder]: Using assembly version of decoder
Page Size: 4096
[Sentry] 2021/02/05 08:14:58 Integration installed: ContextifyFrames
[Sentry] 2021/02/05 08:14:58 Integration installed: Environment
[Sentry] 2021/02/05 08:14:58 Integration installed: Modules
[Sentry] 2021/02/05 08:14:58 Integration installed: IgnoreErrors
I0205 08:14:58.391933      17 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.
W0205 08:14:58.392818      17 run.go:573] --lru_mb is deprecated, use --cache_mb instead
I0205 08:14:58.603221      17 init.go:107] 

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.hypermode.com.

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


I0205 08:14:58.603259      17 run.go:696] x.Config: {PortOffset:0 QueryEdgeLimit:1000000 NormalizeNodeLimit:10000 MutationsNQuadLimit:1000000 PollInterval:1s GraphqlExtension:true GraphqlDebug:false GraphqlLambdaUrl:}
I0205 08:14:58.603294      17 run.go:697] x.WorkerConfig: {TmpDir:t ExportPath:export NumPendingProposals:256 Tracing:0.01 MyAddr:dgraph-alpha-0.dgraph-alpha-headless.production-services.svc.cluster.local:7080 ZeroAddr:[dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080 dgraph-zero-1.dgraph-zero-headless.production-services.svc.cluster.local:5080 dgraph-zero-2.dgraph-zero-headless.production-services.svc.cluster.local:5080] TLSClientConfig:<nil> TLSServerConfig:<nil> RaftId:0 WhiteListedIPRanges:[{Lower:192.168.0.0 Upper:192.168.255.255}] MaxRetries:-1 StrictMutations:false AclEnabled:false AbortOlderThan:5m0s SnapshotAfter:10000 ProposedGroupId:0 StartTime:2021-02-05 08:14:57.932525096 +0000 UTC m=+0.023188101 LudicrousMode:false LudicrousConcurrency:2000 EncryptionKey:**** LogRequest:0 HardSync:false}
I0205 08:14:58.603372      17 run.go:698] worker.Config: {PostingDir:p PostingDirCompression:1 PostingDirCompressionLevel:0 WALDir:w MutationsMode:0 AuthToken: PBlockCacheSize:1395864371 PIndexCacheSize:751619276 WalCache:0 HmacSecret:**** AccessJwtTtl:0s RefreshJwtTtl:0s CachePercentage:0,65,35,0 CacheMb:0}
I0205 08:14:58.606535      17 storage.go:132] Init Raft Storage with snap: 0, first: 1, last: 0
I0205 08:14:58.607205      17 server_state.go:76] Setting Posting Dir Compression Level: 0
I0205 08:14:58.607254      17 server_state.go:120] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x2e0ddf8 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:1395864371 IndexCacheSize:751619276 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}
I0205 08:14:58.636215      17 log.go:34] All 0 tables opened in 0s
I0205 08:14:58.639563      17 log.go:34] Discard stats nextEmptySlot: 0
I0205 08:14:58.639627      17 log.go:34] Set nextTxnTs to 0
I0205 08:14:58.641394      17 groups.go:99] Current Raft Id: 0x0
E0205 08:14:58.641377      17 groups.go:1143] Error during SubscribeForUpdates for prefix "\x00\x00\vdgraph.cors\x00": Unable to find any servers for group: 1. closer err: <nil>
I0205 08:14:58.642055      17 worker.go:104] Worker listening at address: [::]:7080
I0205 08:14:58.644267      17 run.go:519] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql
I0205 08:14:58.644303      17 run.go:520] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin
E0205 08:14:58.644276      17 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>
I0205 08:14:58.644386      17 run.go:552] gRPC server started.  Listening on port 9080
I0205 08:14:58.644412      17 run.go:553] HTTP server started.  Listening on port 8080
I0205 08:14:58.742122      17 pool.go:162] CONNECTING to dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080
I0205 08:14:58.771448      17 groups.go:127] Connected to group zero. Assigned group: 1
I0205 08:14:58.771509      17 groups.go:129] Raft Id after connection to Zero: 0x1
I0205 08:14:58.771677      17 pool.go:162] CONNECTING to dgraph-zero-2.dgraph-zero-headless.production-services.svc.cluster.local:5080
I0205 08:14:58.772209      17 pool.go:162] CONNECTING to dgraph-zero-1.dgraph-zero-headless.production-services.svc.cluster.local:5080
I0205 08:14:58.773345      17 draft.go:230] Node ID: 0x1 with GroupID: 1
I0205 08:14:58.773493      17 node.go:152] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00009a2d0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x2e0ddf8 DisableProposalForwarding:false}
I0205 08:14:58.774403      17 node.go:326] Group 1 found 0 entries
I0205 08:14:58.774971      17 draft.go:1712] New Node for group: 1
I0205 08:14:58.775214      17 log.go:34] 1 became follower at term 0
I0205 08:14:58.775411      17 log.go:34] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]
I0205 08:14:58.775520      17 log.go:34] 1 became follower at term 1
I0205 08:14:58.775636      17 draft.go:180] Operation started with id: opRollup
I0205 08:14:58.775978      17 draft.go:1084] Found Raft progress: 0
I0205 08:14:58.776272      17 node.go:189] Setting conf state to nodes:1 
I0205 08:14:58.776753      17 groups.go:807] Got address of a Zero leader: dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080
I0205 08:14:58.776906      17 groups.go:821] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080.
I0205 08:14:58.777215      17 log.go:34] 1 is starting a new election at term 1
I0205 08:14:58.777247      17 log.go:34] 1 became pre-candidate at term 1
I0205 08:14:58.777255      17 log.go:34] 1 received MsgPreVoteResp from 1 at term 1
I0205 08:14:58.777472      17 log.go:34] 1 became candidate at term 2
I0205 08:14:58.777481      17 log.go:34] 1 received MsgVoteResp from 1 at term 2
I0205 08:14:58.777494      17 log.go:34] 1 became leader at term 2
I0205 08:14:58.777639      17 log.go:34] raft.node: 1 elected leader 1 at term 2
I0205 08:14:58.782339      17 groups.go:838] Received first state update from Zero: counter:7 groups:<key:1 value:<members:<key:1 value:<id:1 group_id:1 addr:"dgraph-alpha-0.dgraph-alpha-headless.production-services.svc.cluster.local:7080" > > > > zeros:<key:1 value:<id:1 addr:"dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080" leader:true > > zeros:<key:2 value:<id:2 addr:"dgraph-zero-1.dgraph-zero-headless.production-services.svc.cluster.local:5080" > > zeros:<key:3 value:<id:3 addr:"dgraph-zero-2.dgraph-zero-headless.production-services.svc.cluster.local:5080" > > maxRaftId:1 cid:"de31e002-671e-4295-8aa4-69a9563db183" license:<maxNodes:18446744073709551615 expiryTs:1615104462 enabled:true > 
I0205 08:14:59.642779      17 pool.go:162] CONNECTING to dgraph-alpha-0.dgraph-alpha-headless.production-services.svc.cluster.local:7080
I0205 08:14:59.776308      17 groups.go:893] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0205 08:14:59.776421      17 groups.go:905] Got Zero leader: dgraph-zero-0.dgraph-zero-headless.production-services.svc.cluster.local:5080
I0205 08:14:59.790928      17 groups.go:487] Serving tablet for: dgraph.cors
I0205 08:14:59.791391      17 draft.go:180] Operation started with id: opIndexing
I0205 08:14:59.791441      17 index.go:889] Computing prefix index for attr dgraph.cors and tokenizers []
I0205 08:14:59.791448      17 index.go:907] Deleting index for attr dgraph.cors and tokenizers [exact]
I0205 08:14:59.791517      17 index.go:779] Deleting indexes for dgraph.cors
I0205 08:14:59.791529      17 log.go:34] DropPrefix called for [dgraph.cors dgraph.cors dgraph.cors dgraph.cors]
I0205 08:14:59.791570      17 log.go:34] Writes flushed. Stopping compactions now...
I0205 08:14:59.791663      17 draft.go:124] Operation completed with id: opRollup
I0205 08:14:59.794378      17 log.go:34] DropPrefix done
I0205 08:14:59.794398      17 log.go:34] Resuming writes
I0205 08:14:59.820387      17 log.go:34] Rebuilding index for predicate dgraph.cors (1/2): Sent data of size 0 B
I0205 08:14:59.831542      17 index.go:942] Rebuilding index for attr dgraph.cors and tokenizers [exact]
I0205 08:14:59.839604      17 groups.go:487] Serving tablet for: dgraph.type
I0205 08:14:59.854852      17 log.go:34] Rebuilding index for predicate dgraph.cors (1/2): Sent data of size 0 B
I0205 08:14:59.862979      17 mutation.go:188] Done schema update predicate:"dgraph.cors" value_type:STRING directive:INDEX tokenizer:"exact" list:true upsert:true 
I0205 08:14:59.863333      17 draft.go:124] Operation completed with id: opIndexing
E0205 08:14:59.863168      17 draft.go:714] Applying proposal. Error: operation opIndexing is already running. Proposal: {"group_id:1 start_ts:2 schema:<predicate:\"dgraph.type\" value_type:STRING directive:INDEX tokenizer:\"exact\" list:true > " [] "<nil>" "" "<nil>" "<nil>" '\b' '\x00' "<nil>" {} "" '\x00'}.
E0205 08:14:59.863546      17 groups.go:260] Error while proposing initial schema: operation opIndexing is already running
I0205 08:14:59.964163      17 draft.go:180] Operation started with id: opIndexing
I0205 08:14:59.964249      17 index.go:889] Computing prefix index for attr dgraph.type and tokenizers []
I0205 08:14:59.964260      17 index.go:907] Deleting index for attr dgraph.type and tokenizers [exact]
I0205 08:14:59.964327      17 index.go:779] Deleting indexes for dgraph.type
I0205 08:14:59.964339      17 log.go:34] DropPrefix called for [dgraph.type dgraph.type dgraph.type dgraph.type]
I0205 08:14:59.964360      17 log.go:34] Writes flushed. Stopping compactions now...
I0205 08:14:59.989912      17 log.go:34] DropPrefix done
I0205 08:14:59.989972      17 log.go:34] Resuming writes
I0205 08:15:00.096132      17 log.go:34] Rebuilding index for predicate dgraph.type (1/2): Sent data of size 0 B
I0205 08:15:00.106508      17 index.go:942] Rebuilding index for attr dgraph.type and tokenizers [exact]
I0205 08:15:00.114464      17 groups.go:487] Serving tablet for: dgraph.drop.op
I0205 08:15:00.253789      17 log.go:34] Rebuilding index for predicate dgraph.type (1/2): Sent data of size 0 B
I0205 08:15:00.267557      17 mutation.go:188] Done schema update predicate:"dgraph.type" value_type:STRING directive:INDEX tokenizer:"exact" list:true 
I0205 08:15:00.267994      17 draft.go:124] Operation completed with id: opIndexing
E0205 08:15:00.267988      17 draft.go:714] Applying proposal. Error: operation opIndexing is already running. Proposal: {"group_id:1 start_ts:3 schema:<predicate:\"dgraph.drop.op\" value_type:STRING > " [] "<nil>" "" "<nil>" "<nil>" '\r' '\x00' "<nil>" {} "" '\x00'}.
E0205 08:15:00.268221      17 groups.go:260] Error while proposing initial schema: operation opIndexing is already running
I0205 08:15:00.369159      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.369241      17 index.go:779] Deleting indexes for dgraph.drop.op
I0205 08:15:00.369440      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:00.377470      17 groups.go:487] Serving tablet for: dgraph.graphql.schema
I0205 08:15:00.377640      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.377722      17 index.go:779] Deleting indexes for dgraph.graphql.schema
I0205 08:15:00.377941      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:00.385259      17 groups.go:487] Serving tablet for: dgraph.graphql.xid
I0205 08:15:00.385738      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.385863      17 index.go:889] Computing prefix index for attr dgraph.graphql.xid and tokenizers []
I0205 08:15:00.385911      17 index.go:907] Deleting index for attr dgraph.graphql.xid and tokenizers [exact]
I0205 08:15:00.385999      17 index.go:779] Deleting indexes for dgraph.graphql.xid
I0205 08:15:00.386012      17 log.go:34] DropPrefix called for [dgraph.graphql.xid dgraph.graphql.xid dgraph.graphql.xid dgraph.graphql.xid]
I0205 08:15:00.386033      17 log.go:34] Writes flushed. Stopping compactions now...
I0205 08:15:00.462746      17 log.go:34] DropPrefix done
I0205 08:15:00.462819      17 log.go:34] Resuming writes
I0205 08:15:00.462938      17 index.go:942] Rebuilding index for attr dgraph.graphql.xid and tokenizers [exact]
I0205 08:15:00.470640      17 groups.go:487] Serving tablet for: dgraph.graphql.schema_history
I0205 08:15:00.625717      17 log.go:34] Rebuilding index for predicate dgraph.graphql.xid (1/2): Sent data of size 0 B
I0205 08:15:00.644274      17 mutation.go:188] Done schema update predicate:"dgraph.graphql.xid" value_type:STRING directive:INDEX tokenizer:"exact" upsert:true 
E0205 08:15:00.644425      17 draft.go:714] Applying proposal. Error: operation opIndexing is already running. Proposal: {"group_id:1 start_ts:6 schema:<predicate:\"dgraph.graphql.schema_history\" value_type:STRING > " [] "<nil>" "" "<nil>" "<nil>" '\x17' '\x00' "<nil>" {} "" '\x00'}.
I0205 08:15:00.644539      17 draft.go:124] Operation completed with id: opIndexing
E0205 08:15:00.644573      17 groups.go:260] Error while proposing initial schema: operation opIndexing is already running
I0205 08:15:00.745310      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.745421      17 index.go:779] Deleting indexes for dgraph.graphql.schema_history
I0205 08:15:00.745542      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:00.755122      17 groups.go:487] Serving tablet for: dgraph.graphql.schema_created_at
I0205 08:15:00.755679      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.755742      17 index.go:779] Deleting indexes for dgraph.graphql.schema_created_at
I0205 08:15:00.755940      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:00.762676      17 groups.go:487] Serving tablet for: dgraph.graphql.p_query
I0205 08:15:00.763174      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.763318      17 index.go:779] Deleting indexes for dgraph.graphql.p_query
I0205 08:15:00.763566      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:00.770488      17 groups.go:487] Serving tablet for: dgraph.graphql.p_sha256hash
I0205 08:15:00.770682      17 draft.go:180] Operation started with id: opIndexing
I0205 08:15:00.770782      17 index.go:889] Computing prefix index for attr dgraph.graphql.p_sha256hash and tokenizers []
I0205 08:15:00.770796      17 index.go:907] Deleting index for attr dgraph.graphql.p_sha256hash and tokenizers [exact]
I0205 08:15:00.770850      17 index.go:779] Deleting indexes for dgraph.graphql.p_sha256hash
I0205 08:15:00.770862      17 log.go:34] DropPrefix called for [edgraph.graphql.p_sha256hash edgraph.graphql.p_sha256hash edgraph.graphql.p_sha256hash edgraph.graphql.p_sha256hash]
I0205 08:15:00.770887      17 log.go:34] Writes flushed. Stopping compactions now...
I0205 08:15:00.821329      17 log.go:34] DropPrefix done
I0205 08:15:00.821405      17 log.go:34] Resuming writes
I0205 08:15:00.821684      17 index.go:942] Rebuilding index for attr dgraph.graphql.p_sha256hash and tokenizers [exact]
I0205 08:15:00.826367      17 groups.go:159] Server is ready
I0205 08:15:00.826541      17 access_ee.go:390] ResetAcl closed
I0205 08:15:00.826703      17 access_ee.go:311] RefreshAcls closed
I0205 08:15:00.840753      17 graphql.go:41] ResetCors closed
I0205 08:15:00.842584      17 run.go:813] Updating cors from subscription.
I0205 08:15:00.842616      17 run.go:837] Updating cors origins: [*]
I0205 08:15:00.876431      17 log.go:34] Rebuilding index for predicate dgraph.graphql.p_sha256hash (1/2): Sent data of size 0 B
I0205 08:15:00.893284      17 mutation.go:188] Done schema update predicate:"dgraph.graphql.p_sha256hash" value_type:STRING directive:INDEX tokenizer:"exact" 
I0205 08:15:00.893402      17 draft.go:124] Operation completed with id: opIndexing
I0205 08:15:03.646354      17 admin.go:697] No GraphQL schema in Dgraph; serving empty GraphQL API
I0205 08:15:09.863600      17 draft.go:180] Operation started with id: opRollup
I0205 08:15:58.776549      17 draft.go:606] Creating snapshot at Index: 45, ReadTs: 15
I0205 08:19:07.595885      17 pool.go:162] CONNECTING to dgraph-alpha-1.dgraph-alpha-headless.production-services.svc.cluster.local:7080
I0205 08:19:07.595917      17 node.go:586] Trying to add 0x2 to cluster. Addr: dgraph-alpha-1.dgraph-alpha-headless.production-services.svc.cluster.local:7080
I0205 08:19:07.595923      17 node.go:587] Current confstate at 0x1: nodes:1 
I0205 08:19:07.596398      17 node.go:189] Setting conf state to nodes:1 nodes:2 
I0205 08:19:07.596475      17 node.go:756] [0x2] Done joining cluster with err: <nil>
W0205 08:19:07.599286      17 pool.go:267] Connection lost with dgraph-alpha-1.dgraph-alpha-headless.production-services.svc.cluster.local:7080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-1.dgraph-alpha-headless.production-services.svc.cluster.local: no such host"
W0205 08:19:08.676254      17 node.go:420] Unable to send message to peer: 0x2. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-alpha-1.dgraph-alpha-headless.production-services.svc.cluster.local: no such host"
W0205 08:19:18.776099      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:19:28.876267      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
E0205 08:19:36.603184      17 groups.go:1035] While proposing delta with MaxAssigned: 18 and num txns: 0. Error=Server overloaded with pending proposals. Please retry later. Retrying...
W0205 08:19:38.976199      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:19:49.076213      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:19:59.176216      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
E0205 08:20:04.603922      17 groups.go:1035] While proposing delta with MaxAssigned: 18 and num txns: 0. Error=Server overloaded with pending proposals. Please retry later. Retrying...
W0205 08:20:09.276313      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:20:19.376156      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:20:29.376171      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
E0205 08:20:32.604804      17 groups.go:1035] While proposing delta with MaxAssigned: 18 and num txns: 0. Error=Server overloaded with pending proposals. Please retry later. Retrying...
W0205 08:20:39.476150      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0205 08:20:49.576104      17 node.go:420] Unable to send message to peer: 0x2. Error: Unhealthy connection