JVM stack trace on restart

[Bernardo Costa]

I had to do a restart on a tomcat server for my scm-manager because it was not responding. I don't know why, it printed a JVM stack trace in tomcat log files. It is attached here. I couldn't find the reason for not being able to answer requests. Any hints on what could have happened here ?

[Bernardo Costa]

Ok, I should have said at least this to make things clearer:

scm-manager = latest (1.35)
java_opts = -Xmx3072m -XX:MaxPermSize=512m
tomcat = apache-tomcat-7.0.50
java = jdk1.7.0_45
machine = linux RHEL 6.5 x86_64

[Sebastian Sdorra]

Sorry, but i could not see any reason for the stacktrace. But there are a lot of svn threads. How many svn repositories do you have?

Sebastian

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

[Bernardo Costa]

Well, it depends on the kind of counting you do...
I have 17 being used but it could go up to 170 repositories. The other 153 are not being used now but they do exist for a reason (I can explain later) and will be used in the near future. What happens is that I am changing my subversion server from a plain apache install to scm-manager, doing one-by-one repo at a time. The old apache server has the directories with real data and scm-manager basically have empty repositories (the case of the 153 repos) or the ones migrated. I'll monitor this for some time to see if it happens again.

[Bernardo Costa]

Well, it did happen again. This time, I got from logs a big permgen space usage (almost 99%). I'll increment the MaxPermSize to 1G and try to use a newer version of JVM (1.7.0-51).

 PSYoungGen      total 873472K, used 787559K [0x00000007c0000000, 0x00000007ff680000, 0x0000000800000000)
  eden space 791040K, 99% used [0x00000007c0000000,0x00000007f0119ce0,0x00000007f0480000)
  from space 82432K, 0% used [0x00000007f0480000,0x00000007f0480000,0x00000007f5500000)
  to   space 123904K, 0% used [0x00000007f7d80000,0x00000007f7d80000,0x00000007ff680000)
 ParOldGen       total 2097152K, used 2096797K [0x0000000740000000, 0x00000007c0000000, 0x00000007c0000000)
  object space 2097152K, 99% used [0x0000000740000000,0x00000007bffa74d0,0x00000007c0000000)
 PSPermGen       total 54272K, used 54221K [0x0000000720000000, 0x0000000723500000, 0x0000000740000000)
  object space 54272K, 99% used [0x0000000720000000,0x00000007234f3408,0x0000000723500000)

Em sexta-feira, 28 de fevereiro de 2014 14h01min38s UTC-3, Bernardo Costa escreveu:

[Bernardo Costa]

Could it be that this issue is appearing again in 1.35 ?

https://bitbucket.org/sdorra/scm-manager/issue/506/website-hangs

[Sebastian Sdorra]

No, i don't think that this problem has something to do with issue #506. Are you familiarly with java heap dump analysing?

Sebastian

--

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

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

[Sebastian Sdorra]

Please execute the following command to create a heap dump (replace <pid> with the pid of scm-manager):

  jmap -dump:format=b,file=scm-manager.hprof <pid>

After the heap dump is created you can start jhat:

  jhat scm-manager.hprof

Open the jhat histo website in your browser (http://localhost:7000/histo/) and save the page. Please zip the html page and post it.

Note the jmap and jhat tools are included in the jdk.

Sebastian

[Bernardo Costa]

I believe I'll have to wait the problem appears again.

[Bernardo Costa]

Well, I can't be sure if it happened again or not, but I have seen scm-manager hanging. I tried to get the dump file as you said but jmap refused saying the JVM was in an uninterruptable state. I tried to do the same with -F option (to force it). It started to build the file but couldn't finish. So I decided to kill the scm-manager pid and upgrade it to 1.36 version. I am still alert on what is happening and it it turns to happen again I'll try again to make these steps as you said. But it could happend that the upgrade might solve the problem.

[Bernardo Costa]

Ok, now I was able to get this dump file. Anyway, I could only do it with -F option and it has thrown an exception in its way out. The binary file is attached here. Executing jhat gives me another exception: EOFException.

$ jmap -F -dump:format=b,file=/tmp/scm-manager.hprof <pid>
Debugger attached successfully.
Server compiler detected.
JVM version is 24.51-b03
Dumping heap to /tmp/scm-manager.hprof ...
Exception in thread "main" java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at sun.tools.jmap.JMap.runTool(JMap.java:197)
        at sun.tools.jmap.JMap.main(JMap.java:128)
Caused by: sun.jvm.hotspot.debugger.UnmappedAddressException: 3980180
        at sun.jvm.hotspot.debugger.PageCache.checkPage(PageCache.java:208)
        at sun.jvm.hotspot.debugger.PageCache.getData(PageCache.java:63)
        at sun.jvm.hotspot.debugger.DebuggerBase.readBytes(DebuggerBase.java:217)
        at sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.readCInteger(LinuxDebuggerLocal.java:482)
        at sun.jvm.hotspot.debugger.DebuggerBase.readCompOopAddressValue(DebuggerBase.java:459)
        at sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.readCompOopHandle(LinuxDebuggerLocal.java:442)
        at sun.jvm.hotspot.debugger.linux.LinuxAddress.getCompOopHandleAt(LinuxAddress.java:125)
        at sun.jvm.hotspot.oops.Oop.getKlassForOopHandle(Oop.java:231)
        at sun.jvm.hotspot.oops.ObjectHeap.newOop(ObjectHeap.java:380)
        at sun.jvm.hotspot.memory.DictionaryEntry.loader(DictionaryEntry.java:62)
        at sun.jvm.hotspot.memory.Dictionary.classesDo(Dictionary.java:67)
        at sun.jvm.hotspot.memory.SystemDictionary.classesDo(SystemDictionary.java:190)
        at sun.jvm.hotspot.memory.SystemDictionary.allClassesDo(SystemDictionary.java:183)
        at sun.jvm.hotspot.utilities.HeapHprofBinWriter.writeClasses(HeapHprofBinWriter.java:863)
        at sun.jvm.hotspot.utilities.HeapHprofBinWriter.write(HeapHprofBinWriter.java:398)
        at sun.jvm.hotspot.tools.HeapDumper.run(HeapDumper.java:56)
        at sun.jvm.hotspot.tools.Tool.start(Tool.java:221)
        at sun.jvm.hotspot.tools.HeapDumper.main(HeapDumper.java:77)
        ... 6 more
$ jhat scm-manager.hprof
java.io.EOFException
        at java.io.DataInputStream.readInt(DataInputStream.java:392)
        at com.sun.tools.hat.internal.parser.HprofReader.read(HprofReader.java:201)
        at com.sun.tools.hat.internal.parser.Reader.readFile(Reader.java:92)
        at com.sun.tools.hat.Main.main(Main.java:159)

[Bernardo Costa]

Looking again at the logging files, I have seen some "broken pipe" errors. It looks something related to ldap searches. It could be one of the reasons of these hanging events.

Caused by: java.net.SocketException: Pipe quebrado
        at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.7.0_51]
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113) ~[na:1.7.0_51]
        at java.net.SocketOutputStream.write(SocketOutputStream.java:159) ~[na:1.7.0_51]
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) ~[na:1.7.0_51]
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) ~[na:1.7.0_51]
        at com.sun.jndi.ldap.Connection.writeRequest(Connection.java:431) ~[na:1.7.0_51]
        at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:555) ~[na:1.7.0_51]
        at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1985) ~[na:1.7.0_51]

[Bernardo Costa]

Being more verbose, this is the complete exception occurring. I have no idea why it is happening. This is not eht only borken pipe exception but it is the most common one.

12:42:56.665 [http-bio-8443-exec-4] ERROR sonia.scm.util.IOUtil - null
org.apache.catalina.connector.ClientAbortException: null
        at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:371) ~[catalina.jar:7.0.50]
        at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:333) ~[catalina.jar:7.0.50]
        at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:101) ~[catalina.jar:7.0.50]
        at sonia.scm.filter.GZipResponseStream.close(GZipResponseStream.java:152) ~[scm-core-1.35.jar:na]
        at sonia.scm.util.IOUtil.close(IOUtil.java:128) ~[scm-core-1.35.jar:na]
        at sonia.scm.filter.GZipResponseWrapper.finishResponse(GZipResponseWrapper.java:99) [scm-core-1.35.jar:na]
        at sonia.scm.filter.GZipFilter.doFilter(GZipFilter.java:113) [scm-core-1.35.jar:na]
        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.35.jar:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at sonia.scm.web.filter.AutoLoginFilter.doFilter(AutoLoginFilter.java:87) [scm-core-1.35.jar:na]
        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.35.jar:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at sonia.scm.filter.BaseUrlFilter.doFilter(BaseUrlFilter.java:117) [BaseUrlFilter.class:na]
        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.35.jar:na]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449) [shiro-web-1.2.2.jar:1.2.2]
        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365) [shiro-web-1.2.2.jar:1.2.2]
        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90) [shiro-core-1.2.2.jar:1.2.2]
        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83) [shiro-core-1.2.2.jar:1.2.2]
        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383) [shiro-core-1.2.2.jar:1.2.2]
        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362) [shiro-web-1.2.2.jar:1.2.2]
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [shiro-web-1.2.2.jar:1.2.2]
        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) [guice-servlet-3.0.jar:na]
        at sonia.scm.boot.BootstrapFilter.doFilter(BootstrapFilter.java:104) [BootstrapFilter.class:na]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) [catalina.jar:7.0.50]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123) [catalina.jar:7.0.50]
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:611) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) [catalina.jar:7.0.50]
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100) [catalina.jar:7.0.50]
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) [catalina.jar:7.0.50]
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409) [catalina.jar:7.0.50]
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) [tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) [tomcat-coyote.jar:7.0.50]
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:313) [tomcat-coyote.jar:7.0.50]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_45]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_45]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]

Caused by: java.net.SocketException: Pipe quebrado

        at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.7.0_45]
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113) ~[na:1.7.0_45]
        at java.net.SocketOutputStream.write(SocketOutputStream.java:159) ~[na:1.7.0_45]
        at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:377) ~[na:1.7.0_45]
        at sun.security.ssl.OutputRecord.write(OutputRecord.java:363) ~[na:1.7.0_45]
        at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:830) ~[na:1.7.0_45]
        at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:801) ~[na:1.7.0_45]
        at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122) ~[na:1.7.0_45]
        at org.apache.coyote.http11.InternalOutputBuffer.realWriteBytes(InternalOutputBuffer.java:215) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:480) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.http11.InternalOutputBuffer.flush(InternalOutputBuffer.java:119) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:805) [tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.Response.action(Response.java:174) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:366) ~[catalina.jar:7.0.50]
        ... 45 common frames omitted

[Sebastian Sdorra]

That are two different exceptions. The first one looks like a problem connecting to your ldapserver and the second one seems to be a problem with gzip response encoding. Do you use GZip Encoding for subversion repositories (Config->Repository Types->Subversion Settings->Enable GZip Encoding)?

Sebastian

[Sebastian Sdorra]

I can't open the core dump, it seems to be incomplete.

Sebastian

[Bernardo Costa]

No, I don't use GZip encoding with subversion. And this dump file might be incomplete/corrupted because I also couldn't start jhat with it. I might have had problems to create this dump file because I needed to use -F option and even using it, jmap gives this UnmappedAddressException and aborts the creation of the dumpfile. I wonder if, at this moment when the server is high loaded and hanging, would be possible to get this dumpfile as the system is running out of resources.

I did some more tests in the way. I think these exceptions related to ClientAbortExcetion are mainly clients that cancel some operation in the middle of it. Everytime I tried to checkout a repository and canceled this operation before it ends properly, this exception is thrown. I can't say precisely if this is the cause of the hanging but it is very possible to be related. I wonder if these canceled operations could cause a high load in the server side and make the application server create threads that aren't killed or stay alive after canceling these operations. I did some tests manually and the server didn't get a high load. But maybe if it is happening for quite a long time, like days or weeks, it could be more feasible. Remember that, in the beginning, I posted a jvm stack dump that showed many threads for just a few repositories.

One problem I am facing is that I couldn't relate the appearance of this problem to a particular action (I am just wondering if successive client connections resets could put the server in a high load). If I could only see a tiny light in the middle of darkness where I could find a path where to go and have some progress...

[Bernardo Costa]

Today I got two exceptions that lately seemed to lead to a java heap space. But this time I could get a full hprof dumpfile. The total size is basically the heap size (~3GB). I believe it won't be possible to put it here. I wonder if this java heap size is too narrow or big for scm-manager execution. How much would be enough ?
Executing jhat with this new hprof file takes a long time. It seems jhat is locked. Killing it is only possible with SIGKILL signal. The normal TERM signal doesn't affect its execution. I was curious about this and checked that it is possible with jhat as like the jvm to print a stack trace with signal 3. I am posting this jhat stack trace, although it might be useless.
I also did a test with another smaller instance of scm-manager and this time the execution starts. The webserver at http://localhost:7000 however complains on the url /histo. It shows this error message: Query '/histo' not implemented. Is this the correct url to check (http://localhost:7000/histo) ?

jhat stack trace with kill -3:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.51-b03 mixed mode):

"Service Thread" daemon prio=10 tid=0x00007f8958091800 nid=0x559d runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007f895808f000 nid=0x559c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007f895808c800 nid=0x559b waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007f8958082000 nid=0x559a waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007f895806b000 nid=0x5599 in Object.wait() [0x00007f8955309000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d174cbd0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
        - locked <0x00000000d174cbd0> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

"Reference Handler" daemon prio=10 tid=0x00007f8958067000 nid=0x5598 in Object.wait() [0x00007f895540a000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d174c690> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:503)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
        - locked <0x00000000d174c690> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x00007f8958009800 nid=0x5594 waiting on condition [0x00007f896003d000]
   java.lang.Thread.State: RUNNABLE
        at com.sun.tools.hat.internal.parser.HprofReader.getStackTraceFromSerial(HprofReader.java:641)
        at com.sun.tools.hat.internal.parser.HprofReader.readInstance(HprofReader.java:731)
        at com.sun.tools.hat.internal.parser.HprofReader.readHeapDump(HprofReader.java:484)
        at com.sun.tools.hat.internal.parser.HprofReader.read(HprofReader.java:275)

        at com.sun.tools.hat.internal.parser.Reader.readFile(Reader.java:92)
        at com.sun.tools.hat.Main.main(Main.java:159)

"VM Thread" prio=10 tid=0x00007f8958065000 nid=0x5597 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f895801f800 nid=0x5595 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f8958021800 nid=0x5596 runnable

"VM Periodic Task Thread" prio=10 tid=0x00007f895809c800 nid=0x559e waiting on condition

JNI global references: 192

Heap
 PSYoungGen      total 101376K, used 27942K [0x00000000f0500000, 0x00000000fbc00000, 0x0000000100000000)
  eden space 15872K, 100% used [0x00000000f0500000,0x00000000f1480000,0x00000000f1480000)
  from space 85504K, 14% used [0x00000000f6800000,0x00000000f73c9bb0,0x00000000fbb80000)
  to   space 85504K, 0% used [0x00000000f1480000,0x00000000f1480000,0x00000000f6800000)
 ParOldGen       total 513024K, used 512829K [0x00000000d1000000, 0x00000000f0500000, 0x00000000f0500000)
  object space 513024K, 99% used [0x00000000d1000000,0x00000000f04cf528,0x00000000f0500000)
 PSPermGen       total 21504K, used 3611K [0x00000000cbe00000, 0x00000000cd300000, 0x00000000d1000000)
  object space 21504K, 16% used [0x00000000cbe00000,0x00000000cc186f00,0x00000000cd300000)

And these were the exceptions seen:

17:17:50.930 [Thread-5939] ERROR sonia.scm.web.cgi.DefaultCGIExecutor - could not read errorstream
java.io.IOException: Stream closed
        at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:162) ~[na:1.7.0_51]
        at java.io.BufferedInputStream.read(BufferedInputStream.java:325) ~[na:1.7.0_51]
        at java.io.FilterInputStream.read(FilterInputStream.java:107) ~[na:1.7.0_51]
        at sonia.scm.util.IOUtil.copy(IOUtil.java:201) ~[scm-core-1.36.jar:na]
        at sonia.scm.util.IOUtil.copy(IOUtil.java:183) ~[scm-core-1.36.jar:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor.processErrorStream(DefaultCGIExecutor.java:492) ~[DefaultCGIExecutor.class:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor.access$000(DefaultCGIExecutor.java:72) ~[DefaultCGIExecutor.class:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor$1.run(DefaultCGIExecutor.java:520) ~[DefaultCGIExecutor$1.class:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
17:18:04.640 [Thread-5940] ERROR sonia.scm.web.cgi.DefaultCGIExecutor - could not read errorstream
java.io.IOException: Stream closed
        at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:162) ~[na:1.7.0_51]
        at java.io.BufferedInputStream.read(BufferedInputStream.java:325) ~[na:1.7.0_51]
        at java.io.FilterInputStream.read(FilterInputStream.java:107) ~[na:1.7.0_51]
        at sonia.scm.util.IOUtil.copy(IOUtil.java:201) ~[scm-core-1.36.jar:na]
        at sonia.scm.util.IOUtil.copy(IOUtil.java:183) ~[scm-core-1.36.jar:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor.processErrorStream(DefaultCGIExecutor.java:492) ~[DefaultCGIExecutor.class:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor.access$000(DefaultCGIExecutor.java:72) ~[DefaultCGIExecutor.class:na]
        at sonia.scm.web.cgi.DefaultCGIExecutor$1.run(DefaultCGIExecutor.java:520) ~[DefaultCGIExecutor$1.class:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]

SEVERE: The exception contained within MappableContainerException could not be mapped to a response, re-throwing to the HTTP container
java.lang.OutOfMemoryError: Java heap space
        at sonia.scm.io.FastByteArrayOutputStream.verifyBufferSize(FastByteArrayOutputStream.java:172)
        at sonia.scm.io.FastByteArrayOutputStream.write(FastByteArrayOutputStream.java:97)
        at java.io.ObjectOutputStream$BlockDataOutputStream.drain(ObjectOutputStream.java:1876)
        at java.io.ObjectOutputStream$BlockDataOutputStream.flush(ObjectOutputStream.java:1821)
        at java.io.ObjectOutputStream.flush(ObjectOutputStream.java:718)
        at java.io.ObjectOutputStream.close(ObjectOutputStream.java:739)
        at com.google.common.io.Closer.close(Closer.java:214)
        at sonia.scm.io.DeepCopy.copy(DeepCopy.java:106)
        at sonia.scm.cache.CopyStrategy.deepCopy(CopyStrategy.java:149)
        at sonia.scm.cache.CopyStrategy.copyOnRead(CopyStrategy.java:98)
        at sonia.scm.cache.GuavaCache.get(GuavaCache.java:221)
        at sonia.scm.repository.api.LogCommandBuilder.getChangesets(LogCommandBuilder.java:252)
        at sonia.scm.activity.collector.CombinedBranchCollector.collectChangesets(CombinedBranchCollector.java:77)
        at sonia.scm.activity.collector.AbstractChangesetCollector.collectChangesets(AbstractChangesetCollector.java:109)
        at sonia.scm.activity.ActivityManager.appendActivities(ActivityManager.java:223)
        at sonia.scm.activity.ActivityManager.getActivities(ActivityManager.java:258)
        at sonia.scm.activity.ActivityManager.getLatestActivity(ActivityManager.java:193)
        at sonia.scm.activity.ActivityResource.getLatestActivity(ActivityResource.java:84)
        at sun.reflect.GeneratedMethodAccessor49.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)

        at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
        at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
        at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
        at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)
        at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
        at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
        at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
        at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542)
        at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473)
        at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
        at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)

[Sebastian Sdorra]

It is possible that you upload the dumb? I could invite you to a google drive folder for the upload. Is this ok?

Sebastian

[Bernardo Costa]

Sure. I am also monitoring with jconsole tomcat.

[Sebastian Sdorra]

Ok, i was able to open the dump and i think i found the problem. SCM-Manager seems not to close subversion repositories and this will consume a lot of memory. I've created a issue at https://bitbucket.org/sdorra/scm-manager/issue/554/subversion-repositories-are-not-closed. I will try to fix it.

[Sebastian Sdorra]

Could you please test the version below:

* http://download.scm-manager.org/issues/554/scm-webapp-2014040301.war

Sebastian

[Bernardo Costa]

Could it be happening also with hg or git repositories ? I am still monitoring scm manager with jconsole. I couldn't get this error still but what I have seen is that from time to time the average heap memory increases due to a bigger PS olg gen mem size. If I push the GC collect button at jconsole, then the heap mem size returns back to its initial allocation: at around 600 MB. I suppose just increasing the JVM mem size would be useless for this problem and would just delay the unavoidable lack of memory. I'll also try this patched version.

[Sebastian Sdorra]

The bug affects only subversion repositories. You could try to reproduce the issue, by browsing the source or the commits from web interface. The bug affects only the rest service of subversion repositories, not the actions from subversion clients. You can identify the bug by monitoring the threads of the jvm. If you see a big amount of threads which contains org.tmatesoft in their stack, then you hit the bug.

Sebastian

[Bernardo Costa]

Ok, I first tried to make a small test manually in another scm server installation, but with just one subversion server I believe I couldn't get much memory consumption. So what I am doing is monitoring the heap space of my tomcat webserver running scm manager. I see that sometimes it goes through different patterns with both average memory consuption increasing and also the memory consumption range increasing. I am posting here a snapshot of the histo diagram in html. Is this the expected behaviour or is there too much org.tmatesoft.* classes loaded in it ? I still have this binary jmap file saved for other queries.

...

[Sebastian Sdorra]

Is the heap histogram from the snapshot version? If you want to check the issue with jmap, you have to force a gc (with jvisualvm or jconsole) before you create the dump with jmap.

Sebastian

--

[Bernardo Costa]

Yes, this one is with the snapshot version. But I didn't force a garbage collector execution to take this histo diagram. I 'll still be monitoring this for the next three weeks or so to see if there is a strange behavior with the jvm heap memory. So next time, I'll force the GC execution before taking the dump and collecting the diagram.

Em segunda-feira, 17 de março de 2014 16h27min18s UTC-3, Bernardo Costa escreveu:<blockquote style="margin:0;margin-left:0.8ex;border-left:1px #ccc solid;pad

...

[Bernardo Costa]

Ok, this time I have executed the garbage collector before getting jmap dumpfile. The attached histogram shows scm-manager execution with this new snapshot version. Is it ok ? About heap memory consumption,  I can see that around 16:00 the range of heap size increases a lot. Until then, the consumption is around 200 MB with a rage around 50 MB. After some event happening around 16:00 the memory consumption goes to an average of 1 GB with the range going to 1.5 GB. Looking at the logfiles, I have found again lots of exceptions around 16:00 like the one listed here:

2014-04-07 16:02:31.616 [http-bio-8443-exec-302] ERROR sonia.scm.util.IOUtil - null

org.apache.catalina.connector.ClientAbortException: null
        at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:371) ~[catalina.jar:7.0.50]
        at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:333) ~[catalina.jar:7.0.50]
        at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:101) ~[catalina.jar:7.0.50]

        at sonia.scm.filter.GZipResponseStream.close(GZipResponseStream.java:152) ~[scm-core-1.37-SNAPSHOT.jar:na]
        at sonia.scm.util.IOUtil.close(IOUtil.java:128) ~[scm-core-1.37-SNAPSHOT.jar:na]
        at sonia.scm.filter.GZipResponseWrapper.finishResponse(GZipResponseWrapper.java:99) [scm-core-1.37-SNAPSHOT.jar:na]
        at sonia.scm.filter.GZipFilter.doFilter(GZipFilter.java:113) [scm-core-1.37-SNAPSHOT.jar:na]
        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.37-SNAPSHOT.jar:na]

        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]

        at sonia.scm.web.filter.AutoLoginFilter.doFilter(AutoLoginFilter.java:87) [scm-core-1.37-SNAPSHOT.jar:na]
        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.37-SNAPSHOT.jar:na]

        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at sonia.scm.filter.BaseUrlFilter.doFilter(BaseUrlFilter.java:117) [BaseUrlFilter.class:na]

        at sonia.scm.web.filter.HttpFilter.doFilter(HttpFilter.java:102) [scm-core-1.37-SNAPSHOT.jar:na]

        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]

        at org.apache.shiro.web.servlet.AbstractShiroFilter.executeChain(AbstractShiroFilter.java:449) [shiro-web-1.2.3.jar:1.2.3]
        at org.apache.shiro.web.servlet.AbstractShiroFilter$1.call(AbstractShiroFilter.java:365) [shiro-web-1.2.3.jar:1.2.3]
        at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90) [shiro-core-1.2.3.jar:1.2.3]
        at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83) [shiro-core-1.2.3.jar:1.2.3]
        at org.apache.shiro.subject.support.DelegatingSubject.execute(DelegatingSubject.java:383) [shiro-core-1.2.3.jar:1.2.3]
        at org.apache.shiro.web.servlet.AbstractShiroFilter.doFilterInternal(AbstractShiroFilter.java:362) [shiro-web-1.2.3.jar:1.2.3]
        at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:125) [shiro-web-1.2.3.jar:1.2.3]

        at com.google.inject.servlet.FilterDefinition.doFilter(FilterDefinition.java:163) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:58) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:118) [guice-servlet-3.0.jar:na]
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:113) [guice-servlet-3.0.jar:na]
        at sonia.scm.boot.BootstrapFilter.doFilter(BootstrapFilter.java:104) [BootstrapFilter.class:na]
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243) [catalina.jar:7.0.50]
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123) [catalina.jar:7.0.50]
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:611) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171) [catalina.jar:7.0.50]
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100) [catalina.jar:7.0.50]
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:953) [catalina.jar:7.0.50]
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) [catalina.jar:7.0.50]
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:409) [catalina.jar:7.0.50]
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1044) [tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:607) [tomcat-coyote.jar:7.0.50]

        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:315) [tomcat-coyote.jar:7.0.50]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_51]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_51]

        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]

Caused by: java.net.SocketException: Pipe quebrado
        at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.7.0_51]
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113) ~[na:1.7.0_51]
        at java.net.SocketOutputStream.write(SocketOutputStream.java:159) ~[na:1.7.0_51]

        at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:377) ~[na:1.7.0_51]
        at sun.security.ssl.OutputRecord.write(OutputRecord.java:363) ~[na:1.7.0_51]
        at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:830) ~[na:1.7.0_51]
        at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:801) ~[na:1.7.0_51]
        at sun.security.ssl.AppOutputStream.write(AppOutputStream.java:122) ~[na:1.7.0_51]

        at org.apache.coyote.http11.InternalOutputBuffer.realWriteBytes(InternalOutputBuffer.java:215) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:480) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.http11.InternalOutputBuffer.flush(InternalOutputBuffer.java:119) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:805) [tomcat-coyote.jar:7.0.50]
        at org.apache.coyote.Response.action(Response.java:174) ~[tomcat-coyote.jar:7.0.50]
        at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:366) ~[catalina.jar:7.0.50]
        ... 45 common frames omitted

...

[Sebastian Sdorra]

The heap histogram looks much better than the last one. I think it look ok. As you forced the gc, could the heap be freed? The exception shows a client abort. If you see a lot of them, it could be an indicator for network problems.

Sebastian

--

[Bernardo Costa]

Yes, the heap was freed. I can also see with jconsole the heap memory usage decreasing to less than 100 MB at night when nobody uses the server.

...

[Sebastian Sdorra]

This sounds like the normal behaviour.

Sebastian

--

[Bernardo Costa]

I am still monitoring scm manager and sometimes I can see its heap memory increase to a newer consumption level without getting back to its original size. It happens for a while (about one hour) and then it gets back to its normal size. Don't know what is really happening as when I log in the web interface I see a completely clean activity panel. If I get in the server, I can't see any activity in both logs and neither the server seems to have a big load. I decided to get the memory histogram with jmap and attached its text version in here. I also have the JVM dumpfile if you want to see. I am just posting it here to be sure that this is not a real issue.

...

[Sebastian Sdorra]

There is a big amount of org.tmatesoft.svn.core.internal.util.SVNHashMap$TableEntry instances. I'm not sure if this is the normal behaviour of svnkit. Could you please upload the dump to the drive folder?

Sebastian

--

[Bernardo Costa]

Ok, the new file will be named scm-28061.hprof.

...

[Sebastian Sdorra]

I've checked the dump and i'm not really sure if it shows a problem. Because it looks like there is one active thread of the activity-plugin and there are a some log entries which could be removed from the gc. So i think the dump looks normal.

Sebastian

--

[Bernardo Costa]

Well, today I have seen this strange behaviour appearing again. I am still monitoring memory consumption. Suddenly it started to grow and did not fall. I tried many times calling GC collector at jconsole but memory consumption still was on top. It only fell after a server restart. But before the server restart I could get a memory dump file. The new dumpfile is called scm-17434.hprof. The scm version was the one you sent me (2014040301). After the restart, I did the upgrade to 1.37. I don't know if it will happen again or if the other changes at 1.37 have corrected this problem. Anyway, I think it is worth taking a look at this dumpfile.

Em sexta-feira, 28 de março de 2014 15h05min22s UTC-3, Sebastian Sdorra escreveu:<blockquote style="margin:0;margin-left:0.8ex;b

...

[Sebastian Sdorra]

Ok, i've looked at the dump and there were 17 threads which are read the latest activities from the activity plugin, 8 thread which are executing subversion actions and one thread which fetches the list of repositories. It is possible that this threads are real activities at the time of the dump? Or do you mean that the threads are hanging? Did your tomcat use an request timeout?

Sebastian

--

[Sebastian Sdorra]

It is possible that you add the "Stuck Thread Detection Valve" to you tomcat instance?

http://tomcat.apache.org/tomcat-7.0-doc/config/valve.html#Stuck_Thread_Detection_Valve

Sebastian

[Bernardo Costa]

I'll try to use this stuck thread detection valve. My tomcat version is 7.0.50 and looks compatible with this valve. Unfortunately, when I saw this problem occurring, I didn't try to push the detect deadlock button from jconsole interface. I just hit the GC collector button and saw it not freeing the heap memory. Again, I'll have to wait to see when it will happen. And remember I also did the upgrade to 1.37 during the restart when this error was seen.

...

[Bernardo Costa]

Well, after enabling Stuck thread detection valve in tomcat, it started to appear many messages like the ones in the attached file. This is an example of what is inside the file:

Grave: The web application [/scm] created a ThreadLocal with key of type [com.sun.xml.bind.v2.ClassFactory$1] (value [com.sun.xml.bind.v2.ClassFactory$1@4d5a3dd7]) and a value of type [java.util.WeakHashMap] (value [{class sonia.scm.repository.Permission=java.lang.ref.WeakReference@5f9215ed, class sonia.scm.security.AssignedPermission=java.lang.ref.WeakReference@6fddab9f, class sonia.scm.repository.xml.XmlRepositoryDatabase=java.lang.ref.WeakReference@422e8d19, class sonia.scm.security.DefaultSecuritySystem$PermissionDescriptors=java.lang.ref.WeakReference@7e318640, class sonia.scm.repository.GitConfig=java.lang.ref.WeakReference@65651479, class java.util.HashSet=java.lang.ref.WeakReference@4f2347f0, class sonia.scm.group.xml.XmlGroupMapAdapter=java.lang.ref.WeakReference@15480627, class java.util.ArrayList=java.lang.ref.WeakReference@2b8bf55b, class sonia.scm.repository.Repository=java.lang.ref.WeakReference@71993fb2, class sonia.scm.group.xml.XmlGroupDatabase=java.lang.ref.WeakReference@424f962, class sonia.scm.plugin.Plugin=java.lang.ref.WeakReference@1770930e, class sonia.scm.cache.GuavaCacheConfiguration=java.lang.ref.WeakReference@5fc68827, class sonia.scm.cache.GuavaCacheManagerConfiguration=java.lang.ref.WeakReference@6314e990, class sonia.scm.plugin.PluginResources=java.lang.ref.WeakReference@71f21fc1, class sonia.scm.group.Group=java.lang.ref.WeakReference@4f02f258, class sonia.scm.xml.XmlSetStringAdapter=java.lang.ref.WeakReference@4a7497ee, class sonia.scm.repository.HgConfig=java.lang.ref.WeakReference@2ca2b072, class sonia.scm.cache.XmlCopyStrategyAdapter=java.lang.ref.WeakReference@6cee2342, class sonia.scm.user.xml.XmlUserList=java.lang.ref.WeakReference@64cf9ed, class sonia.scm.xml.XmlMapStringAdapter=java.lang.ref.WeakReference@27ac39d6, class sonia.scm.repository.xml.XmlRepositoryMapAdapter=java.lang.ref.WeakReference@1c0924f3, class javax.xml.bind.annotation.W3CDomHandler=java.lang.ref.WeakReference@1c58dbe6, class java.util.LinkedList=java.lang.ref.WeakReference@dcce794, class sonia.scm.user.User=java.lang.ref.WeakReference@777aca0, class sonia.scm.user.xml.XmlUserDatabase=java.lang.ref.WeakReference@41e64034, class sonia.scm.cache.GuavaNamedCacheConfiguration=java.lang.ref.WeakReference@738137b8, class sonia.scm.repository.xml.XmlRepositoryList=java.lang.ref.WeakReference@28714c46, class sonia.scm.plugin.PluginInformation=java.lang.ref.WeakReference@26469c68, class sonia.scm.repository.SvnConfig=java.lang.ref.WeakReference@65c68379, class sonia.scm.auth.ldap.XmlCipherAdapter=java.lang.ref.WeakReference@4be1b122, class sonia.scm.group.xml.XmlGroupList=java.lang.ref.WeakReference@4e345619, class sonia.scm.security.PermissionDescriptor=java.lang.ref.WeakReference@4e00ab6b, class sonia.scm.config.ScmConfiguration=java.lang.ref.WeakReference@df625cf, class sonia.scm.plugin.PluginCondition=java.lang.ref.WeakReference@1b2c4032, class sonia.scm.user.xml.XmlUserMapAdapter=java.lang.ref.WeakReference@762aa08d, class sonia.scm.boot.Classpath=java.lang.ref.WeakReference@6892c596, class sonia.scm.auth.ldap.LDAPConfig=java.lang.ref.WeakReference@7bea307c}]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

...

[Sebastian Sdorra]

Hi,

The most entries show thread local cleanup problems of various frameworks used by scm-manager. I'm not sure if the there are threads which a real hanging. Could you create some thread stacktraces with jstack with an interval of some minutes?

Sebastian

--

[Bernardo Costa]

What you really mean ? Just get some "jstack -l <pid>" executions at random through some period ? I can do it but I believe I need to see the problem occurring again. Anyway, I still have jconsole interface monitoring tomcat where I can try to detect a deadlock pushing a button. I can do both too.

To unsubscribe from this group and stop receiving emails from it, send an email to <a href="mailto:scmmanager+unsub...@googlegroups.com" target="_b

...

[Sebastian Sdorra]

Yes, please do both. I don't think the problem has to occur again, because i think the problem occurs after a couple of threads are stuck.

Sebastian

[Bernardo Costa]

Ok, now I have seen again the heap memory increasing, tried to clean it hitting the garbage collector button at jconsole but it still high. Then, I tried to check a possible deadlock at jconsole but it doesn't shows any deadlock detected. Got also a "jstack -l <pid>" log (attached file). As far as I could see, there is no deadlock. But still heap memory is high. This test as made with new 1.38 version. I'll wait the heap memory decreases until it starts to raise some HeapMemoryExceptions just to make sure it can manage the memory properly itself.

...

[Sebastian Sdorra]

Have you made only on stacktrace? We need multiple stacktraces with a period of a minute, to see if there is a hanging or long running thread.

Sebastian

--

[Bernardo Costa]

After a while, it started to raise the OutOfMemoryError Exception. Restarting the server seems to address the issue. I did get different stack traces but I didn't save them. On jconsole, what I could see is that sometimes the deadlock detection delays a negative answer, but always says there is no deadlock detected. If it happens again, I'll take 6 stack traces on 10s intervals. I just wonder if in this new version, this kind of problem is more frequent, because it happened about half an hour after I did the upgrade.

Exception:

Mai 06, 2014 10:04:46 AM com.sun.jersey.spi.container.ContainerResponse mapMappableContainerException
Grave: The exception contained within MappableContainerException could not be mapped to a response, re-throwing to the HTTP container
java.lang.OutOfMemoryError: GC overhead limit exceeded

        at com.sun.tools.hat.internal.parser.HprofReader.readInstance(H</

...

[Sebastian Sdorra]

The stacktrace you've posted before, displays 11 threads which are collecting activities from a subversion repository. I'm pretty sure that this threads consume so much memory. Could you post the first and the last stacktrace from the last memory problem?

Sebastian

--

[Bernardo Costa]

It looks like it is happening again, just one hour after the latest restart. This time I could get a sequence of 6 jstack file (I needed to use -F switch otherwise I wouldn't be able to get the stack traces) with a 10s interval. I am posting just the last stack trace from the unlast GC problem. I am considering downgrading to 1.37 just to be sure that the problem was not introduced in this new release.

...

[Sebastian Sdorra]

The files in the tar are displaying a jstack command usage failure and the attached jstack displays no active threads. I don't think that a downgrade would fix the problem. I think the problem is in the activity plugin. You could try to uninstall the plugin, until i found the issue in the plugin.

Sebastian

--