[Help wanted] Error in no particular time

[gsiotas]

Hi!
I get this error in the wrapper log:

INFO   | jvm 1    | 2015/11/19 09:33:39 | [qtp5487649-33] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
INFO   | jvm 1    | 2015/11/19 09:33:39 | [qtp5487649-33] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners!
INFO   | jvm 1    | 2015/11/19 09:33:39 | com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.Util.handleNewInstance(Util.java:400)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.Util.getInstance(Util.java:383)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:958)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:937)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:926)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:872)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1236)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1231)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.ConnectionImpl.versionMeetsMinimum(ConnectionImpl.java:5274)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mysql.jdbc.StatementImpl.getWarnings(StatementImpl.java:2284)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.getWarnings(NewProxyPreparedStatement.java:1751)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.handleAndClearWarnings(SqlExceptionHelper.java:320)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.logAndClearWarnings(SqlExceptionHelper.java:273)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:529)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.cleanup(JdbcCoordinatorImpl.java:509)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.close(JdbcCoordinatorImpl.java:204)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl.close(TransactionCoordinatorImpl.java:297)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.internal.SessionImpl.close(SessionImpl.java:369)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.hibernate.jpa.internal.EntityManagerImpl.close(EntityManagerImpl.java:153)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.persist.jpa.JpaPersistService.end(JpaPersistService.java:81)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.persist.PersistFilter.doFilter(PersistFilter.java:91)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.Server.handle(Server.java:499)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
INFO   | jvm 1    | 2015/11/19 09:33:39 |   at java.lang.Thread.run(Thread.java:745)

I don't know what causes that, but when this happens the UI becomes very unstable and not usable. If I restart traccar everything is good. This can happen twice or three times in one day or it won't happen at all.

Thank you in advance for any suggestions.

EDIT: I am using 0.9.0 version

[vitalidze]

You need to check the timeout value setting in your MySQL database server. Run the following query:

SHOW VARIABLES LIKE '%timeout%';

Then post results here.

As far as I remember currently traccar is configured to warm up connections every 600 seconds, so if your server closes connection earlier then you will get these issues.

[gsiotas]

Thanks from the prompt answer:

connect_timeout 10
delayed_insert_timeout  300
innodb_lock_wait_timeout    50
innodb_rollback_on_timeout  OFF
interactive_timeout 28800
lock_wait_timeout   31536000
net_read_timeout    30
net_write_timeout   60
slave_net_timeout   3600
wait_timeout    28800

[vitalidze]

Your timeouts look good (the default values). Well, I don't know why it is happening. I guess you need to investigate the log file (both tracker-server.log and wrapper.log) for error messages before this one.

I can say that on all of my servers running 24x7 (I have three of them) I am using MySQL and don't have such issue.

[gsiotas]

Thank you for your prompt answer. I will further investigate the problem. Please leave it open for a few days, in case someone else comment anything useful.

Out of curiosity, in my server there are 7 devices registered that send data (positions) in a interval of 10 to 30 seconds 24/7. Maybe the error has to do with the load of the server?

[vitalidze]

No problem, let's leave it open until there are some update. Your case is a very lightweight. I don't think it produces much load. Anyway, you can try to monitor the workload of your server just in case.

[vitalidze]

Any update on this issue?

[gsiotas]

I managed to increase the memory allocated to Java and now the application seems to run smoother with no more mistakes. For the time being I will close it. Thanks!