SteVe stops responding - Githubissues

lincomatic commented 5 years ago

Checklist

[ x] I checked other issues already, but found no answer/solution
[ x] I checked the documentation and wiki, but found no answer/solution
[ x] I am running the latest version and the issue still occurs
[ x] I am sure that this issue is about SteVe (and not about the charging station software or something unrelated to SteVe)

Specifications

SteVe Version     : 3.3.0 or latest pull from github
Operating system  : Debian 9.4 x64
JDK               : oracle 11.0.4
Database          : mysqld   8.0.16 for Linux on x86_64 (MySQL Community Server - GPL)

Expected Behavior

SteVe doesn't freeze ...

Actual Behavior

SteVe stops responding to both OCPP charge point and web UI. What's interesting is that the sockets seem to stay open.

On web UI side, I hit refresh and the page doesn't respond, but stays open in Chrome.. if I kill SteVe, then the page goes blank.

On OCPP charge point side, the SteVe doesn't send any data out, but the charge point doesn't complain of lost connection. But when I kill SteVe, then the charge point reports that the connection is lost

There is nothing unusual in the logs.. the logs just show whatever occurred before the freeze up. When I kill SteVe, it logs the shutdown to the log file, so it isn't dead.. it just stops responding. ...

Steps to Reproduce the Problem

Install SteVe 3.3.0 or latest from git and start it.
wait 5-15 min until it stops responding

Additional context

Complete log file. SteVe was started, web UI verified alive. Waited 15 min, web UI frozen, killed SteVe:

[INFO ] 2019-07-24 21:57:17,735 de.rwth.idsg.steve.utils.PropertiesFileLoader - Hint: The Java system property 'main.properties' can be set to point to an external properties file, which will be prioritized over the bundled one [INFO ] 2019-07-24 21:57:17,843 de.rwth.idsg.steve.Application - Loaded the properties. Starting with the 'PROD' profile [INFO ] 2019-07-24 21:57:17,861 de.rwth.idsg.steve.Application - Date/time zone of the application is set to UTC. Current date/time: 2019-07-24T21:57:17.850Z [INFO ] 2019-07-24 21:57:17,891 org.eclipse.jetty.util.log - Logging initialized @900ms to org.eclipse.jetty.util.log.Slf4jLog [INFO ] 2019-07-24 21:57:18,090 org.eclipse.jetty.server.Server - jetty-9.4.17.v20190418; built: 2019-04-18T19:45:35.259Z; git: aa1c656c315c011c01e7b21aabb04066635b9f67; jvm 11.0.4+10-LTS [INFO ] 2019-07-24 21:57:18,183 org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=node0 [INFO ] 2019-07-24 21:57:18,183 org.eclipse.jetty.server.session - No SessionScavenger set, using defaults [INFO ] 2019-07-24 21:57:18,183 org.eclipse.jetty.server.session - node0 Scavenging every 600000ms [INFO ] 2019-07-24 21:57:18,189 org.eclipse.jetty.server.handler.ContextHandler.steve - Initializing Spring root WebApplicationContext [INFO ] 2019-07-24 21:57:18,189 org.springframework.web.context.ContextLoader - Root WebApplicationContext: initialization started [INFO ] 2019-07-24 21:57:18,992 com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... [INFO ] 2019-07-24 21:57:19,341 com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. [INFO ] 2019-07-24 21:57:20,955 org.apache.cxf.wsdl.service.factory.ReflectionServiceFactoryBean - Creating Service {urn://Ocpp/Cs/2010/08/}CentralSystemService from class ocpp.cs._2010._08.CentralSystemService [INFO ] 2019-07-24 21:57:21,377 org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /CentralSystemServiceOCPP12 [INFO ] 2019-07-24 21:57:21,392 org.apache.cxf.wsdl.service.factory.ReflectionServiceFactoryBean - Creating Service {urn://Ocpp/Cs/2012/06/}CentralSystemService from class ocpp.cs._2012._06.CentralSystemService [INFO ] 2019-07-24 21:57:21,458 org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /CentralSystemServiceOCPP15 [INFO ] 2019-07-24 21:57:21,458 org.apache.cxf.wsdl.service.factory.ReflectionServiceFactoryBean - Creating Service {urn://Ocpp/Cs/2015/10/}CentralSystemService from class ocpp.cs._2015._10.CentralSystemService [INFO ] 2019-07-24 21:57:21,511 org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /CentralSystemServiceOCPP16 [INFO ] 2019-07-24 21:57:21,513 org.apache.cxf.wsdl.service.factory.ReflectionServiceFactoryBean - Creating Service {urn://Ocpp/Cs/2010/08/}CentralSystemService from class ocpp.cs._2010._08.CentralSystemService [INFO ] 2019-07-24 21:57:21,521 org.apache.cxf.endpoint.ServerImpl - Setting the server's publish address to be /CentralSystemService [INFO ] 2019-07-24 21:57:22,454 org.springframework.security.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/static/'], [] [INFO ] 2019-07-24 21:57:22,454 org.springframework.security.web.DefaultSecurityFilterChain - Creating filter chain: Ant [pattern='/views/'], [] [INFO ] 2019-07-24 21:57:22,487 org.springframework.security.web.DefaultSecurityFilterChain - Creating filter chain: any request, [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@31d8352e, org.springframework.security.web.context.SecurityContextPersistenceFilter@5f510929, org.springframework.security.web.header.HeaderWriterFilter@6805415d, org.springframework.security.web.csrf.CsrfFilter@230dd372, org.springframework.security.web.authentication.logout.LogoutFilter@69cc3370, org.springframework.security.web.authentication.UsernamePasswordAuthenticationFilter@2f006edf, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@28dd038f, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@6abca7a6, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@761ea1f5, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@1d82d35c, org.springframework.security.web.session.SessionManagementFilter@3791160a, org.springframework.security.web.access.ExceptionTranslationFilter@431f8830, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@29612ee2] [INFO ] 2019-07-24 21:57:22,688 org.hibernate.validator.internal.util.Version - HV000001: Hibernate Validator 6.0.16.Final [INFO ] 2019-07-24 21:57:23,052 org.springframework.web.context.ContextLoader - Root WebApplicationContext initialized in 4863 ms [INFO ] 2019-07-24 21:57:23,118 org.eclipse.jetty.server.handler.ContextHandler.steve - Initializing Spring DispatcherServlet 'spring-dispatcher' [INFO ] 2019-07-24 21:57:23,118 org.springframework.web.servlet.DispatcherServlet - Initializing Servlet 'spring-dispatcher' [INFO ] 2019-07-24 21:57:23,126 org.springframework.web.servlet.DispatcherServlet - Completed initialization in 8 ms [INFO ] 2019-07-24 21:57:23,144 org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.w.WebAppContext@d9ff1cd{/steve,jar:file:/home/borkdork/steve/target/steve.jar!/webapp,AVAILABLE} [INFO ] 2019-07-24 21:57:23,157 org.eclipse.jetty.server.AbstractConnector - Started ServerConnector@445adbd7{HTTP/1.1,[http/1.1]}{5.9.13.145:8080} [INFO ] 2019-07-24 21:57:23,157 org.eclipse.jetty.server.Server - Started @6167ms [INFO ] 2019-07-24 22:15:21,633 org.eclipse.jetty.server.AbstractConnector - Stopped ServerConnector@445adbd7{HTTP/1.1,[http/1.1]}{5.9.13.145:8080} [INFO ] 2019-07-24 22:15:21,633 org.eclipse.jetty.server.session - node0 Stopped scavenging [INFO ] 2019-07-24 22:15:21,644 org.eclipse.jetty.server.handler.ContextHandler.steve - Destroying Spring FrameworkServlet 'spring-dispatcher' [INFO ] 2019-07-24 22:15:21,653 com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... [INFO ] 2019-07-24 22:15:21,664 com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed. [INFO ] 2019-07-24 22:15:21,665 org.eclipse.jetty.server.handler.ContextHandler.steve - Closing Spring root WebApplicationContext [INFO ] 2019-07-24 22:15:21,667 org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.w.WebAppContext@d9ff1cd{/steve,jar:file:/home/borkdork/steve/target/steve.jar!/webapp,UNAVAILABLE}

...

goekay commented 5 years ago

as the possible source of the problem i see our server library jetty. i just looked at their releases and they have a new version out, which fixes this reported issue: https://github.com/eclipse/jetty.project/issues/3550

many other projects report similar problems to yours and reference this issue. i will update the jetty version with the hope it fixes it.

lincomatic commented 5 years ago

Looks like the jetty update did the trick. Thanks!

TechOverflow commented 5 years ago

Was just about to post this issue. Thanks for the fix.

steve-community / steve

SteVe stops responding #160