N1QL queries timing out when run in java sdk


#1

Good evening,

Here is a problem that has been troubling me for a few days now. It pertains to both N1QL and the Java sdk, so I apologize if it has more relevance in the other location. I will just provide all the details I know to provide in both to be as certain as possible.

-I am able to run queries in the tutorial and with curl, however, they timeout when done with the sdk.

-I call with (in the 2.1.0-dp sdk) :
Query theQuery = Query.simple(query);
QueryResult queryResult = bucket.query(theQuery);

-The “query” parameter is a String and I have tried the values of “CREATE PRIMARY INDEX ON default” and “SELECT * FROM default”

-This problem developed when moving from dp3 to dp4.

-It occurs with both the 2.0 and the developer preview of the 2.1 java sdk.

-The timeout exception is thrown in blockForSingle of Blocking.java.

-It is the “returnException” caught at “onNext” and is a “java.util.concurrent.TimeoutException”, and the cause stated is “rx.exceptions.OnErrorThrowables$OnNextValue: OnError while emitting onNext value: com.couchbase.client.java.query.DefaultAsyncQueryResult.class”

  • With the “SELECT * FROM default” query the cbq-engine logs "level=“INFO” _msg=“Number of entries fetched from the index 9"”

Just wondering if there is something I am doing incorrectly or if there are new developments waiting for the two to work together.

Thank you for your time.


#2

@somexp

Can you please share the full code and maybe some logs so we can try reproduce it?
Thank you!

(edit: I changed the category to Java SDK since I guess it’s more related to that when people are searching for it)


#3

Hi I have the same issue,
this is a snippet

CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
	        .queryEnabled(true)
	        .build();
Cluster cluster = CouchbaseCluster.create(env,"XXX");
Bucket bucket = cluster.openBucket("meters","");
String query = "SELECT * from meters";
Query cbquery= Query.simple(query);
QueryResult result = bucket.query(cbquery);
    if(result.finalSuccess())
    {
    	
    	Iterator<QueryRow> rows =result.rows();
    	while (rows.hasNext())
    	{
    		QueryRow row= rows.next();
    		System.out.println(row.value());
    	}
    } 
    else
    {
    	for (JsonObject error : result.errors()) {
            System.err.println(error);
    	}

#4

I think loscouw’s example would be easiest. I made the decision to work this into a larger product and much of the logic is broken between methods. He follows similar logic.

This is some of what I do have, though. The place I am querying from is as follows

Bucket bucket = getBucket(bucketName);
try
{
Query theQuery = Query.simple(query);
QueryResult queryResult = bucket.query(theQuery);

        List<QueryRow> rows = queryResult.allRows();
        JsonObject result = JsonObject.create();
        for (QueryRow row : rows)
        {
            Map rowMap = row.value().toMap();
            for (Object key : rowMap.keySet())
            {
                result.put(key.toString(), rowMap.get(key));
            }
        }
        return Response.ok(result.toString (), MediaType.APPLICATION_JSON).build();
    }

Followed by the catches.

The getBucket method returns the results of:

CouchbaseCluster.create([serverAddress]).openBucket(default))


#6

From the logs:

Jan 21, 2015 4:02:53 PM com.couchbase.client.core.endpoint.AbstractEndpoint$2 operationComplete
WARNING: [null][QueryEndpoint]: Could not connect to endpoint, retrying with delay 4096ms:
java.net.ConnectException: Connection refused: couchbasehost/[ip]:8093
at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
at sun.nio.ch.SocketChannelImpl.finishConnect(Unknown Source)
at com.couchbase.client.deps.io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:208)
at com.couchbase.client.deps.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:281)
at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:528)
at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468)
at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382)
at com.couchbase.client.deps.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354)
at com.couchbase.client.deps.io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:116)
at com.couchbase.client.deps.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:137)
at java.lang.Thread.run(Unknown Source)

This is repeated multiple times.


#7

This indicates that you do not have N1QL running on this machine (on port 8093). That is most likely the reason it’s not working for you.


#8

Hi daschl,

I have checked everything, the engine is up and running, no firewall beetween client and server.
I made a wireshark capture and the server can give back a json.

this is what it give

{
"requestID": "12579313-1d52-4865-823d-891d99efc723",
"signature": {
    "*": "*"
},
"results": [
    {
        "meters": {
            "data": "ho hey",
            "type": "comment"
        }
    },
    {
        "meters": {
            "data": "blablabla",
            "type": "blog"
        }
    }
],
"status": "success",
"metrics": {
    "elapsedTime": "5.437266ms",
    "executionTime": "5.073126ms",
    "resultCount": 2,
    "resultSize": 234
}

}


#9

It’s hard to say, but this is a exception from the JVM which indicates that the remote host refuses the connection. Can you check that the hostname is also properly reachable as the SDK uses it? At this point there is not much the SDK can “do”, when the JVM is saying the remote host refuses the connection.


#10

You were right about the query engine being off. I apologize, I rushed that one. After turning it on I still receive the timeout, but it’s hard to find a problem in the logs under “com.couchbase”. The levels are all FINE and FINEST, so I have to adjust my settings to allow for some spam. I do receive the data from the server. I get a series of:

Jan 21, 2015 10:23:25 PM com.couchbase.client.deps.io.netty.handler.logging.LoggingHandler logMessage
FINEST: [id: 0x1576b8e4, /[couchbase client ip]:34977 => couchbasehost/[couchbase server ip]:8093] RECEIVED(4351B)
±------------------------------------------------+
| 0 1 2 3 4 5 6 7 8 9 a b c d e f |
±-------±------------------------------------------------±---------------+
|00000000| 2d 61 34 61 66 2d 34 33 66 62 2d 38 62 30 65 2d |-a4af-43fb-8b0e-|
|00000010| 34 30 37 35 66 30 62 61 38 33 61 35 22 2c 0a 20 |4075f0ba83a5",. |
|00000020| 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 | |

…followed by the rest of the hex data.

Here is a sample from what follows immediately from that:

Jan 21, 2015 10:23:25 PM com.couchbase.client.core.endpoint.AbstractGenericHandler decode
FINEST: [couchbasehost/[couchbase server ip]:8093][QueryEndpoint]: Finished decoding of GenericQueryRequest{observable=rx.subjects.AsyncSubject@dda1ff8, bucket=‘default’}
Jan 21, 2015 10:28:04 PM com.couchbase.client.deps.io.netty.handler.logging.LoggingHandler channelInactive
FINEST: [id: 0x390ea486, /[couchbase client ip]:45470 :> couchbasehost/[couchbase server ip]:8091] INACTIVE
Jan 21, 2015 10:28:04 PM com.couchbase.client.core.endpoint.AbstractGenericHandler channelInactive
FINE: [couchbasehost/[couchbase server ip]:8091][ConfigEndpoint]: Channel Inactive.
Jan 21, 2015 10:28:04 PM com.couchbase.client.core.endpoint.AbstractEndpoint notifyChannelInactive
FINE: [couchbasehost/[couchbase server ip]:8091][ConfigEndpoint]: Got notified from Channel as inactive.
Jan 21, 2015 10:28:04 PM com.couchbase.client.core.config.DefaultConfigurationProvider signalOutdated
FINE: Received signal for outdated configuration.
Jan 21, 2015 10:28:04 PM com.couchbase.client.core.state.AbstractStateMachine transitionState
FINEST: State (ConfigEndpoint) CONNECTED -> DISCONNECTED

That’s about all I am able to get.

Here is the stack trace from the timeout exception:

com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:93)
com.couchbase.client.java.CouchbaseBucket.query(CouchbaseBucket.java:544)
com.couchbase.client.java.CouchbaseBucket.query(CouchbaseBucket.java:481)
[title of module].query(CouchbasePersistenceRestService_2_0.java:1296)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
java.lang.reflect.Method.invoke(Unknown Source)
org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151)
org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:171)
org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:152)
org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104)
org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:406)
org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:350)
org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:106)
org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:259)
org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
org.glassfish.jersey.internal.Errors.process(Errors.java:315)
org.glassfish.jersey.internal.Errors.process(Errors.java:297)
org.glassfish.jersey.internal.Errors.process(Errors.java:267)
org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:320)
org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:236)
org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1028)
org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:373)
org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:381)
org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:344)
org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:219)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:534)
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1081)
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:658)
org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222)
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1566)
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1523)
java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
java.lang.Thread.run(Unknown Source)


#11

Would you mind sharing the full logs and code? You can also send them over as a private message here (or through some other channel) if you don’t want to make them public.


#12

Just a suggestion on your code @somexp: toMap can be a bit expensive since it will make a deep copy of the JsonObject then transform each JsonObject in the tree into a Map, each JsonArray into a List.

If you just want to iterate over each key/value to inject them into a new JSON object, you can use JsonObject.getNames() to get the keyset…

And if there’s multiple rows, for each row your code will overwrite any previous existing enty in result that has the same key, giving you in the end either the last row content or a mix of last rows… is that on purpose?


#13

Concerning both your queries @loscouw and @somexp, I’ve tried similar queries without problem, albeit on the beer-sample bucket. Are you sure your classpath is clean and corresponds to core-io-1.1.0-dp.jar, java-client-2.1.0-dp.jar and rxjava-1.0.4.jar ?

Maybe we can work with a common document space, if you have the possibility to load beer-sample bucket?

Queries I’ve tried are

  • CREATE PRIMARY INDEX ON `beer-sample` -> returns an error saying the index already exists, expected
  • SELECT * FROM `beer-sample` -> 7303 results
  • SELECT name FROM `beer-sample` LIMIT 100 -> 100 results of just beer or brewery names

Code:

public class SomexpLoscouwMain {
public static void main(String[] args) {
    CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
                                                          .queryEnabled(true)
                                                          .build();
    Cluster cluster = CouchbaseCluster.create(env, "127.0.0.1");
    Bucket bucket = cluster.openBucket("beer-sample","");
    //String query = "SELECT * FROM `beer-sample`";
    //String query = "CREATE PRIMARY INDEX ON `beer-sample`";
    String query = "SELECT name FROM `beer-sample` LIMIT 100";
    Query cbquery= Query.simple(query);
    QueryResult result = bucket.query(cbquery);
    if(result.finalSuccess())
    {

        Iterator<QueryRow> rows =result.rows();
        int rowCount = 0;
        while (rows.hasNext())
        {
            QueryRow row= rows.next();
            System.out.println(row.value());
            rowCount++;
        }
        System.err.println("Rows printed: " + rowCount);
    }
    else {
        for (JsonObject error : result.errors()) {
            System.err.println(error);
        }
    }
}
}

#14

@simonbasle

Tnx for your reply.
I have checked for libraries and they are ok.
I have tryed your code but i obtained the same RuntimeException.


#15

I created a new and smaller project, so I can share it more fully now. The code I used was from what Mr. Basle produced, so:

package main.java.dp4Test;

import com.couchbase.client.java.Bucket;
import com.couchbase.client.java.Cluster;
import com.couchbase.client.java.CouchbaseCluster;
import com.couchbase.client.java.document.json.JsonObject;
import com.couchbase.client.java.query.Query;
import com.couchbase.client.java.query.QueryResult;
import com.couchbase.client.java.query.QueryRow;
import com.couchbase.client.java.env.*;

import java.util.Iterator;

public class SomexpLoscouwMain {
public static void main(String[] args) {
CouchbaseEnvironment env = DefaultCouchbaseEnvironment.builder()
.queryEnabled(true)
.build();
Cluster cluster = CouchbaseCluster.create(env, “127.0.0.1”);
Bucket bucket = cluster.openBucket(“beer-sample”,"");
//String query = "SELECT * FROM beer-sample";
//String query = "CREATE PRIMARY INDEX ON beer-sample";
String query = “SELECT name FROM beer-sample LIMIT 100”;
Query cbquery= Query.simple(query);
QueryResult result = bucket.query(cbquery);
if(result.finalSuccess())
{

        Iterator<QueryRow> rows =result.rows();
        int rowCount = 0;
        while (rows.hasNext())
        {
            QueryRow row= rows.next();
            System.out.println(row.value());
            rowCount++;
        }
        System.err.println("Rows printed: " + rowCount);
    }
    else {
        for (JsonObject error : result.errors()) {
            System.err.println(error);
        }
    }
}

}

I ran it locally, so in a Windows environment this time, with the couchbase server and query engine on the same machine as this program runs.

The results are as follows:

C:\programs\Java\jdk1.7.0_67\bin\java -Didea.launcher.port…
Jan 22, 2015 12:19:44 PM com.couchbase.client.core.CouchbaseCore
INFO: CoreEnvironment: {sslEnabled=false, sslKeystoreFile=‘null’, sslKeystorePassword=‘null’, queryEnabled=true, queryPort=8093, bootstrapHttpEnabled=true, bootstrapCarrierEnabled=true, bootstrapHttpDirectPort=8091, bootstrapHttpSslPort=18091, bootstrapCarrierDirectPort=11210, bootstrapCarrierSslPort=11207, ioPoolSize=4, computationPoolSize=4, responseBufferSize=16384, requestBufferSize=16384, kvServiceEndpoints=1, viewServiceEndpoints=1, queryServiceEndpoints=1, ioPool=NioEventLoopGroup, coreScheduler=CoreScheduler, packageNameAndVersion=couchbase-java-client/2.1.0-dp (git: 2.1.0-dp), dcpEnabled=false}
Jan 22, 2015 12:19:45 PM com.couchbase.client.core.node.CouchbaseNode$5 call
INFO: Connected to Node 127.0.0.1
Jan 22, 2015 12:19:45 PM com.couchbase.client.core.config.DefaultConfigurationProvider$6 call
INFO: Opened bucket beer-sample
Exception in thread “main” java.lang.RuntimeException: java.util.concurrent.TimeoutException
at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:93)
at com.couchbase.client.java.query.DefaultQueryResult.(DefaultQueryResult.java:53)
at com.couchbase.client.java.CouchbaseBucket$4.call(CouchbaseBucket.java:550)
at com.couchbase.client.java.CouchbaseBucket$4.call(CouchbaseBucket.java:546)
at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:55)
at rx.internal.operators.OperatorMerge$MergeSubscriber.handleScalarSynchronousObservableWithoutRequestLimits(OperatorMerge.java:225)
at rx.internal.operators.OperatorMerge$MergeSubscriber.handleScalarSynchronousObservable(OperatorMerge.java:214)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:149)
at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:93)
at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:55)
at rx.internal.operators.NotificationLite.accept(NotificationLite.java:150)
at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.pollQueue(OperatorObserveOn.java:189)
at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.access$000(OperatorObserveOn.java:65)
at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber$2.call(OperatorObserveOn.java:153)
at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:47)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.util.concurrent.TimeoutException
… 22 more
Caused by: rx.exceptions.OnErrorThrowable$OnNextValue: OnError while emitting onNext value: com.couchbase.client.java.query.DefaultAsyncQueryResult.class
at rx.exceptions.OnErrorThrowable.addValueAsLastCause(OnErrorThrowable.java:98)
at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:58)
… 17 more

Process finished with exit code 1


#16

ok good news, using the same setup (running it all locally but on a windows machine) I was able to reproduce the problem… seems there is a race condition when there is a little latency. Will try and commit a fix asap, to be part of a dp2 for Java SDK 2.1.0…


#17

tracked in https://issues.couchbase.com/browse/JCBC-692 and fixed on master!
@somexp @loscouw if you have the possibility of building from master and validating the fix works for you, please do :smile:


#18

Hi @simonbasle,

I get the code from master and build it.
Everything goes well.

Tnx :smiley:


#19

Great. Just built and tested it. The issue appears to have been resolved well.


#20

Great news, thanks for validating the fix works guys!


#21

I am having a similar issue on 2.1.0.

java.util.concurrent.TimeoutException: null
at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:93)
at com.couchbase.client.java.CouchbaseBucket.query(CouchbaseBucket.java:547)
at com.couchbase.client.java.CouchbaseBucket.query(CouchbaseBucket.java:490)
at com.apple.ist.salesplatform.dao.CouchbaseService.search(CouchbaseService.java:126)
at com.apple.ist.salesplatform.dao.EntityDao.search(EntityDao.java:88)

public int search(final String q) {
System.setProperty(“com.couchbase.queryEnabled”, “true”);
System.setProperty(“com.couchbase.client.queryEnabled”, “true”);
final QueryResult queryResult = bucket.query(Query.simple(q));
return queryResult.allRows().size();
}

I am doing a performance testing for N1ql as a query solution. It works great in console as N1ql engine. I was able to make it run once without any problems with java sdk. By mistake, i ran a query which would return millions of records (select * from default) , I killed the server . Ever since, I have tried everything, this Blocking.blockForSingle doesn’t go away.

System details : Couchbase Server 3.0.2, MAC OS Yosemite, JDK 7 (and JDK 6)