Query result not as expected

OS info:
image
dgraph.exe version

[Decoder]: Using assembly version of decoder

Dgraph version   : v20.03.0
Dgraph SHA-256   : 2dd8a84711404f19a13375c377084795321f5e022eefafb869dbba6822b4d4fd
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit https://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

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

find bugs in logs
day one:

// do query 
2020-08-13 16:32:18.530  INFO 4380 --- [http-nio-3003-exec-1] app.settings.UserSettingsImpl       : userId: foo
settings: {"settings":[{"userId":"foo","nickname":"bar","language":"en","background":"../../static/bg/bg.png","lng":"121.4879","lat":"31.24916","is_first":true,"collectedInfo":"{}"}]}

// do update
2020-08-13 16:32:18.584  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : save user setting request is :{userId=foo, language=en, background=../../static/bg/bg.png, lat=31.24916, lng=121.4879}
2020-08-13 16:32:18.639  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : Save UserSettings JSON is {"uid":"0x1ea34","APP#usersettings":true,"APP#usersettings/userId":"foo","APP#usersettings/lat":"31.24916","APP#usersettings/language":"en","APP#usersettings/background":"../../static/bg/bg.png","APP#usersettings/lng":"121.4879","APP#dataSet#APP":true}
// do query again
2020-08-13 16:32:18.662  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : userId: foo
2020-08-13 16:32:18.711  INFO 4380 --- [http-nio-3003-exec-2] app.dgraph.DGraphService            : query is 
query x{
    settings(func: has(<APP#usersettings>)) @filter(eq(<APP#usersettings/userId>, <foo>)){
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
       userJobTitle: <APP#usersettings/userJobTitle>
       language: <APP#usersettings/language>
       feeling: <APP#usersettings/feeling>
       background: <APP#usersettings/background>
       lng: <APP#usersettings/lng>
       lat: <APP#usersettings/lat>
       is_first: <APP#usersettings/is_first>
       collectedInfo: <APP#usersettings/collectedInfo>
    }
}
 ,and response time is: 
StopWatch '': running time = 47697800 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
047697800  100%  Query and Response 

// the response of query 
2020-08-13 16:32:18.712  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : userId: foo
settings: {"settings":[{"userId":"foo","nickname":"bar","language":"en","background":"../../static/bg/bg.png","lng":"121.4879","lat":"31.24916","is_first":true,"collectedInfo":"{}"}]}

day two:

// do query
2020-08-14 11:32:48.262  INFO 4380 --- [http-nio-3003-exec-5] app.settings.UserSettingsImpl       : userId: foo
2020-08-14 11:32:48.291  INFO 4380 --- [http-nio-3003-exec-5] app.dgraph.DGraphService            : query is 
query x{
    settings(func: has(<APP#usersettings>)) @filter(eq(<APP#usersettings/userId>, <foo>)){
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
       userJobTitle: <APP#usersettings/userJobTitle>
       language: <APP#usersettings/language>
       feeling: <APP#usersettings/feeling>
       background: <APP#usersettings/background>
       lng: <APP#usersettings/lng>
       lat: <APP#usersettings/lat>
       is_first: <APP#usersettings/is_first>
       collectedInfo: <APP#usersettings/collectedInfo>
    }
}
 ,and response time is: 
StopWatch '': running time = 25138600 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
025138600  100%  Query and Response 

// the response of query, and not response as expected.

2020-08-14 11:32:48.291  INFO 4380 --- [http-nio-3003-exec-5] app.settings.UserSettingsImpl       : userId: foo
settings: {"settings":[]}

// bugs here

expect: settings: {"settings":[{"userId":"foo","nickname":"bar","language":"en","background":"../../static/bg/bg.png","lng":"121.4879","lat":"31.24916","is_first":true,"collectedInfo":"{}"}]}
but got: settings: {"settings":[]}

It’s not 100% happens,but sometimes.
and I can’t provide steps to re-produce this bug.

Java dependency

          <dependency>
            <groupId>io.dgraph</groupId>
            <artifactId>dgraph4j</artifactId>
            <version>20.03.0</version>
            <exclusions>
                <exclusion>
                    <groupId>org.slf4j</groupId>
                    <artifactId>slf4j-simple</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

The code of DGraphService

package app.dgraph;


import io.dgraph.DgraphClient;
import io.dgraph.DgraphGrpc;
import io.dgraph.DgraphProto;
import io.dgraph.Transaction;
import io.grpc.*;
import io.grpc.netty.NettyChannelBuilder;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;

import java.io.IOException;
import java.io.InputStream;
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.TimeUnit;

/**
 *
 */
@Component
public class DGraphService {
    /**
     *
     */
    private static final int DEFAULT_DEADLINE_SECS = 10;
    /**
     * 
     */
    @Value("${dgraph.deadline}")
    private int defaultDeadlineSecs = DEFAULT_DEADLINE_SECS;
    /**
     * @Description: dgraphHost
     */
    @Value("${dgraph.AlphaHost}")
    private String dgraphHost = "localhost";

    /**
     *
     */
    private static final int DEFAULTDGRAPHPORT = 9080;
    /**
     * @Description: port
     */
    @Value("${dgraph.AlphaGrpcPort}")
    private int port = DEFAULTDGRAPHPORT;
    /**
     * @Description: LOGGER
     */
    private static final Logger LOGGER
            = LoggerFactory.getLogger(DGraphService.class);

    /**
     * @return DgraphClient
     */
    public DgraphClient client() {
        return clientWithTimeout(defaultDeadlineSecs);
    }

    /**
     * @param maxBody      max body size
     * @param deadlineSecs deadlineSecs
     * @return client
     */
    public DgraphClient clientWithTimeoutAndMaxBody(
            final int deadlineSecs,
            final int maxBody
    ) {

        ManagedChannel channel = NettyChannelBuilder
                .forAddress(dgraphHost, port)
                .usePlaintext()
                .maxInboundMessageSize(maxBody)
                .build();
        DgraphGrpc.DgraphStub stub = DgraphGrpc.newStub(channel);
        stub.withDeadlineAfter(deadlineSecs, TimeUnit.MILLISECONDS);
        stub.withInterceptors(new TimeOutInterceptor(deadlineSecs));
        return new DgraphClient(stub);
    }

    /**
     * @param deadlineSecs d
     * @return DgraphClient
     */
    public DgraphClient clientWithTimeout(final int deadlineSecs) {
        ManagedChannel channel = NettyChannelBuilder
                .forAddress(dgraphHost, port)
                .usePlaintext()
                .build();
        DgraphGrpc.DgraphStub stub = DgraphGrpc.newStub(channel);
        stub.withDeadlineAfter(deadlineSecs, TimeUnit.MILLISECONDS);
        stub.withInterceptors(new TimeOutInterceptor((deadlineSecs)));
        return new DgraphClient(stub);
    }

    /**
     * @param xdgraphHost set host
     */
    public void setDgraphHost(final String xdgraphHost) {
        this.dgraphHost = xdgraphHost;
    }

    /**
     * @param xport set port.
     */
    public void setPort(final int xport) {
        this.port = xport;
    }


    /**
     * @param query query
     * @param vars  vars
     * @return String
     */
    public String response(
            final String query,
            final Map<String, String> vars) {
        return response(client(), query, vars);
    }

    /**
     * @param query  query
     * @param client client
     * @param vars   vars
     * @return String
     */
    public String response(
            final DgraphClient client,
            final String query,
            final Map<String, String> vars) {
        try (
                Transaction trx = client.newTransaction();
        ) {
            StopWatch sw = new StopWatch();
            sw.start("Query and Response ");
            String ret = trx.queryWithVars(query, vars)
                    .getJson().toStringUtf8();
            sw.stop();
            String sp = sw.prettyPrint();
            LOGGER.info("query is \n{}\n ,and response time is: \n{}",
                    query, sp);
            return ret;
        } catch (StatusRuntimeException e) {
            LOGGER.error(
                    "error query is\n {} \nand params is {}"
                            +
                            ",and hostinfo is {},{} ",
                    query, vars, dgraphHost, port);
            throw e;
        }
    }

    /**
     * @param query   query
     * @param timeout timeout
     * @param maxBody maxbody
     * @param vars    vars
     * @return response
     */
    public String responseWithTimeoutAndMaxBody(
            final String query,
            final int timeout,
            final int maxBody,
            final Map<String, String> vars) {
        DgraphClient client = clientWithTimeoutAndMaxBody(timeout, maxBody);
        return response(client, query, vars);
    }

    /**
     * @param query   query
     * @param timeout timeoutSec
     * @param vars    vars
     * @return String
     */
    public String responseWithTimeout(
            final String query,
            final int timeout,
            final Map<String, String> vars) {
        try (
                Transaction trx = clientWithTimeout(timeout).newTransaction();
        ) {
            StopWatch sw = new StopWatch();
            sw.start("Query and Response ");
            String ret = trx
                    .queryWithVars(query, vars)
                    .getJson().toStringUtf8();
            sw.stop();
            String sp = sw.prettyPrint();
            LOGGER.info("query is {} ,and response time is {}",
                    query, sp);
            return ret;
        } catch (StatusRuntimeException e) {
            LOGGER.error(
                    "error query is\n {} \nand params is {}"
                            +
                            ",and hostinfo is {},{} ",
                    query, vars, dgraphHost, port);
            throw e;
        }
    }

    /**
     * @param query   query
     * @param keyVals keyVals
     * @return String
     */
    public String response(final String query, final String... keyVals) {
        return response(client(), query, keyVals);
    }

    /**
     * @param query   query
     * @param client  client
     * @param keyVals keyVals
     * @return String
     */
    public String response(
            final DgraphClient client,
            final String query, final String... keyVals) {
        Map<String, String> vars = new HashMap<>();
        for (int i = 0; i < keyVals.length; i = i + 2) {
            vars.put(keyVals[i], keyVals[i + 1]);
        }
        return response(client, query, vars);
    }

    /**
     * @param query   query
     * @param timeout 超時時間
     * @param keyVals keyVals
     * @return String
     */
    public String responseWithTimeout(
            final String query, final int timeout, final String... keyVals) {
        Map<String, String> vars = new HashMap<>();
        for (int i = 0; i < keyVals.length; i = i + 2) {
            vars.put(keyVals[i], keyVals[i + 1]);
        }
        return responseWithTimeout(query, timeout, vars);
    }

    /**
     * @param mutation mutation
     */
    public void doMutate(final DgraphProto.Mutation mutation) {
        try (
                Transaction ts = this.client().newTransaction();
        ) {
            ts.mutate(mutation);
            ts.commit();
            ts.discard();
        } catch (Exception e) {
            LOGGER.error(
                    "exception when domutation {},and the error mutation is {}",
                    e, mutation.getSetJson().toStringUtf8());
        }
    }

}

/**
 *
 */
class TimeOutInterceptor implements ClientInterceptor {
    /**
     *
     */
    private int deadlineSecs = 0;

    /**
     * @param deadline deadline in seconds.
     */
    TimeOutInterceptor(final int deadline) {
        this.deadlineSecs = deadline;
    }

    @Override
    public <T, P> ClientCall<T, P> interceptCall(
            final MethodDescriptor<T, P> method,
            final CallOptions callOptions,
            final Channel next) {
        return next.newCall(method, callOptions.withDeadlineAfter(
                deadlineSecs, TimeUnit.MILLISECONDS));
    }
}

MODERATOR EDITS
@chewxy: Potentially similar issue: Queries returning empty results randomly - #13 by BlankRain

I have to ask the obvious question, sorry if it seems silly - has anything written to the DB since? After you did the query which empty results were returned, did subsequent queries also return empty results?

If I return an empty result to client, the client will fetch the data of user settings from another system, and then I save the new data to dgraph .
The saving part has the logs like that:

// do update
2020-08-13 16:32:18.584  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : save user setting request is :{userId=foo, language=en, background=../../static/bg/bg.png, lat=31.24916, lng=121.4879}
2020-08-13 16:32:18.639  INFO 4380 --- [http-nio-3003-exec-2] app.settings.UserSettingsImpl       : Save UserSettings JSON is {"uid":"0x1ea34","APP#usersettings":true,"APP#usersettings/userId":"foo","APP#usersettings/lat":"31.24916","APP#usersettings/language":"en","APP#usersettings/background":"../../static/bg/bg.png","APP#usersettings/lng":"121.4879","APP#dataSet#APP":true}

the save user setting request is is the request I got from client,he fetch new settings data from another system.
the Save UserSettings JSON is is the JSON data I send to dgraph.

I checked the log carefully, no other action to the user foo.
I have many other query request for other users. but not foo, they response as expected.

I’m trying to re-produce this bug. If I make it, I will post here.

I can re-produce this bug now.
follow the steps here: GitHub - awsl-dbq/to-find-bug

please hold. trying to reproduce now and see if this is a javaclient issue.

Hi. I’ve not been able to reproduce this using your code.

The output from your code (latest run) is as follows:

Hello world!
 java -jar target/dgraph-1.0-SNAPSHOT.jar localhost 9080 x.gql minLen maxTimes
args is :
localhost
9080
findbug.gql
50
3
GET GQL from findbug.gql
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

<TRUNCATED netty LOGS>
20:58:04.149 [grpc-default-executor-0] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.ratio: 8
20:58:04.175 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
20:58:04.193 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
20:58:04.202 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=1000}
20:58:04.203 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=true
20:58:04.204 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=true
20:58:04.241 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: localhost:9080, :path: /api.Dgraph/Query, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.26.0, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
20:58:04.253 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=240 bytes=00000000eb22e801717565727920787b0a2020202073657474696e67732866756e633a20686173283c415050237573657273657474696e67733e2929200a2020...
20:58:04.255 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=240
20:58:04.256 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND PING: ack=false bytes=145258749040133895
20:58:04.256 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] OUTBOUND PING: ack=true bytes=145258749040133895
20:58:04.294 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
20:58:04.301 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND DATA: streamId=3 padding=0 endStream=false length=246 bytes=00000000f10a697b2273657474696e6773223a5b7b22756964223a22307831346530222c22757365724964223a22305f6b6579406170702e746f2e66696e6462...
20:58:04.306 [grpc-nio-worker-ELG-1-2] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x465cbc22, L:/127.0.0.1:58046 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
20:58:04.322 [main] INFO app.findbug.DGraphService - query is 
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

 ,and response time is: 
StopWatch '': running time = 399524672 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
399524672  100%  Query and Response 

GET RESPONSE 
{"settings":[{"uid":"0x14e0","userId":"0_key@app.to.findbug.com","nickname":"0_key@app.to.findbug.com"}]}
Length is 105
20:58:04.330 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
20:58:04.343 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
20:58:04.345 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=1000}
20:58:04.345 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=true
20:58:04.345 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=true
20:58:04.347 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: localhost:9080, :path: /api.Dgraph/Query, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.26.0, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
20:58:04.348 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=240 bytes=00000000eb22e801717565727920787b0a2020202073657474696e67732866756e633a20686173283c415050237573657273657474696e67733e2929200a2020...
20:58:04.349 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=240
20:58:04.349 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND PING: ack=false bytes=145258749040133895
20:58:04.349 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] OUTBOUND PING: ack=true bytes=145258749040133895
20:58:04.376 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
20:58:04.377 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND DATA: streamId=3 padding=0 endStream=false length=246 bytes=00000000f10a697b2273657474696e6773223a5b7b22756964223a22307831346530222c22757365724964223a22305f6b6579406170702e746f2e66696e6462...
20:58:04.378 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x971cc19e, L:/127.0.0.1:58048 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
20:58:04.379 [main] INFO app.findbug.DGraphService - query is 
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

 ,and response time is: 
StopWatch '': running time = 53442248 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
053442248  100%  Query and Response 

{"settings":[{"uid":"0x14e0","userId":"0_key@app.to.findbug.com","nickname":"0_key@app.to.findbug.com"}]}
Response Length is 105
20:58:04.387 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
20:58:04.399 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
20:58:04.400 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=1000}
20:58:04.401 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=true
20:58:04.401 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=true
20:58:04.402 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: localhost:9080, :path: /api.Dgraph/Query, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.26.0, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
20:58:04.403 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=240 bytes=00000000eb22e801717565727920787b0a2020202073657474696e67732866756e633a20686173283c415050237573657273657474696e67733e2929200a2020...
20:58:04.405 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=240
20:58:04.405 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND PING: ack=false bytes=145258749040133895
20:58:04.406 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] OUTBOUND PING: ack=true bytes=145258749040133895
20:58:04.424 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
20:58:04.425 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND DATA: streamId=3 padding=0 endStream=false length=246 bytes=00000000f10a697b2273657474696e6773223a5b7b22756964223a22307831346530222c22757365724964223a22305f6b6579406170702e746f2e66696e6462...
20:58:04.426 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0e408914, L:/127.0.0.1:58050 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
20:58:04.426 [main] INFO app.findbug.DGraphService - query is 
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

 ,and response time is: 
StopWatch '': running time = 44388585 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
044388585  100%  Query and Response 

{"settings":[{"uid":"0x14e0","userId":"0_key@app.to.findbug.com","nickname":"0_key@app.to.findbug.com"}]}
Response Length is 105
20:58:04.435 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
20:58:04.449 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
20:58:04.450 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=1000}
20:58:04.450 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=true
20:58:04.451 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=true
20:58:04.452 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: localhost:9080, :path: /api.Dgraph/Query, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.26.0, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
20:58:04.453 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=240 bytes=00000000eb22e801717565727920787b0a2020202073657474696e67732866756e633a20686173283c415050237573657273657474696e67733e2929200a2020...
20:58:04.454 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=240
20:58:04.454 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND PING: ack=false bytes=145258749040133895
20:58:04.454 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] OUTBOUND PING: ack=true bytes=145258749040133895
20:58:04.477 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
20:58:04.478 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND DATA: streamId=3 padding=0 endStream=false length=246 bytes=00000000f10a697b2273657474696e6773223a5b7b22756964223a22307831346530222c22757365724964223a22305f6b6579406170702e746f2e66696e6462...
20:58:04.479 [grpc-nio-worker-ELG-1-8] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x0ca02058, L:/127.0.0.1:58054 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
20:58:04.479 [main] INFO app.findbug.DGraphService - query is 
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

 ,and response time is: 
StopWatch '': running time = 50350146 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
050350146  100%  Query and Response 

{"settings":[{"uid":"0x14e0","userId":"0_key@app.to.findbug.com","nickname":"0_key@app.to.findbug.com"}]}
Response Length is 105
20:58:04.486 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=false settings={ENABLE_PUSH=0, MAX_CONCURRENT_STREAMS=0, INITIAL_WINDOW_SIZE=1048576, MAX_HEADER_LIST_SIZE=8192}
20:58:04.499 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=983041
20:58:04.500 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=false settings={MAX_CONCURRENT_STREAMS=1000}
20:58:04.500 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND SETTINGS: ack=true
20:58:04.501 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND SETTINGS: ack=true
20:58:04.502 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND HEADERS: streamId=3 headers=GrpcHttp2OutboundHeaders[:authority: localhost:9080, :path: /api.Dgraph/Query, :method: POST, :scheme: http, content-type: application/grpc, te: trailers, user-agent: grpc-java-netty/1.26.0, grpc-accept-encoding: gzip] streamDependency=0 weight=16 exclusive=false padding=0 endStream=false
20:58:04.502 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND DATA: streamId=3 padding=0 endStream=true length=240 bytes=00000000eb22e801717565727920787b0a2020202073657474696e67732866756e633a20686173283c415050237573657273657474696e67733e2929200a2020...
20:58:04.504 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND WINDOW_UPDATE: streamId=0 windowSizeIncrement=240
20:58:04.504 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND PING: ack=false bytes=145258749040133895
20:58:04.504 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] OUTBOUND PING: ack=true bytes=145258749040133895
20:58:04.525 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[:status: 200, content-type: application/grpc] padding=0 endStream=false
20:58:04.526 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND DATA: streamId=3 padding=0 endStream=false length=246 bytes=00000000f10a697b2273657474696e6773223a5b7b22756964223a22307831346530222c22757365724964223a22305f6b6579406170702e746f2e66696e6462...
20:58:04.526 [grpc-nio-worker-ELG-1-10] DEBUG io.grpc.netty.NettyClientHandler - [id: 0x79c4d2c9, L:/127.0.0.1:58058 - R:localhost/127.0.0.1:9080] INBOUND HEADERS: streamId=3 headers=GrpcHttp2ResponseHeaders[grpc-status: 0, grpc-message: ] padding=0 endStream=true
20:58:04.527 [main] INFO app.findbug.DGraphService - query is 
query x{
    settings(func: has(<APP#usersettings>)) 
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}

 ,and response time is: 
StopWatch '': running time = 45161475 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
045161475  100%  Query and Response 

{"settings":[{"uid":"0x14e0","userId":"0_key@app.to.findbug.com","nickname":"0_key@app.to.findbug.com"}]}
Response Length is 105
Over!

I also wrote a Go program to simulate exactly what you did, except do it more times. Also found 0 errors.

package main

import (
	"context"
	"encoding/json"
	"fmt"
	"log"

	"github.com/dgraph-io/dgo/v200"
	"github.com/dgraph-io/dgo/v200/protos/api"

	"google.golang.org/grpc"
)

func getDgraphClient() (*dgo.Dgraph, CancelFunc) {
	conn, err := grpc.Dial("127.0.0.1:9080", grpc.WithInsecure())
	if err != nil {
		log.Fatal("While trying to dial gRPC")
	}

	dc := api.NewDgraphClient(conn)
	dg := dgo.NewDgraphClient(dc)

	return dg, func() {
		if err := conn.Close(); err != nil {
			log.Printf("Error while closing connection:%v", err)
		}
	}
}

type Usersettings struct {
	Alias    string `json:"alias,omitempty"`
	Email    string `json:"email,omitempty"`
	Nickname string `json:"nickname,omitempty"`
	UserID   string `json:"userId,omitempty"`
}


const q = `query x{
    settings(func: has(<APP#usersettings>))
    @filter(eq(<APP#usersettings/userId>, <0_key@app.to.findbug.com>)){
        uid
       userId: <APP#usersettings/userId>
       nickname: <APP#usersettings/nickname>
    }
}
`

type CancelFunc func()

type X struct {
	X []Usersettings `json:"settings"`
}

func query(dg *dgo.Dgraph, cancel CancelFunc) (l int) {
	//defer cancel()

	ctx := context.Background()
	resp, err := dg.NewTxn().Query(ctx, q)
	if err != nil {
		log.Fatal(err)
	}

	var x X
	if err = json.Unmarshal(resp.Json, &x); err != nil {
		log.Fatal(err)
	}
	//fmt.Printf("Len: %d\n", len(x.X))
	//fmt.Println(string(resp.Json))
	return len(x.X)
}

func main() {
	dg, cancel := getDgraphClient()
	defer cancel()
	var count int
	for i := 0; i < 500; i++ {
		l := query(dg, cancel)
		if l < 1 {
			count++
		}
	}
	fmt.Printf("Errored %v times\n", count)

}

e…
00 Start zero and alpha


01 load data

02 find bug

Hi,I record some video to show this.

I use your go code ,and find 500 times errors.

Hi , did you setup your dgraph database using the dgraph bin I provided in github?

/dgraph version
[Decoder]: Using assembly version of decoder

Dgraph version   : v20.03.0
Dgraph SHA-256   : 07e63901be984bd20a3505a2ee5840bb8fc4f72cc7749c485f9f77db15b9b75a
Commit SHA-1     : 147c8df9
Commit timestamp : 2020-03-30 17:28:31 -0700
Branch           : HEAD
Go version       : go1.14.1

For Dgraph official documentation, visit https://docs.dgraph.io.
For discussions about Dgraph     , visit https://discuss.dgraph.io.
To say hi to the community       , visit https://dgraph.slack.com.

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

Aha, no. I’m using 20.07.

okay, let me try 20.07 , maybe it won’t occur anymore.

I tried 20-07, and no bugs here.
Okay, I will update my dgraph version to 20-07.

Cool. Solution is to use 20.07 for this. Root cause unknown as at time of posting this message.

1 Like