dgraph4j java client first connect alpha is too slow

[willem520]

every time, when I used dgraph4j to connect alpha, it take too much time to get result in first time,but then ,it was normal, there is any problem in dgraph4j? I used java client

[campoy]

I wonder if @gitlw could have a look at this issue too.

In the meantime, could you give more information on the query you're performing @willem520?

Is the database already running before you connect to it, or do you also start it at the same time as you are trying to connect?

[campoy]

PS: I migrated this issue to dgraph-io/dgraph4j.

[willem520]

yes, it was already before I used it.

when I first used this method, the log was
======minCost:385237379 ns, maxCost:385237379 ns, avgCost:497530185 ns
second was
======minCost:12390223 ns, maxCost:12390223 ns, avgCost:12948185 ns
third was
======minCost:8883041 ns, maxCost:8883041 ns, avgCost:9232029 ns
it always took too much time in first time.
I used dgraph4j v1.7.5 and v2.0.1, got the same result.
Is there any wrong in my use?

[willem520]

I executed a simple mutation,it also took too much time in first time

[campoy]

Hey @mangalaman93 , could you have a look since you worked recently on this client?

Thanks

[mangalaman93]

@willem520 Could you point me to GraphUtil code? The connection setup code is executed by grpc and not written by us in the client. Just want to make sure that the Util code has simple logic too. I was also wondering whether you restart the application between each run?

[willem520]

@mangalaman93 hi，this is the code

@Slf4j
public class GraphUtil {
    public static final String LOG_FORMAT = "******[%s] cost: %s";
    public static final String UID_FORMAT = "{\n"
                                          + " one(func: eq(%s, \"%s\")){\n"
                                          + "  uid\n"
                                          + " }\n"
                                          + "}\n";

    public static DgraphClient buildDgraphClient(List<String> ipPorts) throws Exception {
        if (ipPorts == null || ipPorts.isEmpty()) {
            throw new Exception("init dgraphClient occur error");
        }
        return new DgraphClient(buildDgraphStub(ipPorts));
    }

    public static DgraphAsyncClient buildDgraphAsyncClient(List<String> ipPorts) throws Exception {
        if (ipPorts == null || ipPorts.isEmpty()) {
            throw new Exception("init dgraphAsyncClient occur error");
        }
        return new DgraphAsyncClient(buildDgraphStub(ipPorts));
    }

    private static DgraphGrpc.DgraphStub[] buildDgraphStub(List<String> ipPorts) {
        DgraphGrpc.DgraphStub[] dgraphStubs = new DgraphGrpc.DgraphStub[ipPorts.size()];

        ClientInterceptor timeoutInterceptor = new ClientInterceptor() {
            @Override
            public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(
                    MethodDescriptor<ReqT, RespT> method, CallOptions callOptions, Channel next) {
                return next.newCall(method, callOptions.withDeadlineAfter(30000, TimeUnit.MILLISECONDS));
            }
        };

        ipPorts.stream().map(ipPort -> {
            ManagedChannel channel = ManagedChannelBuilder.forTarget(ipPort).usePlaintext().build();
            return DgraphGrpc.newStub(channel).withInterceptors(timeoutInterceptor);
        }).collect(Collectors.toList()).toArray(dgraphStubs);
        return dgraphStubs;
    }

    public static String getUid(DgraphClient dgraphClient, String gid, String value) {
        Transaction txn = dgraphClient.newReadOnlyTransaction();
        txn.setBestEffort(true);
        String uid = "";
        try {
            long start = System.nanoTime();
            DgraphProto.Response response = txn.query(String.format(UID_FORMAT, gid, value));
            TimeCost uidCost = latency2Cost(response.getLatency());
            uidCost.setClientCost(System.nanoTime() - start);
            JSONObject dataJson = JSON.parseObject(response.getJson().toStringUtf8());
            JSONArray dataArr = dataJson.getJSONArray("one");
            if (!dataArr.isEmpty()) {
                if (dataArr.size() > 1){
                    log.warn(String.format("======[%s:%s] require unique", gid,
                            value));
                }
                uid = dataArr.getJSONObject(0).getString("uid");
            }
            logTimeCost("getUid", uidCost);
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            txn.discard();
        }
        return uid;
    }

    public static String getUid(Transaction txn, String gid, String value) {
        String uid = "";
        try {
            long start = System.nanoTime();
            DgraphProto.Response response = txn.query(String.format(UID_FORMAT, gid, value));
            TimeCost uidCost = latency2Cost(response.getLatency());
            uidCost.setClientCost(System.nanoTime() - start);
            JSONObject dataJson = JSON.parseObject(response.getJson().toStringUtf8());
            JSONArray dataArr = dataJson.getJSONArray("one");
            if (!dataArr.isEmpty()) {
                if (dataArr.size() > 1){
                    log.warn(String.format("======[%s:%s] require unique", gid,
                            value));
                }
                uid = dataArr.getJSONObject(0).getString("uid");
            }
            logTimeCost("getUid", uidCost);
        } catch (Exception e) {
            e.printStackTrace();
        }
        return uid;
    }

    public static TimeCost commitMutate(DgraphClient dgraphClient, JSONArray mutateArr) {
        TimeCost timeCost = new TimeCost();
        if (mutateArr.isEmpty()) {
            return timeCost;
        }
        Transaction txn = dgraphClient.newTransaction();
        try {
            DgraphProto.Mutation.Builder builder = DgraphProto.Mutation.newBuilder();
            builder.setSetJson(ByteString.copyFromUtf8(mutateArr.toJSONString()));
            long start = System.nanoTime();
            DgraphProto.Response response = txn.mutate(builder.build());
            //去掉commit会报错io.grpc.StatusRuntimeException: ABORTED: Transaction has been aborted. Please retry
            txn.commit();
            start = System.nanoTime() - start;
            timeCost = latency2Cost(response.getLatency());
            timeCost.setMaxClientCost(start);
            timeCost.setMinClientCost(start);
            timeCost.setClientCost(start);
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            txn.discard();
        }
        logTimeCost("mutate", timeCost);
        mutateArr.clear();
        return timeCost;
    }

    public static JSONObject buildMutate(int id){
        JSONObject nodeObj = new JSONObject();
        nodeObj.put("gid", "people" + id);
        nodeObj.put("name", "people" + id);
        nodeObj.put("label", "people");

        JSONObject edgeObj = new JSONObject();
        edgeObj.put("gid", "house" + id);
        edgeObj.put("name", "house" + id);
        edgeObj.put("label", "house");

        nodeObj.put("houses", edgeObj);
        return nodeObj;
    }

    public static TimeCost commitQueryMutate(DgraphClient dgraphClient, JSONArray idArr) {
        TimeCost timeCost = new TimeCost();
        JSONArray mutateArr = new JSONArray();
        if (idArr.isEmpty()) {
            return timeCost;
        }
        Transaction txn = dgraphClient.newTransaction();
        try {
            for (int i=0; i<idArr.size(); i++){
                mutateArr.add(buildQueryMutate(txn,idArr.getIntValue(i)));
            }
            DgraphProto.Mutation.Builder builder = DgraphProto.Mutation.newBuilder();
            builder.setSetJson(ByteString.copyFromUtf8(mutateArr.toJSONString()));
            long start = System.nanoTime();
            DgraphProto.Response response = txn.mutate(builder.build());
            txn.commit();
            start = System.nanoTime() - start;
            timeCost = latency2Cost(response.getLatency());
            timeCost.setMaxClientCost(start);
            timeCost.setMinClientCost(start);
            timeCost.setClientCost(start);
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            txn.discard();
        }
        logTimeCost("mutate", timeCost);
        mutateArr.clear();
        return timeCost;
    }

    private static JSONObject buildQueryMutate(Transaction txn, int id) {
        String nodeGid = "people"+id;
        String edgeGid = "house"+id;
        String peopleUid = getUid(txn,"gid", nodeGid);
        String houseUid = getUid(txn,"gid", edgeGid);

        JSONObject nodeObj = new JSONObject();
        JSONObject edgeObj = new JSONObject();
        if (peopleUid.length() > 0){
            nodeObj.put("uid", peopleUid);
        }
        nodeObj.put("gid", "people" + id);
        nodeObj.put("label", "people");
        nodeObj.put("name", "people" + id);
        if (houseUid.length() > 0) {
            edgeObj.put("uid", houseUid);
        }
        edgeObj.put("gid", "house" + id);
        edgeObj.put("label", "house");
        edgeObj.put("name", "house" + id);
        nodeObj.put("houses", edgeObj);
        return nodeObj;
    }

    public static TimeCost asyncCommitMutate(DgraphAsyncClient dgraphAsyncClient, JSONArray nodeArr) {
        TimeCost timeCost = new TimeCost();
        if (nodeArr.isEmpty()) {
            return timeCost;
        }
        AsyncTransaction txn = dgraphAsyncClient.newTransaction();
        try {
            DgraphProto.Mutation.Builder builder = DgraphProto.Mutation.newBuilder();
            builder.setSetJson(ByteString.copyFromUtf8(nodeArr.toJSONString()));
            long start = System.nanoTime();
            CompletableFuture<DgraphProto.Response> response = txn.mutate(builder.build());
            txn.commit();
            DgraphProto.Latency latency = response.get().getLatency();
            start = System.nanoTime() - start;
            timeCost = latency2Cost(latency);
            timeCost.setMaxClientCost(start);
            timeCost.setMinClientCost(start);
            timeCost.setClientCost(start);

        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            txn.discard();
        }
        logTimeCost("asyncMutate", timeCost);
        nodeArr.clear();
        return timeCost;
    }

    public static TimeCost commitQuery(DgraphClient dgraphClient, String query, Map<String, String> params) {
        Transaction txn = dgraphClient.newReadOnlyTransaction();
        txn.setBestEffort(true);
        long start = System.nanoTime();
        DgraphProto.Response response = txn.queryWithVars(query, params);
        start = System.nanoTime() - start;
        TimeCost timeCost = latency2Cost(response.getLatency());
        timeCost.setMaxClientCost(start);
        timeCost.setMinClientCost(start);
        timeCost.setClientCost(start);
        logTimeCost("query", timeCost);
        return timeCost;
    }

    public static TimeCost asyncCommitQuery(DgraphAsyncClient dgraphAsyncClient, String query, Map<String, String> params) {
        TimeCost timeCost = new TimeCost();
        AsyncTransaction asyncTxn = dgraphAsyncClient.newReadOnlyTransaction();
        asyncTxn.setBestEffort(true);
        try{
            long start = System.nanoTime();
            CompletableFuture<DgraphProto.Response> response = asyncTxn.queryWithVars(query, params);
            DgraphProto.Latency latency = response.get().getLatency();
            start = System.nanoTime() - start;
            timeCost = latency2Cost(latency);
            timeCost.setMaxClientCost(start);
            timeCost.setMinClientCost(start);
            timeCost.setClientCost(start);
        } catch (Exception e){
            e.printStackTrace();
        }
        logTimeCost("asyncQuery", timeCost);
        return timeCost;
    }

    public static TimeCost commitUpsert(DgraphClient dgraphClient, String query, Map<String, String> params, JSONArray nodeArr){
        TimeCost timeCost = new TimeCost();
        if (nodeArr.isEmpty()) {
            return timeCost;
        }
        Transaction txn = dgraphClient.newTransaction();
        try {
            DgraphProto.Mutation.Builder builder = DgraphProto.Mutation.newBuilder();
            builder.setSetJson(ByteString.copyFromUtf8(nodeArr.toJSONString()));
            long start = System.nanoTime();
            DgraphProto.Request request =
                    DgraphProto.Request.newBuilder().setQuery(query).putAllVars(params).addMutations(builder).build();
            DgraphProto.Response response = txn.doRequest(request);
            txn.commit();
            start = System.nanoTime() - start;
            timeCost = latency2Cost(response.getLatency());
            timeCost.setMaxClientCost(start);
            timeCost.setMinClientCost(start);
            timeCost.setClientCost(start);
        } catch (Exception e) {
            e.printStackTrace();
        } finally {
            txn.discard();
        }
        logTimeCost("upsert", timeCost);
        nodeArr.clear();
        return timeCost;
    }

    public static JSONObject buildUpsert(String nodeGid, String edgeGid) {
        JSONObject nodeObj = new JSONObject();
        JSONObject edgeObj = new JSONObject();

        nodeObj.put("uid", "uid(node" + nodeGid + ")");
        nodeObj.put("gid", nodeGid);
        nodeObj.put("name", nodeGid);
        nodeObj.put("label", "people");

        edgeObj.put("uid", "uid(edge" + edgeGid + ")");
        edgeObj.put("gid", edgeGid);
        edgeObj.put("name", edgeGid);
        edgeObj.put("label", "house");

        nodeObj.put("houses", edgeObj);
        return nodeObj;
    }

    private static TimeCost latency2Cost(DgraphProto.Latency latency) {
        long parsingNs = latency.getParsingNs();
        long processingNs = latency.getProcessingNs();
        long encodingNs = latency.getEncodingNs();
        long totalNs = parsingNs + processingNs + encodingNs;
        return new TimeCost(0,totalNs, totalNs,totalNs, 0, 0, 0);
    }

    public static void logTimeCost(String op, TimeCost timeCost){
        log.info(String.format(LOG_FORMAT, op, JSONObject.toJSONString(timeCost)));
    }

    public static TimeCost mergeTimeCost(TimeCost timeCost1, TimeCost timeCost2) {
        Long maxServer = timeCost1.getMaxServerCost();
        Long minServer = timeCost1.getMinServerCost();
        Long maxClient = timeCost1.getMaxClientCost();
        Long minClient = timeCost1.getMinClientCost();

        Long maxServer2 = timeCost2.getMaxServerCost();
        Long minServer2 = timeCost2.getMinServerCost();
        Long maxClient2 = timeCost2.getMaxClientCost();
        Long minClient2 = timeCost2.getMinClientCost();

        if (maxServer < maxServer2){
            maxServer = maxServer2;
        }
        if (minServer > minServer2){
            minServer = minServer2;
        }

        if (maxClient < maxClient2){
            maxClient = maxClient2;
        }
        if (minClient > minClient2){
            minClient = minClient2;
        }

        Long clientCost = timeCost1.getClientCost() + timeCost2.getClientCost();
        Long serverCost = timeCost1.getServerCost() + timeCost2.getServerCost();
        return new TimeCost(0L, minServer, maxServer, serverCost, minClient, maxClient, clientCost);
    }
}`
and the TimeCost is just a simple Java bean

[mangalaman93]

@willem520 I am looking into this issue. There is code missing for TimeCost class and this code does't compile. I can't figure what json library are you importing.

One possible explanation could be that the second time the existing connection is reused and that reduces the overall time taken.

[willem520]

@willem520 I am looking into this issue. There is code missing for TimeCost class and this code does't compile. I can't figure what json library are you importing.

One possible explanation could be that the second time the existing connection is reused and that reduces the overall time taken.

I used fastjson jar by alibaba. I think when it first connect to dgraph, maybe it would need init some resource(eg threadpool). and then these resources can reused.

thx very much for your answer