KarelCemus / play-redis

Play framework 2 cache plugin as an adapter to redis-server
Mozilla Public License 2.0
164 stars 44 forks source link

Facing java.util.concurrent.TimeoutException when redis server is frequently called #245

Closed veetragdeora closed 3 years ago

veetragdeora commented 3 years ago

play-redis -> 2.6.1 Scala -> 2.13.1 Play -> 2.8.1 redis-cli -> 3.0.6

Hi,

I am getting java.util.concurrent.TimeoutException when the redis server is frequently called.

[play.cache.DefaultSyncCacheApi.blocking(DefaultSyncCacheApi.java:80), play.cache.DefaultSyncCacheApi.get(DefaultSyncCacheApi.java:38), SettingsService.getSettingsByKey(SettingsService.java:66), MailerService.sendWelcomeEmail(MailerService.java:488), UserService.setNewAccountSettings(UserService.java:863), SignUpController.lambda$createUser$0(SignUpController.java:275), play.db.jpa.DefaultJPAApi.withTransaction(DefaultJPAApi.java:169), play.db.jpa.DefaultJPAApi.withTransaction(DefaultJPAApi.java:126), play.db.jpa.DefaultJPAApi.withTransaction(DefaultJPAApi.java:101), SignUpController.createUser(SignUpController.java:87), router.Routes$$anonfun$routes$1.$anonfun$applyOrElse$1364(Routes.scala:14673), play.core.routing.HandlerInvokerFactory$$anon$8.resultCall(HandlerInvoker.scala:148), play.core.routing.HandlerInvokerFactory$$anon$8.resultCall(HandlerInvoker.scala:147), play.core.routing.HandlerInvokerFactory$JavaActionInvokerFactory$$anon$3$$anon$4$$anon$5.invocation(HandlerInvoker.scala:113), play.core.j.JavaAction$$anon$1.call(JavaAction.scala:119), ActionCreator$1.call(ActionCreator.java:17), play.core.j.JavaAction.$anonfun$apply$8(JavaAction.scala:175), scala.concurrent.Future$.$anonfun$apply$1(Future.scala:661), scala.concurrent.impl.Promise$Transformation.run(Promise.scala:430), play.core.j.HttpExecutionContext.$anonfun$execute$1(HttpExecutionContext.scala:64), play.api.libs.streams.Execution$trampoline$.execute(Execution.scala:70), play.core.j.HttpExecutionContext.execute(HttpExecutionContext.scala:59), scala.concurrent.impl.Promise$Transformation.submitWithValue(Promise.scala:392), scala.concurrent.impl.Promise$DefaultPromise.submitWithValue(Promise.scala:302), scala.concurrent.impl.Promise$DefaultPromise.dispatchOrAddCallbacks(Promise.scala:276), scala.concurrent.impl.Promise$DefaultPromise.map(Promise.scala:146), scala.concurrent.Future$.apply(Future.scala:661), play.core.j.JavaAction.apply(JavaAction.scala:176), play.api.mvc.Action.$anonfun$apply$4(Action.scala:82), scala.concurrent.impl.Promise$Transformation.run(Promise.scala:433), akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:55), akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:92), scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.scala:18), scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:94), akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:92), akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:47), akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:47), java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289), java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056), java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692), java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:175)] java.lang.RuntimeException: java.util.concurrent.TimeoutException at play.cache.DefaultSyncCacheApi.blocking(DefaultSyncCacheApi.java:80) at play.cache.DefaultSyncCacheApi.get(DefaultSyncCacheApi.java:38)

Any solution for this ?

arigoldx commented 3 years ago

Does it ever work? That is, can you connect to the redis server?

Any chance you can post your config here?

veetragdeora commented 3 years ago

Thanks @arigoldx!! Yes, it is working in normal condition and I can connect to redis server too when this issue occurs and it is using only 0.3% of server memory and redis server logs also shows normal working condition.

Configuration redis-server -> Ubuntu 18.04.5 LTS (GNU/Linux 5.4.0-1037-aws x86_64) application-serve -> Ubuntu 16.04.6 LTS (GNU/Linux 4.4.0-1121-aws x86_64) play-redis -> 2.6.1 Scala -> 2.13.1 Play -> 2.8.1 redis-cli -> 3.0.6

https://github.com/playframework/playframework/pull/7802 this is fixed in play 2.6.x but it is coming in 2.8.1

KarelCemus commented 3 years ago

I might have a hunch but just to be sure: which API do you use? The stacktrace shows that it is default java API, which is blocking.

I suspect that the issue might be the threadpool pool. If you have a significant load and use blocking code which block thread, the issue might be that there is no available thread for the play-redis to execute the commands.

I suggest either using a nonblocking implementation or introducing a dedicated thread pool for the play-redis. See play.cache.redis.dispatcher in docs

KarelCemus commented 3 years ago

Closing due to inactivity. If the issue persists and the suggestion above doesn't help, feel free to reopen the ticket