I have a Play Framework Java app that has been growing in users and now I am starting to see some errors that I am having trouble resolving. I am using SmartMeter.io (uses jMeter) to load test and what I find is that these errors occur when I increase my users (simulated users during load testing) from 10 to 50.
The errors all seem to point to where and when I use Deadbolt's template convenience functions, such as restrict, restrictOr, subjectPresentOr, pattern, among others. When I remove these view function helpers or when I only run with 1-10 users, I no longer see the issues, however, once I have 25+ simultaneous users, I start to get these Java errors reported below. The errors hang my app and I need to reboot, which is undesirable. What I am seeing seems to be an infinite loop that makes the server unresponsive.
My test scenario that reports these issues is simple: login, access my home page which makes MySQL calls to get data, then log out. If all I do is remove all these Deadlbolt functions from my view, I no longer get these issues. I have tried increasing my deadbolt.java settings, but nothing seems to help.
Can anyone offer any suggestions on how to troubleshoot this? What other information can I provide to help support my situation? Thank you for any help.
I am using:
Play Framework 2.5
Deadbolt Jave 2.5.0
Deadbolt Core 2.4.3
Play Authenticate 0.8.3
Jooq 3.7.3
MySQL 5.7.19
I have not upgraded to the latest Play 2.6 because I am waiting on Play Authenticate to update.
# ------- Deadbolt -------
deadbolt {
java {
handler=security.MyDeadboltHandler,
cache-user=true,
view-timeout=10000, # Default 1000
blocking-timeout=10000 # Default 1000
}
}
Below are some sample errors at different timeout settings (10s in this case).
[error] b.o.d.j.ViewSupport - Timeout when attempting to complete future within [10000]ms. Denying access to resource.
java.util.concurrent.TimeoutException: null
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at be.objectify.deadbolt.java.ViewSupport.viewRestrict(ViewSupport.java:104)
at be.objectify.deadbolt.java.views.html.restrict_Scope0$restrict_Scope1$restrict.apply(restrict.template.scala:41)
at views.html.main_Scope0$main_Scope1$main.apply(main.template.scala:97)
at views.html.player.list.players_Scope0$players_Scope1$players.apply(players.template.scala:43)
at views.html.player.list.players_Scope0$players_Scope1$players.render(players.template.scala:60)
at views.html.player.list.players.render(players.template.scala)
at controllers.player.ListController.list(ListController.java:86)
at router.Routes$$anonfun$routes$1$$anonfun$applyOrElse$29$$anonfun$apply$29.apply(Routes.scala:1800)
[error] b.o.d.j.ViewSupport - Timeout when attempting to complete future within [10000]ms. Denying access to resource.
java.util.concurrent.TimeoutException: null
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at be.objectify.deadbolt.java.ViewSupport.viewRestrict(ViewSupport.java:104)
at be.objectify.deadbolt.java.views.html.restrict_Scope0$restrict_Scope1$restrict.apply(restrict.template.scala:41)
at views.html.main_Scope0$main_Scope1$main.apply(main.template.scala:97)
at views.html.player.list.players_Scope0$players_Scope1$players.apply(players.template.scala:43)
at views.html.player.list.players_Scope0$players_Scope1$players.render(players.template.scala:60)
at views.html.player.list.players.render(players.template.scala)
at controllers.player.ListController.list(ListController.java:86)
at router.Routes$$anonfun$routes$1$$anonfun$applyOrElse$29$$anonfun$apply$29.apply(Routes.scala:1800)
[error] b.o.d.j.ViewSupport - Timeout when attempting to complete future within [10000]ms. Denying access to resource.
java.util.concurrent.TimeoutException: null
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at be.objectify.deadbolt.java.ViewSupport.viewRestrict(ViewSupport.java:104)
at be.objectify.deadbolt.java.views.html.restrict_Scope0$restrict_Scope1$restrict.apply(restrict.template.scala:41)
at views.html.player.list.players_Scope0$players_Scope1$players$$anonfun$apply$2.apply(players.template.scala:548)
at views.html.player.list.players_Scope0$players_Scope1$players$$anonfun$apply$2.apply(players.template.scala:542)
at views.html.helper.form_Scope0$form.apply(form.template.scala:35)
at views.html.player.list.players_Scope0$players_Scope1$players.apply(players.template.scala:542)
at views.html.player.list.players_Scope0$players_Scope1$players.render(players.template.scala:616)
at views.html.player.list.players.render(players.template.scala)
[error] b.o.d.j.ViewSupport - Timeout when attempting to complete future within [10000]ms. Denying access to resource.
java.util.concurrent.TimeoutException: null
at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1771)
at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
at be.objectify.deadbolt.java.ViewSupport.viewPattern(ViewSupport.java:231)
at be.objectify.deadbolt.java.views.html.pattern_Scope0$pattern_Scope1$pattern.apply(pattern.template.scala:40)
at views.html.player.list._table_Scope0$_table_Scope1$_table$$anonfun$apply$9$$anonfun$apply$22$$anonfun$apply$23.apply(_table.template.scala:534)
at views.html.player.list._table_Scope0$_table_Scope1$_table$$anonfun$apply$9$$anonfun$apply$22$$anonfun$apply$23.apply(_table.template.scala:530)
at play.twirl.api.TemplateMagic$.defining(TemplateMagic.scala:13)
at views.html.player.list._table_Scope0$_table_Scope1$_table$$anonfun$apply$9$$anonfun$apply$22.apply(_table.template.scala:530)
at views.html.player.list._table_Scope0$_table_Scope1$_table$$anonfun$apply$9$$anonfun$apply$22.apply(_table.template.scala:529)
at play.twirl.api.TemplateMagic$.defining(TemplateMagic.scala:13)
----- Update One Day Later -----
I took a different approach and tried to determine what information each Deadbolt convenience function was trying to access for restrict, subjectNotPresent, and pattern, as these were the three I was using liberally in my one view. This one view consisted of a main.scala.html, plus three more views. I may have had 20-30 usages of restrict, restricOr, pattern, and subject. I then created a view model object that I pass down into my view from my controller. I am able to run with 50 concurrent users without any timeout issues.
Perhaps this is better use of data retrieval in general and perhaps I was abusing Deadbolt by using it too much. I would think each time a restrict or pattern is executed, it takes some time to run, and each instance runs that same amount of time, and when you have more concurrent users, timeouts happen? With my view model approach, I access the information I need and each request to it gets the already calculated data.
@restrict(roles = anyOf(allOf("admin"))) { }
now becomes @if(globalViewModel.isAdmin) { }
.
Just because this is working for me, doesn't mean it is a better approach. Any suggestions are welcome. Thank you.