Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream. #21

Closed
mayfield opened this issue Aug 5, 2017 · 6 comments
Assignees

Comments

@mayfield
Copy link
Member

mayfield commented Aug 5, 2017

In heroku I get exceptions after the server is idle for a few minutes. It looks like the redis connection is flaky or maybe the redis instance is super small and we hit conditions that jedis doesn't handle on its own. Never seen these in AWS with localhost redis, so I'm leaning towards it being an infrastructure issue.

2017-08-05T07:53:44.567657+00:00 app[web.1]: ! redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream.
2017-08-05T07:53:44.567658+00:00 app[web.1]: ! at redis.clients.util.RedisInputStream.ensureFill(RedisInputStream.java:199)
2017-08-05T07:53:44.567659+00:00 app[web.1]: ! at redis.clients.util.RedisInputStream.readByte(RedisInputStream.java:40)
2017-08-05T07:53:44.567660+00:00 app[web.1]: ! at redis.clients.jedis.Protocol.process(Protocol.java:151)
2017-08-05T07:53:44.567661+00:00 app[web.1]: ! at redis.clients.jedis.Protocol.read(Protocol.java:215)
2017-08-05T07:53:44.567662+00:00 app[web.1]: ! at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:340)
2017-08-05T07:53:44.567662+00:00 app[web.1]: ! at redis.clients.jedis.Connection.getIntegerReply(Connection.java:265)
2017-08-05T07:53:44.567663+00:00 app[web.1]: ! at redis.clients.jedis.BinaryJedis.hdel(BinaryJedis.java:975)
2017-08-05T07:53:44.567663+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.DirectoryManager.remove(DirectoryManager.java:65)
2017-08-05T07:53:44.567664+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.DirectoryManager.remove(DirectoryManager.java:56)
2017-08-05T07:53:44.567665+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.AccountsManager.updateDirectory(AccountsManager.java:108)
2017-08-05T07:53:44.567666+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.AccountsManager.create(AccountsManager.java:70)
2017-08-05T07:53:44.567666+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.controllers.AccountController.resetAccount(AccountController.java:229)
2017-08-05T07:53:44.567667+00:00 app[web.1]: ! at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
2017-08-05T07:53:44.567667+00:00 app[web.1]: ! at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2017-08-05T07:53:44.567668+00:00 app[web.1]: ! at java.lang.reflect.Method.invoke(Method.java:498)
2017-08-05T07:53:44.567669+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
2017-08-05T07:53:44.567670+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
2017-08-05T07:53:44.567671+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
2017-08-05T07:53:44.567673+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:205)
2017-08-05T07:53:44.567674+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
2017-08-05T07:53:44.567675+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
2017-08-05T07:53:44.567676+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
2017-08-05T07:53:44.567676+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
2017-08-05T07:53:44.567677+00:00 app[web.1]: ! at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
2017-08-05T07:53:44.567678+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
2017-08-05T07:53:44.567678+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
2017-08-05T07:53:44.567679+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
2017-08-05T07:53:44.567679+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
2017-08-05T07:53:44.567680+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
2017-08-05T07:53:44.567680+00:00 app[web.1]: ! at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
2017-08-05T07:53:44.567681+00:00 app[web.1]: ! at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
2017-08-05T07:53:44.567682+00:00 app[web.1]: ! at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
2017-08-05T07:53:44.567682+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:403)
2017-08-05T07:53:44.567683+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:386)
2017-08-05T07:53:44.567683+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:334)
2017-08-05T07:53:44.567684+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:221)
2017-08-05T07:53:44.567684+00:00 app[web.1]: ! at io.dropwizard.jetty.NonblockingServletHolder.handle(NonblockingServletHolder.java:49)
2017-08-05T07:53:44.567685+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634)
2017-08-05T07:53:44.567685+00:00 app[web.1]: ! at io.dropwizard.servlets.ThreadNameFilter.doFilter(ThreadNameFilter.java:34)
2017-08-05T07:53:44.567685+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
2017-08-05T07:53:44.567686+00:00 app[web.1]: ! at io.dropwizard.jersey.filter.AllowedMethodsFilter.handle(AllowedMethodsFilter.java:50)
2017-08-05T07:53:44.567686+00:00 app[web.1]: ! at io.dropwizard.jersey.filter.AllowedMethodsFilter.doFilter(AllowedMethodsFilter.java:44)
2017-08-05T07:53:44.567687+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
2017-08-05T07:53:44.567690+00:00 app[web.1]: ! at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:308)
2017-08-05T07:53:44.567691+00:00 app[web.1]: ! at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:262)
2017-08-05T07:53:44.567691+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
2017-08-05T07:53:44.567692+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:541)
2017-08-05T07:53:44.567692+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
2017-08-05T07:53:44.567692+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1239)
2017-08-05T07:53:44.567693+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
2017-08-05T07:53:44.567693+00:00 app[web.1]: ! at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:481)
2017-08-05T07:53:44.567706+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
2017-08-05T07:53:44.567707+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1141)
2017-08-05T07:53:44.567708+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
2017-08-05T07:53:44.567708+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
2017-08-05T07:53:44.567709+00:00 app[web.1]: ! at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:241)
2017-08-05T07:53:44.567710+00:00 app[web.1]: ! at io.dropwizard.jetty.RoutingHandler.handle(RoutingHandler.java:52)
2017-08-05T07:53:44.567710+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:494)
2017-08-05T07:53:44.567711+00:00 app[web.1]: ! at io.dropwizard.jetty.BiDiGzipHandler.handle(BiDiGzipHandler.java:68)
2017-08-05T07:53:44.567712+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:56)
2017-08-05T07:53:44.567713+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:169)
2017-08-05T07:53:44.567713+00:00 app[web.1]: ! at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
2017-08-05T07:53:44.567714+00:00 app[web.1]: ! at org.eclipse.jetty.server.Server.handle(Server.java:564)
2017-08-05T07:53:44.567714+00:00 app[web.1]: ! at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
2017-08-05T07:53:44.567715+00:00 app[web.1]: ! at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
2017-08-05T07:53:44.567716+00:00 app[web.1]: ! at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
2017-08-05T07:53:44.567716+00:00 app[web.1]: ! at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
2017-08-05T07:53:44.567717+00:00 app[web.1]: ! at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
2017-08-05T07:53:44.567718+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.Invocable.invokePreferred(Invocable.java:122)
2017-08-05T07:53:44.567718+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.strategy.ExecutingExecutionStrategy.invoke(ExecutingExecutionStrategy.java:58)
2017-08-05T07:53:44.567719+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:201)
2017-08-05T07:53:44.567720+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:133)
2017-08-05T07:53:44.567721+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672)
2017-08-05T07:53:44.567721+00:00 app[web.1]: ! at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590)
2017-08-05T07:53:44.567722+00:00 app[web.1]: ! at java.lang.Thread.run(Thread.java:745)
@mayfield
Copy link
Member Author

mayfield commented Aug 5, 2017

Possibly related: redis/jedis#932

@mayfield
Copy link
Member Author

mayfield commented Aug 9, 2017

Still happening and for other endpoints too, which is pretty bad for us..

2017-08-09T21:56:35.273828+00:00 app[web.1]: ! redis.clients.jedis.exceptions.JedisConnectionException: Unexpected end of stream.
2017-08-09T21:56:35.273830+00:00 app[web.1]: ! at redis.clients.util.RedisInputStream.ensureFill(RedisInputStream.java:199)
2017-08-09T21:56:35.273830+00:00 app[web.1]: ! at redis.clients.util.RedisInputStream.readByte(RedisInputStream.java:40)
2017-08-09T21:56:35.273831+00:00 app[web.1]: ! at redis.clients.jedis.Protocol.process(Protocol.java:151)
2017-08-09T21:56:35.273832+00:00 app[web.1]: ! at redis.clients.jedis.Protocol.read(Protocol.java:215)
2017-08-09T21:56:35.273833+00:00 app[web.1]: ! at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:340)
2017-08-09T21:56:35.273834+00:00 app[web.1]: ! at redis.clients.jedis.Connection.getIntegerReply(Connection.java:265)
2017-08-09T21:56:35.273835+00:00 app[web.1]: ! at redis.clients.jedis.BinaryJedis.hset(BinaryJedis.java:839)
2017-08-09T21:56:35.273836+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.DirectoryManager.add(DirectoryManager.java:78)
2017-08-09T21:56:35.273836+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.AccountsManager.updateDirectory(AccountsManager.java:106)
2017-08-09T21:56:35.273837+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.storage.AccountsManager.update(AccountsManager.java:78)
2017-08-09T21:56:35.273837+00:00 app[web.1]: ! at org.whispersystems.textsecuregcm.controllers.DeviceController.verifyDeviceToken(DeviceController.java:179)
2017-08-09T21:56:35.273838+00:00 app[web.1]: ! at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2017-08-09T21:56:35.273838+00:00 app[web.1]: ! at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2017-08-09T21:56:35.273844+00:00 app[web.1]: ! at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2017-08-09T21:56:35.273845+00:00 app[web.1]: ! at java.lang.reflect.Method.invoke(Method.java:498)
2017-08-09T21:56:35.273846+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
2017-08-09T21:56:35.273846+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
2017-08-09T21:56:35.273849+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$TypeOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:205)
2017-08-09T21:56:35.273847+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
2017-08-09T21:56:35.273850+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
2017-08-09T21:56:35.273850+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
2017-08-09T21:56:35.273851+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
2017-08-09T21:56:35.273851+00:00 app[web.1]: ! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
2017-08-09T21:56:35.273852+00:00 app[web.1]: ! at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
2017-08-09T21:56:35.273852+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
2017-08-09T21:56:35.273853+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
2017-08-09T21:56:35.273853+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
2017-08-09T21:56:35.273854+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
2017-08-09T21:56:35.273854+00:00 app[web.1]: ! at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
2017-08-09T21:56:35.273855+00:00 app[web.1]: ! at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
2017-08-09T21:56:35.273855+00:00 app[web.1]: ! at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
2017-08-09T21:56:35.273856+00:00 app[web.1]: ! at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
2017-08-09T21:56:35.273856+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:403)
2017-08-09T21:56:35.273857+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:386)
2017-08-09T21:56:35.273857+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:334)
2017-08-09T21:56:35.273857+00:00 app[web.1]: ! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:221)
2017-08-09T21:56:35.273858+00:00 app[web.1]: ! at io.dropwizard.jetty.NonblockingServletHolder.handle(NonblockingServletHolder.java:49)

@mayfield
Copy link
Member Author

Looking better, will close until it pops up again..

@chriswil-codev
Copy link

chriswil-codev commented Aug 10, 2017 via email

@mayfield
Copy link
Member Author

@chriswil-codev

It was a timeout issue. Fixed with 722dcfd

@chriswil-codev
Copy link

chriswil-codev commented Aug 10, 2017 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants