From ea7fe9fe1ff1dfe22bc8b0b9ac7744bc44f85711 Mon Sep 17 00:00:00 2001 From: Naman Jain Date: Thu, 13 May 2021 13:49:22 +0530 Subject: [PATCH] BREAKING: fix json marshal unmarshal for namespace > 127 (#7810) We used to store predicate as | (pipe | signifies concatenation). We store this as a string. is 8 bytes uint64, which when marshaled to JSON bytes mess up the predicate. This is because for the namespace greater than 127, the UTF-8 encoding might take up several bytes (also if the mapping does not exist, then it replaces it with some other rune). This affects three identified places in Dgraph: Live loader Backup and List Backup Http clients and Ratel Fix: Fix is to have a UTF-8 string when dealing with JSON. A better idea is to use UTF-8 string even for internal operations. Only when we read/write to badger we convert it into the format of the byte. New Format: - (- is the hyphen literal) (cherry picked from commit 90d77f337a8509d21e94288fa2ea0e0c8542404e) --- dgraph/cmd/alpha/http_test.go | 2 +- dgraph/cmd/alpha/upsert_test.go | 2 +- dgraph/cmd/zero/oracle.go | 4 +- edgraph/server.go | 11 +- posting/index.go | 18 +- posting/list_test.go | 16 +- t/test-286-1491914842.log | 919 ++++++++++++++++++++++++++++++++ worker/groups.go | 2 +- x/keys.go | 135 ++--- x/keys_test.go | 69 ++- 10 files changed, 1045 insertions(+), 133 deletions(-) create mode 100644 t/test-286-1491914842.log diff --git a/dgraph/cmd/alpha/http_test.go b/dgraph/cmd/alpha/http_test.go index fa1dc20f40c..f43c7fc53b4 100644 --- a/dgraph/cmd/alpha/http_test.go +++ b/dgraph/cmd/alpha/http_test.go @@ -432,7 +432,7 @@ func TestTransactionBasic(t *testing.T) { require.Equal(t, 2, len(mr.preds)) var parsedPreds []string for _, pred := range mr.preds { - p := strings.Split(pred, "-")[1] + p := strings.SplitN(pred, "-", 2)[1] parsedPreds = append(parsedPreds, x.ParseAttr(p)) } sort.Strings(parsedPreds) diff --git a/dgraph/cmd/alpha/upsert_test.go b/dgraph/cmd/alpha/upsert_test.go index a597250e7d6..f532f6a7d97 100644 --- a/dgraph/cmd/alpha/upsert_test.go +++ b/dgraph/cmd/alpha/upsert_test.go @@ -39,7 +39,7 @@ type QueryResult struct { func splitPreds(ps []string) []string { for i, p := range ps { - ps[i] = x.ParseAttr(strings.Split(p, "-")[1]) + ps[i] = x.ParseAttr(strings.SplitN(p, "-", 2)[1]) } return ps diff --git a/dgraph/cmd/zero/oracle.go b/dgraph/cmd/zero/oracle.go index 4df2de2af37..5109e095973 100644 --- a/dgraph/cmd/zero/oracle.go +++ b/dgraph/cmd/zero/oracle.go @@ -369,7 +369,7 @@ func (s *Server) commit(ctx context.Context, src *api.TxnContext) error { checkPreds := func() error { // Check if any of these tablets is being moved. If so, abort the transaction. for _, pkey := range src.Preds { - splits := strings.Split(pkey, "-") + splits := strings.SplitN(pkey, "-", 2) if len(splits) < 2 { return errors.Errorf("Unable to find group id in %s", pkey) } @@ -377,7 +377,7 @@ func (s *Server) commit(ctx context.Context, src *api.TxnContext) error { if err != nil { return errors.Wrapf(err, "unable to parse group id from %s", pkey) } - pred := strings.Join(splits[1:], "-") + pred := splits[1] tablet := s.ServingTablet(pred) if tablet == nil { return errors.Errorf("Tablet for %s is nil", pred) diff --git a/edgraph/server.go b/edgraph/server.go index 422ee8e9948..e6a621fe137 100644 --- a/edgraph/server.go +++ b/edgraph/server.go @@ -1198,16 +1198,7 @@ func filterTablets(ctx context.Context, ms *pb.MembershipState) error { return errors.Errorf("Namespace not found in JWT.") } if namespace == x.GalaxyNamespace { - // For galaxy namespace, we don't want to filter out the predicates. We only format the - // namespace to human readable form. - for _, group := range ms.Groups { - tablets := make(map[string]*pb.Tablet) - for tabletName, tablet := range group.Tablets { - tablet.Predicate = x.FormatNsAttr(tablet.Predicate) - tablets[x.FormatNsAttr(tabletName)] = tablet - } - group.Tablets = tablets - } + // For galaxy namespace, we don't want to filter out the predicates. return nil } for _, group := range ms.GetGroups() { diff --git a/posting/index.go b/posting/index.go index f3a9ae17369..685cca19c7e 100644 --- a/posting/index.go +++ b/posting/index.go @@ -579,7 +579,7 @@ func (r *rebuilder) Run(ctx context.Context) error { glog.V(1).Infof( "Rebuilding index for predicate %s: Starting process. StartTs=%d. Prefix=\n%s\n", - x.FormatNsAttr(r.attr), r.startTs, hex.Dump(r.prefix)) + r.attr, r.startTs, hex.Dump(r.prefix)) // Counter is used here to ensure that all keys are committed at different timestamp. // We set it to 1 in case there are no keys found and NewStreamAt is called with ts=0. @@ -587,8 +587,7 @@ func (r *rebuilder) Run(ctx context.Context) error { tmpWriter := tmpDB.NewManagedWriteBatch() stream := pstore.NewStreamAt(r.startTs) - stream.LogPrefix = fmt.Sprintf("Rebuilding index for predicate %s (1/2):", - x.FormatNsAttr(r.attr)) + stream.LogPrefix = fmt.Sprintf("Rebuilding index for predicate %s (1/2):", r.attr) stream.Prefix = r.prefix stream.KeyToList = func(key []byte, itr *badger.Iterator) (*bpb.KVList, error) { // We should return quickly if the context is no longer valid. @@ -650,21 +649,19 @@ func (r *rebuilder) Run(ctx context.Context) error { return err } glog.V(1).Infof("Rebuilding index for predicate %s: building temp index took: %v\n", - x.FormatNsAttr(r.attr), time.Since(start)) + r.attr, time.Since(start)) // Now we write all the created posting lists to disk. - glog.V(1).Infof("Rebuilding index for predicate %s: writing index to badger", - x.FormatNsAttr(r.attr)) + glog.V(1).Infof("Rebuilding index for predicate %s: writing index to badger", r.attr) start = time.Now() defer func() { glog.V(1).Infof("Rebuilding index for predicate %s: writing index took: %v\n", - x.FormatNsAttr(r.attr), time.Since(start)) + r.attr, time.Since(start)) }() writer := pstore.NewManagedWriteBatch() tmpStream := tmpDB.NewStreamAt(counter) - tmpStream.LogPrefix = fmt.Sprintf("Rebuilding index for predicate %s (2/2):", - x.FormatNsAttr(r.attr)) + tmpStream.LogPrefix = fmt.Sprintf("Rebuilding index for predicate %s (2/2):", r.attr) tmpStream.KeyToList = func(key []byte, itr *badger.Iterator) (*bpb.KVList, error) { l, err := ReadPostingList(key, itr) if err != nil { @@ -707,8 +704,7 @@ func (r *rebuilder) Run(ctx context.Context) error { if err := tmpStream.Orchestrate(ctx); err != nil { return err } - glog.V(1).Infof("Rebuilding index for predicate %s: Flushing all writes.\n", - x.FormatNsAttr(r.attr)) + glog.V(1).Infof("Rebuilding index for predicate %s: Flushing all writes.\n", r.attr) return writer.Flush() } diff --git a/posting/list_test.go b/posting/list_test.go index d6a551242d9..05f7e1173d8 100644 --- a/posting/list_test.go +++ b/posting/list_test.go @@ -563,7 +563,7 @@ func TestAddMutation_mrjn2(t *testing.T) { } func TestAddMutation_gru(t *testing.T) { - key := x.DataKey("question.tag", 0x01) + key := x.DataKey(x.GalaxyAttr("question.tag"), 0x01) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) @@ -596,7 +596,7 @@ func TestAddMutation_gru(t *testing.T) { } func TestAddMutation_gru2(t *testing.T) { - key := x.DataKey("question.tag", 0x100) + key := x.DataKey(x.GalaxyAttr("question.tag"), 0x100) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) @@ -643,7 +643,7 @@ func TestAddMutation_gru2(t *testing.T) { func TestAddAndDelMutation(t *testing.T) { // Ensure each test uses unique key since we don't clear the postings // after each test - key := x.DataKey("dummy_key", 0x927) + key := x.DataKey(x.GalaxyAttr("dummy_key"), 0x927) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) @@ -882,7 +882,7 @@ func createMultiPartList(t *testing.T, size int, addFacet bool) (*List, int) { defer setMaxListSize(maxListSize) maxListSize = 5000 - key := x.DataKey(uuid.New().String(), 1331) + key := x.DataKey(x.GalaxyAttr(uuid.New().String()), 1331) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) commits := 0 @@ -931,7 +931,7 @@ func createAndDeleteMultiPartList(t *testing.T, size int) (*List, int) { defer setMaxListSize(maxListSize) maxListSize = 1000 - key := x.DataKey(uuid.New().String(), 1331) + key := x.DataKey(x.GalaxyAttr(uuid.New().String()), 1331) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) commits := 0 @@ -1095,7 +1095,7 @@ func TestBinSplit(t *testing.T) { defer func() { maxListSize = originalListSize }() - key := x.DataKey(uuid.New().String(), 1331) + key := x.DataKey(x.GalaxyAttr(uuid.New().String()), 1331) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) for i := 1; i <= size; i++ { @@ -1331,7 +1331,7 @@ func TestMultiPartListDeleteAndAdd(t *testing.T) { maxListSize = 5000 // Add entries to the maps. - key := x.DataKey(uuid.New().String(), 1331) + key := x.DataKey(x.GalaxyAttr(uuid.New().String()), 1331) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) for i := 1; i <= size; i++ { @@ -1472,7 +1472,7 @@ func TestRecursiveSplits(t *testing.T) { // Create a list that should be split recursively. size := int(1e5) - key := x.DataKey(uuid.New().String(), 1331) + key := x.DataKey(x.GalaxyAttr(uuid.New().String()), 1331) ol, err := getNew(key, ps, math.MaxUint64) require.NoError(t, err) commits := 0 diff --git a/t/test-286-1491914842.log b/t/test-286-1491914842.log new file mode 100644 index 00000000000..12fc576f97d --- /dev/null +++ b/t/test-286-1491914842.log @@ -0,0 +1,919 @@ +2021/05/19 08:04:36 profile: block profiling enabled, /tmp/profile706780864/block.pprof +[Sentry] 2021/05/19 08:04:36 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:36 Integration installed: Environment +[Sentry] 2021/05/19 08:04:36 Integration installed: Modules +[Sentry] 2021/05/19 08:04:36 Integration installed: IgnoreErrors +[Sentry] 2021/05/19 08:04:37 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:37 Integration installed: Environment +[Sentry] 2021/05/19 08:04:37 Integration installed: Modules +[Sentry] 2021/05/19 08:04:37 Integration installed: IgnoreErrors +2021/05/19 08:04:37 profile: block profiling enabled, /tmp/profile605144523/block.pprof +I0519 08:04:38.099403 18 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:38.537363 18 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:38.537468 18 run.go:254] Setting Config to: {raft:0xc0001b20b0 telemetry:0xc0002fc060 limit:0xc0001b20b8 bindall:true portOffset:0 numReplicas:3 peer: w:zw rebalanceInterval:480000000000 tlsClientConfig: audit: limiterConfig:0xc0001b03c0} +I0519 08:04:38.537528 18 run.go:144] Setting up grpc listener at: 0.0.0.0:5080 +I0519 08:04:38.537833 18 run.go:144] Setting up http listener at: 0.0.0.0:6080 +I0519 08:04:38.539382 18 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:38.539652 18 node.go:152] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc0004f6440 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:38.540955 18 node.go:326] Group 0 found 0 entries +I0519 08:04:38.541219 18 raft.go:663] Starting a brand new node +I0519 08:04:38.541330 18 log.go:34] 1 became follower at term 0 +I0519 08:04:38.541419 18 log.go:34] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:38.541506 18 log.go:34] 1 became follower at term 1 +I0519 08:04:38.541918 18 zero.go:116] Starting telemetry data collection for zero... +E0519 08:04:38.542222 18 raft.go:547] While proposing CID: Not Zero leader. Aborting proposal: cid:"63ee35ab-5bbf-42b1-949e-90810e7cea96" . Retrying... +I0519 08:04:38.542308 18 run.go:388] Running Dgraph Zero... +I0519 08:04:38.542142 18 node.go:189] Setting conf state to nodes:1 +I0519 08:04:38.542731 18 raft.go:966] Done applying conf change at 0x1 +I0519 08:04:38.785296 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:38.785468 18 log.go:34] 1 no leader at term 1; dropping index reading msg +W0519 08:04:40.786439 18 node.go:680] [0x1] Read index context timed out +I0519 08:04:40.786488 18 log.go:34] 1 no leader at term 1; dropping index reading msg +I0519 08:04:40.964886 18 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:40.964937 18 node.go:585] Trying to add 0x2 to cluster. Addr: zero2:5080 +I0519 08:04:40.964945 18 node.go:586] Current confstate at 0x1: nodes:1 +E0519 08:04:41.545028 18 raft.go:547] While proposing CID: Not Zero leader. Aborting proposal: cid:"b5dc2403-9620-41f5-bee5-0fe8c710bda1" . Retrying... +I0519 08:04:42.342559 18 log.go:34] 1 is starting a new election at term 1 +I0519 08:04:42.342592 18 log.go:34] 1 became pre-candidate at term 1 +I0519 08:04:42.342600 18 log.go:34] 1 received MsgPreVoteResp from 1 at term 1 +I0519 08:04:42.342623 18 log.go:34] 1 became candidate at term 2 +I0519 08:04:42.342627 18 log.go:34] 1 received MsgVoteResp from 1 at term 2 +I0519 08:04:42.342641 18 log.go:34] 1 became leader at term 2 +I0519 08:04:42.342648 18 log.go:34] raft.node: 1 elected leader 1 at term 2 +I0519 08:04:42.342719 18 raft.go:912] I've become the leader, updating leases. +I0519 08:04:42.342727 18 assign.go:47] Updated UID: 1. Txn Ts: 1. NsID: 1. +I0519 08:04:42.344419 18 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:42.344483 18 raft.go:966] Done applying conf change at 0x1 +I0519 08:04:42.344569 18 node.go:755] [0x2] Done joining cluster with err: +I0519 08:04:42.634803 18 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:42.634816 18 node.go:585] Trying to add 0x3 to cluster. Addr: zero3:5080 +I0519 08:04:42.634822 18 node.go:586] Current confstate at 0x1: nodes:1 nodes:2 +W0519 08:04:42.786732 18 node.go:680] [0x1] Read index context timed out +I0519 08:04:44.445021 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.445317 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.445989 18 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:44.446027 18 raft.go:966] Done applying conf change at 0x1 +I0519 08:04:44.446076 18 node.go:755] [0x3] Done joining cluster with err: +I0519 08:04:44.447929 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.448021 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.450049 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.450151 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.450661 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.450994 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.451657 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.451699 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.452210 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.452241 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.452813 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.452855 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.453535 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.545633 18 raft.go:540] CID set for cluster: 2374c3f6-f0a2-4482-8073-43a6ae90ac6f +I0519 08:04:44.546222 18 license_ee.go:46] Enterprise trial license proposed to the cluster: license: +I0519 08:04:44.588703 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.589359 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.590278 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.590832 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.731877 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:44.732473 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:44.733024 18 zero.go:447] Got connection request: addr:"alpha5:7080" +I0519 08:04:44.733604 18 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:44.734433 18 zero.go:612] Connected: id:1 group_id:1 addr:"alpha5:7080" +I0519 08:04:45.474045 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.474511 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.475340 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.475760 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.553208 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.553713 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.553795 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.554218 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.554321 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.554907 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.555009 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.555704 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.555805 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.556367 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.556451 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.557044 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.557437 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.557993 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.558080 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.558505 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.615100 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.615676 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.616303 18 zero.go:447] Got connection request: addr:"alpha6:7080" +I0519 08:04:45.616946 18 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.617641 18 zero.go:612] Connected: id:2 group_id:1 addr:"alpha6:7080" +I0519 08:04:45.704121 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.704540 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.704955 18 zero.go:447] Got connection request: addr:"alpha3:7080" +I0519 08:04:45.705514 18 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.706201 18 zero.go:612] Connected: id:3 group_id:1 addr:"alpha3:7080" +I0519 08:04:45.706327 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.708146 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.709544 18 zero.go:447] Got connection request: addr:"alpha1:7080" +I0519 08:04:45.710917 18 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:45.713564 18 zero.go:612] Connected: id:4 group_id:2 addr:"alpha1:7080" +I0519 08:04:45.714150 18 zero.go:447] Got connection request: cluster_info_only:true +W0519 08:04:45.714593 18 pool.go:267] Connection lost with alpha1:7080. Error: rpc error: code = Unknown desc = No node has been set up yet +I0519 08:04:45.721123 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.721891 18 zero.go:447] Got connection request: cluster_info_only:true +I0519 08:04:45.722888 18 zero.go:472] Connected: cluster_info_only:true +I0519 08:04:45.723225 18 zero.go:447] Got connection request: addr:"alpha4:7080" +I0519 08:04:45.724102 18 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:45.724936 18 zero.go:612] Connected: id:5 group_id:2 addr:"alpha4:7080" +I0519 08:04:45.725138 18 zero.go:447] Got connection request: addr:"alpha2:7080" +I0519 08:04:45.725853 18 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:45.726575 18 zero.go:612] Connected: id:6 group_id:2 addr:"alpha2:7080" +I0519 08:04:47.655194 18 main.go:83] Num goroutines: 130 +[Sentry] 2021/05/19 08:04:38 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:38 Integration installed: Environment +[Sentry] 2021/05/19 08:04:38 Integration installed: Modules +[Sentry] 2021/05/19 08:04:38 Integration installed: IgnoreErrors +[Sentry] 2021/05/19 08:04:40 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:40 Integration installed: Environment +[Sentry] 2021/05/19 08:04:40 Integration installed: Modules +[Sentry] 2021/05/19 08:04:40 Integration installed: IgnoreErrors +I0519 08:04:40.443711 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:40.938779 16 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:40.939232 16 run.go:254] Setting Config to: {raft:0xc0000dc100 telemetry:0xc0000dc0d8 limit:0xc0000dc108 bindall:true portOffset:0 numReplicas:3 peer:zero1:5080 w:zw rebalanceInterval:480000000000 tlsClientConfig: audit: limiterConfig:0xc0000d4a30} +I0519 08:04:40.939435 16 run.go:144] Setting up grpc listener at: 0.0.0.0:5080 +I0519 08:04:40.939858 16 run.go:144] Setting up http listener at: 0.0.0.0:6080 +I0519 08:04:40.941448 16 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:40.941800 16 node.go:152] Setting raft.Config to: &{ID:2 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc0000e0e80 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:40.956510 16 node.go:326] Group 0 found 0 entries +I0519 08:04:40.956675 16 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:42.344988 16 raft.go:659] [0x2] Starting node +I0519 08:04:42.345025 16 log.go:34] 2 became follower at term 0 +I0519 08:04:42.345034 16 log.go:34] newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:42.345042 16 log.go:34] 2 became follower at term 1 +I0519 08:04:42.345400 16 zero.go:116] Starting telemetry data collection for zero... +I0519 08:04:42.345643 16 run.go:388] Running Dgraph Zero... +I0519 08:04:43.443315 16 log.go:34] 2 [term: 1] received a MsgHeartbeat message with higher term from 1 [term: 2] +I0519 08:04:43.443338 16 log.go:34] 2 became follower at term 2 +I0519 08:04:43.443347 16 log.go:34] raft.node: 2 elected leader 1 at term 2 +I0519 08:04:44.445317 16 node.go:189] Setting conf state to nodes:1 +I0519 08:04:44.445595 16 raft.go:966] Done applying conf change at 0x2 +I0519 08:04:44.445702 16 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:44.445783 16 raft.go:966] Done applying conf change at 0x2 +I0519 08:04:44.447387 16 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:44.447510 16 raft.go:966] Done applying conf change at 0x2 +I0519 08:04:44.448169 16 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:44.734659 16 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.617979 16 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.706505 16 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.713948 16 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:45.725178 16 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:45.726699 16 pool.go:162] CONNECTING to alpha2:7080 +W0519 08:04:45.732261 16 pool.go:267] Connection lost with alpha2:7080. Error: rpc error: code = Unknown desc = No node has been set up yet +I0519 08:04:50.003271 16 main.go:83] Num goroutines: 119 +[Sentry] 2021/05/19 08:04:40 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:40 Integration installed: Environment +[Sentry] 2021/05/19 08:04:40 Integration installed: Modules +[Sentry] 2021/05/19 08:04:40 Integration installed: IgnoreErrors +[Sentry] 2021/05/19 08:04:41 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:41 Integration installed: Environment +[Sentry] 2021/05/19 08:04:41 Integration installed: Modules +[Sentry] 2021/05/19 08:04:41 Integration installed: IgnoreErrors +I0519 08:04:42.215480 19 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:42.627918 19 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:42.627986 19 run.go:254] Setting Config to: {raft:0xc0001144e8 telemetry:0xc0001144c0 limit:0xc0001144f0 bindall:true portOffset:0 numReplicas:3 peer:zero1:5080 w:zw rebalanceInterval:480000000000 tlsClientConfig: audit: limiterConfig:0xc00013a6f0} +I0519 08:04:42.628052 19 run.go:144] Setting up grpc listener at: 0.0.0.0:5080 +I0519 08:04:42.628292 19 run.go:144] Setting up http listener at: 0.0.0.0:6080 +I0519 08:04:42.629331 19 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:42.629400 19 node.go:152] Setting raft.Config to: &{ID:3 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00013dcc0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:42.631905 19 node.go:326] Group 0 found 0 entries +I0519 08:04:42.632119 19 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.446313 19 raft.go:659] [0x3] Starting node +I0519 08:04:44.446419 19 log.go:34] 3 became follower at term 0 +I0519 08:04:44.446435 19 log.go:34] newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:44.446462 19 log.go:34] 3 became follower at term 1 +I0519 08:04:44.446572 19 zero.go:116] Starting telemetry data collection for zero... +I0519 08:04:44.449215 19 run.go:388] Running Dgraph Zero... +I0519 08:04:45.448980 19 log.go:34] 3 [term: 1] received a MsgHeartbeat message with higher term from 1 [term: 2] +I0519 08:04:45.448995 19 log.go:34] 3 became follower at term 2 +I0519 08:04:45.448999 19 log.go:34] raft.node: 3 elected leader 1 at term 2 +I0519 08:04:46.450983 19 node.go:189] Setting conf state to nodes:1 +I0519 08:04:46.451204 19 raft.go:966] Done applying conf change at 0x3 +I0519 08:04:46.451329 19 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:46.451378 19 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:46.451381 19 raft.go:966] Done applying conf change at 0x3 +I0519 08:04:46.451416 19 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:46.451448 19 raft.go:966] Done applying conf change at 0x3 +I0519 08:04:46.451541 19 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:46.451565 19 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:46.451751 19 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:46.451881 19 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:46.452132 19 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:46.453847 19 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:51.847940 19 main.go:83] Num goroutines: 119 +2021/05/19 08:04:36 profile: block profiling enabled, /tmp/profile381555905/block.pprof +[Sentry] 2021/05/19 08:04:36 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:36 Integration installed: Environment +[Sentry] 2021/05/19 08:04:36 Integration installed: Modules +[Sentry] 2021/05/19 08:04:36 Integration installed: IgnoreErrors +2021/05/19 08:04:37 profile: block profiling enabled, /tmp/profile467004910/block.pprof +[Sentry] 2021/05/19 08:04:37 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:37 Integration installed: Environment +[Sentry] 2021/05/19 08:04:37 Integration installed: Modules +[Sentry] 2021/05/19 08:04:37 Integration installed: IgnoreErrors +I0519 08:04:38.172347 18 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:38.173676 18 run.go:658] ACL secret key loaded successfully. +I0519 08:04:38.174014 18 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:38.673074 18 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:38.673325 18 run.go:744] x.Config: {PortOffset:0 Limit:normalize-node=10000; txn-abort-after=5m; max-pending-queries=10000; max-retries=-1; shared-instance=false; mutations=allow; query-edge=1000000; mutations-nquad=1000000; disallow-drop=false; query-timeout=0ms LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:introspection=true; debug=false; extensions=true; poll-interval=1s; lambda-url= GraphQLDebug:false} +I0519 08:04:38.673563 18 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:datadog=; ratio=0.01; jaeger= MyAddr:alpha1:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:learner=false; snapshot-after-entries=10000; snapshot-after-duration=30m; pending-proposals=256; idx=; group= Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc0004161b0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:36.821163994 +0000 UTC m=+0.343695029 Security:whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16; token= EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:38.673837 18 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:38.674504 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:38.776986 18 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.446064 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.452628 18 groups.go:1118] Retry Zero Connection +I0519 08:04:45.453038 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.554557 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.556164 18 server_state.go:114] Encryption feature enabled. +I0519 08:04:45.572729 18 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:45.572906 18 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:45.601457 18 log.go:34] All 0 tables opened in 0s +I0519 08:04:45.604924 18 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:45.604953 18 log.go:34] Set nextTxnTs to 0 +I0519 08:04:45.605612 18 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:45.605629 18 groups.go:115] Sending member request to Zero: addr:"alpha1:7080" +I0519 08:04:45.605709 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.606025 18 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:45.607570 18 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +I0519 08:04:45.607589 18 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +I0519 08:04:45.607758 18 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:45.607807 18 run.go:590] HTTP server started. Listening on port 8080 +E0519 08:04:45.607831 18 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:45.708868 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.714495 18 groups.go:134] Connected to group zero. Assigned group: 2 +I0519 08:04:45.714514 18 groups.go:136] Raft Id after connection to Zero: 0x4 +I0519 08:04:45.714584 18 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.714621 18 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.714660 18 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.714697 18 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:45.714727 18 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:45.714734 18 draft.go:306] Node ID: 0x4 with GroupID: 2 +I0519 08:04:45.714741 18 draft.go:315] RaftContext: id:4 group:2 addr:"alpha1:7080" +I0519 08:04:45.714832 18 node.go:152] Setting raft.Config to: &{ID:4 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00015b280 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:45.714918 18 node.go:326] Group 2 found 0 entries +I0519 08:04:45.714930 18 draft.go:2140] New Node for group: 2 +I0519 08:04:45.714952 18 log.go:34] 4 became follower at term 0 +I0519 08:04:45.714960 18 log.go:34] newRaft 4 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:45.714966 18 log.go:34] 4 became follower at term 1 +I0519 08:04:45.715008 18 draft.go:244] Operation started with id: opRollup +I0519 08:04:45.717216 18 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:45.717272 18 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:45.717388 18 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:45.718410 18 node.go:189] Setting conf state to nodes:4 +I0519 08:04:45.718736 18 log.go:34] 4 is starting a new election at term 1 +I0519 08:04:45.718756 18 log.go:34] 4 became pre-candidate at term 1 +I0519 08:04:45.718762 18 log.go:34] 4 received MsgPreVoteResp from 4 at term 1 +I0519 08:04:45.718776 18 log.go:34] 4 became candidate at term 2 +I0519 08:04:45.718780 18 log.go:34] 4 received MsgVoteResp from 4 at term 2 +I0519 08:04:45.718790 18 log.go:34] 4 became leader at term 2 +I0519 08:04:45.718796 18 log.go:34] raft.node: 4 elected leader 4 at term 2 +I0519 08:04:45.722920 18 groups.go:847] Received first state update from Zero: counter:11 groups: > members: > members: > > > groups: > > > zeros: > zeros: > zeros: > maxRaftId:4 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:45.736892 18 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:45.736908 18 node.go:585] Trying to add 0x5 to cluster. Addr: alpha4:7080 +I0519 08:04:45.736913 18 node.go:586] Current confstate at 0x4: nodes:4 +I0519 08:04:45.737312 18 node.go:189] Setting conf state to nodes:4 nodes:5 +I0519 08:04:45.737446 18 node.go:755] [0x5] Done joining cluster with err: +I0519 08:04:45.737812 18 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:45.738685 18 node.go:585] Trying to add 0x6 to cluster. Addr: alpha2:7080 +I0519 08:04:45.739085 18 node.go:586] Current confstate at 0x4: nodes:4 nodes:5 +I0519 08:04:46.715491 18 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:46.715515 18 groups.go:902] Leader idx=0x4 of group=2 is connecting to Zero for txn updates +I0519 08:04:46.715524 18 groups.go:914] Got Zero leader: zero1:5080 +I0519 08:04:46.715759 18 groups.go:166] Server is ready +I0519 08:04:47.407428 18 main.go:83] Num goroutines: 160 +I0519 08:04:47.645331 18 access_ee.go:437] Unable to upsert the guardian group. Error: while upserting group with id guardians: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:47.742281 18 node.go:189] Setting conf state to nodes:4 nodes:5 nodes:6 +I0519 08:04:47.742313 18 node.go:755] [0x6] Done joining cluster with err: +I0519 08:04:47.752477 18 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:47.826775 18 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:47.826791 18 access_ee.go:412] ResetAcl closed +I0519 08:04:50.611923 18 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.611999 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.612166 18 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.612177 18 login.go:38] Got login request +I0519 08:04:50.612249 18 server.go:1749] Got Login request from: "172.31.0.1:48462" +I0519 08:04:50.681712 18 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:54.972170 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:54.972322 18 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:54.972334 18 login.go:38] Got login request +I0519 08:04:54.972387 18 server.go:1749] Got Login request from: "172.31.0.1:48516" +I0519 08:04:55.041803 18 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:55.043052 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:55.043189 18 middlewares.go:210] GraphQL admin mutation. Name = deleteUser +I0519 08:04:55.047661 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:55.047834 18 middlewares.go:210] GraphQL admin mutation. Name = addUser +I0519 08:04:55.125523 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:55.125828 18 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:55.125841 18 login.go:38] Got login request +I0519 08:04:55.125924 18 server.go:1749] Got Login request from: "172.31.0.1:48528" +I0519 08:04:55.195130 18 access_ee.go:85] alice logged in successfully in namespace 0x0 +I0519 08:04:55.196258 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +2021/05/19 08:04:37 profile: block profiling enabled, /tmp/profile132444780/block.pprof +[Sentry] 2021/05/19 08:04:37 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:37 Integration installed: Environment +[Sentry] 2021/05/19 08:04:37 Integration installed: Modules +[Sentry] 2021/05/19 08:04:37 Integration installed: IgnoreErrors +2021/05/19 08:04:39 profile: block profiling enabled, /tmp/profile242578779/block.pprof +[Sentry] 2021/05/19 08:04:39 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:39 Integration installed: Environment +[Sentry] 2021/05/19 08:04:39 Integration installed: Modules +[Sentry] 2021/05/19 08:04:39 Integration installed: IgnoreErrors +I0519 08:04:40.281056 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:40.281623 17 run.go:658] ACL secret key loaded successfully. +I0519 08:04:40.284927 17 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:40.705185 17 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:40.705437 17 run.go:744] x.Config: {PortOffset:0 Limit:disallow-drop=false; query-timeout=0ms; max-pending-queries=10000; max-retries=-1; mutations=allow; query-edge=1000000; normalize-node=10000; mutations-nquad=1000000; txn-abort-after=5m; shared-instance=false LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:introspection=true; debug=false; extensions=true; poll-interval=1s; lambda-url= GraphQLDebug:false} +I0519 08:04:40.705690 17 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:ratio=0.01; jaeger=; datadog= MyAddr:alpha2:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:group=; learner=false; snapshot-after-entries=10000; snapshot-after-duration=30m; pending-proposals=256; idx= Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc0001dc0d0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:39.178040291 +0000 UTC m=+0.661061169 Security:whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16; token= EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:40.705986 17 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:40.706780 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:40.807303 17 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.448265 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.453368 17 groups.go:1118] Retry Zero Connection +I0519 08:04:45.454401 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.556761 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.558317 17 server_state.go:114] Encryption feature enabled. +I0519 08:04:45.575373 17 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:45.575458 17 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:45.604832 17 log.go:34] All 0 tables opened in 0s +I0519 08:04:45.610215 17 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:45.610249 17 log.go:34] Set nextTxnTs to 0 +I0519 08:04:45.611404 17 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:45.611583 17 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:45.611571 17 groups.go:115] Sending member request to Zero: addr:"alpha2:7080" +I0519 08:04:45.611872 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.612619 17 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +I0519 08:04:45.612632 17 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +I0519 08:04:45.612641 17 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:45.612648 17 run.go:590] HTTP server started. Listening on port 8080 +E0519 08:04:45.612667 17 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:45.724006 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.729134 17 groups.go:134] Connected to group zero. Assigned group: 2 +I0519 08:04:45.729167 17 groups.go:136] Raft Id after connection to Zero: 0x6 +I0519 08:04:45.729307 17 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.729381 17 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.729454 17 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.729500 17 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:45.729655 17 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:45.729744 17 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:45.729782 17 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:45.729791 17 draft.go:306] Node ID: 0x6 with GroupID: 2 +I0519 08:04:45.729798 17 draft.go:315] RaftContext: id:6 group:2 addr:"alpha2:7080" +I0519 08:04:45.729922 17 node.go:152] Setting raft.Config to: &{ID:6 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc00015bdc0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:45.730034 17 node.go:326] Group 2 found 0 entries +I0519 08:04:45.730063 17 draft.go:2065] Calling IsPeer +I0519 08:04:45.736422 17 draft.go:2070] Done with IsPeer call +I0519 08:04:45.736441 17 draft.go:2140] New Node for group: 2 +I0519 08:04:45.736449 17 draft.go:2147] Trying to join peers. +I0519 08:04:45.736455 17 draft.go:2048] Calling JoinCluster via leader: alpha1:7080 +I0519 08:04:47.742468 17 draft.go:2052] Done with JoinCluster call +I0519 08:04:47.742584 17 log.go:34] 6 became follower at term 0 +I0519 08:04:47.742634 17 log.go:34] newRaft 6 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:47.742680 17 log.go:34] 6 became follower at term 1 +I0519 08:04:47.742739 17 draft.go:244] Operation started with id: opRollup +I0519 08:04:47.742933 17 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:47.743220 17 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:47.743275 17 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:47.743891 17 groups.go:847] Received first state update from Zero: counter:31 groups: > members: > members: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > checksum:13681338879762120592 > > groups: > members: > members: > checksum:11160318154034397263 > > zeros: > zeros: > zeros: > maxUID:10000 maxTxnTs:10000 maxRaftId:6 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:48.743515 17 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:48.743869 17 groups.go:166] Server is ready +I0519 08:04:48.743968 17 log.go:34] 6 [term: 1] received a MsgApp message with higher term from 4 [term: 2] +I0519 08:04:48.743980 17 log.go:34] 6 became follower at term 2 +I0519 08:04:48.743988 17 log.go:34] raft.node: 6 elected leader 4 at term 2 +I0519 08:04:48.748042 17 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:48.752959 17 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:48.752978 17 access_ee.go:412] ResetAcl closed +I0519 08:04:49.665212 17 main.go:83] Num goroutines: 162 +I0519 08:04:49.746950 17 node.go:189] Setting conf state to nodes:4 +I0519 08:04:49.747155 17 node.go:189] Setting conf state to nodes:4 nodes:5 +I0519 08:04:49.747194 17 node.go:189] Setting conf state to nodes:4 nodes:5 nodes:6 +I0519 08:04:50.617954 17 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.690082 17 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.690253 17 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.690260 17 login.go:38] Got login request +I0519 08:04:50.690323 17 server.go:1749] Got Login request from: "172.31.0.1:43776" +I0519 08:04:50.758643 17 access_ee.go:85] groot logged in successfully in namespace 0x0 +2021/05/19 08:04:39 profile: block profiling enabled, /tmp/profile758604461/block.pprof +[Sentry] 2021/05/19 08:04:39 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:39 Integration installed: Environment +[Sentry] 2021/05/19 08:04:39 Integration installed: Modules +[Sentry] 2021/05/19 08:04:39 Integration installed: IgnoreErrors +2021/05/19 08:04:41 profile: block profiling enabled, /tmp/profile120289121/block.pprof +[Sentry] 2021/05/19 08:04:41 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:41 Integration installed: Environment +[Sentry] 2021/05/19 08:04:41 Integration installed: Modules +[Sentry] 2021/05/19 08:04:41 Integration installed: IgnoreErrors +I0519 08:04:41.665777 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:41.666198 17 run.go:658] ACL secret key loaded successfully. +I0519 08:04:41.666456 17 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:41.960368 17 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:41.960392 17 run.go:744] x.Config: {PortOffset:0 Limit:mutations=allow; mutations-nquad=1000000; disallow-drop=false; query-timeout=0ms; shared-instance=false; query-edge=1000000; normalize-node=10000; txn-abort-after=5m; max-pending-queries=10000; max-retries=-1 LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:extensions=true; poll-interval=1s; lambda-url=; introspection=true; debug=false GraphQLDebug:false} +I0519 08:04:41.960463 17 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:ratio=0.01; jaeger=; datadog= MyAddr:alpha3:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:group=; learner=false; snapshot-after-entries=10000; snapshot-after-duration=30m; pending-proposals=256; idx= Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc000078360 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:40.464487176 +0000 UTC m=+0.387202331 Security:whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16; token= EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:41.960648 17 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:41.961198 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:42.061471 17 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.450620 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.452050 17 groups.go:1118] Retry Zero Connection +I0519 08:04:45.452754 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.553973 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.555217 17 server_state.go:114] Encryption feature enabled. +I0519 08:04:45.569602 17 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:45.569703 17 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:45.598806 17 log.go:34] All 0 tables opened in 0s +I0519 08:04:45.602410 17 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:45.602445 17 log.go:34] Set nextTxnTs to 0 +I0519 08:04:45.603142 17 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:45.603168 17 groups.go:115] Sending member request to Zero: addr:"alpha3:7080" +I0519 08:04:45.603335 17 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:45.603351 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.604416 17 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +I0519 08:04:45.604427 17 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +E0519 08:04:45.604420 17 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:45.604436 17 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:45.604476 17 run.go:590] HTTP server started. Listening on port 8080 +I0519 08:04:45.704751 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.706654 17 groups.go:134] Connected to group zero. Assigned group: 1 +I0519 08:04:45.706676 17 groups.go:136] Raft Id after connection to Zero: 0x3 +I0519 08:04:45.706741 17 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.706771 17 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.706790 17 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:45.706817 17 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:45.706824 17 draft.go:306] Node ID: 0x3 with GroupID: 1 +I0519 08:04:45.706829 17 draft.go:315] RaftContext: id:3 group:1 addr:"alpha3:7080" +I0519 08:04:45.706895 17 node.go:152] Setting raft.Config to: &{ID:3 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc000049980 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:45.706950 17 node.go:326] Group 1 found 0 entries +I0519 08:04:45.706956 17 draft.go:2065] Calling IsPeer +I0519 08:04:45.709992 17 draft.go:2070] Done with IsPeer call +I0519 08:04:45.710005 17 draft.go:2140] New Node for group: 1 +I0519 08:04:45.710014 17 draft.go:2147] Trying to join peers. +I0519 08:04:45.710024 17 draft.go:2048] Calling JoinCluster via leader: alpha5:7080 +I0519 08:04:47.638797 17 draft.go:2052] Done with JoinCluster call +I0519 08:04:47.638859 17 log.go:34] 3 became follower at term 0 +I0519 08:04:47.638867 17 log.go:34] newRaft 3 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:47.638870 17 log.go:34] 3 became follower at term 1 +I0519 08:04:47.638893 17 draft.go:244] Operation started with id: opRollup +I0519 08:04:47.639039 17 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:47.639221 17 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:47.639289 17 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:47.640229 17 groups.go:847] Received first state update from Zero: counter:26 groups: > members: > members: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > tablets: > checksum:13681338879762120592 > > groups: > members: > members: > checksum:11160318154034397263 > > zeros: > zeros: > zeros: > maxTxnTs:10000 maxRaftId:6 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:47.640645 17 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:47.640727 17 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:47.640748 17 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:48.639010 17 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:48.639207 17 log.go:34] 3 [term: 1] received a MsgApp message with higher term from 1 [term: 2] +I0519 08:04:48.639220 17 log.go:34] 3 became follower at term 2 +I0519 08:04:48.639228 17 log.go:34] raft.node: 3 elected leader 1 at term 2 +I0519 08:04:48.640153 17 groups.go:166] Server is ready +I0519 08:04:49.640860 17 node.go:189] Setting conf state to nodes:1 +I0519 08:04:49.641023 17 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:49.641046 17 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:49.641530 17 log.go:34] Handover found 2038 B data in current memtable. Pushing to flushChan. +I0519 08:04:49.649565 17 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:49.654152 17 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:49.654338 17 access_ee.go:412] ResetAcl closed +I0519 08:04:49.654420 17 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:50.606732 17 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.769559 17 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.769735 17 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.769743 17 login.go:38] Got login request +I0519 08:04:50.769806 17 server.go:1749] Got Login request from: "172.31.0.1:39748" +I0519 08:04:50.838514 17 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:51.133282 17 main.go:83] Num goroutines: 178 +2021/05/19 08:04:41 profile: block profiling enabled, /tmp/profile507204121/block.pprof +[Sentry] 2021/05/19 08:04:41 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:41 Integration installed: Environment +[Sentry] 2021/05/19 08:04:41 Integration installed: Modules +[Sentry] 2021/05/19 08:04:41 Integration installed: IgnoreErrors +2021/05/19 08:04:42 profile: block profiling enabled, /tmp/profile828319670/block.pprof +[Sentry] 2021/05/19 08:04:42 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:42 Integration installed: Environment +[Sentry] 2021/05/19 08:04:42 Integration installed: Modules +[Sentry] 2021/05/19 08:04:42 Integration installed: IgnoreErrors +I0519 08:04:43.126042 18 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:43.126383 18 run.go:658] ACL secret key loaded successfully. +I0519 08:04:43.126604 18 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:43.368218 18 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:43.368237 18 run.go:744] x.Config: {PortOffset:0 Limit:query-edge=1000000; normalize-node=10000; mutations-nquad=1000000; query-timeout=0ms; txn-abort-after=5m; max-pending-queries=10000; max-retries=-1; mutations=allow; shared-instance=false; disallow-drop=false LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:introspection=true; debug=false; extensions=true; poll-interval=1s; lambda-url= GraphQLDebug:false} +I0519 08:04:43.368284 18 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:ratio=0.01; jaeger=; datadog= MyAddr:alpha4:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:snapshot-after-entries=10000; snapshot-after-duration=30m; pending-proposals=256; idx=; group=; learner=false Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc000078240 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:42.54940756 +0000 UTC m=+0.520973032 Security:whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16; token= EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:43.368365 18 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:43.368698 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:43.469047 18 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.451523 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.454115 18 groups.go:1118] Retry Zero Connection +I0519 08:04:45.454759 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.557308 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.558748 18 server_state.go:114] Encryption feature enabled. +I0519 08:04:45.575375 18 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:45.575457 18 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:45.602145 18 log.go:34] All 0 tables opened in 0s +I0519 08:04:45.607508 18 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:45.607541 18 log.go:34] Set nextTxnTs to 0 +I0519 08:04:45.608810 18 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:45.608887 18 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:45.608938 18 groups.go:115] Sending member request to Zero: addr:"alpha4:7080" +I0519 08:04:45.609020 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.609478 18 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +I0519 08:04:45.609492 18 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +I0519 08:04:45.609505 18 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:45.609512 18 run.go:590] HTTP server started. Listening on port 8080 +E0519 08:04:45.609529 18 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:45.722305 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.725702 18 groups.go:134] Connected to group zero. Assigned group: 2 +I0519 08:04:45.725720 18 groups.go:136] Raft Id after connection to Zero: 0x5 +I0519 08:04:45.725786 18 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:45.725822 18 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.725851 18 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.726076 18 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.726191 18 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:45.726596 18 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:45.726610 18 draft.go:306] Node ID: 0x5 with GroupID: 2 +I0519 08:04:45.726617 18 draft.go:315] RaftContext: id:5 group:2 addr:"alpha4:7080" +I0519 08:04:45.727214 18 node.go:152] Setting raft.Config to: &{ID:5 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc000049fc0 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:45.727356 18 node.go:326] Group 2 found 0 entries +I0519 08:04:45.727375 18 draft.go:2065] Calling IsPeer +I0519 08:04:45.734504 18 draft.go:2070] Done with IsPeer call +I0519 08:04:45.734533 18 draft.go:2140] New Node for group: 2 +I0519 08:04:45.734543 18 draft.go:2147] Trying to join peers. +I0519 08:04:45.734550 18 draft.go:2048] Calling JoinCluster via leader: alpha1:7080 +I0519 08:04:45.738084 18 draft.go:2052] Done with JoinCluster call +I0519 08:04:45.738303 18 log.go:34] 5 became follower at term 0 +I0519 08:04:45.738513 18 log.go:34] newRaft 5 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:45.738632 18 log.go:34] 5 became follower at term 1 +I0519 08:04:45.738964 18 draft.go:244] Operation started with id: opRollup +I0519 08:04:45.739269 18 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:45.739294 18 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:45.739520 18 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:45.740591 18 groups.go:847] Received first state update from Zero: counter:15 groups: > members: > members: > tablets: > checksum:722545940012700602 > > groups: > members: > members: > checksum:11160318154034397263 > > zeros: > zeros: > zeros: > maxRaftId:6 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:45.741077 18 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:46.740114 18 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:46.740172 18 log.go:34] 5 [term: 1] received a MsgApp message with higher term from 4 [term: 2] +I0519 08:04:46.740189 18 log.go:34] 5 became follower at term 2 +I0519 08:04:46.740199 18 log.go:34] raft.node: 5 elected leader 4 at term 2 +I0519 08:04:46.740514 18 groups.go:166] Server is ready +I0519 08:04:47.646180 18 access_ee.go:437] Unable to upsert the guardian group. Error: while upserting group with id guardians: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:47.741825 18 node.go:189] Setting conf state to nodes:4 +I0519 08:04:47.741964 18 node.go:189] Setting conf state to nodes:4 nodes:5 +I0519 08:04:47.742430 18 node.go:189] Setting conf state to nodes:4 nodes:5 nodes:6 +I0519 08:04:47.752321 18 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:47.831817 18 access_ee.go:449] Unable to upsert the groot account. Error: while upserting user with id groot: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:47.935061 18 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:47.935075 18 access_ee.go:412] ResetAcl closed +I0519 08:04:50.611273 18 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.847012 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.847184 18 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.847192 18 login.go:38] Got login request +I0519 08:04:50.847243 18 server.go:1749] Got Login request from: "172.31.0.1:36382" +I0519 08:04:50.914839 18 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:52.833606 18 main.go:83] Num goroutines: 162 +2021/05/19 08:04:42 profile: block profiling enabled, /tmp/profile123898037/block.pprof +[Sentry] 2021/05/19 08:04:42 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:42 Integration installed: Environment +[Sentry] 2021/05/19 08:04:42 Integration installed: Modules +[Sentry] 2021/05/19 08:04:42 Integration installed: IgnoreErrors +2021/05/19 08:04:43 profile: block profiling enabled, /tmp/profile150082284/block.pprof +[Sentry] 2021/05/19 08:04:43 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:43 Integration installed: Environment +[Sentry] 2021/05/19 08:04:43 Integration installed: Modules +[Sentry] 2021/05/19 08:04:43 Integration installed: IgnoreErrors +I0519 08:04:44.189392 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:44.189799 17 run.go:658] ACL secret key loaded successfully. +I0519 08:04:44.190015 17 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:44.485479 17 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:44.485506 17 run.go:744] x.Config: {PortOffset:0 Limit:mutations-nquad=1000000; disallow-drop=false; query-timeout=0ms; txn-abort-after=5m; max-retries=-1; shared-instance=false; normalize-node=10000; query-edge=1000000; max-pending-queries=10000; mutations=allow LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:poll-interval=1s; lambda-url=; introspection=true; debug=false; extensions=true GraphQLDebug:false} +I0519 08:04:44.485569 17 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:ratio=0.01; jaeger=; datadog= MyAddr:alpha5:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:snapshot-after-entries=10000; snapshot-after-duration=30m; pending-proposals=256; idx=; group=; learner=false Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc0000acd10 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:43.700396522 +0000 UTC m=+0.426069172 Security:whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16; token= EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:44.485691 17 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:44.486246 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:44.586613 17 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:44.590038 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.591196 17 server_state.go:114] Encryption feature enabled. +I0519 08:04:44.608301 17 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:44.608387 17 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:44.627416 17 log.go:34] All 0 tables opened in 0s +I0519 08:04:44.630295 17 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:44.630336 17 log.go:34] Set nextTxnTs to 0 +I0519 08:04:44.631097 17 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:44.631129 17 groups.go:115] Sending member request to Zero: addr:"alpha5:7080" +I0519 08:04:44.631203 17 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:44.631289 17 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:44.633460 17 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +E0519 08:04:44.633457 17 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:44.633488 17 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +I0519 08:04:44.633544 17 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:44.633559 17 run.go:590] HTTP server started. Listening on port 8080 +I0519 08:04:44.732804 17 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:44.734796 17 groups.go:134] Connected to group zero. Assigned group: 1 +I0519 08:04:44.734814 17 groups.go:136] Raft Id after connection to Zero: 0x1 +I0519 08:04:44.734868 17 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:44.734904 17 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:44.734911 17 draft.go:306] Node ID: 0x1 with GroupID: 1 +I0519 08:04:44.734917 17 draft.go:315] RaftContext: id:1 group:1 addr:"alpha5:7080" +I0519 08:04:44.735000 17 node.go:152] Setting raft.Config to: &{ID:1 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc000614740 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:44.735093 17 node.go:326] Group 1 found 0 entries +I0519 08:04:44.735111 17 draft.go:2140] New Node for group: 1 +I0519 08:04:44.735131 17 log.go:34] 1 became follower at term 0 +I0519 08:04:44.735140 17 log.go:34] newRaft 1 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:44.735147 17 log.go:34] 1 became follower at term 1 +I0519 08:04:44.735186 17 draft.go:244] Operation started with id: opRollup +I0519 08:04:44.735326 17 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:44.735468 17 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:44.735568 17 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:44.735657 17 node.go:189] Setting conf state to nodes:1 +I0519 08:04:44.736124 17 log.go:34] 1 is starting a new election at term 1 +I0519 08:04:44.736138 17 log.go:34] 1 became pre-candidate at term 1 +I0519 08:04:44.736143 17 log.go:34] 1 received MsgPreVoteResp from 1 at term 1 +I0519 08:04:44.736157 17 log.go:34] 1 became candidate at term 2 +I0519 08:04:44.736161 17 log.go:34] 1 received MsgVoteResp from 1 at term 2 +I0519 08:04:44.736171 17 log.go:34] 1 became leader at term 2 +I0519 08:04:44.736177 17 log.go:34] raft.node: 1 elected leader 1 at term 2 +I0519 08:04:44.740571 17 groups.go:847] Received first state update from Zero: counter:8 groups: > > > zeros: > zeros: > zeros: > maxRaftId:1 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:45.622329 17 pool.go:162] CONNECTING to alpha6:7080 +I0519 08:04:45.622345 17 node.go:585] Trying to add 0x2 to cluster. Addr: alpha6:7080 +I0519 08:04:45.622351 17 node.go:586] Current confstate at 0x1: nodes:1 +I0519 08:04:45.622451 17 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:45.622559 17 node.go:755] [0x2] Done joining cluster with err: +I0519 08:04:45.633668 17 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.710347 17 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:45.710362 17 node.go:585] Trying to add 0x3 to cluster. Addr: alpha3:7080 +I0519 08:04:45.710367 17 node.go:586] Current confstate at 0x1: nodes:1 nodes:2 +I0519 08:04:45.736123 17 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:45.736189 17 groups.go:902] Leader idx=0x1 of group=1 is connecting to Zero for txn updates +I0519 08:04:45.736202 17 groups.go:914] Got Zero leader: zero1:5080 +I0519 08:04:45.740925 17 groups.go:491] Serving tablet for: 0-dgraph.type +I0519 08:04:45.741535 17 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:45.741578 17 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:45.741609 17 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:45.746216 17 groups.go:491] Serving tablet for: 0-dgraph.drop.op +I0519 08:04:45.747908 17 groups.go:491] Serving tablet for: 0-dgraph.graphql.schema +I0519 08:04:45.749405 17 groups.go:491] Serving tablet for: 0-dgraph.graphql.xid +I0519 08:04:45.750688 17 groups.go:491] Serving tablet for: 0-dgraph.graphql.p_query +I0519 08:04:45.751879 17 groups.go:491] Serving tablet for: 0-dgraph.xid +I0519 08:04:45.752999 17 groups.go:491] Serving tablet for: 0-dgraph.password +I0519 08:04:45.754273 17 groups.go:491] Serving tablet for: 0-dgraph.user.group +I0519 08:04:45.755586 17 groups.go:491] Serving tablet for: 0-dgraph.acl.rule +I0519 08:04:45.760945 17 groups.go:491] Serving tablet for: 0-dgraph.rule.predicate +I0519 08:04:45.761974 17 groups.go:491] Serving tablet for: 0-dgraph.rule.permission +I0519 08:04:45.762331 17 groups.go:166] Server is ready +I0519 08:04:47.638513 17 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:47.638576 17 node.go:755] [0x3] Done joining cluster with err: +I0519 08:04:47.645201 17 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:47.646317 17 log.go:34] Handover found 2038 B data in current memtable. Pushing to flushChan. +I0519 08:04:47.830769 17 access_ee.go:449] Unable to upsert the groot account. Error: while upserting user with id groot: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:47.935350 17 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:47.935417 17 access_ee.go:412] ResetAcl closed +I0519 08:04:49.634848 17 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.923400 17 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.923571 17 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.923578 17 login.go:38] Got login request +I0519 08:04:50.923644 17 server.go:1749] Got Login request from: "172.31.0.1:36592" +I0519 08:04:50.990743 17 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:53.943977 17 main.go:83] Num goroutines: 183 +2021/05/19 08:04:44 profile: block profiling enabled, /tmp/profile071788661/block.pprof +[Sentry] 2021/05/19 08:04:44 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:44 Integration installed: Environment +[Sentry] 2021/05/19 08:04:44 Integration installed: Modules +[Sentry] 2021/05/19 08:04:44 Integration installed: IgnoreErrors +2021/05/19 08:04:44 profile: block profiling enabled, /tmp/profile417061282/block.pprof +[Sentry] 2021/05/19 08:04:44 Integration installed: ContextifyFrames +[Sentry] 2021/05/19 08:04:44 Integration installed: Environment +[Sentry] 2021/05/19 08:04:44 Integration installed: Modules +[Sentry] 2021/05/19 08:04:44 Integration installed: IgnoreErrors +I0519 08:04:45.156378 18 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 --telemetry "sentry=false;" flag. For more info, see https://dgraph.io/docs/howto/#data-handling. +I0519 08:04:45.156679 18 run.go:658] ACL secret key loaded successfully. +I0519 08:04:45.156879 18 server.go:114] Starting telemetry data collection for alpha... +I0519 08:04:45.371810 18 init.go:110] + +Dgraph version : v20.11.0-rc1-630-g05c0ee419 +Dgraph codename : unnamed +Dgraph SHA-256 : 2e162c940122699302e86ede2fd369c0757f1e9aa0972e21eef85d9365d8634c +Commit SHA-1 : 05c0ee419 +Commit timestamp : 2021-05-19 13:28:23 +0530 +Branch : naman/fix-live-auth +Go version : go1.16.3 +jemalloc enabled : true + +For Dgraph official documentation, visit https://dgraph.io/docs. +For discussions about Dgraph , visit https://discuss.dgraph.io. +For fully-managed Dgraph Cloud , visit https://dgraph.io/cloud. + +Licensed variously under the Apache Public License 2.0 and Dgraph Community License. +Copyright 2015-2021 Dgraph Labs, Inc. + + +I0519 08:04:45.371831 18 run.go:744] x.Config: {PortOffset:0 Limit:mutations=allow; query-edge=1000000; max-pending-queries=10000; max-retries=-1; shared-instance=false; normalize-node=10000; mutations-nquad=1000000; disallow-drop=false; query-timeout=0ms; txn-abort-after=5m LimitMutationsNquad:1000000 LimitQueryEdge:1000000 BlockClusterWideDrop:false LimitNormalizeNode:10000 QueryTimeout:0s MaxRetries:-1 SharedInstance:false GraphQL:poll-interval=1s; lambda-url=; introspection=true; debug=false; extensions=true GraphQLDebug:false} +I0519 08:04:45.371879 18 run.go:745] x.WorkerConfig: {TmpDir:t ExportPath:export Trace:ratio=0.01; jaeger=; datadog= MyAddr:alpha6:7080 ZeroAddr:[zero1:5080 zero2:5080 zero3:5080] TLSClientConfig: TLSServerConfig: Raft:pending-proposals=256; idx=; group=; learner=false; snapshot-after-entries=10000; snapshot-after-duration=30m Badger:{Dir: ValueDir: SyncWrites:false NumVersionsToKeep:1 ReadOnly:false Logger:0xc0001f8cb0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:true NamespaceOffset:-1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} WhiteListedIPRanges:[{Lower:10.0.0.0 Upper:10.255.255.255} {Lower:172.16.0.0 Upper:172.31.255.255} {Lower:192.168.0.0 Upper:192.168.255.255}] StrictMutations:false AclEnabled:true HmacSecret:**** AbortOlderThan:5m0s ProposedGroupId:0 StartTime:2021-05-19 08:04:44.677178116 +0000 UTC m=+0.323916475 Security:token=; whitelist=10.0.0.0/8,172.16.0.0/12,192.168.0.0/16 EncryptionKey:**** LogRequest:0 HardSync:false Audit:false} +I0519 08:04:45.371963 18 run.go:746] worker.Config: {PostingDir:p WALDir:w MutationsMode:0 AuthToken: HmacSecret:**** AccessJwtTtl:20s RefreshJwtTtl:720h0m0s CachePercentage:0,65,35 CacheMb:1024 Audit: ChangeDataConf:file=; kafka=; sasl_user=; sasl_password=; ca_cert=; client_cert=; client_key=; sasl-mechanism=PLAIN;} +I0519 08:04:45.372333 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.472594 18 pool.go:162] CONNECTING to zero1:5080 +I0519 08:04:45.475140 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.476044 18 server_state.go:114] Encryption feature enabled. +I0519 08:04:45.492602 18 storage.go:125] Init Raft Storage with snap: 0, first: 1, last: 0 +I0519 08:04:45.492672 18 server_state.go:139] Opening postings BadgerDB with options: {Dir:p ValueDir:p SyncWrites:false NumVersionsToKeep:2147483647 ReadOnly:false Logger:0x32b9cd0 Compression:1 InMemory:false MetricsEnabled:true NumGoroutines:8 MemTableSize:67108864 BaseTableSize:2097152 BaseLevelSize:10485760 LevelSizeMultiplier:10 TableSizeMultiplier:2 MaxLevels:7 VLogPercentile:0 ValueThreshold:1048576 NumMemtables:15 BlockSize:4096 BloomFalsePositive:0.01 BlockCacheSize:697932185 IndexCacheSize:375809638 NumLevelZeroTables:5 NumLevelZeroTablesStall:15 ValueLogFileSize:1073741823 ValueLogMaxEntries:1000000 NumCompactors:4 CompactL0OnClose:false LmaxCompaction:false ZSTDCompressionLevel:0 VerifyValueChecksum:false EncryptionKey:[] EncryptionKeyRotationDuration:240h0m0s BypassLockGuard:false ChecksumVerificationMode:0 AllowStopTheWorld:true DetectConflicts:false NamespaceOffset:1 managedTxns:false maxBatchCount:0 maxBatchSize:0 maxValueThreshold:0} +I0519 08:04:45.510636 18 log.go:34] All 0 tables opened in 0s +I0519 08:04:45.513440 18 log.go:34] Discard stats nextEmptySlot: 0 +I0519 08:04:45.513467 18 log.go:34] Set nextTxnTs to 0 +I0519 08:04:45.514113 18 groups.go:99] Current Raft Id: 0x0 +I0519 08:04:45.514128 18 groups.go:115] Sending member request to Zero: addr:"alpha6:7080" +I0519 08:04:45.514223 18 groups.go:652] No healthy Zero leader found. Trying to find a Zero leader... +I0519 08:04:45.514311 18 worker.go:114] Worker listening at address: [::]:7080 +I0519 08:04:45.515730 18 run.go:561] Bringing up GraphQL HTTP API at 0.0.0.0:8080/graphql +E0519 08:04:45.515723 18 groups.go:1177] Error during SubscribeForUpdates for prefix "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x15dgraph.graphql.schema\x00": Unable to find any servers for group: 1. closer err: +I0519 08:04:45.515745 18 run.go:562] Bringing up GraphQL HTTP admin API at 0.0.0.0:8080/admin +I0519 08:04:45.515758 18 run.go:589] gRPC server started. Listening on port 9080 +I0519 08:04:45.515768 18 run.go:590] HTTP server started. Listening on port 8080 +I0519 08:04:45.616014 18 groups.go:698] Found connection to leader: zero1:5080 +I0519 08:04:45.618038 18 groups.go:134] Connected to group zero. Assigned group: 1 +I0519 08:04:45.618129 18 groups.go:136] Raft Id after connection to Zero: 0x2 +I0519 08:04:45.618279 18 pool.go:162] CONNECTING to alpha5:7080 +I0519 08:04:45.618378 18 pool.go:162] CONNECTING to zero2:5080 +I0519 08:04:45.618625 18 pool.go:162] CONNECTING to zero3:5080 +I0519 08:04:45.618719 18 draft.go:306] Node ID: 0x2 with GroupID: 1 +I0519 08:04:45.618823 18 draft.go:315] RaftContext: id:2 group:1 addr:"alpha6:7080" +I0519 08:04:45.619729 18 node.go:152] Setting raft.Config to: &{ID:2 peers:[] learners:[] ElectionTick:20 HeartbeatTick:1 Storage:0xc0000a6280 Applied:0 MaxSizePerMsg:262144 MaxCommittedSizePerReady:67108864 MaxUncommittedEntriesSize:0 MaxInflightMsgs:256 CheckQuorum:false PreVote:true ReadOnlyOption:0 Logger:0x32b9cd0 DisableProposalForwarding:false} +I0519 08:04:45.620003 18 node.go:326] Group 1 found 0 entries +I0519 08:04:45.620168 18 draft.go:2065] Calling IsPeer +I0519 08:04:45.621501 18 draft.go:2070] Done with IsPeer call +I0519 08:04:45.621703 18 draft.go:2140] New Node for group: 1 +I0519 08:04:45.621836 18 draft.go:2147] Trying to join peers. +I0519 08:04:45.621934 18 draft.go:2048] Calling JoinCluster via leader: alpha5:7080 +I0519 08:04:45.623319 18 draft.go:2052] Done with JoinCluster call +I0519 08:04:45.623511 18 log.go:34] 2 became follower at term 0 +I0519 08:04:45.623524 18 log.go:34] newRaft 2 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] +I0519 08:04:45.623529 18 log.go:34] 2 became follower at term 1 +I0519 08:04:45.623607 18 draft.go:244] Operation started with id: opRollup +I0519 08:04:45.623929 18 draft.go:1463] Found Raft checkpoint: 0 +I0519 08:04:45.623977 18 groups.go:816] Got address of a Zero leader: zero1:5080 +I0519 08:04:45.624048 18 groups.go:830] Starting a new membership stream receive from zero1:5080. +I0519 08:04:45.625418 18 groups.go:847] Received first state update from Zero: counter:9 groups: > members: > > > zeros: > zeros: > zeros: > maxRaftId:2 cid:"2374c3f6-f0a2-4482-8073-43a6ae90ac6f" license: +I0519 08:04:46.624691 18 groups.go:197] Done informing Zero about the 0 tablets I have +I0519 08:04:46.626308 18 pool.go:162] CONNECTING to alpha1:7080 +I0519 08:04:46.626331 18 pool.go:162] CONNECTING to alpha2:7080 +I0519 08:04:46.626351 18 pool.go:162] CONNECTING to alpha4:7080 +I0519 08:04:46.626377 18 pool.go:162] CONNECTING to alpha3:7080 +I0519 08:04:46.627123 18 groups.go:166] Server is ready +I0519 08:04:46.636691 18 log.go:34] 2 [term: 1] received a MsgHeartbeat message with higher term from 1 [term: 2] +I0519 08:04:46.636703 18 log.go:34] 2 became follower at term 2 +I0519 08:04:46.636708 18 log.go:34] raft.node: 2 elected leader 1 at term 2 +I0519 08:04:47.638159 18 node.go:189] Setting conf state to nodes:1 +I0519 08:04:47.638327 18 node.go:189] Setting conf state to nodes:1 nodes:2 +I0519 08:04:47.638747 18 node.go:189] Setting conf state to nodes:1 nodes:2 nodes:3 +I0519 08:04:47.644863 18 access_ee.go:437] Unable to upsert the guardian group. Error: while upserting group with id guardians: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:47.646513 18 log.go:34] Handover found 2018 B data in current memtable. Pushing to flushChan. +I0519 08:04:47.749214 18 access_ee.go:522] Successfully upserted the guardian of namespace: 0 +I0519 08:04:48.721741 18 access_ee.go:449] Unable to upsert the groot account. Error: while upserting user with id groot: rpc error: code = Aborted desc = Transaction has been aborted. Please retry +I0519 08:04:48.828716 18 access_ee.go:598] Successfully upserted groot account for namespace 0 +I0519 08:04:48.828731 18 access_ee.go:412] ResetAcl closed +I0519 08:04:50.522124 18 admin.go:874] namespace: 0. No GraphQL schema in Dgraph; serving empty GraphQL API +I0519 08:04:50.998828 18 http.go:240] namespace: 0. Got GraphQL request over HTTP. +I0519 08:04:50.999007 18 middlewares.go:210] GraphQL admin mutation. Name = login +I0519 08:04:50.999015 18 login.go:38] Got login request +I0519 08:04:50.999072 18 server.go:1749] Got Login request from: "172.31.0.1:44298" +I0519 08:04:51.065753 18 access_ee.go:85] groot logged in successfully in namespace 0x0 +I0519 08:04:54.923157 18 main.go:83] Num goroutines: 164 diff --git a/worker/groups.go b/worker/groups.go index d5969dbc8aa..0a656d52c48 100644 --- a/worker/groups.go +++ b/worker/groups.go @@ -488,7 +488,7 @@ func (g *groupi) sendTablet(tablet *pb.Tablet) (*pb.Tablet, error) { } if out.GroupId == groups().groupId() { - glog.Infof("Serving tablet for: %v\n", x.FormatNsAttr(tablet.GetPredicate())) + glog.Infof("Serving tablet for: %v\n", tablet.GetPredicate()) } return out, nil } diff --git a/x/keys.go b/x/keys.go index 50467ab0109..3c1197e8774 100644 --- a/x/keys.go +++ b/x/keys.go @@ -57,6 +57,8 @@ const ( IgnoreBytes = "1-8" // NamespaceOffset is the offset in badger key from which the next 8 bytes contain namespace. NamespaceOffset = 1 + // NsSeparator is the separator between between the namespace and attribute. + NsSeparator = "-" ) func NamespaceToBytes(ns uint64) []byte { @@ -67,7 +69,7 @@ func NamespaceToBytes(ns uint64) []byte { // NamespaceAttr is used to generate attr from namespace. func NamespaceAttr(ns uint64, attr string) string { - return string(NamespaceToBytes(ns)) + attr + return uintToStr(ns) + NsSeparator + attr } func NamespaceAttrList(ns uint64, preds []string) []string { @@ -84,21 +86,25 @@ func GalaxyAttr(attr string) string { // ParseNamespaceAttr returns the namespace and attr from the given value. func ParseNamespaceAttr(attr string) (uint64, string) { - return binary.BigEndian.Uint64([]byte(attr[:8])), attr[8:] + splits := strings.SplitN(attr, NsSeparator, 2) + return strToUint(splits[0]), splits[1] } func ParseNamespaceBytes(attr string) ([]byte, string) { - return []byte(attr[:8]), attr[8:] + splits := strings.SplitN(attr, NsSeparator, 2) + ns := make([]byte, 8) + binary.BigEndian.PutUint64(ns, strToUint(splits[0])) + return ns, splits[1] } // ParseAttr returns the attr from the given value. func ParseAttr(attr string) string { - return attr[8:] + return strings.SplitN(attr, NsSeparator, 2)[1] } // ParseNamespace returns the namespace from the given value. func ParseNamespace(attr string) uint64 { - return binary.BigEndian.Uint64([]byte(attr[:8])) + return strToUint(strings.SplitN(attr, NsSeparator, 2)[0]) } func ParseAttrList(attrs []string) []string { @@ -109,13 +115,19 @@ func ParseAttrList(attrs []string) []string { return resp } -func IsReverseAttr(attr string) bool { - return attr[8] == '~' +// For consistency, use base16 to encode/decode the namespace. +func strToUint(s string) uint64 { + ns, err := strconv.ParseUint(s, 16, 64) + Check(err) + return ns +} +func uintToStr(ns uint64) string { + return strconv.FormatUint(ns, 16) } -func FormatNsAttr(attr string) string { - ns, attr := ParseNamespaceAttr(attr) - return strconv.FormatUint(ns, 10) + "-" + attr +func IsReverseAttr(attr string) bool { + pred := strings.SplitN(attr, NsSeparator, 2)[1] + return pred[0] == '~' } func ExtractNamespaceFromPredicate(predicate string) (uint64, error) { @@ -143,19 +155,18 @@ func writeAttr(buf []byte, attr string) []byte { // genKey creates the key and writes the initial bytes (type byte, length of attribute, // and the attribute itself). It leaves the rest of the key empty for further processing -// if necessary. -func generateKey(typeByte byte, attr string, totalLen int) []byte { - AssertTrue(totalLen >= 1+2+len(attr)) - - buf := make([]byte, totalLen) - buf[0] = typeByte +// if necessary. It also returns next index from where further processing should be done. +func generateKey(typeByte byte, attr string, extra int) ([]byte, int) { // Separate namespace and attribute from attr and write namespace in the first 8 bytes of key. namespace, attr := ParseNamespaceBytes(attr) + prefixLen := 1 + 8 + 2 + len(attr) // byteType + ns + len(pred) + pred + buf := make([]byte, prefixLen+extra) + buf[0] = typeByte AssertTrue(copy(buf[1:], namespace) == 8) rest := buf[9:] writeAttr(rest, attr) - return buf + return buf, prefixLen } // SchemaKey returns schema key for given attribute. Schema keys are stored @@ -166,7 +177,8 @@ func generateKey(typeByte byte, attr string, totalLen int) []byte { // byte 1-2: length of attr // next len(attr) bytes: value of attr func SchemaKey(attr string) []byte { - return generateKey(ByteSchema, attr, 1+2+len(attr)) + key, _ := generateKey(ByteSchema, attr, 0) + return key } // TypeKey returns type key for given type name. Type keys are stored separately @@ -177,7 +189,8 @@ func SchemaKey(attr string) []byte { // byte 1-2: length of typeName // next len(attr) bytes: value of attr (the type name) func TypeKey(attr string) []byte { - return generateKey(ByteType, attr, 1+2+len(attr)) + key, _ := generateKey(ByteType, attr, 0) + return key } // DataKey generates a data key with the given attribute and UID. @@ -191,9 +204,8 @@ func TypeKey(attr string) []byte { // next eight bytes (optional): if the key corresponds to a split list, the startUid of // the split stored in this key and the first byte will be sets to ByteSplit. func DataKey(attr string, uid uint64) []byte { - prefixLen := 1 + 2 + len(attr) - totalLen := prefixLen + 1 + 8 - buf := generateKey(DefaultPrefix, attr, totalLen) + extra := 1 + 8 // ByteData + UID + buf, prefixLen := generateKey(DefaultPrefix, attr, extra) rest := buf[prefixLen:] rest[0] = ByteData @@ -214,9 +226,8 @@ func DataKey(attr string, uid uint64) []byte { // next eight bytes (optional): if the key corresponds to a split list, the startUid of // the split stored in this key. func ReverseKey(attr string, uid uint64) []byte { - prefixLen := 1 + 2 + len(attr) - totalLen := prefixLen + 1 + 8 - buf := generateKey(DefaultPrefix, attr, totalLen) + extra := 1 + 8 // ByteReverse + UID + buf, prefixLen := generateKey(DefaultPrefix, attr, extra) rest := buf[prefixLen:] rest[0] = ByteReverse @@ -237,9 +248,8 @@ func ReverseKey(attr string, uid uint64) []byte { // next eight bytes (optional): if the key corresponds to a split list, the startUid of // the split stored in this key. func IndexKey(attr, term string) []byte { - prefixLen := 1 + 2 + len(attr) - totalLen := prefixLen + 1 + len(term) - buf := generateKey(DefaultPrefix, attr, totalLen) + extra := 1 + len(term) // ByteIndex + term + buf, prefixLen := generateKey(DefaultPrefix, attr, extra) rest := buf[prefixLen:] rest[0] = ByteIndex @@ -259,9 +269,8 @@ func IndexKey(attr, term string) []byte { // next byte: data type prefix (set to ByteCount or ByteCountRev) // next four bytes: value of count. func CountKey(attr string, count uint32, reverse bool) []byte { - prefixLen := 1 + 2 + len(attr) - totalLen := prefixLen + 1 + 4 - buf := generateKey(DefaultPrefix, attr, totalLen) + extra := 1 + 4 // ByteCount + Count + buf, prefixLen := generateKey(DefaultPrefix, attr, extra) rest := buf[prefixLen:] if reverse { @@ -346,14 +355,9 @@ func (p ParsedKey) IsOfType(typ byte) bool { // SkipPredicate returns the first key after the keys corresponding to the predicate // of this key. Useful when iterating in the reverse order. func (p ParsedKey) SkipPredicate() []byte { - buf := make([]byte, 1+2+len(p.Attr)+1) - buf[0] = p.bytePrefix - ns, attr := ParseNamespaceBytes(p.Attr) - AssertTrue(copy(buf[1:], ns) == 8) - rest := buf[9:] - k := writeAttr(rest, attr) - AssertTrue(len(k) == 1) - k[0] = 0xFF + buf, prefixLen := generateKey(p.bytePrefix, p.Attr, 1) + AssertTrue(len(buf[prefixLen:]) == 1) + buf[prefixLen] = 0xFF return buf } @@ -374,56 +378,33 @@ func (p ParsedKey) SkipType() []byte { // DataPrefix returns the prefix for data keys. func (p ParsedKey) DataPrefix() []byte { - buf := make([]byte, 1+2+len(p.Attr)+1) - buf[0] = p.bytePrefix - ns, attr := ParseNamespaceBytes(p.Attr) - AssertTrue(copy(buf[1:], ns) == 8) - rest := buf[9:] - k := writeAttr(rest, attr) - AssertTrue(len(k) == 1) - k[0] = ByteData + buf, prefixLen := generateKey(p.bytePrefix, p.Attr, 1) + buf[prefixLen] = ByteData return buf } // IndexPrefix returns the prefix for index keys. func (p ParsedKey) IndexPrefix() []byte { - buf := make([]byte, 1+2+len(p.Attr)+1) - buf[0] = DefaultPrefix - ns, attr := ParseNamespaceBytes(p.Attr) - AssertTrue(copy(buf[1:], ns) == 8) - rest := buf[9:] - k := writeAttr(rest, attr) - AssertTrue(len(k) == 1) - k[0] = ByteIndex + buf, prefixLen := generateKey(DefaultPrefix, p.Attr, 1) + buf[prefixLen] = ByteIndex return buf } // ReversePrefix returns the prefix for index keys. func (p ParsedKey) ReversePrefix() []byte { - buf := make([]byte, 1+2+len(p.Attr)+1) - buf[0] = DefaultPrefix - ns, attr := ParseNamespaceBytes(p.Attr) - AssertTrue(copy(buf[1:], ns) == 8) - rest := buf[9:] - k := writeAttr(rest, attr) - AssertTrue(len(k) == 1) - k[0] = ByteReverse + buf, prefixLen := generateKey(DefaultPrefix, p.Attr, 1) + buf[prefixLen] = ByteReverse return buf } // CountPrefix returns the prefix for count keys. func (p ParsedKey) CountPrefix(reverse bool) []byte { - buf := make([]byte, 1+2+len(p.Attr)+1) - buf[0] = p.bytePrefix - ns, attr := ParseNamespaceBytes(p.Attr) - AssertTrue(copy(buf[1:], ns) == 8) - rest := buf[9:] - k := writeAttr(rest, attr) - AssertTrue(len(k) == 1) + buf, prefixLen := generateKey(DefaultPrefix, p.Attr, 1) + buf[prefixLen] = ByteReverse if reverse { - k[0] = ByteCountRev + buf[prefixLen] = ByteCountRev } else { - k[0] = ByteCount + buf[prefixLen] = ByteCount } return buf } @@ -509,12 +490,8 @@ func TypePrefix() []byte { // PredicatePrefix returns the prefix for all keys belonging to this predicate except schema key. func PredicatePrefix(predicate string) []byte { - buf := make([]byte, 1+2+len(predicate)) - buf[0] = DefaultPrefix - ns, predicate := ParseNamespaceBytes(predicate) - AssertTrue(copy(buf[1:], ns) == 8) - k := writeAttr(buf[9:], predicate) - AssertTrue(len(k) == 0) + buf, prefixLen := generateKey(DefaultPrefix, predicate, 0) + AssertTrue(len(buf) == prefixLen) return buf } @@ -569,7 +546,7 @@ func Parse(key []byte) (ParsedKey, error) { if len(k) < sz { return p, errors.Errorf("Invalid size %v for key %v", sz, key) } - p.Attr = string(namespace) + string(k[:sz]) + p.Attr = NamespaceAttr(binary.BigEndian.Uint64(namespace), string(k[:sz])) k = k[sz:] switch p.bytePrefix { diff --git a/x/keys_test.go b/x/keys_test.go index 50ceb8b83ef..646ef71a63f 100644 --- a/x/keys_test.go +++ b/x/keys_test.go @@ -17,6 +17,7 @@ package x import ( + "encoding/json" "fmt" "math" "sort" @@ -29,8 +30,8 @@ func TestNameSpace(t *testing.T) { ns := uint64(133) attr := "name" nsAttr := NamespaceAttr(ns, attr) - require.Equal(t, 8+len(attr), len(nsAttr)) - parsedAttr := ParseAttr(nsAttr) + parsedNs, parsedAttr := ParseNamespaceAttr(nsAttr) + require.Equal(t, ns, parsedNs) require.Equal(t, attr, parsedAttr) } @@ -39,7 +40,7 @@ func TestDataKey(t *testing.T) { // key with uid = 0 is invalid uid = 0 - key := DataKey(NamespaceAttr(GalaxyNamespace, "bad uid"), uid) + key := DataKey(GalaxyAttr("bad uid"), uid) _, err := Parse(key) require.Error(t, err) @@ -47,7 +48,7 @@ func TestDataKey(t *testing.T) { // Use the uid to derive the attribute so it has variable length and the test // can verify that multiple sizes of attr work correctly. sattr := fmt.Sprintf("attr:%d", uid) - key := DataKey(NamespaceAttr(GalaxyNamespace, sattr), uid) + key := DataKey(GalaxyAttr(sattr), uid) pk, err := Parse(key) require.NoError(t, err) @@ -59,14 +60,14 @@ func TestDataKey(t *testing.T) { keys := make([]string, 0, 1024) for uid = 1024; uid >= 1; uid-- { - key := DataKey(NamespaceAttr(GalaxyNamespace, "testing.key"), uid) + key := DataKey(GalaxyAttr("testing.key"), uid) keys = append(keys, string(key)) } // Test that sorting is as expected. sort.Strings(keys) require.True(t, sort.StringsAreSorted(keys)) for i, key := range keys { - exp := DataKey(NamespaceAttr(GalaxyNamespace, "testing.key"), uint64(i+1)) + exp := DataKey(GalaxyAttr("testing.key"), uint64(i+1)) require.Equal(t, string(exp), key) } } @@ -76,7 +77,7 @@ func TestParseDataKeyWithStartUid(t *testing.T) { startUid := uint64(math.MaxUint64) for uid = 1; uid < 1001; uid++ { sattr := fmt.Sprintf("attr:%d", uid) - key := DataKey(NamespaceAttr(GalaxyNamespace, sattr), uid) + key := DataKey(GalaxyAttr(sattr), uid) key, err := SplitKey(key, startUid) require.NoError(t, err) pk, err := Parse(key) @@ -96,7 +97,7 @@ func TestIndexKey(t *testing.T) { sattr := fmt.Sprintf("attr:%d", uid) sterm := fmt.Sprintf("term:%d", uid) - key := IndexKey(NamespaceAttr(GalaxyNamespace, sattr), sterm) + key := IndexKey(GalaxyAttr(sattr), sterm) pk, err := Parse(key) require.NoError(t, err) @@ -113,7 +114,7 @@ func TestIndexKeyWithStartUid(t *testing.T) { sattr := fmt.Sprintf("attr:%d", uid) sterm := fmt.Sprintf("term:%d", uid) - key := IndexKey(NamespaceAttr(GalaxyNamespace, sattr), sterm) + key := IndexKey(GalaxyAttr(sattr), sterm) key, err := SplitKey(key, startUid) require.NoError(t, err) pk, err := Parse(key) @@ -132,7 +133,7 @@ func TestReverseKey(t *testing.T) { for uid = 1; uid < 1001; uid++ { sattr := fmt.Sprintf("attr:%d", uid) - key := ReverseKey(NamespaceAttr(GalaxyNamespace, sattr), uid) + key := ReverseKey(GalaxyAttr(sattr), uid) pk, err := Parse(key) require.NoError(t, err) @@ -148,7 +149,7 @@ func TestReverseKeyWithStartUid(t *testing.T) { for uid = 1; uid < 1001; uid++ { sattr := fmt.Sprintf("attr:%d", uid) - key := ReverseKey(NamespaceAttr(GalaxyNamespace, sattr), uid) + key := ReverseKey(GalaxyAttr(sattr), uid) key, err := SplitKey(key, startUid) require.NoError(t, err) pk, err := Parse(key) @@ -167,7 +168,7 @@ func TestCountKey(t *testing.T) { for count = 0; count < 1001; count++ { sattr := fmt.Sprintf("attr:%d", count) - key := CountKey(NamespaceAttr(GalaxyNamespace, sattr), count, true) + key := CountKey(GalaxyAttr(sattr), count, true) pk, err := Parse(key) require.NoError(t, err) @@ -183,7 +184,7 @@ func TestCountKeyWithStartUid(t *testing.T) { for count = 0; count < 1001; count++ { sattr := fmt.Sprintf("attr:%d", count) - key := CountKey(NamespaceAttr(GalaxyNamespace, sattr), count, true) + key := CountKey(GalaxyAttr(sattr), count, true) key, err := SplitKey(key, startUid) require.NoError(t, err) pk, err := Parse(key) @@ -202,7 +203,7 @@ func TestSchemaKey(t *testing.T) { for uid = 0; uid < 1001; uid++ { sattr := fmt.Sprintf("attr:%d", uid) - key := SchemaKey(NamespaceAttr(GalaxyNamespace, sattr)) + key := SchemaKey(GalaxyAttr(sattr)) pk, err := Parse(key) require.NoError(t, err) @@ -216,7 +217,7 @@ func TestTypeKey(t *testing.T) { for uid = 0; uid < 1001; uid++ { sattr := fmt.Sprintf("attr:%d", uid) - key := TypeKey(NamespaceAttr(GalaxyNamespace, sattr)) + key := TypeKey(GalaxyAttr(sattr)) pk, err := Parse(key) require.NoError(t, err) @@ -236,16 +237,16 @@ func TestBadStartUid(t *testing.T) { require.Error(t, err) } - key := DataKey(NamespaceAttr(GalaxyNamespace, "aa"), 1) + key := DataKey(GalaxyAttr("aa"), 1) testKey(key) - key = ReverseKey(NamespaceAttr(GalaxyNamespace, "aa"), 1) + key = ReverseKey(GalaxyAttr("aa"), 1) testKey(key) - key = CountKey(NamespaceAttr(GalaxyNamespace, "aa"), 0, false) + key = CountKey(GalaxyAttr("aa"), 0, false) testKey(key) - key = CountKey(NamespaceAttr(GalaxyNamespace, "aa"), 0, true) + key = CountKey(GalaxyAttr("aa"), 0, true) testKey(key) } @@ -271,7 +272,35 @@ func TestBadKeys(t *testing.T) { // key with uid = 0 is invalid uid := 0 - key = DataKey(NamespaceAttr(GalaxyNamespace, "bad uid"), uint64(uid)) + key = DataKey(GalaxyAttr("bad uid"), uint64(uid)) _, err = Parse(key) require.Error(t, err) } + +func TestJsonMarshal(t *testing.T) { + type predicate struct { + Predicate string `json:"predicate,omitempty"` + } + + p := &predicate{Predicate: NamespaceAttr(129, "name")} + b, err := json.Marshal(p) + require.NoError(t, err) + + var p2 predicate + require.NoError(t, json.Unmarshal(b, &p2)) + ns, attr := ParseNamespaceAttr(p2.Predicate) + require.Equal(t, uint64(129), ns) + require.Equal(t, "name", attr) +} + +func TestNsSeparator(t *testing.T) { + uid := uint64(10) + pred := "name" + NsSeparator + "surname" + key := DataKey(GalaxyAttr(pred), uid) + pk, err := Parse(key) + require.NoError(t, err) + require.Equal(t, uid, pk.Uid) + ns, attr := ParseNamespaceAttr(pk.Attr) + require.Equal(t, GalaxyNamespace, ns) + require.Equal(t, pred, attr) +}