Showing posts with label Java Performance / JMX / JConsole. Show all posts
Showing posts with label Java Performance / JMX / JConsole. Show all posts

Friday, July 9, 2010

Cannot read NBM, com-sun-btrace.nbm

Jvisualvm is a great tool even for developers. Brace is on popular profiling tool which enable you to add some profiling logic to the existing jvm. Like dump out the variable passed to the given method.

Btrace has one plugin for jvisualvm, if you followed this link https://btrace.dev.java.net/visualvm_uc.html.

you may get an error, something like cannot read NBM, network issue.

image

the server is definitely available.   3 nbms have been downloaed to that folder.

Now, you need change the plug-in update address to http://btrace.kenai.com/uc/visualvm/updates.xml

then reload the catalog and click to install the plug-in. easy you profiling

image

Friday, July 2, 2010

JMX - jconsole connection / TCP Port redirection,Fireware issue

JMX provides a standard way to instrument the Java runtime environment and applications, and the JMX Remote API allows that instrumentation to be accessed remotely. there are couple system properties that you need to setup.

To enable the JMX agent and configure its operation using jconsole, your must set some specific system properties when you start the JVM. For local access, set the property com.sun.management.jmxremote as follows when starting the JVM:

prompt> java -Dcom.sun.management.jmxremote AppName

And, to enable monitoring and management from remote systems [here we disable the authentication and ssl]  , set the property:

-Dcom.sun.management.jmxremote.port=portNumber
-Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false

When we talk about the firewall settings, here is one quick question, Is the PortNumber pretty much all we needed to put it into our exception list? if you answer yes like me. you need read the following parts. or maybe that’s why you are redirected to this blog. 

lets do a simple test, Just open you notepad and write a helloworld Application.

public class MyApp
{
    public static void main(String[] args)  throws java.io.IOException
    {
        System.out.println("hello,world, press to continue");
         int i=System.in.read();
    }
}

then Compile and Run the application.

C:\temp>javac MyApp.java

C:\temp>java -cp "." -Dcom.sun.management.jmxremote.port=2222 -Dcom.sun.management.jmxremote.ssl=false
-Dcom.sun.management.jmxremote.authenticate=false   MyApp

hello,world, press to continue

Keep the application running, and Open Jconsole, put localost:2222 to the remote process field, and click to go. nothing special here, you will be able to see the Mbeans .

So, How does the jconsole communicate with our JMXRemote Port? your may run netstat or download a utility offered from microsoft called tcpview.  when you filter to jconsole process, you may find the following sessions. besides, the port 2222, it open one extra tcp port . the port number looks like it just pick it up randomly

image

at the end of one day, if somebody enforce the firewall policy by adding port 2222 to the only allowed port,  then Nobody can use the jconsole to monitor this jvm.

So how can we Restrict the JMX listening Port/TCP to use the predefined Port? here is the steps.
basic Idea,  when the application startup, just start one JMXConnectorServer service explicitly.  the server will expose jmxjmi service to the client. In java, there is one serverfactory called JMXConnectorServerFactory

public static JMXConnectorServer newJMXConnectorServer(JMXServiceURL serviceURL, Map<String,?> environment, MBeanServer mbeanServer) throws IOException

The connector server will generate an RMIServerImpl based on the protocol (rmi or iiop) and, for rmi, the port if any. When the connector server is started, it will derive a stub from this object using its toStub method and store the object using the given jndi-name. The properties defined by the JNDI API are consulted as usual.

For example, if the JMXServiceURL is:

service:jmx:rmi://ignoredhost/jndi/rmi://myhost/myname

then the connector server will generate an RMIJRMPServerImpl and store its stub using the JNDI name

rmi://myhost/myname

then we just change the myapp.java to loadup the connecterserver directly.

finally code:

import java.lang.management.ManagementFactory;
import java.rmi.registry.LocateRegistry;
import javax.management.remote.JMXConnectorServer;
import javax.management.remote.JMXConnectorServerFactory;
import javax.management.remote.JMXServiceURL;

public class MyApp
{
    public static void main(String[] args)  throws java.io.IOException
    {
        int port=3333;
        LocateRegistry.createRegistry(port);
        JMXServiceURL url =
            new JMXServiceURL("service:jmx:rmi://localhost:"+port+"/jndi/rmi://:"+port+"/jmxrmi");
               JMXConnectorServer cs =
            JMXConnectorServerFactory.newJMXConnectorServer(url, null, ManagementFactory.getPlatformMBeanServer());
        cs.start();

        System.out.println("hello,world, press to continue");

        int i=System.in.read();
    }
}

Recompile and restart the app, run jconsole. check the tcp session. Only TCP Port 3333 is open and required this time now.

image

In this case, we owned the source code of our application. if you are using the commercial package or third party application,  you can’t change their source code then.
not a big problem, the Insturment package allow Java programming language agents to instrument programs running on the JVM.  we just inject the save logic by writing a customeragent , and use the javaagent parameter to load our customeAgent.

we define another class, named JconsoleAgent

import java.lang.instrument.Instrumentation;
import java.lang.management.ManagementFactory;
import java.net.InetAddress;
import java.rmi.registry.LocateRegistry; import javax.management.remote.JMXConnectorServer;
import javax.management.remote.JMXConnectorServerFactory;
import javax.management.remote.JMXServiceURL; public class JconsoleAgent {
    public static void premain(String agentArgs, Instrumentation inst)
    {
        try
        {
            int port= Integer.parseInt(
                    System.getProperty("MyJMXPORT","5000"));
             LocateRegistry.createRegistry(port);
              String hostname = InetAddress.getLocalHost().getHostName();
            JMXServiceURL url =new JMXServiceURL("service:jmx:rmi://"+hostname+":"+port+"/jndi/rmi://"+hostname+":"+port+"/jmxrmi");
             JMXConnectorServer cs =
                JMXConnectorServerFactory.newJMXConnectorServer(url, null, ManagementFactory.getPlatformMBeanServer());
            cs.start();
        }
        catch (Exception ex)
        {
            System.out.println("SETUP MyJMXPORT Failed" + ex.getMessage());
        }
    }
}

then export the compiled class to a jar file named Jconsoleagent.jar . Edit the MANIFEST.MF file inclued in the jar, and put one more line.

Manifest-Version: 1.0
Premain-Class: JconsoleAgent

then startup the application like

C:\temp>java -cp "." -DMyJMXPORT=3333 -javaagent:Jconsoleagent.jar MyApp
you will be able to use the port 3333 only here to do the jmx monitoring.

image

Hope it Helps.

Another question, if you have multi NICS on the server, you can specify which RMI server that will server the request by adding parameters like

-Djava.rmi.server.hostname=MyInternalNIC

Also, make sure you jconsole client can resmove the MyInternalNIC to the same IPaddress as you defined on the server. otherwise, you can’t conenct to the remote server

here is my great reference link, http://www.cs.washington.edu/education/courses/cse341/98au/java/jdk1.2beta4/docs/guide/rmi/rmiNetworkingFAQ.html

Monday, June 14, 2010

Troubleshooting High 100% CPU utilization

When I open windows task manager it says that CPU usage is at 100%. Even I have enough Memory, CPU cores. What happened under the hood? Before you dig more, remember to Show the Kernel time vs User time.  [Click View->Show kernel times], then you will see some spikes in red. The Percentage of the red really means a lot. Here is two snapshoot. It’s a live snapshoot I captured. You may see the source code at the end of the blog.

c1

CPU 100%, Kernel time is less than 5% percent.

c2

Same 100% CPU, Kernel time is over 60%.

even I change the app to run a more powerful machine. with 8 Cores, Xeron CPU.

NODISK

 

IO

in this specific case, CPU is extremely busy, Memory looks good (no spike, and still at lot free RAM available.), What are those resources drained a lot CPU?  for those kernel things, they might be the following types

  • DISK I/O, Check the VMstat or disk queue length in windows, Driver issue?
  • Network I/O.  (DB connection, lot round-trip call?)
  • Thread context switching. ( Locks, contention. quantum management.), you can check the cs in vmstat , In windows, using the performance counter System->Context Switches/sec
    • System\Context Switches/sec, which measures how frequently the processor has to switch from user- to kernel-mode to handle a request from a thread running in user mode. The heavier the workload running on your machine, the higher this counter will generally be, but over long term the value of this counter should remain fairly constant. If this counter suddenly starts increasing however, it may be an indicating of a malfunctioning device, especially if you are seeing a similar jump in the Processor(_Total)\Interrupts/sec counter on your machine.

image

if you want to reproduce the above CPU usage. here is the C# source code.

Comment or uncomment the link of ReadFile("c:\\windows"); will make a big difference. in this code, the read time is spent by Disk I/O.

namespace ConsoleApplication4
{
    class Program
    {
        static volatile int iiii = 0;
        static void Main(string[] args)
        {
            System.Net.ServicePointManager.MaxServicePoints = 1000;
            int count = 40;
            Thread[] trs = new Thread[count];
            for (int i = 0; i < count; i++)
            {
                trs[i] = new Thread(Func);

            }

            for (int i = 0; i < count; i++)
            {
                trs[i].Start();

            }

            Console.ReadLine();
        }

        static void Func(object o)
        {
            while (true)
            {
                for (int i = 0; i < 10000; i++)
                {
                    iiii += 2;
                    try
                    {
                        ReadFile("c:\\windows");
                    }
                    catch
                    {
                    }
                }

            }
        }

        private static void ReadFile(string Dir)
        {

            foreach (String f in System.IO.Directory.GetFiles(Dir))
            {
                string D = f;
            }
            foreach (string folder in System.IO.Directory.GetDirectories(Dir))
            {
                ReadFile(folder);
            }
        }

    }
}

reference

Key Performance Monitor Counters http://www.windowsnetworking.com/articles_tutorials/Key-Performance-Monitor-Counters.html
vmstat command : http://publib.boulder.ibm.com/infocenter/aix/v6r1/index.jsp?topic=/com.ibm.aix.prftungd/doc/prftungd/vmstat_command.htm

Wednesday, June 9, 2010

GC Log Visulation, HPJmeter

Jon has a great blogging about different JAVA gc collections. check the link : http://blogs.sun.com/jonthecollector/entry/our_collectors, basically it means different Collector means different   young age / old generation collection behavior.

Each blue box represents a collector that is used to collect a generation. The young generation is collected by the blue boxes in the yellow region and the tenured generation is collected by the blue boxes in the gray region.

  • "Serial" is a stop-the-world, copying collector which uses a single GC thread.
  • "ParNew" is a stop-the-world, copying collector which uses multiple GC threads. It differs from "Parallel Scavenge" in that it has enhancements that make it usable with CMS. For example, "ParNew" does the synchronization needed so that it can run during the concurrent phases of CMS.
  • "Parallel Scavenge" is a stop-the-world, copying collector which uses multiple GC threads.
  • "Serial Old" is a stop-the-world, mark-sweep-compact collector that uses a single GC thread.
  • "CMS" is a mostly concurrent, low-pause collector.
  • "Parallel Old" is a compacting collector that uses multiple GC threads.

    Using the -XX flags for our collectors for jdk6,

  • UseSerialGC is "Serial" + "Serial Old"
  • UseParNewGC is "ParNew" + "Serial Old"
  • UseConcMarkSweepGC is "ParNew" + "CMS" + "Serial Old". "CMS" is used most of the time to collect the tenured generation. "Serial Old" is used when a concurrent mode failure occurs.
  • UseParallelGC is "Parallel Scavenge" + "Serial Old"
  • UseParallelOldGC is "Parallel Scavenge" + "Parallel Old"
  • given different options, you need to compare and balance the different tradeoffs. like latency, responsetime, low footprint. etc.  How to make sure which one fits you? HPJmeter is your friend to tell that.

    How it works. 
      Turn on GC log which will enable the jvm to dump GC detailed information to a Logfile. try different colelctors, then you get the result matrix. HPJmeter has the feature to compare several log files. then you can compare the GC time, Heap Allocation.

    for example, Like me, I want to compare the ParallenGC vs the Concurrent GC. here is how it do it.
    download HPJmeter from HP, it’s a free tool.

    then enable the gc loging and try different switch. here is two options I tried

    java -XX:+UseParallelGC  -Xloggc:gcParallelGC.log MyApplication

    java -XX:+UseConcMarkSweepGC  -Xloggc:gccms.log MyApplication

    after run the app for a while, you get enough gc information and stop you app. two logs are generated. they are basically text file and has a fixed format.

    0.158: [GC 20544K->18152K(32192K), 0.0062129 secs]
    0.185: [GC 22312K->19728K(36352K), 0.0103363 secs]
    0.236: [GC 28048K->22500K(36352K), 0.0135180 secs]
    0.250: [Full GC 22500K->5706K(27264K), 0.0271364 secs]


    clock time :{gc type, before->after, pause time]

    start the HPJmeter, and open the log you just collected. there are several tabls that show you the summary /Heap usage/Duration,etc

    image

    the above summary tells the ParallelGC does’t work well in my application. 20% of CPU time is spent on GC collection. and several FULL GCs which is CPU intensive has been invoked.
    then click the user-defined tab and select cumulative GC, it shows the GC time vs the clock time

    image

    of course, the less time spent on GC, the more you app get responsive.

    now time to compare with the Concurrent collectors. CLick the File->compare to load another log file.

    image

    the CMS with Concurrent Collector wins, it takes less time . test it , and the chart tells. 

    Tuesday, June 8, 2010

    VisualGC plugin ,VisualVM

    I’ve always looking for some 3rd party tools to visualize the JVM GC , It turns out some great tool has been part of the java 6 SDK [so remember to use the jdk 1.6  , nee 1.5/1/4].  visualVM is part of the toolsets.

    Just go to bin directory of the SDK, and Run “JvisualVM”, the GUI tool showing the general view of Threads, Heap will popup

    image

    however you can’t see the detailed GC details. Like the S1/S2 , Eden space , Survior space /Perm Space.

    now, time to turnon the visualGC. Just click the tools->plugin and Select to enable the visualgc plugin.

    image

    check the visualGC , accept terms and install the plug-in. then Restart the jvisualvm

    image

    in the visual GC tab, you get the detailed inside of the heapspace. with the time goes on, you can see eden space get collected and copied to s0/s1, when s0 is filled up, compact to s1/s0, then goes to old space.

    what a great plug-in.

    Some links here: VisualGC options and filed descriptions. http://java.sun.com/performance/jvmstat/visualgc.html

    Try some parameters and verify it works?

    image

    •A+B+C=Young Age

    •D=Old Age

    •E=Per Age

    •Size of B == Size of C

    •D/(A+B+C)= -XX:NewRatio

    •A/B or A/C= -XX:SurvivorRatio

    you can tell from the description.

    image

    I setup the -XX:NewRatio=10, which will increase the Old space quota. you can do some math here

    454.562 /(36.4+4.5+4.5)=10 here.

    Dump the Heap?

    her is one sample code, that I keep creating Persons which has an Address object. then release the reference periodically. when you dump the heap, you may see their instances keep jumping up and down

    image

    or just enable the Sample on Memory and put a filter in the bottom.

    image

    heap Walker?

    Is the data correct? what’s the root for those junk data. Heap walker is the answer.

    after you dump the heap, double click the Class that you are interested. like the Person Here. you get the root of this object, and you can drill up to the Top  root

    image

    show GCRoot,those are the key point for potential Memory leak

    when you right click one instance in the references list,  click show neareast gc root.
      Remember that when you click heap dump, it will trigger a GC. in the last gc secion, you can see one note called ‘heap dump initiated GC”. so you won’t be able to see the “dirty” objects.

    image

    Untitled

    image

    here, aaa is a static field of a class. so static class loader is the GC root.

    Sample Code is attached here.

    import java.io.IOException;
    import java.util.ArrayList;
    import java.util.List;

    public class GCHeap {

    •   static  List<Person []> aaa=new ArrayList<Person []>(); 
          public static void main(String[] args) throws IOException { 
                  int j=0;
              while(true)
              {
                  if(j++ % 5==0)
                  {
                      aaa=new ArrayList<Person []>();
                  }
                  Person [] arrs=new Person[20];
                  for(int i=0;i<20;i++)
                  {
                      Person p=new Person();
                      Address a=new Address();
                      a.StreetName="STREET " + i;
                      a.StreeNumber="NO" +i;
                      p.Add=a;
                      arrs[i]=p;
                  }
                  aaa.add(arrs);
                  System.out.println("j"  + j);
                  int i =System.in.read();
              }
          }

        private static class Person
        {
            public String Name;

            public Address Add;
        }

        private static class Address
        {
            public String StreetName;
            public String StreeNumber;

        }
    }

    Other Blogs about Java monitoring.

    Monday, May 10, 2010

    java.net.SocketException: Unrecognized Windows Sockets error: 0: Cannot bind

    Oracle Coherence is a JVM-based Clustering technology. sometimes, when you start the jvms on windows environment, you may get some strange error. like this, java.net.SocketException: Unrecognized Windows Sockets error: 0 : Cannot bind at com.tangosol.coherence.component.net.Cluster.onStart(Cluster.CDB:108) at com.tangosol.coherence.component.net.Cluster.start(Cluster.CDB:11) at com.tangosol.coherence.component.util.SafeCluster.startCluster(SafeCl uster.CDB:3) at com.tangosol.coherence.component.util.SafeCluster.restartCluster(Safe Cluster.CDB:7) at com.tangosol.coherence.component.util.SafeCluster.ensureRunningCluste r(SafeCluster.CDB:27) at com.tangosol.coherence.component.util.SafeCluster.start(SafeCluster.C DB:2) at com.tangosol.net.CacheFactory.ensureCluster(CacheFactory.java:998) at com.tangosol.net.DefaultConfigurableCacheFactory.ensureService(Defaul double check you config file, it’s all correct. then check whether you have enabled some network acceleration solution, Like Microsoft ISA Client, or Google Accelerator. they try to hooked up with windows socket provider. disable them, then problem gone. have fun. coherence user guide: http://coherence.oracle.com/display/COH35UG/Coherence+3.5+Home some other googled exception:
     
    Locations of visitors to this page