[v1.2.0-rc1] alpha fails to connect to zero: ] Connection lost with 127.0.0.1:5080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure,

[marvin-hansen]

What version of Dgraph are you using?

Dgraph version : v1.2.0-rc1
Dgraph SHA-256 : b0087ce7f8987e1d565c9c9097451d86c2c40b97c90bd7c6a7a1f300ef660c4d
Commit SHA-1 : 1b83472
Commit timestamp : 2020-01-15 01:36:25 +0530
Branch : HEAD
Go version : go1.13.5

Docker image from Dockerhub

Have you tried reproducing the issue with the latest release?

Yes, I tried the master branch with the commit from Jan/14 and it yields the same problem. (1b83472)

The previous release 1.1 is unaffected.

What is the hardware spec (RAM, OS)?

HP Spectre, i7, 16GB memory

GKE / Kubernetes 4 vCPU / 8 GB memory

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

1. Start Zero:

docker run -it -p 5080:5080 -p 6080:6080 -v zero:/dgraph dgraph/dgraph:v1.2.0-rc1 dgraph zero --my=localhost:5080

2. Start Alpha

docker run -it -p 7080:7080 -p 8080:8080 -p 9080:9080 -v server1:/dgraph dgraph/dgraph:v1.2.0-rc1 dgraph alpha --lru_mb=1024 --zero=127.0.0.1:5080 --my=127.0.0.1:7080

docker run -it -p 7081:7081 -p 8081:8081 -p 9081:9081 -v server2:/dgraph dgraph/dgraph:v1.2.0-rc1 dgraph alpha --lru_mb=1024 --zero=127.0.0.1:5080 --my=127.0.0.1:7081

3. Start Ratel:

docker run -it -p 8000:8000 dgraph/dgraph:v1.2.0-rc1 dgraph-ratel

Expected behavior

Alpha nodes should connect to running zero instance

Actual result

CONNECTING to 127.0.0.1:5080
W0115 11:54:01.821226 1 pool.go:254] Connection lost with 127.0.0.1:5080. Error: rpc error:
code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection > error: desc = "transport: Error while dialing dial tcp 127.0.0.1:5080: connect: connection refused"

Detailed log attached!

alpha.log
zero.log

[dihmeetree]

Bumping this up! Getting the same thing, however; I'm trying to deploy using kubectl and this config https://github.com/dgraph-io/dgraph/blob/master/contrib/config/kubernetes/dgraph-ha/dgraph-ha.yaml

Alpha logs

E0115 16:16:18.889772       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:19.888890       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:19.888924       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:19.889517       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:20.888929       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:20.888976       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:20.889806       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:21.888944       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:21.888978       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:21.889539       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:22.889093       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:22.889116       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:22.889927       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:23.889044       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:23.889109       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:23.889780       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:24.888998       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:24.889058       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:24.889691       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:25.888954       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:25.888989       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:25.889671       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:26.888919       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:26.889778       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:26.890280       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:27.889091       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:27.889118       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:27.889763       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:28.888962       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:28.888993       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:28.889681       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:29.888939       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:29.888970       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:29.889586       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
W0115 16:16:30.888853       1 groups.go:812] No membership update for 10s. Closing connection to Zero.
I0115 16:16:30.888901       1 groups.go:752] Got address of a Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
I0115 16:16:30.889347       1 groups.go:765] Starting a new membership stream receive from dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080.
E0115 16:16:30.889079       1 groups.go:773] Unable to sync memberships. Error: rpc error: code = Canceled desc = context canceled. State: <nil>
I0115 16:16:30.889527       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:30.889540       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:30.889931       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:31.888967       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:31.889003       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:31.889883       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:32.889098       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:32.889198       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:32.890524       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:33.888925       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:33.888958       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:33.889607       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:34.888978       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:34.889043       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:34.889961       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:35.888965       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:35.889115       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:35.889822       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader
I0115 16:16:36.888948       1 groups.go:833] Leader idx=0x1 of group=1 is connecting to Zero for txn updates
I0115 16:16:36.889232       1 groups.go:842] Got Zero leader: dgraph-zero-0.dgraph-zero.default.svc.cluster.local:5080
E0115 16:16:36.890591       1 groups.go:873] Error in oracle delta stream. Error: rpc error: code = Unknown desc = Node is no longer leader

Zero logs

W0115 16:14:26.591391       1 pool.go:238] Connection lost with dgraph-zero-1.dgraph-zero.default.svc.cluster.local:5080. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-zero-1.dgraph-zero.default.svc.cluster.local: no such host"
W0115 16:14:27.629746       1 node.go:415] Unable to send message to peer: 0x2. Error: rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = "transport: Error while dialing dial tcp: lookup dgraph-zero-1.dgraph-zero.default.svc.cluster.local: no such host"
W0115 16:14:28.890176       1 node.go:669] [0x1] Read index context timed out
I0115 16:14:29.370745       1 zero.go:415] Got connection request: cluster_info_only:true
W0115 16:14:30.890336       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:32.890533       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:34.890668       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:36.890819       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:37.729607       1 node.go:415] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0115 16:14:38.891060       1 node.go:669] [0x1] Read index context timed out
I0115 16:14:39.367145       1 zero.go:424] Connected: cluster_info_only:true
I0115 16:14:39.567599       1 zero.go:415] Got connection request: cluster_info_only:true
W0115 16:14:40.891235       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:42.891483       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:44.891692       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:46.891867       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:47.829699       1 node.go:415] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0115 16:14:48.892094       1 node.go:669] [0x1] Read index context timed out
I0115 16:14:49.567578       1 zero.go:424] Connected: cluster_info_only:true
I0115 16:14:49.968140       1 zero.go:415] Got connection request: cluster_info_only:true
W0115 16:14:50.892278       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:52.892696       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:54.892894       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:56.893095       1 node.go:669] [0x1] Read index context timed out
W0115 16:14:57.893573       1 node.go:415] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0115 16:14:58.893298       1 node.go:669] [0x1] Read index context timed out
I0115 16:14:59.967956       1 zero.go:424] Connected: cluster_info_only:true
I0115 16:15:00.768345       1 zero.go:415] Got connection request: cluster_info_only:true
W0115 16:15:00.893491       1 node.go:669] [0x1] Read index context timed out
W0115 16:15:02.893679       1 node.go:669] [0x1] Read index context timed out
W0115 16:15:04.893844       1 node.go:669] [0x1] Read index context timed out
W0115 16:15:06.894075       1 node.go:669] [0x1] Read index context timed out
W0115 16:15:07.897043       1 node.go:415] Unable to send message to peer: 0x2. Error: Unhealthy connection
W0115 16:15:08.894290       1 node.go:669] [0x1] Read index context timed out
I0115 16:15:10.768330       1 zero.go:424] Connected: cluster_info_only:true
W0115 16:15:10.894541       1 node.go:669] [0x1] Read index context timed out
I0115 16:15:12.368690       1 zero.go:415] Got connection request: cluster_info_only:true
W0115 16:15:12.895395       1 node.go:669] [0x1] Read index context timed out
I0115 16:15:14.670739       1 run.go:242] --- Received terminated signal
I0115 16:15:14.670936       1 run.go:253] Shutting down...
E0115 16:15:14.670991       1 http.go:245] Stopped taking more http(s) requests. Err: accept tcp [::]:6080: use of closed network connection
E0115 16:15:14.671183       1 node.go:707] [0x1] While trying to do lin read index: Closer has been called
E0115 16:15:14.671210       1 node.go:654] Error while trying to call ReadIndex: raft: stopped
E0115 16:15:14.671219       1 node.go:707] [0x1] While trying to do lin read index: raft: stopped
I0115 16:15:14.671244       1 zero.go:424] Connected: cluster_info_only:true
I0115 16:15:14.671571       1 raft.go:631] Zero Node.Run finished.
I0115 16:15:14.671601       1 run.go:140] gRPC server stopped : accept tcp [::]:5080: use of closed network connection
I0115 16:15:15.171174       1 http.go:249] All http(s) requests finished.
I0115 16:15:19.671814       1 run.go:153] Stopping grpc gracefully is taking longer than 5s. Force stopping now. Pending RPCs will be abandoned.
I0115 16:15:19.672111       1 run.go:268] All done.
badger 2020/01/15 16:15:19 DEBUG: Storing value log head: {Fid:0 Len:30 Offset:1661}
badger 2020/01/15 16:15:19 INFO: Got compaction priority: {level:0 score:1.73 dropPrefix:[]}
badger 2020/01/15 16:15:19 INFO: Running for level: 0
badger 2020/01/15 16:15:19 DEBUG: LOG Compact. Added 13 keys. Skipped 8 keys. Iteration took: 78.285µs
badger 2020/01/15 16:15:19 DEBUG: Discard stats: map[]
badger 2020/01/15 16:15:19 INFO: LOG Compact 0->1, del 1 tables, add 1 tables, took 9.684106ms
badger 2020/01/15 16:15:19 INFO: Compaction for level: 0 DONE
badger 2020/01/15 16:15:19 INFO: Force compaction on level 0 done

[marvin-hansen]

@lolcoolkat I had the exact same issue in Kubernetes. Afaik, there is no fix right now, not even in the master branch, so you have to revert to any prior version to avoid the issue.

[danielmai]

@marvin-hansen @lolcoolkat Regarding the K8s config, there are K8s config changes in the current master regarding liveness and readiness probes that don't apply to the latest Dgraph release (v1.1.1). Please use the v1.1.1 K8s configs: https://github.com/dgraph-io/dgraph/blob/v1.1.1/contrib/config/kubernetes/dgraph-ha/dgraph-ha.yaml.

[danielmai]

@marvin-hansen The three docker run commands creates three separate Docker containers that are not connected to each other on a shared network, so communication over 127.0.0.1 doesn't work.

You'll need to network them together to get it working. You can try the sample Docker Compose config which will create a shared network among the different containers defined in the docker-compose.yml: https://github.com/dgraph-io/dgraph/blob/master/contrib/config/docker/docker-compose.yml. You can update the image tag to try v1.2.0-rc1.

[marvin-hansen]

@danielmai Thank you for the hint.

The docker-compose kinda works with v1.2.0-rc1 in the sense that zero & alpha connect, and Ratel shows a working DB connection. However, when I try to deploy a GraphQL schema to the admin endpoint, exactly as shown in the GraphQL tutorial, I get an unauthorized error:

jq -n --arg schema "$(cat schema.graphql)" '{ query: "mutation updateGQLSchema($sch: String!) { updateGQLSchema(input: { set: { schema: $sch }}) { gqlSchema { schema } } }", variables: { sch: $schema }}' | curl -X POST -H "Content-Type: application/json" http://localhost:8080/admin -d @- | jq -r

 {
   "errors": [
     {
       "message": "Request from IP: 172.18.0.1",
       "extensions": {
         "code": "ErrorUnauthorized"
       }
     }
   ]
 }
$:/mnt/c/Users/marvi/PycharmProjects/goci-dgraph$

BTW, why is the request from "172.18.0.1", which is non-assigned in my net, and not from 127.0.0.1???

[marvin-hansen]

@danielmai is there an update for the single k8s config planned?

Out of curiosity, are the helm-charts already been tested for the 1.2X release?

@marvin-hansen @lolcoolkat Regarding the K8s config, there are K8s config changes in the current master regarding liveness and readiness probes that don't apply to the latest Dgraph release (v1.1.1). Please use the v1.1.1 K8s configs: https://github.com/dgraph-io/dgraph/blob/v1.1.1/contrib/config/kubernetes/dgraph-ha/dgraph-ha.yaml.

[MichelDiz]

This ip 172.18.0.1 is from the docker network context. To run any admin operation, you need to "docker exec" into that container. Or set a whitelist https://docs.dgraph.io/deploy/#whitelist-admin-operations

[danielmai]

Out of curiosity, are the helm-charts already been tested for the 1.2X release?

We'll update the master branch K8s configs today. For now, you can use the configs in the v1.1.1 branch.

[MichelDiz]

As Dmai said

marvin-hansen The three docker run commands creates three separate Docker containers that are not connected to each other on a shared network, so communication over 127.0.0.1 doesn't work.

The problem is that Docker does not know how to handle connections between containers. The correct way to do it follows below. It's more complicated and longer typing than choosing the easiest way that is go with docker-compose.

I will close this issue because the problem is related to how Docker works and not Dgraph - But if need any further clarification, feel free to ping me or Dmai on Discuss.

There is another problem with this release, but it was already fixed in a recent commit that is on its way to being merged into Master branch.

Cheers

Create a network

docker network create dgraph_default

Run the containers:

docker run -it \
-p 5080:5080 \
-p 6080:6080 \
 -v zero:/dgraph \
--name zero \
--network dgraph_default \
dgraph/dgraph:v1.2.0-rc1 dgraph zero --my=zero:5080

docker run -it \
-p 7080:7080 \
-p 8080:8080 \
-p 9080:9080 \
-v server0:/dgraph \
--network dgraph_default \
--name alpha0 \
dgraph/dgraph:v1.2.0-rc1 \
dgraph alpha --lru_mb=1024 --zero=zero:5080 --my=alpha0:7080

If any container fails giving an error/panic restart it by doing
docker ps -a
docker rm 7488469a8fea 7488469a8fea is the ID of the failed container. Then use the same command used for it.

docker run -it \
-p 7081:7081 \
-p 8081:8081 \
-p 9081:9081 \
-v server1:/dgraph \
--network dgraph_default \
--name alpha1 \
dgraph/dgraph:v1.2.0-rc1 \
dgraph alpha --lru_mb=1024 --zero=zero:5080 --my=alpha1:7081 -o=1

docker run -it \
-p 8000:8000 \
--network dgraph_default \
--name ratel \
dgraph/dgraph:v1.2.0-rc1 \
dgraph-ratel

To retry do this steps:

Be careful - Stop and Remove ALL containers running in Docker

docker stop $(docker ps -a -q)
docker rm $(docker ps -a -q) 

delete the volumes

docker volume rm server1 server2 zero

or

docker volume rm $(docker volume ls) 

Now go to:

http://${ localhost or vm IP}:8000/?latest
http://192.168.99.100:8000/?latest

Enter the url http://${ localhost or vm IP}:8080/

[marvin-hansen]

We'll update the master branch K8s configs today. For now, you can use the configs in the v1.1.1 branch.

@danielmai please add some bare minimum security to the k8s config. I opened another issue related to the security problems I found in the default config:

https://github.com/dgraph-io/dgraph/issues/

There is an example with DGraph & ngnix as a proxy in front of DGraph. So technically, one can configure ngnix for authentication and I think it is the most sensible approach for the time being:

https://gist.github.com/MichelDiz/42954e321620159c872c35c20e9d85c6

https://docs.nginx.com/nginx/admin-guide/security-controls/configuring-http-basic-authentication/