Random gRPC error: cancelled before receiving half close

[viktorrobin]

Description

Similar to issue #17

When inserting data using python client, random gRPC errors occur

Environment

1. OS (where Grakn server runs): Mac OS Mojave 10.14.5
2. Grakn version (and platform): docker graknlabs/grakn:1.5.3
3. Grakn client-python version: client-python 1.5.3
4. Python version: 3.7.2

Reproducible Steps

Error random, but when inserting data using phone call examples, one might run into this error.

Seems to be happening when creating a new transaction.

Expected Output

No error.

Actual Output

erver/network error: <_Rendezvous of RPC that terminated with:
        status = StatusCode.UNKNOWN
        details = "null. Please check server logs for the stack trace."
        debug_error_string = "{"created":"@1559448052.745006000","description":"Error received from peer","file":"src/core/lib/surface/call.cc","file_line":1017,"grpc_message":"null. Please check server logs for the stack trace.","grpc_status":2}"
>

 generated from request: open_req {
  sessionId: "dh31abea9bc-7ba7-47e2-a776-05bf8c9a9499"
  type: WRITE
}

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/grakn/service/Session/TransactionService.py", line 156, in send
    response = next(self._response_iterator)
  File "/usr/local/lib/python3.7/site-packages/grpc/_channel.py", line 364, in __next__
    return self._next()
  File "/usr/local/lib/python3.7/site-packages/grpc/_channel.py", line 358, in _next
    raise self
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with:
        status = StatusCode.UNKNOWN
        details = "null. Please check server logs for the stack trace."
        debug_error_string = "{"created":"@1559448052.745006000","description":"Error received from peer","file":"src/core/lib/surface/call.cc","file_line":1017,"grpc_message":"null. Please check server logs for the stack trace.","grpc_status":2}"
>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "migrate.py", line 31, in build_phone_call_graph
    load_data_into_grakn(input, session)
  File "migrate.py", line 40, in load_data_into_grakn
    with session.transaction().write() as transaction:
  File "/usr/local/lib/python3.7/site-packages/grakn/client.py", line 106, in write
    transaction_service = TransactionService(self._session_id, _TxType.WRITE, self._transaction_rpc_constructor)
  File "/usr/local/lib/python3.7/site-packages/grakn/service/Session/TransactionService.py", line 39, in __init__
    self._communicator.send(open_req)
  File "/usr/local/lib/python3.7/site-packages/grakn/service/Session/TransactionService.py", line 160, in send
    raise GraknError("Server/network error: {0}\n\n generated from request: {1}".format(e, request))
grakn.exception.GraknError.GraknError: Server/network error: <_Rendezvous of RPC that terminated with:
        status = StatusCode.UNKNOWN
        details = "null. Please check server logs for the stack trace."
        debug_error_string = "{"created":"@1559448052.745006000","description":"Error received from peer","file":"src/core/lib/surface/call.cc","file_line":1017,"grpc_message":"null. Please check server logs for the stack trace.","grpc_status":2}"
>

 generated from request: open_req {
  sessionId: "dh31abea9bc-7ba7-47e2-a776-05bf8c9a9499"
  type: WRITE
}


During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "migrate.py", line 303, in <module>
    build_phone_call_graph(inputs)
  File "migrate.py", line 34, in build_phone_call_graph
    raise
  File "/usr/local/lib/python3.7/site-packages/grakn/client.py", line 88, in __exit__
    self.close()
  File "/usr/local/lib/python3.7/site-packages/grakn/client.py", line 81, in close
    self._stub.close(close_session_req)
  File "/usr/local/lib/python3.7/site-packages/grpc/_channel.py", line 533, in __call__
    return _end_unary_response_blocking(state, call, False, None)
  File "/usr/local/lib/python3.7/site-packages/grpc/_channel.py", line 467, in _end_unary_response_blocking
    raise _Rendezvous(state, None, None, deadline)
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with:
        status = StatusCode.UNKNOWN
        details = "null. Please check server logs for the stack trace."
        debug_error_string = "{"created":"@1559448052.748124000","description":"Error received from peer","file":"src/core/lib/surface/call.cc","file_line":1017,"grpc_message":"null. Please check server logs for the stack trace.","grpc_status":2}"
>

Logs from grakn server:

[grpc-default-executor-4] ERROR g.c.s.r.SessionService$TransactionListener - Runtime Exception in RPC TransactionListener: 
io.grpc.StatusRuntimeException: CANCELLED: cancelled before receiving half close
	at io.grpc.Status.asRuntimeException(Status.java:517)
	at io.grpc.stub.ServerCalls$StreamingServerCallHandler$StreamingServerCallListener.onCancel(ServerCalls.java:272)
	at io.grpc.internal.ServerCallImpl$ServerStreamListenerImpl.closed(ServerCallImpl.java:293)
	at io.grpc.internal.ServerImpl$JumpToApplicationThreadServerStreamListener$1Closed.runInContext(ServerImpl.java:741)
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37)
	at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:123)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

[viktorrobin]

So I found what was causing the issue, but can't really explain it...

I am using your migrate.py provided in the phone calls example, which randomly returns the error described above when grakn runs as a container:

def build_phone_call_graph(inputs):
    with GraknClient(uri=URI) as client:
        with client.session(keyspace = KEYSPACE) as session:
            for input in inputs:
                print("Loading from [" + input["data_path"] + "] into Grakn ...")
                load_data_into_grakn(input, session)
             
            
def load_data_into_grakn(input, session):
    items = parse_data_to_dictionaries(input)

    for item in items:
        with session.transaction().write() as transaction:
            graql_insert_query = input["template"](item)
            print("Executing Graql Query: " + graql_insert_query)
            transaction.query(graql_insert_query)
            transaction.commit()

    print("\nInserted " + str(len(items)) + " items from [ " + input["data_path"] + "] into Grakn.\n")

However, if you write the same thing this way, by simply not passing the session to the function, the error completely disappear...

def build_phone_call_graph(inputs):
    with GraknClient(uri=URI) as client:
        with client.session(keyspace = KEYSPACE) as session:
            for input in inputs:
                print("Loading from [" + input["data_path"] + "] into Grakn ...")
            
                # load_data_into_grakn(input, session)
                items = parse_data_to_dictionaries(input)

                for item in items:
                    with session.transaction().write() as transaction:
                        graql_insert_query = input["template"](item)
                        print("Executing Graql Query: " + graql_insert_query)
                        transaction.query(graql_insert_query)
                        transaction.commit()

                print("\nInserted " + str(len(items)) + " items from [ " + input["data_path"] + "] into Grakn.\n")

Can't explain why... Only happens with docker.

[haikalpribadi]

Thanks for reporting this issue, @viktorrobin. Given how old this issue is from Grakn 1.5, and that we have rewritten Grakn in the 2.0 release (and renamed it to TypeDB), we do not believe this issue still exist and will close this now.