3

We have recently upgraded our banking application from java 1.6 to 1.8 and jboss 4.x to wildfly 10.1.

We have observed that java consuming all the cores (10), available on the machine.

Can someone tell what is the reason, normally with jboss 4.x max CPU utilisation was up to 4 cores.

Do i need to configure anything for Garbage collection?

Below is the result of (added on process consuming high cpu)

ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args|grep 3630

enter image description here

Below is the hex for each LWP consuming high cpu

enter image description here

Now i have checked thread dump For LWP 7914

"default task-7" #182 prio=5 os_prio=0 tid=0x00007f5c24033800 nid=0x1c1a runnable [0x00007f5bb85e5000] java.lang.Thread.State: RUNNABLE at org.xnio.conduits.ConduitStreamSinkChannel.write(ConduitStreamSinkChannel.java:150) at io.undertow.channels.DetachableStreamSinkChannel.write(DetachableStreamSinkChannel.java:240) at io.undertow.server.HttpServerExchange$WriteDispatchChannel.write(HttpServerExchange.java:2028) at io.undertow.servlet.spec.ServletOutputStreamImpl.writeBufferBlocking(ServletOutputStreamImpl.java:563) at io.undertow.servlet.spec.ServletOutputStreamImpl.write(ServletOutputStreamImpl.java:216) at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) at java.io.BufferedOutputStream.write(BufferedOutputStream.java:95) - locked <0x00000004d6c5f900> (a java.io.BufferedOutputStream) at com.eko.app.offlineKyc.servlet.KycPictureServlet.doGet(KycPictureServlet.java:58) at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) at com.eko.framework.CrossScriptingFilter.doFilter(CrossScriptingFilter.java:48) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at com.eko.framework.URLSessionFilter.doFilter(URLSessionFilter.java:38) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.mifos.framework.security.util.FileNameFilter.doFilter(FileNameFilter.java:59) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84) at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53) at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59) at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60) at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77) at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50) at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292) at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135) at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)

For LWP 7249

"default task-27" #231 prio=5 os_prio=0 tid=0x00007f5c2401c000 nid=0x1c51 runnable [0x00007f5ca9a63000] java.lang.Thread.State: RUNNABLE at org.xnio.conduits.ConduitStreamSinkChannel.write(ConduitStreamSinkChannel.java:158) at io.undertow.channels.DetachableStreamSinkChannel.write(DetachableStreamSinkChannel.java:179) at io.undertow.server.HttpServerExchange$WriteDispatchChannel.write(HttpServerExchange.java:1993) at org.xnio.channels.Channels.writeBlocking(Channels.java:152) at io.undertow.servlet.spec.ServletOutputStreamImpl.write(ServletOutputStreamImpl.java:283) at io.undertow.io.BlockingSenderImpl.writeBuffer(BlockingSenderImpl.java:190) at io.undertow.io.BlockingSenderImpl.send(BlockingSenderImpl.java:71) at io.undertow.server.handlers.resource.CachedResource.serve(CachedResource.java:187) at io.undertow.servlet.handlers.DefaultServlet.serveFileBlocking(DefaultServlet.java:332) at io.undertow.servlet.handlers.DefaultServlet.doGet(DefaultServlet.java:180) at javax.servlet.http.HttpServlet.service(HttpServlet.java:687) at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) at com.eko.framework.MifosNGFilter.doNormal(MifosNGFilter.java:283) at com.eko.framework.MifosNGFilter.doFilter(MifosNGFilter.java:137) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at com.eko.framework.CrossScriptingFilter.doFilter(CrossScriptingFilter.java:48) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at com.eko.framework.URLSessionFilter.doFilter(URLSessionFilter.java:38) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at org.mifos.framework.security.util.FileNameFilter.doFilter(FileNameFilter.java:59) at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61) at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84) at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131) at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53) at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59) at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60) at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77) at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50) at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292) at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138) at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135) at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44) at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272) at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81) at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104) at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202) at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)

below is the link for Complete thread dump Thread dump

Server not getting stable so we had to revert back to jdk 1.6 and jboss 4. And i wonder with jboss 4 everything working perfectly, now i am not able to identify where is the problem, with wildfly settings, or my application or GC setting.

Link for thread dump analysis Thread dump analysis result

Code KycPictureServlet

@Override
public void doGet(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
    ServletOutputStream out = null;
    FileInputStream fin = null;
    BufferedInputStream bin = null;
    BufferedOutputStream bout = null;
    try {

        String filename = String.valueOf(request.getParameter("fileName"));
        String folderPathId = String.valueOf(request.getParameter("folderPathId"));
        String kycDocPath = "";
        System.out.println("Folder Path : " + folderPathId + " \t" + filename);
        if (folderPathId != null && !folderPathId.equals("null")) {
            kycDocPath = new StoragePathService().getStoragePathByPathID(Integer.parseInt(folderPathId)).getFolderPath();
        } else {
            kycDocPath = new StoragePathService().getStoragePathByPathID(EkoDBConstants.KYC_FILE_UPLOAD_PATH).getFolderPath();
        }
        String uploadFolderPath = kycDocPath;
        final String filetofetch = uploadFolderPath + filename;

        if (filetofetch.toLowerCase().endsWith("pdf")) {
            response.setContentType("application/pdf");
            // response.setHeader("Content-Disposition", "inline;
            // filename=\"" + filetofetch + "\"");
        } else if (filetofetch.toLowerCase().endsWith("tif") || filetofetch.endsWith("tiff")) {
            response.setContentType("image/tiff");
        } else {
            response.setContentType("image/jpeg");
        }

        File uploadFolder = new File(filetofetch);
        if(uploadFolder != null && uploadFolder.exists()){

        out = response.getOutputStream();
        fin = new FileInputStream(filetofetch);
        bin = new BufferedInputStream(fin);
        bout = new BufferedOutputStream(out);
        int ch = 0;
        ;
        while ((ch = bin.read()) != -1) {
            bout.write(ch);

        }
    }

    } catch (Exception e) {
        e.printStackTrace();
    } finally {
        if (bin != null) {
            bin.close();
        }

        if (fin != null) {
            fin.close();
        }

        if (bout != null) {
            bout.close();
        }

        if (out != null) {
            out.close();
        }

    }
}

Previously there was not any finally block, so in case of exception streams was not getting closed, second thing i have added extra check to check if file exists then only open stream.

After making changes no more threads getting stuck on that servlet.

I have taken latest dump and found some weird processes consuming cpu and not getting end

"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007ff8dc231000 nid=0x11b6 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007ff8dc22e800 nid=0x11b5 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007ff8dc22d000 nid=0x11b4 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007ff8dc22a000 nid=0x11b3 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

Also i have configured GC settings copied from OLD Jboss 4

In thread dump i have found some LWP which are consuming CPU and not ending

"VM Thread" os_prio=0 tid=0x00007ff8dc1e9000 nid=0x11B411af runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007ff8dc01e800 nid=0x11a6 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007ff8dc020800 nid=0x11a7 runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007ff8dc022000 nid=0x11a8 runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007ff8dc024000 nid=0x11a9 runnable 

"GC task thread#4 (ParallelGC)" os_prio=0 tid=0x00007ff8dc026000 nid=0x11aa runnable 

"GC task thread#5 (ParallelGC)" os_prio=0 tid=0x00007ff8dc027800 nid=0x11ab runnable 

"GC task thread#6 (ParallelGC)" os_prio=0 tid=0x00007ff8dc029800 nid=0x11ac runnable 

"GC task thread#7 (ParallelGC)" os_prio=0 tid=0x00007ff8dc02b800 nid=0x11ad runnable 

"GC task thread#8 (ParallelGC)" os_prio=0 tid=0x00007ff8dc02d000 nid=0x11ae runnable 

Memory and GC setting

JAVA_OPTS="-Xms4G -Xmx12G -XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=512m -Djava.net.preferIPv4Stack=true -Dsun.rmi.dgc.client.gcInterval=1800000 -Dsun.rmi.dgc.server.gcInterval=1800000 -XX:-UseConcMarkSweepGC -XX:SurvivorRatio=6 -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps  -Xloggc:/data/eko/GC.log -verbose:gc   -XX:NewRatio=2"
ROHIT
  • 185
  • 1
  • 3
  • 17
  • Alright so what does your `com.eko.app.offlineKyc.servlet.KycPictureServlet.doGet` do? based on the thread dump, it runs for a very long time considering it is a servlet. Are you sure, that you close all resources(streams, servlet response,..) correctly? The first thread is the servlet handler handling some HTTP request and obviously blocking on IO, consuming CPU on writing. The stack gives the precise line number: `58` where it is stuck - Go check it.The second one is servlet filter, which might be related to the first one. – yntelectual Jun 22 '17 at 08:07
  • Yes your are right it is a servlet, we were not closing streams if we get any exception between, so i have added finally block to handle this situation. will deploy changes and share the results. – ROHIT Jun 22 '17 at 13:03
  • @yntelectual After deploying changes right now not facing issue with that servlet. Again i have analysed thread dump and found some weird results and add added same. It would be great if you can suggest regarding GC settings. – ROHIT Jul 02 '17 at 14:58
  • There is not simple answer. When does the issue manifest? Under heavy load or also without usage? Does it only happen after some time? Do the GC thread really consume all your CPU? If the GC threads are really consuming too much CPU, then you probably have some memory leak and the server is desperately trying to stay within its heap limits. Create an [MRE](https://en.wikipedia.org/wiki/Minimal_Working_Example) and use that for analysis. Try lowering the Xmx value to something like 2g,, reproduce the issue and make a heap dump. Analyze it and investigate if you do not have any leaks. – yntelectual Jul 04 '17 at 12:55

1 Answers1

2

Sadly, my magical crystal ball is broken, so we will have to get our hands dirty with thread dump.
First, we need to figure out, what thread is causing the Cpu load, as app server is not single-threaded. Assumimg you are on linux, you can use standard ps to get details of cpu usage per process thread:

ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args | grep [PID_OF_YOUR_WILDFLY_PROCESS] > unixthread.txt

Here we are interested in columns nlwp lwp and pcpu. Find the threads with highest cpu load.
Next we need java thread dump: Obtain a thread dump during the period of high CPU load:

jstack -l [PID_OF_YOUR_WILDFLY_PROCESS] > jstack.out

And now for some thread hunting: say your unixthread identified a thread with nwlp 9999 as the CPU hog, convert the number to hex- 0x270F and search for this value in your jstack.out file. It should match a java thread, with stacktrace that should help you pinpoint the problem.

If it is GC related, then proceed with heap dump to ensure it ia not a leak in your app.
If you do your analysis and still think it is an issue with jvm or gc settings, you should get in touch with redhat guys. I believe, that if you intend to run a banking app on RedHat stack, you should definitely go for EAP7 with paid support and not hazzard with Upstream OS project without support for eventual bugs or issues.

yntelectual
  • 3,028
  • 18
  • 24
  • add result of ps -eLo pid,lwp,nlwp,ruser,pcpu,stime,etime,args|grep – ROHIT Jun 15 '17 at 11:28
  • I have updated the ps command. Basically you only need pid, lwp and pcpu - `ps -eLo pid,lwp,pcpu | grep `. The output will have three columns: process pid, lwp(thread id), pcpu(cpu load) like this: `4192 4192 0.0` `4192 4193 0.0` `4192 4194 0.0` So your lwp is the second column and after conversion to hex you should find a match in your thread dump. – yntelectual Jun 15 '17 at 13:02
  • Thanks for help, i have found couple of threads which are consuming cpu. – ROHIT Jun 16 '17 at 07:46
  • Ok, now if you take the LWP, convert it to hex and find a matching thread in java thread dump, what do you get? For every thread you should see a stacktrace. Is it your application logic or internal jboss housekeeping? – yntelectual Jun 16 '17 at 13:48
  • I have added thread dump, and new LWP ids. It would be great if you can help me to identify the issue. – ROHIT Jun 21 '17 at 16:04