1 Reply Latest reply: Mar 6, 2012 3:53 PM by PHCharbonneau RSS

    Managed server goes slow |  Thread Dump o/p seen below | Pls suggest fix

    921788
      "[ACTIVE] ExecuteThread: '129' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x0233f358 nid=0x73d9 waiting for monitor entry [0x4647f000..0x4647fbf0]
      at weblogic.timers.internal.TimerManagerImpl.complete(TimerManagerImpl.java:652)
      - waiting to lock <0x7882c488> (a weblogic.timers.internal.TimerThread)
      at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:285)
      at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      "[ACTIVE] ExecuteThread: '128' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x02aa85d0 nid=0x73d8 runnable [0x4657e000..0x4657fc70]
      at java.lang.Object.getClass(Native Method)
      at com.sun.crypto.provider.RSACipher.<init>(DashoA12275)
      at sun.reflect.GeneratedConstructorAccessor90.newInstance(Unknown Source)
      at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
      at java.lang.reflect.Constructor.newInstance(Constructor.java:494)
      at java.lang.Class.newInstance0(Class.java:350)
      at java.lang.Class.newInstance(Class.java:303)
      at java.security.Provider$Service.newInstance(Provider.java:1130)
      at javax.crypto.Cipher.a(DashoA12275)
      - locked <0xe75288a0> (a java.lang.Object)
      at javax.crypto.Cipher.getProvider(DashoA12275)
      at weblogic.jce.WLCipher.getProvider(WLCipher.java:38)
      at com.certicom.tls.provider.Cipher.getInstance(Unknown Source)
      at com.certicom.tls.record.handshake.ServerStateSentHelloDone.handle(Unknown Source)
      at com.certicom.tls.record.handshake.HandshakeHandler.handleHandshakeMessage(Unknown Source)
      at com.certicom.tls.record.handshake.HandshakeHandler.handleHandshakeMessages(Unknown Source)
      at com.certicom.tls.record.MessageInterpreter.interpretContent(Unknown Source)
      at com.certicom.tls.record.MessageInterpreter.decryptMessage(Unknown Source)
      at com.certicom.tls.record.ReadHandler.processRecord(Unknown Source)
      at com.certicom.tls.record.ReadHandler.readRecord(Unknown Source)
      at com.certicom.tls.record.ReadHandler.readUntilHandshakeComplete(Unknown Source)
      at com.certicom.tls.interfaceimpl.TLSConnectionImpl.completeHandshake(Unknown Source)
      - locked <0xe6a3c780> (a com.certicom.tls.interfaceimpl.TLSConnectionImpl)
      at javax.net.ssl.impl.SSLSocketImpl.startHandshake(Unknown Source)
      at weblogic.server.channels.DynamicSSLListenThread$1.run(DynamicSSLListenThread.java:130)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      "[ACTIVE] ExecuteThread: '127' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x02fab040 nid=0x73d7 waiting for monitor entry [0x4667f000..0x4667faf0]
      at weblogic.timers.internal.TimerManagerImpl.complete(TimerManagerImpl.java:652)
      - waiting to lock <0x7882c488> (a weblogic.timers.internal.TimerThread)
      at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:285)
      at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      "[ACTIVE] ExecuteThread: '126' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x033acd58 nid=0x73d6 runnable [0x4677f000..0x4677fb70]
      at weblogic.work.RequestManager.reclaimHogger(RequestManager.java:620)
      at weblogic.work.RequestManager.updateStats(RequestManager.java:580)
      at weblogic.work.RequestManager.registerIdle(RequestManager.java:348)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:175)

      "[ACTIVE] ExecuteThread: '125' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x038db180 nid=0x73d5 waiting for monitor entry [0x4687f000..0x4687f9f0]
      at weblogic.timers.internal.TimerManagerImpl.complete(TimerManagerImpl.java:652)
      - waiting to lock <0x7882c488> (a weblogic.timers.internal.TimerThread)
      at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:285)
      at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      "[ACTIVE] ExecuteThread: '124' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x03f8f8b8 nid=0x73d4 waiting for monitor entry [0x4697f000..0x4697fa70]
      at weblogic.timers.internal.TimerManagerImpl.complete(TimerManagerImpl.java:652)
      - waiting to lock <0x7882c488> (a weblogic.timers.internal.TimerThread)
      at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:285)
      at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:464)
      at weblogic.work.ExecuteThread.execute(ExecuteThread.java:200)
      at weblogic.work.ExecuteThread.run(ExecuteThread.java:172)

      "[ACTIVE] ExecuteThread: '123' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=3 tid=0x03e1f6e0 nid=0x73d3 runnable [0x46a7e000..0x46a7f8f0]
      at java.lang.String.<init>(String.java:174)
        • 1. Re: Managed server goes slow |  Thread Dump o/p seen below | Pls suggest fix
          PHCharbonneau
          Hi,

          Thread #128 is giving us the information below:

          -     Request is coming in your your WL server via the SSL / HTTPS port (via the SSLListenThread)
          -     Weblogic then initiate a SSL handshake with the calling client and then attempt to decrypt the returned message
          -     In order to decrypt the message, WL (certicom) has to initialize a new Cipher
          -     This task then trigger the usage of the current configured Crypto Provider in your running WL / JVM
          -     Finally, we can see that you are using com.sun.crypto.provider.RSACipher as the crypto Cipher

          This SSL handshake process appears to be taking some abnormal time to complete but again it could be a “victim” of another problem / heavy CPU going on in your environment / JVM e.g. heavy GC process for example or other high CPU conditions can expose in the Thread Dump computing intense processing tasks such as logging/IO/SSL computing etc.

          In order to pinpoint the root cause, you will need to correlate the Thread Dump data with prstat (if running on Solaris), ps –mp (if on AIX), top Thread toggle view (if on Linux) etc.

          I have tutorials below for you that explains how to do this.
          In the meantime, can you please provide us with more Threads Stack Trace (especially any hogging or stuck Threads) from the captured Thread Dump so I can help you identify other patterns that could be consuming the CPU in your environment.

          Thanks.
          P-H
          http://javaeesupportpatterns.blogspot.com/2012/02/prstat-linux-how-to-pinpoint-high-cpu.html
          http://javaeesupportpatterns.blogspot.com/2011/12/prstat-aix-how-to-pinpoint-high-cpu.html