Aplikacja webowa: Broken pipe; duże zużycie ramu

Cześć.

Wczoraj uruchomiłem moją aplikację webową w sieci (więcej tutaj). I natknąłem się na problemy, których wcześniej nie znałem. Zazwyczaj przez kilka godzin aplikacja sobie fajnie pochodzi bez problemów, a po kilku godzinach coś nie działa, więc patrze w logi:

• java.net.SocketException: Broken pipe - nigdy takiego błędu wcześniej nie spotkałem; na samych socketach bezpośrednio też nie operuję więc nie mam pojęcia co z tym zrobić. Czy ktoś ma doświadczenie, czemu w aplikacji webowej się coś takiego pojawia (dalsze opisy wyjątku były raczej standardowe; tj: nie odnosiły się do części kodu którą ja pisałem, ale za dużo powiedzieć nie mogę, gdyż usunąłem plik z logami, co wiem, że było dość głupie)?

• Drugim problemem jest dość spore zużycie ramu. Testuję sobie opcję gdzie na hotingu mam max 1gb ramu, ale już po samym odpaleniu wszystko skacze na 150% i wymaga około 1,5-1,6gb. To jeszcze zrozumiem, że odpalenie wszystkiego wymaga, ale jak np po kilku godzinach widzę, że potrzeba ponad 2gb a wczoraj wieczorem zanim zrestartowałem pokazywało aż 3gb to trochę coś mi nie pasuje, jak na aplikację o małym ruchu. I zazwyczaj gdy zużycie ramu jest takie duże, to właśnie każda operacja powoduje jakiś dziwny Exception (np. ten wyżej), albo inne z połączeniem się z bazą danych, albo niemocą wykonania zapytania do bazy.

Bardzo proszę o pomoc.

Masz memory leaki w swojej aplikacji. Skorzystaj z profilera aby zlokalizować przyczynę. Ja polecam 'VisualVM' który masz razem z JDK.

Mały Szczur -> szczerze pierwszy raz o czymś takim słyszę. Udało mi się coś poszperać, połączyłem to z moim IDE i dobiłem się do statystyk, ale nie mam pojęcia zbytnio czego szukać, na co patrzeć itp itd. W sensie jak mam wykryć gdzie w kodzie robi mi się taki memory leak za pomocą tego profilera? I czym dokładnie byłby taki memory leak? Jakąś referencją, której nie używam, ale GC nie chce jej usunąć? Daje zdjęcie i jakby ktoś mógł dać hinta co dalej / na co zwrócić uwagę to byłoby super.

PS: czy to możliwe, żeby zwyczajna apka z wbudowanym tomcatem i połączeniem do bazy zżerała na start aż 1,5gb ramu?

@Naitoreivun widzisz tam chyba ze z jakiegoś powodu na starcie zaalokowało ci milion stringów na 220MB? To nie do końca normalne. Tak samo jak ten wątek który od razu ma 1.5GB ;] Niemniej potrzymaj to odpalone jakiś czas i zobacz jak sie zmienia poziom alokacji bo wyciek zwykle widać dopiero po czasie.

Też jestem ciekawy jak to jest z tymi memory leakami. Czym mogą być spowodowane? Niezwalnianie zasobów nie podlegających GC?

@Lectre wystarczy że gdzieś jest dostępna referencja i GC nie usunie takiej pamięci. Więc jakiś źle zrobione cache, mapa która puchnie itd wystarczą do memory leaka.

A sprawdź dokładnie konfigurację hibernata jeżeli go masz na pokładzie. Pierwszy błąd zazwyczaj dotyczy zrywania połączenia z bazą, bo przy małym ruchu kończy się czas podtrzymywania połączenia.

Co do wycieków. Spróbuj potestować / jakieś brakepointy, umieszczając w podejrzanych miejscach:

System.out.println("RAM usage: " + (Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory()));

EDIT: przy okazji się zapytam: nowa wersja intellij pro (16.2) nie rekomenduje wstrzykiwania przez pola, tylko radzi przez konstruktor; dlaczego tak jest? jakie to ma plusy i czy może też wpływać jakoś na moje problemy z kodem?

Dzięki za tak duży odzew :) Jeszcze dodam może jedną przydatną (lub nie) rzecz. Jako że nie znam się na tomcat'cie, postanowiłem korzystać z możliwości stworzenia jara, i na serwerze, na którym mam hosting, odpalam apkę poleceniem: java -jar nazwa_apki.jar (+ jakiś tmux, żeby w tle sobie działało) i całkiem dobrze się sprawuje.

@Shalom -> jako, że na początku myślałem, że jedyna opcja żeby uruchomić, to zrobić plik war, to kilka razy modyfikowałem pliki zgodnie z dokumentacją, w tym również plik pom.xml, przez co w ostatecznej wersji zapomniałem usunąć takich zależności jak livereload i inne rzeczy, które obserwują każdą zmianę w programie, może przez to te stringi i file watcher; teraz, po usunięciu, jest lepiej (zdjęcie w załączniku), ale mimo to nadal po odpaleniu aplikacji na hostingu od razu wymaga jak poprzednio 1,5gb ramu. U mnie lokalnie co prawda pokazuje ponad 0,7gb (czyli też tyle, ile przed usunięciem livereloaderów), ale wydaje mi się, że taka mała apka nie powinna wymagać równie tyle, co potężny IntelliJ :) Zastanawia mnie też skąd ta różnica dwukrotna między odpaleniem apki lokalnie, a gdzieś na hostingu. Jedyny zauważalny plus to taki, ze już nie rośnie bez końca w górę zużycie ramu (chociaż może to przez mniejszy ruch wieczorem, będę pewniejszy za 24h czy poprawnie wraca do podstawowych wymagań jeśli nie jest eksploatowana). Ten RMI TCP Connection dużo chce i rośnie ciągle.

@Koziołek -> Spring Boot zapewnia podstawową konfigurację Hibernata, ja tylko dołączyłem odpowiednio zrobiony pod siebie plik z parametrami. W wersji developmentu wygląda to TAK. Przy czym w wersji produkcyjnej testWhileIdle nie mam ustawionego na true. (EDIT: a jak tak się właśnie zastanowiłem i popatrzyłem na komentarz obok, to chyba jest to niezbędne i właśnie sobie odpowiedziałem chociaż na jeden problem; ciągle mi się myli że profil production to ten testowy a nie ten wyjściowy i go wywaliłem z końcowej konfiguracji).

Natomiast już poza konfiguracją, to na przykład mam takie klasy, które są połączone ze sobą wiele do wielu, np wiele userów może należeć do różnych grup (klasa je łączące to UserGroup). Nie pamiętam już dlaczego dokładnie, ale w userach i/lub grupach musiałem klasę łączącą od razu inicjować w konstruktorze, a odpowiedni FeachType ustawić na zachłanny. Możliwe, że w takich przypadkach (których jeszcze kilka w aplikacji jest) są memory leaki? Chociaż to cały czas nie wyjaśniałoby, że na starcie aż 1,5gb trzeba :/

@bobojak -> problem w tym, że nigdy nie spotkałem się z czymś takim w javie jak memory leaki i nie mam pojęcia, gdzie mogą występować takie "podejrzane miejsca".

No i kryzys, kolejny wyjątek, którego nigdy wcześniej nie miałem, a który znowu zablokował możliwość poprawnego wykonania jakiejkolwiek operacji. Wyłapując słowa kluczowe rozumiem, że połączenie z bazą jakby zostało zerwane? Ale nie mam pojęcia czemu się tak dzieje (EDIT: być może chodzi o to, że nie ustawiłem testWhileIdle na true). Podam głównie początek:

2016-07-25 01:34:53.439  WARN 77322 --- [nio-8080-exec-3] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 08S01
2016-07-25 01:34:53.439 ERROR 77322 --- [nio-8080-exec-3] o.h.engine.jdbc.spi.SqlExceptionHelper   : Communications link failure

The last packet successfully received from the server was 3 058 224 milliseconds ago.  The last packet sent successfully to the server was 2 milliseconds ago.
2016-07-25 01:34:53.445 ERROR 77322 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: could not extract ResultSet; nested exception is org.hibernate.exception.JDBCConnectionException: could not extract ResultSet] with root cause

java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
  at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2957) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:82) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.getResultSet(Loader.java:2066) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1863) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1839) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doQuery(Loader.java:910) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:355) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doList(Loader.java:2554) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doList(Loader.java:2540) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2370) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.list(Loader.java:2365) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:497) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:387) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:236) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1300) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:573) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.internal.QueryImpl.getSingleResult(QueryImpl.java:495) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.criteria.compile.CriteriaQueryTypeQueryAdapter.getSingleResult(CriteriaQueryTypeQueryAdapter.java:71) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:206) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:78) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:100) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:91) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:462) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:440) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:61) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:131) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at com.sun.proxy.$Proxy89.findById(Unknown Source) ~[na:na]
  at com.naitoreivun.lop.service.UserService.getById(UserService.java:29) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.service.GroupService.getWithoutUser(GroupService.java:101) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.rest.GroupRest.getWithoutCurrentUser(GroupRest.java:167) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.rest.GroupRest$$FastClassBySpringCGLIB$$c31b45eb.invoke(<generated>) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at com.naitoreivun.lop.rest.GroupRest$$EnhancerBySpringCGLIB$$310fee5.getWithoutCurrentUser(<generated>) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source) ~[na:na]
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_92]
  at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_92]
  at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:817) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:731) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:968) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:859) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:618) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:844) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:301) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at com.naitoreivun.lop.security.JwtFilter.doFilter(JwtFilter.java:54) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:121) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:136) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:74) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:516) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1015) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:652) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1575) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1533) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_92]
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_92]
  at java.lang.Thread.run(Thread.java:745) [na:1.8.0_92]

2016-07-25 01:34:53.461  WARN 77322 --- [nio-8080-exec-4] o.h.engine.jdbc.spi.SqlExceptionHelper   : SQL Error: 0, SQLState: 08003
2016-07-25 01:34:53.461 ERROR 77322 --- [nio-8080-exec-4] o.h.engine.jdbc.spi.SqlExceptionHelper   : No operations allowed after connection closed.
2016-07-25 01:34:53.465 ERROR 77322 --- [nio-8080-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: could not prepare statement; nested exception is org.hibernate.exception.JDBCConnectionException: could not prepare statement] with root cause

java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
  at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2957) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3375) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3365) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3805) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1962) ~[mysql-connector-java-5.1.38.jar!/:5.1.38]
  at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:82) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.getResultSet(Loader.java:2066) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1863) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.executeQueryStatement(Loader.java:1839) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doQuery(Loader.java:910) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:355) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doList(Loader.java:2554) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.doList(Loader.java:2540) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2370) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.Loader.list(Loader.java:2365) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:497) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:387) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:236) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1300) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.internal.QueryImpl.list(QueryImpl.java:103) ~[hibernate-core-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:573) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.internal.QueryImpl.getSingleResult(QueryImpl.java:495) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.hibernate.jpa.criteria.compile.CriteriaQueryTypeQueryAdapter.getSingleResult(CriteriaQueryTypeQueryAdapter.java:71) ~[hibernate-entitymanager-4.3.11.Final.jar!/:4.3.11.Final]
  at org.springframework.data.jpa.repository.query.JpaQueryExecution$SingleEntityExecution.doExecute(JpaQueryExecution.java:206) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:78) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:100) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:91) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:462) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:440) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:61) ~[spring-data-commons-1.11.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) ~[spring-tx-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:131) ~[spring-data-jpa-1.9.4.RELEASE.jar!/:na]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at com.sun.proxy.$Proxy89.findById(Unknown Source) ~[na:na]
  at com.naitoreivun.lop.service.UserService.getById(UserService.java:29) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.service.GroupService.getWithoutUser(GroupService.java:101) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.rest.GroupRest.getWithoutCurrentUser(GroupRest.java:167) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at com.naitoreivun.lop.rest.GroupRest$$FastClassBySpringCGLIB$$c31b45eb.invoke(<generated>) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at com.naitoreivun.lop.rest.GroupRest$$EnhancerBySpringCGLIB$$310fee5.getWithoutCurrentUser(<generated>) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source) ~[na:na]
  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_92]
  at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_92]
  at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:817) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:731) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:968) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:859) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:618) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:844) ~[spring-webmvc-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:301) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at com.naitoreivun.lop.security.JwtFilter.doFilter(JwtFilter.java:54) ~[leagueofphotos-0.0.1-SNAPSHOT.jar!/:0.0.1-SNAPSHOT]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:87) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:121) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-4.2.5.RELEASE.jar!/:4.2.5.RELEASE]
  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) ~[tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:136) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:74) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:516) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1015) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:652) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1575) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1533) [tomcat-embed-core-8.0.3.jar!/:8.0.3]
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_92]
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_92]
  at java.lang.Thread.run(Thread.java:745) [na:1.8.0_92]

Na początek problemów z pamięcią? Czy masz ustawione Xmx i na ile?

@Naitoreivun jeśli teraz zużycie nagle nie rośnie to znaczy ze jest ok, widocznie te śmieszne biblioteki to powodowały. To że aplikacja na start zjada dużo o niczym nie swiadczy bo możliwe że na serwerze ustawili w parametrach javy żeby startowała od razu z dużym heapem na wszelki wypadek.

Naitoreivun napisał(a):

@bobojak -> problem w tym, że nigdy nie spotkałem się z czymś takim w javie jak memory leaki i nie mam pojęcia, gdzie mogą występować takie "podejrzane miejsca".

Tego typu problemy mogą się pojawić przy tworzeniu dużej liczby obiektów, np. encji w ramach odczytu danych z bazy. Poza tym, jeśli jakaś kolekcja (pisał o tym Shalom) lub klasa trzyma referencje do tych obiektów, to GC tego nie usunie ani z automatu, ani przymuszane (Runtime.getRuntime().gc()). Coś masz chyba skopane w implementacji (z heapem raczej to nie ma nic wspólnego).

Poniżej przykład jak działa GC. Po pierwszym zapchaniu połowy dostępnej dla JVM pamięci czyszczona jest lista z referencjami do dużych stringów i przestawiana flaga (kolejny raz po zapchaniu referencje zostają).

import java.util.ArrayList;
import java.util.List;

public class App 
{
	
	private static int iterationCounter;
	private static List<String> bigStringList;
	private static boolean cleanListEnabled;
	
	public static void main(String[] args)
	{
		cleanListEnabled = true;
		bigStringList = new ArrayList<>();
		RamTool.logRamUsage();
		runNextIteration();
	}

	private static void runNextIteration() 
	{
		iterationCounter++;
		System.out.println("\n--- runNextIteration " + iterationCounter);
		try {
		    Thread.sleep(1000);

		    // prevent OutOfMemoryError > no more than half of total memory
		    if (Runtime.getRuntime().maxMemory() * 0.5 > RamTool.getRamUsage())
		    {
		    	createBigString();
		    } else {
		    	System.out.println("Wait for GC, more than half memory used");

		    	// if clean enabled remove reference to big strings
		    	if (cleanListEnabled && bigStringList.size() > 0)
		    	{
		    		System.out.println("***** DESTROY bigStringList AND set clenListEnabled to false *****");
		    		bigStringList = new ArrayList<>();
		    		// don't clean next time
		    		cleanListEnabled = false;
		    	}
		    	// enforce run GC
		    	Runtime.getRuntime().gc();
		    }
		    
		    RamTool.logRamUsage();
		    
		    runNextIteration();
		} catch(InterruptedException e) {
		}
	}
	
	private static void createBigString()
	{
		StringBuffer stringBuffer = new StringBuffer();
		for (int i = 0; i < 1000000; i++) 
		{
			stringBuffer.append("xxxxxxxxxxxx");
		}
		bigStringList.add(stringBuffer.toString());
		System.out.println("next string created " + bigStringList.size());
	}
	
}

class RamTool
{
	private static final long MEGABYTE = 1024L * 1024L;
	
    public static void logRamUsage()
    {
    	String log = "";
    	log += "RAM usage (MB): ";
    	log += RamTool.getRamUsage() / MEGABYTE;
    	log += " | total memory (MB): "; 
    	log += Runtime.getRuntime().maxMemory() / MEGABYTE;
    	System.out.println(log);
    }

	public static long getRamUsage() 
	{
		return Runtime.getRuntime().totalMemory() - Runtime.getRuntime().freeMemory();
	}
	
}

Nie powinieneś mieć w ogóle klasy UserGroup tylko adnotacje @ManyToMany na polach w User i/lub Group. Lepiej też używać Set zamiast List.

Fajne to VisualVM :)

Ok, to taka obserwacja: na hostingu serwerek chodzi od około 36-48h tak na oko. Nie wywalił się, nie ma dziwnych wyjątków -> wniosek taki, że po prostu zrywało połączenia z bazą, brakowało odpowiedniego propertisa. Z tych mniej fajnych rzeczy - ram jest na około 2,2gb, a startował z 1,5 więc ciągle coś nie tak :/

@Shalom - lokalnie potrzymałem kilka godzin aplikacje (ale podłączoną do bazy normalnej) i rzeczywiście się uspokoiło jak patrzę w menadżerze, ale np na zdjęciu się to nieco inaczej (gorzej) przedstawia [załącznik].

@Naitoreivun ciekawszy byłby wykres jak sie zmienia heap. Mozesz też wymusić GC i zobaczyć czy nie spadnie do bardzo niskiego poziomu. Bo może po prostu cośtam nabija pamieć (logger czy coś) ale nie zwalnia bo nie musi ;]

@Shalom - tylko zastanawiam się, czy jest sens obserwować coś, jeśli apka nadaje tylko na localhoście(mimo że podpięta do tej samej bazy co na hostingu). Ogólnie ten wykres strasznie nie wygląda, nawet przyjemnie. Co masz na myśli mówić wymusić GC? Że zrobić sobie jakiś timer i np. co 10minut odpalać czyszczenie? Jest na to ta metoda, którą podał bobojak, czyli Runtime.getRuntime().gc()?

@bobojak -> to może taki przykład (może o to by mogło chodzić): w 90 linijce jest funkcja, która znajduje wszystkie grupy, do których należy dany user (tzn ma rolę w tej grupie: member/admin/moderator). Nie zwracam listy tych grup, tylko najpierw całą listę mapuję (106 linijka) na odpowiednie klasy DTO, żeby ładnie do JSONa pasowały. I tam każdy z nich przechodzi przez 'new'. Zwrócona zostaje lista, która leci np. do 149 linijki. Czy tutaj może coś pójść nie tak? To jeden z bardziej 'skomplikowanych' przykładów. Inne, w w których ewentualnie mapuję do DTO, to pojedyncze obiekty, a czasem po prostu zwracam to, co zwróci baza.

A jak wejdziesz sobie w "Monitor"? Tam powinien być dość ładny wykres Heap Size i Used Heap i będzie widać kiedy GC cos robi i ile zwalnia. Masz tam też u góry guzik "perform GC" ;)

Użytkowników i grup na razie chyba za dużo nie masz, ale z tego co zerknąłem do repo, to trzymasz fotki w bazie (a każda bitmapa to sporo bajtów). Słabo znam Hibernate, ale podejrzewam, że może być tak sprytne, że pcha dane do pamięci i je tam trzyma, żeby znowu nie odpytywać bazy w razie ponownego zapotrzebowania na te same dane. Czy tak jest nie wiem, ale zacząłbym od testów w klasie ImageRest, np. opakował linijkę:

		RamTool.logRamUsage("getVotableImagesByContestId");
		List<VotableImage> images = imageService.getVotableImagesByContestId(contestId, currentUserId);
		RamTool.logRamUsage("AFTER getVotableImagesByContestId");

Potem połaził lokalnie po różnych contestach, tak żeby zaciągnąć jak najwięcej fotek i popatrzył co mi wyskakuje w konsoli.

A nie możesz po prostu w momencie tego leaka (albo zwolnienia aplikacji) - bo albo dostaniesz Out of memorry albo twoja aplikacja zacznie wyć od częstotliwości GC - uruchomić eclipse memorry analizera ? http://www.eclipse.org/mat/ - jest o tyle spoko, że potencjalne issue sam Ci wskaże, a i tutki jak "analizować" potencjalne błędy też się znajdą.

A jak nie jesteś w stanie (bo to nie jest proste - w sensie analizy) - wrzuć tutaj heap dumpa swojej aplikacji (jak zrobić, wygooglasz)

@maryiusz4 - pewnie mogę, tylko na niczym się nie znam, podanego przez Ciebie sposobu też nie słyszałem, być może skorzystam; póki co mam pewien trop...

@bobojak - no powiem Ci, że coś jest :)

1. Jako, że w jednej grupie rozpoczęła się faza oceniania, to trzeba było zgrać wszystkie zdjęcia (jeszcze nie dodałem opcji miniaturek), a co za tym idzie, przy każdym refreshu strony został wykonywany request powiązany z metodą imageService.getVotableImagesByContestId. To sobie odświeżyłem stronę ~50 razy.

RAM usage (MB): 369 | total memory (MB): 27305
RAM usage (MB): 401 | total memory (MB): 27305
RAM usage (MB): 517 | total memory (MB): 27305
RAM usage (MB): 548 | total memory (MB): 27305
RAM usage (MB): 613 | total memory (MB): 27305
RAM usage (MB): 639 | total memory (MB): 27305
RAM usage (MB): 722 | total memory (MB): 27305
RAM usage (MB): 722 | total memory (MB): 27305
RAM usage (MB): 754 | total memory (MB): 27305
RAM usage (MB): 779 | total memory (MB): 27305
RAM usage (MB): 835 | total memory (MB): 27305
RAM usage (MB): 861 | total memory (MB): 27305
RAM usage (MB): 893 | total memory (MB): 27305
RAM usage (MB): 922 | total memory (MB): 27305
RAM usage (MB): 1016 | total memory (MB): 27305
RAM usage (MB): 1041 | total memory (MB): 27305
RAM usage (MB): 120 | total memory (MB): 27305
RAM usage (MB): 148 | total memory (MB): 27305
RAM usage (MB): 210 | total memory (MB): 27305
RAM usage (MB): 239 | total memory (MB): 27305
RAM usage (MB): 475 | total memory (MB): 27305
RAM usage (MB): 504 | total memory (MB): 27305
RAM usage (MB): 540 | total memory (MB): 27305
RAM usage (MB): 569 | total memory (MB): 27305
RAM usage (MB): 614 | total memory (MB): 27305
RAM usage (MB): 643 | total memory (MB): 27305
RAM usage (MB): 643 | total memory (MB): 27305
RAM usage (MB): 670 | total memory (MB): 27305
RAM usage (MB): 674 | total memory (MB): 27305
RAM usage (MB): 702 | total memory (MB): 27305
RAM usage (MB): 707 | total memory (MB): 27305
RAM usage (MB): 738 | total memory (MB): 27305
RAM usage (MB): 738 | total memory (MB): 27305
RAM usage (MB): 767 | total memory (MB): 27305
RAM usage (MB): 767 | total memory (MB): 27305
RAM usage (MB): 797 | total memory (MB): 27305
RAM usage (MB): 801 | total memory (MB): 27305
RAM usage (MB): 826 | total memory (MB): 27305
RAM usage (MB): 844 | total memory (MB): 27305
RAM usage (MB): 872 | total memory (MB): 27305
RAM usage (MB): 872 | total memory (MB): 27305
RAM usage (MB): 898 | total memory (MB): 27305
RAM usage (MB): 903 | total memory (MB): 27305
RAM usage (MB): 931 | total memory (MB): 27305
RAM usage (MB): 931 | total memory (MB): 27305
RAM usage (MB): 959 | total memory (MB): 27305
RAM usage (MB): 959 | total memory (MB): 27305
RAM usage (MB): 984 | total memory (MB): 27305
RAM usage (MB): 988 | total memory (MB): 27305
RAM usage (MB): 1016 | total memory (MB): 27305
RAM usage (MB): 1021 | total memory (MB): 27305
RAM usage (MB): 1051 | total memory (MB): 27305
RAM usage (MB): 1051 | total memory (MB): 27305
RAM usage (MB): 1080 | total memory (MB): 27305
RAM usage (MB): 1080 | total memory (MB): 27305
RAM usage (MB): 1105 | total memory (MB): 27305
RAM usage (MB): 1109 | total memory (MB): 27305
RAM usage (MB): 1136 | total memory (MB): 27305
RAM usage (MB): 1141 | total memory (MB): 27305
RAM usage (MB): 1171 | total memory (MB): 27305
RAM usage (MB): 1171 | total memory (MB): 27305
RAM usage (MB): 1200 | total memory (MB): 27305
RAM usage (MB): 1209 | total memory (MB): 27305
RAM usage (MB): 1234 | total memory (MB): 27305
RAM usage (MB): 1239 | total memory (MB): 27305
RAM usage (MB): 1264 | total memory (MB): 27305
RAM usage (MB): 1273 | total memory (MB): 27305
RAM usage (MB): 1296 | total memory (MB): 27305
RAM usage (MB): 1309 | total memory (MB): 27305
RAM usage (MB): 1334 | total memory (MB): 27305
RAM usage (MB): 1348 | total memory (MB): 27305
RAM usage (MB): 1378 | total memory (MB): 27305
RAM usage (MB): 1378 | total memory (MB): 27305
RAM usage (MB): 1406 | total memory (MB): 27305
RAM usage (MB): 1406 | total memory (MB): 27305
RAM usage (MB): 1416 | total memory (MB): 27305
RAM usage (MB): 1417 | total memory (MB): 27305
RAM usage (MB): 1449 | total memory (MB): 27305
RAM usage (MB): 1486 | total memory (MB): 27305
RAM usage (MB): 1490 | total memory (MB): 27305
RAM usage (MB): 1499 | total memory (MB): 27305
RAM usage (MB): 1526 | total memory (MB): 27305
RAM usage (MB): 1526 | total memory (MB): 27305
RAM usage (MB): 1555 | total memory (MB): 27305
RAM usage (MB): 1560 | total memory (MB): 27305
RAM usage (MB): 1585 | total memory (MB): 27305
RAM usage (MB): 1599 | total memory (MB): 27305
RAM usage (MB): 68 | total memory (MB): 27305
RAM usage (MB): 90 | total memory (MB): 27305
RAM usage (MB): 114 | total memory (MB): 27305
RAM usage (MB): 132 | total memory (MB): 27305
RAM usage (MB): 157 | total memory (MB): 27305
RAM usage (MB): 192 | total memory (MB): 27305
RAM usage (MB): 216 | total memory (MB): 27305
RAM usage (MB): 221 | total memory (MB): 27305
RAM usage (MB): 248 | total memory (MB): 27305
RAM usage (MB): 259 | total memory (MB): 27305
RAM usage (MB): 285 | total memory (MB): 27305
RAM usage (MB): 297 | total memory (MB): 27305
RAM usage (MB): 325 | total memory (MB): 27305
RAM usage (MB): 325 | total memory (MB): 27305
RAM usage (MB): 353 | total memory (MB): 27305
RAM usage (MB): 358 | total memory (MB): 27305
RAM usage (MB): 384 | total memory (MB): 27305

Przy okazji przed chwilą zmieniłem taryfę na serwerze hostingowym na 2gb i teraz doszło to jeszcze dalej (urywek):

RAM usage (MB): 2234 | total memory (MB): 27305
RAM usage (MB): 2246 | total memory (MB): 27305
RAM usage (MB): 2269 | total memory (MB): 27305
RAM usage (MB): 2275 | total memory (MB): 27305
RAM usage (MB): 2304 | total memory (MB): 27305
RAM usage (MB): 2315 | total memory (MB): 27305
RAM usage (MB): 2338 | total memory (MB): 27305
RAM usage (MB): 2349 | total memory (MB): 27305
RAM usage (MB): 2372 | total memory (MB): 27305
RAM usage (MB): 2378 | total memory (MB): 27305
RAM usage (MB): 74 | total memory (MB): 27305
RAM usage (MB): 87 | total memory (MB): 27305
RAM usage (MB): 111 | total memory (MB): 27305
RAM usage (MB): 116 | total memory (MB): 27305
RAM usage (MB): 145 | total memory (MB): 27305
RAM usage (MB): 153 | total memory (MB): 27305
RAM usage (MB): 182 | total memory (MB): 27305

2. Niby widać, że rośnie i się gromadzi, ale po jakimś czasie się resetuje. Ale mimo to, przez to moje odświeżanie i ciągłe wykonywanie tej metody, na hostingu zużycie ramu wynosi teraz... 2,91gb. Trochę urosło w te 5 minut (i nie spada! mimo że logi pokazują, iż ram się zredukował dość mocno). Czyli już np. wiadomo, że hibernate sobie lubi wczytać zdjęcia i je potrzymać. To jest jakiś sposób żeby wymusić na nim gc? Ponadto, pragnę zaznaczyć, że testowana metoda mogła się dopiero teraz wykonać, gdyż wcześniej chyba nie było jeszcze na mojej stronie fazy testowej w żadnej grupie (no może raz), a ram i tak się nabijał. Wnioskuję z tego, że podobne zachowania mają się do innych metod, np pobranie listy grup i użytkowników w danej grupie, które są zapewne baaardzo często wykonywane. Ktoś ma jakiś pomysł, jak temu zaradzić, aby hibernate nie trzymał sobie tych referencji, tylko po zakończeniu REST'a zwalniał referencje? Moja wiedza odnośnie tych frameworków jest dość podstawowa. @Koziołek, @Shalom?

Ale po co? Bo ja chyba nie rozumiem. To nie jest problem Hibernate samego w sobie, tylko tego jak działa JVM, co zresztą widać po spadku zużycia po GC.
Po prostu następuje alokacja pamięci i dopóki nie wykona się GC to ta pamięć jest nadal zajęta. Jak braknie heapu to JVM sobie wykona GC i zwolni co już zbędne. Możesz mi wyjaśnić jaką ci to robi różnicę że masz większe zużycie? o_O Problem to by był jakby pamięci brakowało, tzn nawet po wykonaniu GC zużycie nadal byłoby bardzo wysokie, albo jakby gdzieś ciekło i zużycie ciągle wzrastało mimo GC.

Jak bardzo potrzebujesz to możesz próbować robić jakiś fine-tuning GC ale to się raczej skończy źle.

Jakby kogoś interesowało, to mały update: trochę aplikacją postała, czasami się powywalała jak kombinowałem z flagami. Aktualnie używam następujących:
-Xms1g -Xmx2g -XX:MaxMetaspaceSize=2g -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled
których niezły opis znalazłem tutaj -> http://blog.sokolenko.me/2014/11/javavm-options-production.html

Zobaczę co z tego będzie.

Dzięki wszystkim za wskazówki :)