Any hints for recovering from database connection leak problems

3,581 views
Skip to first unread message

Saiki Tanabe

unread,
Jan 19, 2017, 11:42:35 AM1/19/17
to Lift
Hi there,

I have being using Lift 3.0-RC4 in production. Having problems with database connection leaks, that leads to application unresponsiveness. Currently application is automatically restarted to fix the problem.

Now trying to figure out how situation could be improved, and was wondering if anyone in here have phased similar problems or otherwise know how this kind of situation could be improved?

Problem arises when there are more users in the service.

- Application uses Lift Mapper with HikariCP
- Application uses comets, and can have also "idle" connections where users have browser tab open, but not actively using the application.
- Application is deployed under Jetty 9.3.12.v20160915

Before application becomes unresponsive there is lots of connection leak warnings logged by HikariCP. Currently HikariCP is configured to have max 100 connections. I have read from HikariCP documentation that recommended size should be way smaller like 10, but then the application becomes unresponsive faster. Only way that been so far handling the situation has been to increase maximum number of database connections.

Application configures HikariCP with connection leak detection that logs following stack trace. There is not much hints for me, since stack trace doesn't include code from the application other than creating a new database connection, code.config.HikariDBVendor.newConnection.

Sorry for pasting a long stack trace in here.

18:38:49.137 [HikariPool-1 housekeeper] WARN  com.zaxxer.hikari.pool.ProxyLeakTask - Connection leak detection triggered for org.postgresql.jdbc.PgConnection@28ca959b, stack trace follows
java.lang.Exception: Apparent connection leak detected
at code.config.HikariDBVendor.newConnection(MapperConfig.scala:176) ~[classes/:na]
at net.liftweb.db.DB$$anonfun$cmSuperConnection$1$1.apply(DB.scala:162) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anonfun$cmSuperConnection$1$1.apply(DB.scala:162) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.common.EmptyBox.or(Box.scala:864) ~[lift-common_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$class.cmSuperConnection$1(DB.scala:162) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anonfun$9.apply(DB.scala:173) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anonfun$9.apply(DB.scala:172) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.common.Full.flatMap(Box.scala:808) ~[lift-common_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$class.newConnection(DB.scala:172) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$class.getConnection(DB.scala:286) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$class.use(DB.scala:680) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anon$1.use(DB.scala:40) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anon$2$$anonfun$apply$15.net$liftweb$db$DB$class$$anon$$anonfun$$recurseMe$1(DB.scala:251) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anon$2$$anonfun$apply$15.apply(DB.scala:253) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.DynoVar$class.run(ThreadGlobal.scala:95) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anon$2$DepthCnt$.run(DB.scala:224) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.db.DB$$anon$2.apply(DB.scala:227) ~[lift-db_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.net$liftweb$http$S$$doAround(S.scala:1492) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_nest2InnerInit$1.apply(S.scala:1716) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.net$liftweb$http$S$$_nest2InnerInit(S.scala:1715) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_innerInit$1$$anonfun$apply$44$$anonfun$apply$45$$anonfun$apply$46$$anonfun$apply$47.apply(S.scala:1762) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$withReq$2.apply(S.scala:1772) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.withReq(S.scala:1771) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$.withReq(S.scala:47) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_innerInit$1$$anonfun$apply$44$$anonfun$apply$45$$anonfun$apply$46.apply(S.scala:1757) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_innerInit$1$$anonfun$apply$44$$anonfun$apply$45.apply(S.scala:1755) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_innerInit$1$$anonfun$apply$44.apply(S.scala:1754) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_innerInit$1.apply(S.scala:1753) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.net$liftweb$http$S$$_innerInit(S.scala:1752) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2$$anonfun$apply$52$$anonfun$apply$53$$anonfun$apply$54$$anonfun$apply$55$$anonfun$apply$56.apply(S.scala:1795) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2$$anonfun$apply$52$$anonfun$apply$53$$anonfun$apply$54$$anonfun$apply$55.apply(S.scala:1793) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$class.apply(Vars.scala:605) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.RequestVarHandler$.apply(Vars.scala:507) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2$$anonfun$apply$52$$anonfun$apply$53$$anonfun$apply$54.apply(S.scala:1792) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$class.apply(Vars.scala:605) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.TransientRequestVarHandler$.apply(Vars.scala:520) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2$$anonfun$apply$52$$anonfun$apply$53.apply(S.scala:1791) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2$$anonfun$apply$52.apply(S.scala:1790) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$$anonfun$net$liftweb$http$S$$_init$2.apply(S.scala:1789) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.net$liftweb$http$S$$_init(S.scala:1788) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$class.init(S.scala:1376) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.S$.init(S.scala:47) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet$StatefulResponse$.doSession$1(LiftServlet.scala:384) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet$StatefulResponse$.process(LiftServlet.scala:394) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet.stepThroughPipeline$1(LiftServlet.scala:428) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet.doService(LiftServlet.scala:436) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet$$anonfun$doIt$1$2.apply(LiftServlet.scala:157) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet$$anonfun$doIt$1$2.apply(LiftServlet.scala:156) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.TimeHelpers$class.calcTime(TimeHelpers.scala:427) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.Helpers$.calcTime(Helpers.scala:34) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.TimeHelpers$class.logTime(TimeHelpers.scala:446) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.Helpers$.logTime(Helpers.scala:34) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet.doIt$1(LiftServlet.scala:156) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftServlet.service(LiftServlet.scala:167) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply$mcV$sp(HTTPProvider.scala:72) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(HTTPProvider.scala:71) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(HTTPProvider.scala:71) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.URLRewriter$.doWith(Req.scala:1344) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1.apply$mcV$sp(HTTPProvider.scala:70) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1.apply(HTTPProvider.scala:70) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2$$anonfun$apply$mcV$sp$1.apply(HTTPProvider.scala:70) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2.apply$mcV$sp(HTTPProvider.scala:66) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2.apply(HTTPProvider.scala:60) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$$anonfun$service$2.apply(HTTPProvider.scala:60) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.HTTPProvider$class.service(HTTPProvider.scala:60) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftFilter.service(LiftServlet.scala:1064) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply$mcV$sp(ServletFilterProvider.scala:82) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(ServletFilterProvider.scala:82) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1$$anonfun$apply$mcV$sp$2.apply(ServletFilterProvider.scala:82) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$class.handleLoan$1(ServletFilterProvider.scala:59) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$class.net$liftweb$http$provider$servlet$ServletFilterProvider$$handleLoanWrappers(ServletFilterProvider.scala:63) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(ServletFilterProvider.scala:82) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1.apply(ServletFilterProvider.scala:77) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1$$anonfun$apply$mcV$sp$1.apply(ServletFilterProvider.scala:77) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17$$anonfun$apply$18$$anonfun$apply$19.apply(Vars.scala:611) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17$$anonfun$apply$18.apply(Vars.scala:610) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17.apply(Vars.scala:609) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16.apply(Vars.scala:608) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$class.apply(Vars.scala:607) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.RequestVarHandler$.apply(Vars.scala:507) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1.apply$mcV$sp(ServletFilterProvider.scala:75) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1.apply(ServletFilterProvider.scala:75) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$$anonfun$doFilter$1.apply(ServletFilterProvider.scala:75) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17$$anonfun$apply$18$$anonfun$apply$19.apply(Vars.scala:611) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17$$anonfun$apply$18.apply(Vars.scala:610) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16$$anonfun$apply$17.apply(Vars.scala:609) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$$anonfun$apply$16.apply(Vars.scala:608) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.util.ThreadGlobal.doWith(ThreadGlobal.scala:71) ~[lift-util_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.CoreRequestVarHandler$class.apply(Vars.scala:607) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.TransientRequestVarHandler$.apply(Vars.scala:520) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.provider.servlet.ServletFilterProvider$class.doFilter(ServletFilterProvider.scala:74) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at net.liftweb.http.LiftFilter.doFilter(LiftServlet.scala:1064) ~[lift-webkit_2.11-3.0-RC4.jar:3.0-RC4]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1668) ~[jetty-servlet-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:581) ~[jetty-servlet-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) ~[jetty-security-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511) ~[jetty-servlet-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:213) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:119) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.Server.handle(Server.java:523) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) ~[jetty-server-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) ~[jetty-io-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) ~[jetty-io-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) ~[jetty-io-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) ~[jetty-util-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) ~[jetty-util-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) ~[jetty-util-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) ~[jetty-util-9.3.12.v20160915.jar:9.3.12.v20160915]
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) ~[jetty-util-9.3.12.v20160915.jar:9.3.12.v20160915]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]

Donald McLean

unread,
Jan 19, 2017, 11:57:29 AM1/19/17
to liftweb
Hi Saiki,

You should probably refactor the application to put the code doing the DB queries somewhere else. Probably in an actor, or a small group of actors. Each user does not need their own DB connection.

Donald

--
--
Lift, the simply functional web framework: http://liftweb.net
Code: http://github.com/lift
Discussion: http://groups.google.com/group/liftweb
Stuck? Help us help you: https://www.assembla.com/wiki/show/liftweb/Posting_example_code

---
You received this message because you are subscribed to the Google Groups "Lift" group.
To unsubscribe from this group and stop receiving emails from it, send an email to liftweb+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--
Family photographs are a critical legacy for
ourselves and our descendants. Protect that
legacy with a digital backup and recovery plan.

Antonio Salazar Cardozo

unread,
Jan 19, 2017, 12:48:34 PM1/19/17
to Lift
How many concurrent users starts triggering this? Are you using a connection pool
to manage the HikariCP connections?
Thanks,
Antonio

Saiki Tanabe

unread,
Jan 19, 2017, 1:41:42 PM1/19/17
to Lift
I don't have accurate measures, but google real-time analytics shows about 70-90 concurrent active users with comet. Then there are "idle" connections from browser tabs, but those are not actively doing anything and therefore not shown on analytics, but might briefly use also a database connection with the heartbeat... there can be quite a few of those...

There is no extra connection pool on database side for HikariCP, and using only HikariCP connection pool.

Saiki

Saiki Tanabe

unread,
Jan 20, 2017, 4:07:07 AM1/20/17
to Lift
Thanks Donald for the hint! This would probably mean that all database calls become asynchronous. Would you happen to have any example where I could study more about this option?

Saiki
To unsubscribe from this group and stop receiving emails from it, send an email to liftweb+u...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

Antonio Salazar Cardozo

unread,
Jan 20, 2017, 8:14:40 AM1/20/17
to Lift
Hmm, interesting. I believe Lift wraps the message handler for comets in session
initialization, which from what I see above seems like it probably grabs a connection.
If that's true, any comet message handling will grab a connection. Are you doing any
work directly within a comet message handler that takes more than a very short amount
of time?
Thanks,
Antonio

Donald McLean

unread,
Jan 20, 2017, 10:33:39 AM1/20/17
to liftweb
Hi Saiki,

The database calls should be asynchronous and not in your CometActor. The reason is time. A database call might take 100 milliseconds, which doesn't seem like much to a human, but is an eternity to a modern computer. If you think of one microsecond as one second of computer time, that 100 milliseconds would be the equivalent of almost 28 hours to a computer. In actuality, a "computer second" is probably more like 10 nanoseconds.

I can think of several different ways to implement something like this. If the application is fairly simple, it can be done with a LiftActor and message objects. I'm going to give an example with just two features get A, save A.

trait DBMessage {
  def apply(connection: DBConnection)
}

class GetAMessage(aKey: AKeyType, requester: CometActor) extends DBMessage {
  def apply(connection: DBConnection) {
    // do the get A thing here
    requester ! resultObject
  }
}

class SaveAMessage(anA: A, requester: CometActor) extends DBMessage {
  def apply(connection: DBConnection) {
    // do the save A thing here
    requester ! resultObject
  }
}

The purpose of having the requester as part of the message is so that the actor can send back either whatever the result is - an A, or an error message. Because the requester is a CometActor, the message handlers for CometActors run inside a request and so when handling the result, it will be able to send updates back to the client web browser.
class  DBCallHandler(val myConnection: DBConnection) extends LiftActor {

  override protected def messageHandler: PartialFunction[Any, Unit] = {
    case m: DBMessage => m(myConnection)
  }
}
This outline obviously skip over lots of details and I don't even guarantee that the syntax is completely right, but hopefully this will convey at least one possible approach.

Donald

Saiki Tanabe

unread,
Jan 22, 2017, 1:26:52 AM1/22/17
to Lift
Hi Donald,

Thanks for your example and nice timing analogies! Tried to follow this principle and keep CometActor very light that passes actual request to LiftActor that does the actual work and having actual database calls. Refactoring database calls within LiftActor to asynchronous would be quite a lot of work.

Now that reviewed the code there is one synchronous call from CometActor to LiftActor with !? and will refactor at least that now to asynchronous version. Also user information is needed to know who is making a request with User.currentUser in CometActor before passing the request to LiftActor.

Application uses user extended session and will debug if comet heartbeat/long poll grabs a database connection as Antonio hinted.

Saiki

Saiki Tanabe

unread,
Jan 27, 2017, 5:50:23 AM1/27/17
to Lift
TL;DR Solved so far! Wanted to share solution in case someone needs it in the future, use eager=false.

I did some debugging and application acquires huge amounts of database connections. Application uses heavily CometActors with two different comets and using about 10 RoundTrips on a single page app. Connections are grabbed periodically also when user doesn't do anything. When user does some realtime activity, then connections are reserved more.

Application starts to be in trouble when there are more active users + idle users (users who doesn't do anything). Acquiring new database connections and releasing those is pretty fast, but after when there is relatively a lot concurrent usage, everything starts to sum up and application ends up not responding any longer.

Luckily I had a chance to chat off-list with David Pollak and he pointed out to use eager=false on buildLoadWrapper. It is an awesome feature in Lift, when using eager = false database connection is acquired only if it is actually used and then released when the Actor scope is exited.

S.addAround(DB.buildLoanWrapper(eager = false))

This solution really dropped the number of acquired db connections to bare minimum when those were actually used. There are still some periodic times when all database connections are acquired at once. I will debug that further if it brings any problems. Traffic has not being super high yet after the fix, but overall application server load average has dropped (when using uptime command).

Thanks Lift community for guidance and David for pointing out a simple, but very efficient solution!

Saiki

Diego Medina

unread,
Jan 27, 2017, 6:53:31 AM1/27/17
to Lift
Thanks for sharing the solution!

--
--
Lift, the simply functional web framework: http://liftweb.net
Code: http://github.com/lift
Discussion: http://groups.google.com/group/liftweb
Stuck? Help us help you: https://www.assembla.com/wiki/show/liftweb/Posting_example_code

---
You received this message because you are subscribed to the Google Groups "Lift" group.
To unsubscribe from this group and stop receiving emails from it, send an email to liftweb+unsubscribe@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.



--
Diego Medina
Lift/Scala Consultant
di...@fmpwizard.com
https://blog.fmpwizard.com/

Antonio Salazar Cardozo

unread,
Jan 27, 2017, 12:54:17 PM1/27/17
to Lift
Oh man, yeah, nice find, thanks for sharing!
Antonio

Matt Farmer

unread,
Jan 31, 2017, 10:35:27 PM1/31/17
to Lift
We should have a blog or something were we capture good solutions to obscure problems like this somewhere that more SEO friendly than the google list. =)

Thanks for sharing this Saiki!

—
Matt Farmer | Blog | Twitter
GPG: CD57 2E26 F60C 0A61 E6D8  FC72 4493 8917 D667 4D07

To unsubscribe from this group and stop receiving emails from it, send an email to liftweb+u...@googlegroups.com.

Diego Medina

unread,
Feb 1, 2017, 1:13:03 AM2/1/17
to Lift
A long time ago I started https://app.assembla.com/spaces/liftweb/wiki/cool_tips , maybe you can add it there and/or the cookbook may be a good place too
Reply all
Reply to author
Forward
0 new messages