Empty get response throws exception

[mick-h]

If I issue the following query:

val result = r.db("dbName").table[User]("users").get(userid).run

where there is no record for userid, the following occurs:

16:48:06.792 [New I/O worker #6] ERROR c.r.net.JsonVersionHandler - Error in trying to handle token
scala.MatchError: null
at com.rethinkscala.net.JsonVersionHandler$$anonfun$handle$1.apply(VersionHandler.scala:88) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler$$anonfun$handle$1.apply(VersionHandler.scala:88) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply$mcV$sp(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at scala.util.Try$.apply(Try.scala:191) ~[scala-library-2.11.1.jar:0.13.5]
at com.rethinkscala.net.VersionHandler$class.handle(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:79) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:87) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:79) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.ConnectionAttachment.handle(Connection.scala:48) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.RethinkChannelHandler$$anonfun$messageReceived$1.apply(Handler.scala:24) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.RethinkChannelHandler$$anonfun$messageReceived$1.apply(Handler.scala:24) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at scala.Option.map(Option.scala:145) [scala-library-2.11.1.jar:0.13.5]
at com.rethinkscala.net.RethinkChannelHandler.messageReceived(Handler.scala:24) [core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.9.3.Final.jar:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_45]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_45]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]
q: scala.util.Either[com.rethinkscala.net.RethinkError,models.messages.User] = Left(com.rethinkscala.net.RethinkRuntimeError: null)

scala> 16:48:06.797 [New I/O worker #6] ERROR c.r.net.JsonVersionHandler - UnCaught Exception token not resolved
scala.MatchError: null
at com.rethinkscala.net.JsonVersionHandler$$anonfun$handle$1.apply(VersionHandler.scala:88) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler$$anonfun$handle$1.apply(VersionHandler.scala:88) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply$mcV$sp(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.VersionHandler$$anonfun$1.apply(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at scala.util.Try$.apply(Try.scala:191) ~[scala-library-2.11.1.jar:0.13.5]
at com.rethinkscala.net.VersionHandler$class.handle(VersionHandler.scala:59) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:79) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:87) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.JsonVersionHandler.handle(VersionHandler.scala:79) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.ConnectionAttachment.handle(Connection.scala:48) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.RethinkChannelHandler$$anonfun$messageReceived$1.apply(Handler.scala:24) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at com.rethinkscala.net.RethinkChannelHandler$$anonfun$messageReceived$1.apply(Handler.scala:24) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at scala.Option.map(Option.scala:145) ~[scala-library-2.11.1.jar:0.13.5]
at com.rethinkscala.net.RethinkChannelHandler.messageReceived(Handler.scala:24) ~[core_2.11-0.4.6-SNAPSHOT.jar:0.4.6-SNAPSHOT]
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:296) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:268) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.Channels.fireMessageReceived(Channels.java:255) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108) [netty-3.9.3.Final.jar:na]
at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42) [netty-3.9.3.Final.jar:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_45]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_45]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]

It seems to be relatively benign, and it is happening on a separate thread.

[kclay]

New snapshot up, let me know if it works out for you.

[mick-h]

Keyston the exception is gone, but I think that this now causes the connection to not be returned to the pool.  Contrast this - a filtered search with no results:

2014-11-28 00:00:30,001 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(event-bus-responders-akka.actor.default-dispatcher-8) Writing WithFields(Filter(Table(users,None,Some(DB(notifications
))),FuncWrap(ScalaBooleanPredicate1()),Some(false)),WrappedArray(id, firstName, email))
2014-11-28 00:00:30,002 - [DEBUG] - com.rethinkscala.utils.SimpleConnectionPool(event-bus-responders-akka.actor.default-dispatcher-8) take connection with id (1)
2014-11-28 00:00:30,002 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-5) Logger already configured
2014-11-28 00:00:30,002 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-5) Received connection from pool
2014-11-28 00:00:30,074 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-5) Writing query
2014-11-28 00:00:30,117 - [DEBUG] - com.rethinkscala.net.JsonFrameDecoder(New I/O worker #10) Decoding Frame TOKEN = 2 LENGTH = 14
2014-11-28 00:00:30,117 - [DEBUG] - com.rethinkscala.net.JsonFrameDecoder(New I/O worker #10) JSON = {"t":2,"r":[]}
2014-11-28 00:00:30,397 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-3) Restoring connection (1)
2014-11-28 00:00:30,398 - [DEBUG] - com.rethinkscala.utils.SimpleConnectionPool(pool-44-thread-3) giveBack(connection:1)
2014-11-28 00:00:30,397 - [DEBUG] - com.rethinkscala.net.JsonVersionHandler(New I/O worker #10) Results = ()

with this - a primary key query for a non-existent key:

2014-11-28 00:00:31,023 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(event-bus-responders-akka.actor.default-dispatcher-10) Writing Get(Table(users,None,Some(DB(notifications))),5477206e712f1c230058824d)
2014-11-28 00:00:31,024 - [DEBUG] - com.rethinkscala.utils.SimpleConnectionPool(event-bus-responders-akka.actor.default-dispatcher-10) take connection with id (1)
2014-11-28 00:00:31,024 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-4) Logger already configured
2014-11-28 00:00:31,024 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-4) Received connection from pool
2014-11-28 00:00:31,025 - [DEBUG] - com.rethinkscala.net.BlockingConnection$$anon$2(pool-44-thread-4) Writing query
2014-11-28 00:00:31,027 - [DEBUG] - com.rethinkscala.net.JsonFrameDecoder(New I/O worker #10) Decoding Frame TOKEN = 3 LENGTH = 18
2014-11-28 00:00:31,027 - [DEBUG] - com.rethinkscala.net.JsonFrameDecoder(New I/O worker #10) JSON = {"t":1,"r":[null]}
2014-11-28 00:00:31,065 - [DEBUG] - com.rethinkscala.net.JsonVersionHandler(New I/O worker #10) Results = ()

In the second response JSON r is [null], whereas in the first response r was [].  In the second there is no restoring or giving back the connection.  As a result my pool is starved after I issue of these operations.

Hope this is enough info.

On 27 November 2014 at 2:50:29 am, Keyston (notifications@github.com) wrote:

New snapshot up, let me know if it works out for you.

—
Reply to this email directly or view it on GitHub.

[kclay]

Wow how did I miss this one. Fixed logic for it.

[mick-h]

Awesome.  Let me know when the snapshot’s up and I’ll give it a whirl.

On 28 November 2014 at 12:37:28 am, Keyston (notifications@github.com) wrote:

Wow how did I miss this one. Fixed logic for it.

—
Reply to this email directly or view it on GitHub.

[kclay]

Its up