Mirth Community

Mirth Community (http://www.mirthcorp.com/community/forums/index.php)
-   Support (http://www.mirthcorp.com/community/forums/forumdisplay.php?f=6)
-   -   com.mirth.connect.server.controllers.DefaultChanne lController:Error refreshing channe (http://www.mirthcorp.com/community/forums/showthread.php?t=11807)

rohit.chawla12 10-07-2014 03:18 PM

com.mirth.connect.server.controllers.DefaultChanne lController:Error refreshing channe
 
Hi Guys,
I have the following error(PersistenceException) logs in my logs/mirth.log file which is located in the MIRTH_HOME directory. I am using Mirth 3.0.1 version. And mySql 5.6.14. I am not sure whether it's mirth or mySql issue. Please suggest.

ERROR 2014-10-01 09:01:46,230 [qtp280726080-36] com.mirth.connect.server.controllers.DefaultChanne lController: Error refreshing channel cache
com.mirth.connect.server.controllers.ControllerExc eption: org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.apache.ibatis.transaction.TransactionException : Error configuring AutoCommit. Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false. Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsExce ption: The last packet successfully received from the server was 62,318,009 milliseconds ago. The last packet sent successfully to the server was 62,318,009 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
### The error may exist in mysql/mysql-channel.xml
### The error may involve Channel.getChannelRevision
### The error occurred while executing a query
### Cause: org.apache.ibatis.transaction.TransactionException : Error configuring AutoCommit. Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false. Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsExce ption: The last packet successfully received from the server was 62,318,009 milliseconds ago. The last packet sent successfully to the server was 62,318,009 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at com.mirth.connect.server.controllers.DefaultChanne lController.getChannelRevisions(DefaultChannelCont roller.java:331)
at com.mirth.connect.server.controllers.DefaultChanne lController$ChannelCache.refreshCache(DefaultChann elController.java:416)
at com.mirth.connect.server.controllers.DefaultChanne lController$ChannelCache.getAllChannels(DefaultCha nnelController.java:481)
at com.mirth.connect.server.controllers.DefaultChanne lController$ChannelCache.access$200(DefaultChannel Controller.java:408)
at com.mirth.connect.server.controllers.DefaultChanne lController.getChannels(DefaultChannelController.j ava:64)
at com.mirth.connect.server.controllers.DefaultChanne lController.getChannelTags(DefaultChannelControlle r.java:176)
at com.mirth.connect.server.servlets.ChannelServlet.d oPost(ChannelServlet.java:124)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:727)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(Ser vletHolder.java:652)
at org.eclipse.jetty.servlet.ServletHandler.doHandle( ServletHandler.java:447)
at org.eclipse.jetty.server.session.SessionHandler.do Handle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.do Handle(ContextHandler.java:1038)
at org.eclipse.jetty.servlet.ServletHandler.doScope(S ervletHandler.java:374)
at org.eclipse.jetty.server.session.SessionHandler.do Scope(SessionHandler.java:189)
at org.eclipse.jetty.server.handler.ContextHandler.do Scope(ContextHandler.java:972)
at org.eclipse.jetty.server.handler.ScopedHandler.han dle(ScopedHandler.java:135)
at org.eclipse.jetty.server.handler.HandlerList.handl e(HandlerList.java:52)
at org.eclipse.jetty.server.handler.HandlerWrapper.ha ndle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java :363)
at org.eclipse.jetty.server.AbstractHttpConnection.ha ndleRequest(AbstractHttpConnection.java:483)
at org.eclipse.jetty.server.AbstractHttpConnection.co ntent(AbstractHttpConnection.java:931)
at org.eclipse.jetty.server.AbstractHttpConnection$Re questHandler.content(AbstractHttpConnection.java:9 92)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpPa rser.java:856)
at org.eclipse.jetty.http.HttpParser.parseAvailable(H ttpParser.java:240)
at org.eclipse.jetty.server.AsyncHttpConnection.handl e(AsyncHttpConnection.java:82)
at org.eclipse.jetty.io.nio.SslConnection.handle(SslC onnection.java:196)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.han dle(SelectChannelEndPoint.java:627)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.r un(SelectChannelEndPoint.java:51)
at org.eclipse.jetty.util.thread.QueuedThreadPool.run Job(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.r un(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:744)

Thanks & Regards,
Rohit Chawla

wayneh 10-07-2014 05:20 PM

Seems like left your Administrator open and idle for 17 hours. MySQL has a default wait_timeout of 8 hours so if you try to use a connection that's been idle for more than that you will usually get this exception.

If you refresh again MyBatis may automatically retrieve a new connection and everyone will continue again. Is this the case or do you keep getting the same exception each time?

rohit.chawla12 10-07-2014 07:04 PM

Thanks Wayneh.
I think you have made the right point here saying that I might have left Administrator open for long time. I have looked into mirth server logs and found that certainly, there was big time gap between the execution of two jobs and meanwhile the above exception was threw while my Admin window was still open. But I have also found that the time gap is different every time this exception was threw, in one place it's 6 hours and other place is 7 hours.

As of now, I am closing my Admin window and hoping that this issue wouldn't appear.

Thanks again.

Regards,
Rohit Chawla

rohit.chawla12 10-08-2014 02:28 PM

I have looked into the mirth logs this morning and found the same exception again(below). I closed the mirth admin yesterday but still got the exception. From previous days logs, I have found that the same exception was generated when the time gap between the execution of two jobs were 10, 12 or 5 hours.
From Yesterday mirth logs:
com.mirth.connect.server.servlets.UserServlet: javax.servlet.ServletException: com.mirth.connect.server.controllers.ControllerExc eption: com.mirth.connect.server.controllers.ControllerExc eption: org.apache.ibatis.exceptions.PersistenceException:
### Error querying database. Cause: org.apache.ibatis.transaction.TransactionException : Error configuring AutoCommit. Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false. Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsExce ption: The last packet successfully received from the server was 68,183,445 milliseconds ago. The last packet sent successfully to the server was 68,183,445 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
### The error may exist in mysql/mysql-user.xml
### The error may involve User.getUser
### The error occurred while executing a query
### Cause: org.apache.ibatis.transaction.TransactionException : Error configuring AutoCommit. Your driver may not support getAutoCommit() or setAutoCommit(). Requested setting: false. Cause: com.mysql.jdbc.exceptions.jdbc4.CommunicationsExce ption: The last packet successfully received from the server was 68,183,445 milliseconds ago. The last packet sent successfully to the server was 68,183,445 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at com.mirth.connect.server.servlets.UserServlet.logi n(UserServlet.java:229)
at com.mirth.connect.server.servlets.UserServlet.doPo st(UserServlet.java:64)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:727)
at javax.servlet.http.HttpServlet.service(HttpServlet .java:820)
at org.eclipse.jetty.servlet.ServletHolder.handle(Ser vletHolder.java:652)
at org.eclipse.jetty.servlet.ServletHandler.doHandle( ServletHandler.java:447)
at org.eclipse.jetty.server.session.SessionHandler.do Handle(SessionHandler.java:225)
at org.eclipse.jetty.server.handler.ContextHandler.do Handle(ContextHandler.java:1038)
at org.eclipse.jetty.servlet.ServletHandler.doScope(S ervletHandler.java:374)
at org.eclipse.jetty.server.session.SessionHandler.do Scope(SessionHandler.java:189)
at org.eclipse.jetty.server.handler.ContextHandler.do Scope(ContextHandler.java:972)
at org.eclipse.jetty.server.handler.ScopedHandler.han dle(ScopedHandler.java:135)
at org.eclipse.jetty.server.handler.HandlerList.handl e(HandlerList.java:52)
at org.eclipse.jetty.server.handler.HandlerWrapper.ha ndle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java :363)
at org.eclipse.jetty.server.AbstractHttpConnection.ha ndleRequest(AbstractHttpConnection.java:483)
at org.eclipse.jetty.server.AbstractHttpConnection.co ntent(AbstractHttpConnection.java:931)
at org.eclipse.jetty.server.AbstractHttpConnection$Re questHandler.content(AbstractHttpConnection.java:9 92)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpPa rser.java:856)
at org.eclipse.jetty.http.HttpParser.parseAvailable(H ttpParser.java:240)
at org.eclipse.jetty.server.AsyncHttpConnection.handl e(AsyncHttpConnection.java:82)
at org.eclipse.jetty.io.nio.SslConnection.handle(SslC onnection.java:196)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.han dle(SelectChannelEndPoint.java:627)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.r un(SelectChannelEndPoint.java:51)
at org.eclipse.jetty.util.thread.QueuedThreadPool.run Job(QueuedThreadPool.java:608)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.r un(QueuedThreadPool.java:543)
at java.lang.Thread.run(Thread.java:744)


Please suggest.

Thanks & Regards,
Rohit Chawla

wayneh 10-09-2014 12:00 PM

This makes sense because the connections are pooled on the server so even if the Administrator is closed MySQL will still close the connections after the wait_timeout. I've created an issue for us to look at this more in the future.

Usually the error is harmless and a new connection will be created the next time a request is made. If for some reason someone REALLY needs a workaround right now, the answer is to run the following code from a deploy script or something each time the server is started. Ideally the "setPoolPingConnectionsNotUsedFor" value should be slightly less than the "wait_timeout" value that's set in MySQL. Note that the "wait_timeout" value is in seconds while the "setPoolPingConnectionsNotUsedFor" value is in milliseconds.

The example below is set to 1 second which means once the connection is idle for at least 1 second the validation query will be run the next time a connection is retrieved. You should find out what your server's wait_timeout value is and set the setPoolPingConnectionsNotUsedFor value to about 15 minutes less than that for best performance.

Code:

var manager = Packages.com.mirth.connect.server.util.SqlConfig.getSqlSessionManager();
var dataSource = manager.getConfiguration().getEnvironment().getDataSource();
dataSource.setPoolPingEnabled(true);
dataSource.setPoolPingQuery("SELECT 1");
dataSource.setPoolPingConnectionsNotUsedFor(1000);

Note that this workaround is using an unsupported API call and is not something we recommend using. There's no guarantee it will work in the future.

rohit.chawla12 10-09-2014 04:34 PM

Thanks Wayneh.
As of now, I do implement the above code in my development environment. And should keep the tab on the proceedings.

Thanks again for your time.

Regards,
Rohit Chawla

wayneh 01-08-2015 10:31 AM

In 3.2 we will be enabling MyBatis validation automatically so there won't be a need to use the above workaround anymore.

See MIRTH-3484 for more information.


All times are GMT -8. The time now is 01:40 PM.

Powered by vBulletin® Version 3.8.7
Copyright ©2000 - 2019, vBulletin Solutions, Inc.
Mirth Corporation