Read graph action throws com.orientechnologies.orient.core.exception.OStorageException: Error on executing command.

[RajathiNatarajan]

This issues arrives when deploying orient in amazon instance and connecting it concurrently via api..
below is the stack trace contains variable information which is hard to derive what could be the actual root cause..but, on analyzing could guess it because of multiple retry happens for connection to database...

2016-03-07T16:37:20.772+0530 STDIO [ERROR] Mar 07, 2016 4:37:20 PM com.orientechnologies.common.log.OLogManager log
SEVERE: Removing disconnected network channel 'ip:2424/database'...
2016-03-07T16:37:20.773+0530 STDIO [ERROR] Mar 07, 2016 4:37:20 PM com.orientechnologies.common.log.OLogManager log

also follows with

com.orientechnologies.orient.core.exception.OStorageException: Error on executing command: sql.SELECT EXPAND($c) LET $a = (SELECT FROM E), $b = (SELECT FROM V), $c = UNIONALL( $a, $b )

2016-03-07T16:37:20.782+0530 STDIO [ERROR] Caused by: java.lang.NullPointerException
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.setReadResponseTimeout(OChannelBinaryAsynchClient.java:415)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:216)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:171)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.beginResponse(OStorageRemote.java:1887)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.command(OStorageRemote.java:986)

it links to same issue #4914

[RajathiNatarajan]

Hi tglman,
Any quick updates would be more helpful to resolve this issue.

[tglman]

Hi @RajathiNatarajan,

Yes i saw this exception already and i never been abl4e to reproduce it, it's probably a problem of concurrency between operations and starting-up/shutdown of the client while some operation are running.

What version of orientdb are you using ?

Do you connect using everytime the same user or you use multiple users ? do you use one or multiple database from the same client ?

Sorry for asking so many information, but this bug sneak out my fixes few times, so propably i'm missing the use case where it happen.

bye

[RajathiNatarajan]

Hi tglman,

Yeah, its really hard for me to reproduce the same, but the thing is it not looks good to move it for production with unreliable system.

version am using is 2.0.8

Trying to connect with same user and also a single database.

hope this information would help you....

Thanks

[RajathiNatarajan]

com.orientechnologies.orient.core.exception.OStorageException: Error on executing command:

 sql.SELECT EXPAND($c) LET $a = (SELECT FROM E), $b = (SELECT FROM V), $c = UNIONALL( $a, $b )
2016-03-07T16:37:20.781+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.handleException(OStorageRemote.java:1507)
2016-03-07T16:37:20.781+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.command(OStorageRemote.java:1065)
2016-03-07T16:37:20.781+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemoteThread.command(OStorageRemoteThread.java:436)
2016-03-07T16:37:20.781+0530 STDIO [ERROR] at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:63)
2016-03-07T16:37:20.782+0530 STDIO [ERROR] at com.tinkerpop.blueprints.impls.orient.OrientGraphCommand.execute(OrientGraphCommand.java:48)
2016-03-07T16:37:20.782+0530 STDIO [ERROR] ... 21 more
2016-03-07T16:37:20.782+0530 STDIO [ERROR] Caused by: java.lang.NullPointerException
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.setReadResponseTimeout(OChannelBinaryAsynchClient.java:415)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:216)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:171)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.beginResponse(OStorageRemote.java:1887)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] at com.orientechnologies.orient.client.remote.OStorageRemote.command(OStorageRemote.java:986)
2016-03-07T16:37:20.783+0530 STDIO [ERROR] ... 26 more

Adding few more stacktrace for your reference. It looks like when OChannelBinaryAsynchClient goes null it leads to this ???.

Before this an action happens like removing disconnected network channel.

[waltron]

I've hit this on 2.1.7 also, for what it's worth, and then things went south. We restarted.

We use the same user, connecting from 3 running instances to the one db, using remote: binary connection. pool size max = 50, min = 5.

The environment is relatively concurrent and db has upwards of 500,000 nodes.

com.orientechnologies.orient.core.exception.OStorageException: Error on executing command: sql.select uid as idfo, @class as clazz, name, rank from mmnode where index LUCENE ? order by rank desc LIMIT 20
    at com.orientechnologies.orient.client.remote.OStorageRemote.handleException(OStorageRemote.java:1768)
    at com.orientechnologies.orient.client.remote.OStorageRemote.command(OStorageRemote.java:1241)
    at com.orientechnologies.orient.client.remote.OStorageRemoteThread.command(OStorageRemoteThread.java:444)
    at com.orientechnologies.orient.core.sql.query.OSQLQuery.run(OSQLQuery.java:72)
    at com.orientechnologies.orient.core.sql.query.OSQLSynchQuery.run(OSQLSynchQuery.java:85)
    at com.orientechnologies.orient.core.query.OQueryAbstract.execute(OQueryAbstract.java:33)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.query(ODatabaseDocumentTx.java:719)
    at uk.co.probability.liquid.orient.service.search.OrientSearchService.trendingSearch(OrientSearchService.java:58)
    at uk.co.probability.liquid.search.service.search.TrendingServiceImpl.trendingSearch(TrendingServiceImpl.java:71)
    at uk.co.probability.liquid.search.service.search.TrendingServiceImpl.getAndCacheTrending(TrendingServiceImpl.java:66)
    at sun.reflect.GeneratedMethodAccessor120.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.cache.interceptor.CacheInterceptor$1.invoke(CacheInterceptor.java:52)
    at org.springframework.cache.interceptor.CacheAspectSupport.invokeOperation(CacheAspectSupport.java:317)
    at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:350)
    at org.springframework.cache.interceptor.CacheAspectSupport.execute(CacheAspectSupport.java:299)
    at org.springframework.cache.interceptor.CacheInterceptor.invoke(CacheInterceptor.java:61)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207)
    at com.sun.proxy.$Proxy37.getAndCacheTrending(Unknown Source)
    at uk.co.probability.liquid.search.config.SearchConfig.populateCache(SearchConfig.java:41)
    at sun.reflect.GeneratedMethodAccessor119.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65)
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    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:724)
Caused by: java.lang.NullPointerException
    at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.setReadResponseTimeout(OChannelBinaryAsynchClient.java:417)
    at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:216)
    at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:171)
    at com.orientechnologies.orient.client.remote.OStorageRemote.beginResponse(OStorageRemote.java:2155)
    at com.orientechnologies.orient.client.remote.OStorageRemote.command(OStorageRemote.java:1188)
    ... 40 more  

[tglman]

fixed this on the develop branch checking it there before backport it to 2.2.

[tglman]

closing this because already fixed in 2.2.3