7 Replies Latest reply on Jul 31, 2007 4:15 PM by 807605

    JVM performance slowed down after

    807605
      Hello all,

      My java application is heavily multithreaded and its supposed to run as a 24/7 service. Its supposed to collect SMS from different servers, store in memory/flat-files and send them to clients.

      The application has been running for the past 6 days and
      the JVM has slowed down considerably. (performance has gone down)

      Initially the app used to receive/send arnd 50 SMS per second and now it process aroubd 20-25 SMS per second.

      I've been using Your kit profiler to profile my app.

      The maximum heap I allocated was 500MB; the alloted Heap shown in the
      profiler is 95MB and the used Heap is 65MB

      The CPU usage looks fairly stable,i.e. it does go up when SMS comes in
      and i/o operations takes place and goes to 0% when no process is being done.

      memory usage also looks fairly stable.

      (No explicit memory leaks)

      The application has over 133 threads and that stays the same as per
      the profiler tool kit.

      Also in my application I have a maintainance phase at 23:00 hours during which i do some cleaning work like
      -deleting of expired SMS from memory
      -deleting old log files
      -deleteing other flat files
      -and finally I explicitly call the garbage collector

      What should I look in - to maintain the performance, should I not explicitly call
      the GC and let JVM do it on its own? or is it beacause the heap space has become fragmented? - I do make a lots of read/writes from/to the objects stored in Heap.

      I also make around 160,000+ read/write from/to flat files in the hard disk.
      Could this cause the JVM to slow down?

      Any suggestion on this will be great.
        • 1. Re: JVM performance slowed down after
          807605
          What should I look in - to maintain the performance,
          should I not explicitly call
          the GC and let JVM do it on its own? or is it
          beacause the heap space has become fragmented? - I do
          make a lots of read/writes from/to the objects stored
          in Heap.
          Instead of explicitly calling the gc which probably won't make a bit of a difference, I would experiment with the different gc algorithms available.

          http://java.sun.com/docs/hotspot/gc5.0/gc_tuning_5.html

          As for fragmentation, the JVM can move heap memory around, and a full gc should take care of that for you.
          • 2. Re: JVM performance slowed down after
            807605
            Did you notice any slowdown on the machine as a whole? Look also for specific OS performance indicators: Native Threads, I/O Operations / sec, I/O Reads/Writes, File Handles etc.
            • 3. Re: JVM performance slowed down after
              807605
              I will look into that article on GC.

              No, i cant say if the entire OS has slowed down, the OS seems to look fine,
              All other apps work as usual.
              so its something to do with the JVM in particular.

              Another question - is there any limit on the heap space usage; right now I've specified 496MB and 65MB is being used, is there any max limit for heap space?
              • 4. Re: JVM performance slowed down after
                807605
                Another question - is there any limit on the heap
                space usage; right now I've specified 496MB and 65MB
                is being used, is there any max limit for heap space?
                Between 2 and 4G for the entire java process, depending on systems and VM configurations (-XX+AggressiveHeap etc..).

                A part of that space is used by the VM itself, JNI, etc...

                I have worked with applications where 1GB of heap space is a pretty common thing. So I don't see you anywhere near that limit.
                • 5. Re: JVM performance slowed down after
                  807605
                  Initially the app used to receive/send arnd 50 SMS
                  per second and now it process aroubd 20-25 SMS per
                  second.

                  I've been using Your kit profiler to profile my app.
                  Does it have CPU profiling? If yes, then you can look at where the time's being spent when processing a message.

                  The maximum heap I allocated was 500MB; the alloted
                  Heap shown in the profiler is 95MB and the used Heap is 65MB
                  So not a memory problem.

                  The CPU usage looks fairly stable,i.e. it does go up
                  when SMS comes in and i/o operations takes place
                  and goes to 0% when no process is being done.
                  So not a background thread that's run amok (probably).

                  The application has over 133 threads and that stays
                  the same as per the profiler tool kit.
                  You could be running into contention for a shared resource. This will show up in the CPU profiler, or you can get a "quick and dirty" report by hitting Ctrl-\ in the window where the JVM is running (or, if on Unix, sending SIGQUIT to the JVM process). This will send a thread dump to the console. Look for a lot of threads "wait"ing on some object, then look for the thread that holds that object.

                  What should I look in - to maintain the performance,
                  should I not explicitly call the GC and let JVM do it on its own?
                  Never call GC directly. The JVM will do it when necessary. Plus, you don't appear to have a memory issue.

                  I also make around 160,000+ read/write from/to flat
                  files in the hard disk. Could this cause the JVM to slow down?
                  Ahh ... flat files in a single directory? A lot of files in one directory will definitely slow things down, especially if you're opening them for every read and write: the OS has to scan the entire directory to find the file.

                  Does performance improve after your nightly cleanup? If yes, and you're removing old files, then this is an indication of the problem.
                  • 6. Re: JVM performance slowed down after
                    807605
                    Initially the app used to receive/send arnd 50 SMS
                    per second and now it process aroubd 20-25 SMS per
                    second.

                    I've been using Your kit profiler to profile my
                    app.

                    Does it have CPU profiling? If yes, then you can look
                    at where the time's being spent when processing a
                    message.
                    It does have a CPU profiling graph, but there is nothing much i can infer from it, I can see the graph peaking to 60-80% CPU usage when SMS are comming in (i.e. SMS is received, stored in memory & a copy is also put in the flat file - which is a read/write I/O operation, so I would defenitely expect the CPU to peak up); this peaking up would normally happen between 6-9am when lots of SMS come it to my app. The rest of the time (in the afternoon & evening) CPU is 0% ; so I can defenitely rule ot memory leak right?

                    its difficult to find out the time taken to process every message; the rough estimate I got from the log file is 50SMS / Sec. i.e. 50SMS receievd via TCP/IP; then store it in flat file & memory and also deliver it across to a client via socket; get a response back; change some status in memory and also in the flat file; this count of 50 has defenitely dropped to 25-30 in 6 days.

                    >
                    The maximum heap I allocated was 500MB; the
                    alloted
                    Heap shown in the profiler is 95MB and the used
                    Heap is 65MB

                    So not a memory problem.

                    The CPU usage looks fairly stable,i.e. it does go
                    up
                    when SMS comes in and i/o operations takes place
                    and goes to 0% when no process is being done.
                    So not a background thread that's run amok
                    (probably).

                    The application has over 133 threads and that
                    stays
                    the same as per the profiler tool kit.
                    You could be running into contention for a shared
                    resource. This will show up in the CPU profiler, or
                    you can get a "quick and dirty" report by hitting
                    Ctrl-\ in the window where the JVM is running (or, if
                    on Unix, sending SIGQUIT to the JVM process). This
                    will send a thread dump to the console. Look for a
                    lot of threads "wait"ing on some object, then look
                    for the thread that holds that object.
                    You are talking of possible dead-locks right? thats something i@ve go to llok into; the profiler does lists ot a list of possible thread-deadlocks. but all of them are purposefully made into TIMED_WAITING ; would that cause the performance to drop?

                    >
                    What should I look in - to maintain the
                    performance,
                    should I not explicitly call the GC and let JVM do
                    it on its own?

                    Never call GC directly. The JVM will do it when
                    necessary. Plus, you don't appear to have a memory
                    issue.
                    Yep, would change that and avoid calling GC directly.

                    >
                    I also make around 160,000+ read/write from/to
                    flat
                    files in the hard disk. Could this cause the JVM to
                    slow down?

                    Ahh ... flat files in a single directory? A lot of
                    files in one directory will definitely slow things
                    down, especially if you're opening them for every
                    read and write: the OS has to scan the entire
                    directory to find the file.
                    Nothing much I can do there.


                    >
                    Does performance improve after your nightly cleanup?
                    If yes, and you're removing old files, then this is
                    an indication of the problem.
                    I'll look into the logs to see if there is any increase in performance after GC and clome back
                    • 7. Re: JVM performance slowed down after
                      807605
                      its difficult to find out the time taken to process
                      every message; the rough estimate I got from the log
                      Sounds like your profiler doesn't support drill-down then.

                      NetBeans does provide this, as does the built-in "hprof" profiler. You would probably want to set up a test environment that sends SMS messages, so that you're not mucking with your production server.

                      Basically, you're looking for the methods that take the most time. The profiler tracks the entry and exit points of the methods, all the way down to the API. So you'd start with "main", which should take 100% of the time. Looking at the methods it calls, you see that "processSMS" takes 98% ... and so on, until you're seeing a call to "File.open" that takes 50% (for example).

                      file is 50SMS / Sec. i.e. 50SMS receievd via TCP/IP;
                      then store it in flat file & memory and also deliver
                      it across to a client via socket; get a response
                      back; change some status in memory and also in the
                      flat file; this count of 50 has defenitely dropped to
                      25-30 in 6 days.
                      There are a lot of places here that could be your bottleneck. It could even be the client that's slow, and dragging down the rest of the system. Generally bottlenecks have a disproportionate effect -- one of the things you learn from Queing Theory is that as you reach saturation, the response time graph becomes exponential.

                      You are talking of possible dead-locks right? thats
                      something i@ve go to llok into; the profiler does
                      lists ot a list of possible thread-deadlocks. but all
                      of them are purposefully made into TIMED_WAITING ;
                      would that cause the performance to drop?
                      Not sure what "TIMED_WAITING" means -- that sounds more like a socket condition than an in-process lock. But yeah, again you're in an exponential graph, the more threads you have waiting on a shared resource.

                      Ahh ... flat files in a single directory? A lot of
                      files in one directory will definitely slow things
                      down, especially if you're opening them for every
                      read and write: the OS has to scan the entire
                      directory to find the file.
                      Nothing much I can do there.
                      Sure there is. One common strategy is to create a hierarchy of directories based on the first few letters of the filename. So, rather than having directory "foo" with files "123.txt", "456.txt" and so on, you'd create the following:
                      foo/
                          foo/1/
                              123.txt
                          foo/4/
                              456.txt
                      You may think it will take longer to work through the directory hierarchy, but in fact it's much faster -- each directory contains fewer entries, and the intermediate directories are probably in a disk cache somewhere.