Java Forum / General / July 2007
Tuning suggestions, please?
Bret Schuhmacher - 04 Jul 2007 06:47 GMT Hello all,
I have a program that runs very quickly with one small exception. I'm trying to tune the performance and I can't track down a 15ms delay. Maybe you can help. 15ms may not sound like much, but this is supposed to be a VERY high performing app, and 15ms adds up...
I've got log4j spitting out log statements at the entrance and exit of the method in question. All the program does is open a file and read the contents into a bufferedreader, then enter a loop and call the method until there are no more rows to read. Here are the timings from the log4j log: 2007-07-03 19:40:21,678 INFO 2007-07-03 19:40:21,678 INFO 2007-07-03 19:40:21,678 INFO 2007-07-03 19:40:21,693 INFO 2007-07-03 19:40:21,693 INFO 2007-07-03 19:40:21,709 INFO 2007-07-03 19:40:21,709 INFO 2007-07-03 19:40:21,709 INFO 2007-07-03 19:40:21,725 INFO 2007-07-03 19:40:21,725 INFO 2007-07-03 19:40:21,740 INFO 2007-07-03 19:40:21,740 INFO 2007-07-03 19:40:21,740 INFO 2007-07-03 19:40:21,756 INFO 2007-07-03 19:40:21,756 INFO 2007-07-03 19:40:21,771 INFO 2007-07-03 19:40:21,771 INFO 2007-07-03 19:40:21,771 INFO 2007-07-03 19:40:21,787 INFO 2007-07-03 19:40:21,787 INFO 2007-07-03 19:40:21,787 INFO 2007-07-03 19:40:21,803 INFO 2007-07-03 19:40:21,803 INFO 2007-07-03 19:40:21,803 INFO 2007-07-03 19:40:21,818 INFO 2007-07-03 19:40:21,818 INFO 2007-07-03 19:40:21,818 INFO 2007-07-03 19:40:21,834 INFO 2007-07-03 19:40:21,834 INFO 2007-07-03 19:40:21,850 INFO 2007-07-03 19:40:21,850 INFO 2007-07-03 19:40:21,850 INFO 2007-07-03 19:40:21,865 INFO 2007-07-03 19:40:21,865 INFO 2007-07-03 19:40:21,865 INFO 2007-07-03 19:40:21,881 INFO
Notice the 15ms delay every so often? I'll get about 3 calls to the method in the same millisecond, then it'll delay about 15-16ms, and continue. I thought it was garbage collection, but if it is, I can't find the 15ms. And GC wouldn't run so frequently, would it? I'm running inside the Informix JRE (it's an IBM recompiled 1.4.2) and Sun 1.5.0_6. In the Sun JRE I use the following tuning: -Xms128m -Xmx768m -XX:MaxPermSize=128m -XX:+UseParallelGC -verbosegc -XX:MaxNewSize=32M -XX:NewSize=32M. That shows me this info:
[GC 24576K->1121K(126976K), 0.0162035 secs] [GC 25697K->1120K(126976K), 0.0185842 secs] [GC 25696K->1121K(126976K), 0.0144689 secs] [GC 25697K->1121K(126976K), 0.0177961 secs] [GC 25697K->1109K(126976K), 0.0154531 secs] [GC 25685K->1113K(129920K), 0.0149296 secs] [GC 31577K->1137K(128512K), 0.0141060 secs] [GC 31281K->1137K(129408K), 0.0029744 secs] [GC 30833K->1137K(128064K), 0.0011108 secs] [GC 30833K->1137K(129344K), 0.0010085 secs] [GC 30577K->1121K(129408K), 0.0044000 secs] [GC 30561K->1121K(129408K), 0.0015647 secs] [GC 30561K->1121K(129408K), 0.0035977 secs] [GC 30561K->1121K(129472K), 0.0015692 secs] [GC 30625K->1121K(129408K), 0.0011789 secs] [GC 30625K->1121K(129536K), 0.0029607 secs] [GC 30753K->1121K(129472K), 0.0025517 secs] [GC 30753K->1137K(129664K), 0.0014398 secs] [GC 31025K->1121K(129600K), 0.0014365 secs] [GC 31009K->1121K(129792K), 0.0009292 secs]
Any idea what might cause this 15ms delay? Any other avenues I should be looking into? FWIW, I got the 15ms delay before I added any JVM arguments (i.e. they didn't cause the problem). I only added the JVM args to try to figure out the issue.
Thanks in advance for your thoughts and suggestions!
Rgds,
Bret
Twisted - 04 Jul 2007 07:08 GMT > I've got log4j spitting out log statements at the entrance and exit of the > method in question. All the program does is open a file and read the > contents into a bufferedreader, then enter a loop and call the method until > there are no more rows to read.
> Notice the 15ms delay every so often? I'll get about 3 calls to the method > in the same millisecond, then it'll delay about 15-16ms, and continue. It's probably just when the BufferedReader has to fetch more data from the disk. If one row is about 256 bytes and the buffer in the BufferedReader is 1K, it will indeed grab more data from the disk about every fourth call.
It may be possible to tweak BufferedReader to a larger buffer size, or use NIO to get double-buffering where it will fill up one buffer while your code reads from another then switch.
Bret Schuhmacher - 04 Jul 2007 07:29 GMT Thanks for the quick reply! Unfortunately I don't think it's the BufferedReader. I first noticed the problem when the method in question was called from Informix as a User Defined Routine and there was no BufferedReader. I added a main() and some code to open a flat file today to see if Informix was the issue and the problem persisted exactly as it had under Informix - 15ms delays.
Thanks very much for the response, though.
Rgds,
Bret
Twisted - 04 Jul 2007 07:48 GMT > Thanks for the quick reply! Unfortunately I don't think it's the > BufferedReader. I first noticed the problem when the method in question was > called from Informix as a User Defined Routine and there was no > BufferedReader. I added a main() and some code to open a flat file today to > see if Informix was the issue and the problem persisted exactly as it had > under Informix - 15ms delays. Well there's a few other things it could be: * Another Java thread is doing stuff -- anything from incremental GCs to the random things I see in Eclipse's debugger from time to time like "JVM termination thread", "Finalization thread", and "AWT image fetcher thread". These manage a bunch of stuff under the hood. Some only for graphical apps; others for any app, to finalize dead objects with nontrivial finalize() methods, handle reference queues, and etc. * JIT compiling (but that should stop after a few iterations when it's fully optimized) * The JVM is simply doing something weird * Something else on the host system is hogging the CPU and yielding timeslices every 15 ms that are just long enough for the Java task to get a few iterations in * The OS you're running it on is doing something weird (Windoze by any chance?) * The very hardware you're running it on is doing something weird
> Thanks very much for the response, though. YW.
pascal.lecointe@euriware.fr - 04 Jul 2007 08:38 GMT > Hello all, > [quoted text clipped - 84 lines] > > Bret If I remember coreectly, the frequency of the user clock timer on windows is between 15 and 16 ms, so you can't have a better resolution within Java 1.4.
Since Java5 (or Java6, don't remember), there is the new method System.nanoTime(), which has a much better resolution (use another clock timer of the OS)
Juha Laiho - 04 Jul 2007 08:57 GMT "Bret Schuhmacher" <bret@thelastmilellc.com> said:
>Hello all, > >I have a program that runs very quickly with one small exception. I'm >trying to tune the performance and I can't track down a 15ms delay. Maybe >you can help. 15ms may not sound like much, but this is supposed to be a >VERY high performing app, and 15ms adds up... Could it be OS context switches; is there something else in the machine doing something, and thus stealing the CPU every now and then?
 Signature Wolf a.k.a. Juha Laiho Espoo, Finland (GC 3.0) GIT d- s+: a C++ ULSH++++$ P++@ L+++ E- W+$@ N++ !K w !O !M V PS(+) PE Y+ PGP(+) t- 5 !X R !tv b+ !DI D G e+ h---- r+++ y++++ "...cancel my subscription to the resurrection!" (Jim Morrison)
David Gourley - 04 Jul 2007 22:10 GMT > "Bret Schuhmacher" <bret@thelastmilellc.com> said: > [quoted text clipped - 7 lines] > Could it be OS context switches; is there something else in the machine > doing something, and thus stealing the CPU every now and then? There is a virtual machine thread which wakes up and does some stuff every 20 ms.. (This might show up as introducing pauses on single CPUs). (you can see this effect if you look at a JVM running with a kernel profiler e.g. prospect on hpux). Also on single CPU boxes, some kernel threads will periodically steal cycles (e.g. to flush file cache).
Another thing to look out for (as your thread looks like it might be CPU bound) is what's happening to it priority wise. The default scheduler behaviour on many OSs reduces the priority of long running threads if they run without yielding the CPU... this behaviour can often be modified (e.g. using rtsched command on hp-ux, but solaris and windows have equivalents as well, so I'm guessing AIX does). Setting thread priority from Java affects base priority but may not stop the priority from getting adjusted dynamically if that's the default OS scheduling policy.
You need to do UNIX profiling to see this last effect (shows up as the priority getting reduced for your application thread, and a large number of involuntary context switches).
If you're looking to benchmark with the nanosecond routines, you probably need to double check what system call they map onto.. on some hardware platforms, the high accuracy time routines can get mapped onto a fixed CPU (essentially to avoid clock drift between processors) and this can become a bottleneck.
Cheers
Dave
Nigel Wade - 04 Jul 2007 11:53 GMT > Hello all, > [quoted text clipped - 43 lines] > 2007-07-03 19:40:21,865 INFO > 2007-07-03 19:40:21,881 INFO
> Any idea what might cause this 15ms delay? A I don't think it's a 15ms delay, rather it's the resolution of the clock. On my Windows XP laptop the resolution is exactly 10ms. On my Linux desktop the resolution is 1ms.
Try this simple piece of code to see what your resolution is. It outputs the difference in mS of the clock every time the clock generates a new value, along with the number of times that it was able to create a new Date() (with the same value) during that interval.
import java.util.Date; public class TestClock { public static void main(String[] args) { int count = 0; Date olddate = new Date(); while(true) { Date date = new Date(); if ( date.after(olddate)) { long step = date.getTime() - olddate.getTime(); System.out.println(step+" "+count); olddate = date; count = 0; } else { count++; }
} } }
 Signature Nigel Wade, System Administrator, Space Plasma Physics Group, University of Leicester, Leicester, LE1 7RH, UK E-mail : nmw@ion.le.ac.uk Phone : +44 (0)116 2523548, Fax : +44 (0)116 2523555
Bret Schuhmacher - 04 Jul 2007 14:53 GMT Thanks for the code, Nigel. Here's the output: 15 193573 16 186582 16 190201 15 183223 16 116424 16 123012 15 100954 16 183436 15 170407 16 180246 16 195359 15 186473 16 190119 16 148391 . . .
Looks like the timer resolution on my laptop running Windows XP is 15-16ms - consistent with the 15-16 ms I was trying to track down.
I originally saw the issue at a customer's site on an AIX v5.2 box and replicated it on my Windows laptop. Is it possible an AIX box has the same timer resolution a Windows box does? I see the same issues inside and outside of Eclipse, as well as under different JVM versions (for those of you who were asking).
Is there *anything* I can do about this? Sounds like it's hardwired into the CPU. I tried adding this: Thread thisThread = Thread.currentThread(); thisThread.setPriority(Thread.MAX_PRIORITY); But it didn't help.
Are there other ways of dedicating a CPU or increasing the timeslice or priority to a thread in Java? Would it help?
Thanks again, Nigel!
Rgds,
Bret
Nigel Wade - 04 Jul 2007 15:47 GMT > Thanks for the code, Nigel. Here's the output: > 15 193573 [quoted text clipped - 38 lines] > > Bret You don't need to do anything. Your CPU is getting 100% (or pretty much). The only issue is the time resolution - you can't resolve the time to better than 15ms.
In the above test output you can see that during the 15ms resolution of your clock the code is actually running round the loop between 100,000 and 200,000 times.
 Signature Nigel Wade, System Administrator, Space Plasma Physics Group, University of Leicester, Leicester, LE1 7RH, UK E-mail : nmw@ion.le.ac.uk Phone : +44 (0)116 2523548, Fax : +44 (0)116 2523555
Patricia Shanahan - 04 Jul 2007 16:32 GMT > Thanks for the code, Nigel. Here's the output: > 15 193573 [quoted text clipped - 32 lines] > Are there other ways of dedicating a CPU or increasing the timeslice or > priority to a thread in Java? Would it help? You still seem to be looking for something like context switches that would cause intermittent delays. However, the message from the timer resolution measurement is that all you know is the average time for a series of calls. Maybe there are intermittent delays. Maybe every single call takes between 8.5 and 8.7 milliseconds. Both are consistent with the data.
The next step should be to redo the measurement, using System.nanoTime(). That will tell you what type of problem you are looking for.
Patricia
Bjorn Borud - 04 Jul 2007 17:43 GMT ["Bret Schuhmacher" <bret@thelastmilellc.com>]
| Looks like the timer resolution on my laptop running Windows XP is 15-16ms - | consistent with the 15-16 ms I was trying to track down. if it is a timer-resolution problem then why not increase the number of times the calculation is run between sampling of the clock? if you run it 10, 100 and 1000 times you should be less and less dependent on the resolution of the timer.
(other factors may come into play, like GC, but I don't think this should be an issue here. anyway, make sure that the heap is large enough so that the young generation comfortably can cope with all the (transient) objects allocated during the calculation. not that I suspect this to be a problem here (I'd have to take a look at the code), but if all your objects are really short-lived, you will actually lessen the GC burden).
(oh, and you should check if there are any differences in running the code in -server or -client mode).
-Bjørn
Roedy Green - 04 Jul 2007 14:49 GMT On Wed, 4 Jul 2007 05:47:19 GMT, "Bret Schuhmacher" <bret@thelastmilellc.com> wrote, quoted or indirectly quoted someone who said :
>Notice the 15ms delay every so often? see http://mindprod.com/jgloss/garbagecollection.html -- Roedy Green Canadian Mind Products The Java Glossary http://mindprod.com
Roedy Green - 04 Jul 2007 14:57 GMT On Wed, 4 Jul 2007 05:47:19 GMT, "Bret Schuhmacher" <bret@thelastmilellc.com> wrote, quoted or indirectly quoted someone who said :
> And >GC wouldn't run so frequently, would it? I wish I could remember what the tool was I used, (might have just been IntelliJ) but it let me know every time GC ran. I was amazed at how frequent it was. It seemed to do big gcs and little gcs.
One type of optimisation I have not seen much attention paid to is reducing the frequency of garbage collection by avoiding creating new objects uncessarily, particularly large objects like a buffer to read on entire file into RAM.
Other possible culprits:
1. some other task on your machine, e.g. indexing, mail check, cache flushing. You might run the resource monity with and without your code to see what other tasks are up to.
2. you should see a couple of pauses for HotSpot to do some optimisation.
As a practical matter, consider Jet to ultra optimise this code. See http://mindprod.com/jgloss/jet.html ' -- Roedy Green Canadian Mind Products The Java Glossary http://mindprod.com
Bjorn Borud - 04 Jul 2007 17:57 GMT [Roedy Green <see_website@mindprod.com.invalid>]
| I wish I could remember what the tool was I used, (might have just | been IntelliJ) but it let me know every time GC ran. I was amazed at | how frequent it was. It seemed to do big gcs and little gcs. probably VisualGC? if you run Java 1.5 or later it should be very simple to just attach it to a running VM and inspect what the GC system is doing.
check here:
http://java.sun.com/performance/jvmstat/#Tools
If you see several minor-collections per second then you might have heap that is too small. also have a look at how the tenured generation grows.
the hardest thing to optimize is code that keeps filling up the tenured generation, triggering major collections. (a few years ago I had an application that strained the GC a lot. turned out that by getting rid of some caches in the application¹, I got much smoother overall performance since the system wasn't doing major collections as often)
¹) the assumption of the programmer who put them there was possibly that these would make the system faster since he was used to the expense of frequent object creation and destruction in C++. it turned out that in this case the cache just slowed things down and that instantiation of the classes in question was pretty quick anyway.
| One type of optimisation I have not seen much attention paid to is | reducing the frequency of garbage collection by avoiding creating new | objects uncessarily, particularly large objects like a buffer to read | on entire file into RAM. well, and then hanging on to them for so long that they go into the tenured generation. remember, if you get rid of the object *quickly* it won't have to be copied during a number of minor collections and it won't end up in the tenured generation -- which is significantly slower to garbage collect.
-Bjørn
Bret Schuhmacher - 04 Jul 2007 22:34 GMT Thanks for the tips everyone! I do appreciate your input :-).
I've run visualgc and the GC time shows 94 collections, 59.81ms and unknown GC reason. The Eden space graph is up and down like a yo-yo very regularly. Is that normal? I don't know where the tenured GC is, though. I have an image of the tool running, but probably can't post it to this non binary newsgroup. I'll try to extend my heap as you suggested Bjorn - I do see a lot of GC in the Eden space - it's wild.
Thanks,
Bret
Wojtek - 05 Jul 2007 00:28 GMT Bret Schuhmacher wrote :
> Thanks for the tips everyone! I do appreciate your input :-). > > The Eden space graph is up and down like a yo-yo very regularly. > Is that normal? I have a Web app where I capture the used memory every ten minutes. The result is displayed as a bar graph. Even when the app is idle, the used memory looks like a saw tooth:
* * * ** ** ** *** *** *** *************
 Signature Wojtek :-)
Twisted - 05 Jul 2007 00:53 GMT > I have a Web app where I capture the used memory every ten minutes. The > result is displayed as a bar graph. Even when the app is idle, the used [quoted text clipped - 4 lines] > *** *** *** > ************* Is it really idle? If it's got a GUI all kinds of short-lived FooEvent objects are buzzing around, and every so often the GC will clear up the accumulated cruft. If it's doing networking stuff in the background, that activity also probably involves some rate of object turnover. You'll see a sawtooth graph like this whenever the rate of object turnover isn't basically zero.
Wojtek - 05 Jul 2007 01:15 GMT Twisted wrote :
>> I have a Web app where I capture the used memory every ten minutes. The >> result is displayed as a bar graph. Even when the app is idle, the used [quoted text clipped - 11 lines] > turnover. You'll see a sawtooth graph like this whenever the rate of > object turnover isn't basically zero. It is a Web application. When no hits are happening, it should be doing nothing. And my code does no networking.
Mind you I do have several timers running, but then the memory use goes from 30M to 74M over a 2 hour period, then drops back to 30M, which seems kind of excessive for timers.
 Signature Wojtek :-)
Twisted - 05 Jul 2007 01:55 GMT > Twisted wrote : > [quoted text clipped - 20 lines] > from 30M to 74M over a 2 hour period, then drops back to 30M, which > seems kind of excessive for timers. 5 or 6 bytes per millisecond on average. One new object created each millisecond on average is more than enough to cause what you observe. If the timers have resolutions of a few ms, there are a few of them, and they generate new Dates each time they update ... there you go.
Wojtek - 05 Jul 2007 16:27 GMT Twisted wrote :
>> Twisted wrote : >> [quoted text clipped - 25 lines] > If the timers have resolutions of a few ms, there are a few of them, > and they generate new Dates each time they update ... there you go. The memory stat timer triggers every ten mnutes. The others are set for 24 hours.
 Signature Wojtek :-)
Bjorn Borud - 05 Jul 2007 10:06 GMT [Wojtek <nowhere@a.com>]
| It is a Web application. When no hits are happening, it should be | doing nothing. And my code does no networking. | | Mind you I do have several timers running, but then the memory use | goes from 30M to 74M over a 2 hour period, then drops back to 30M, | which seems kind of excessive for timers. you're talking about the Eden space, right? 44Mb allocated in a 2 hour period isn't really dramatic enough to warrant frenetic "optimization" efforts for an idle app, in my opinion. if Eden is collected only every 2 hours there is next to no cost associated with those objects. if you really want to reduce memory footprint, make sure that you keep eden large enough to cope comfortably during high load.
44Mb is a trivial amount of memory if you compare to memory hogs like Firefox :-).
-Bjørn
Tom Hawtin - 05 Jul 2007 12:42 GMT >> I have a Web app where I capture the used memory every ten minutes. The >> result is displayed as a bar graph. Even when the app is idle, the used [quoted text clipped - 6 lines] > > Is it really idle? If it's got a GUI all kinds of short-lived FooEvent Well, no it's not. It presumably has instrumentation attached to it. The effect is quite normal if you are using something like jconsole.
Tom Hawtin
Bret Schuhmacher - 05 Jul 2007 03:45 GMT Thanks Wojtek, that's exactly what I saw. Maybe it's normal.
Rgds,
Bret
Bjorn Borud - 05 Jul 2007 09:46 GMT [Wojtek <nowhere@a.com>]
| I have a Web app where I capture the used memory every ten | minutes. The result is displayed as a bar graph. Even when the app is [quoted text clipped - 4 lines] | *** *** *** | ************* provided that you have an adequate sampling frequency, which in this case would be at least two samples or more in the time between minor collections, a distinct sawtooth shape is usually what you want for programs like web apps. the period of the sawtooth should be some multiple of the request time for the great majority of requests. (which should be simple unless you have obscene variance).
-Bjørn
Wojtek - 05 Jul 2007 16:25 GMT Bjorn Borud wrote :
> [Wojtek <nowhere@a.com>] >> [quoted text clipped - 13 lines] > multiple of the request time for the great majority of requests. > (which should be simple unless you have obscene variance). No, this is a totaly idle effect. This is observed on the test server where no one is using it over-night. Logs prove that no hits were made.
With activity the pattern is much more random, with spikes as graphics are processed. It takes a LOT of memory to rotate a 3Mbyte image.
 Signature Wojtek :-)
Bjorn Borud - 05 Jul 2007 21:13 GMT [Wojtek <nowhere@a.com>]
| No, this is a totaly idle effect. This is observed on the test server | where no one is using it over-night. Logs prove that no hits were | made. well, there is obviously some periodic activity and the sampling of values itself probably causes objects to be created and dropped.
| With activity the pattern is much more random, with spikes as graphics | are processed. It takes a LOT of memory to rotate a 3Mbyte image. if you get a high rate of minor collections you may need more memory allocated to the heap?
-Bjørn
Wojtek - 05 Jul 2007 21:48 GMT Bjorn Borud wrote :
> [Wojtek <nowhere@a.com>] >> [quoted text clipped - 10 lines] > if you get a high rate of minor collections you may need more memory > allocated to the heap? It is set to 2GBytes on the test machine, 1GBytes on my dev machine.
Spikes is relative. If I see use go from 8% to 20%, then back to 2%, that 20% is a spike.
The highest I ever saw it was 80%, after several image manipulations in a short time. The next image process caused GC to run, and the usage dropped to 2%, then up again as more images were processed. On my dev machine, done by myself during testing.
The usual idle is from 2% to 9%, back to 2%.
I am not worried at all about the actual memory used, just curios about the use pattern. It may very well be that my app is not causing it at all, but rather Tomcat doing something periodically, then GC runs.
 Signature Wojtek :-)
Twisted - 06 Jul 2007 03:27 GMT > I am not worried at all about the actual memory used, just curios about > the use pattern. It may very well be that my app is not causing it at > all, but rather Tomcat doing something periodically, then GC runs. If the app is running on the same JVM as some additional code, it's very likely that code isn't completely idle when it's "idle". To get the observed behavior you would not need a very high rate of object creation, depending on the sizes of the objects. Even small objects at the glacial pace of one every few million clock cycles is sufficient to rack up 44MB of garbage in two hours.
As long as the sawtooth is level rather than trending upward I wouldn't worry. If it's trending upward it's accumulating cruft somewhere and is doomed to eventually die of OOME, probably because a permanently-reachable collection is growing without bound. But it doesn't look like that's happening in your case. (If it ever does, identify the culprit collection. If it's a Map consider using WeakHashMap. If it's anything else consider changing it from Set<Foo> or List<Foo> or whatever to <WeakReference<Foo>> and holding a direct reference to each Foo somewhere else that is discarded once that Foo is no longer useful. Each WeakReference must be created on a ReferenceQueue which must be occasionally polled to remove references from the queue, and remove any that are found also from the collection. A thread can sleep(1000) then lock and poll the reference queue until empty, then lock the collection and remove all the polled reference objects, then sleep again. In fact, there really should be Soft and WeakFoo collection wrapper classes that do this for you -- hold an internal ReferenceQueue, wrap added items in a reference object on that queue, are synchronized, and collectively use a worker thread pool to periodically clean out their queues and dead reference objects, while also handling dereferencing objects and releasing resources. Heck maybe I should write and publish WeakList and WeakSet wrappers ... I may need some myself some day anyway. Soft versions would make good caches; Weak versions where you want to store references to objects live elsewhere in a system for whatever reason but not to otherwise-dead objects, and the collection isn't a map's keys. A map with weak values might be useful too, for that matter...
Bjorn Borud - 06 Jul 2007 10:58 GMT [Wojtek <nowhere@a.com>]
| The highest I ever saw it was 80%, after several image manipulations | in a short time. The next image process caused GC to run, and the | usage dropped to 2%, then up again as more images were processed. On | my dev machine, done by myself during testing. how often do minor and major GCs, respectively, run during this? does it run minor GCs several times per second?
-Bjørn
Bjorn Borud - 05 Jul 2007 10:00 GMT ["Bret Schuhmacher" <bret@thelastmilellc.com>]
| I've run visualgc and the GC time shows 94 collections, 59.81ms and unknown | GC reason. The Eden space graph is up and down like a yo-yo very regularly. | Is that normal? I don't know where the tenured GC is, though. I have an | image of the tool running, but probably can't post it to this non binary | newsgroup. I'll try to extend my heap as you suggested Bjorn - I do see a | lot of GC in the Eden space - it's wild. it looks like your Eden space may be a bit small (I don't know what your application does, so I can't really give you very precise advice). I did however remember that you had some parameters to choose the parallell GC and that some other memory tuning options.
the general advice is to start with the "coarse grained" tuning parameters -- start by just enlarging the heap size. RAM is cheap and the JVM is a lot happier when it has a bit of room. the next thing to do may be to tune the ratio of eden space (young generation) to the rest of the heap etc.
switching GC algorithms is not something I have a lot of experience doing since I usually am able to get the behavior I want just by doing really simple tweaks and looking at visual GC.
in any case, having visual GC you can now get a better idea of what the system is doing, so it should be possible to figure out when you are making changes that have a positive effect :-).
-Bjørn
Joshua Cranmer - 04 Jul 2007 22:29 GMT > Any idea what might cause this 15ms delay? Any other avenues I should > be looking into? FWIW, I got the 15ms delay before I added any JVM > arguments (i.e. they didn't cause the problem). I only added the JVM > args to try to figure out the issue. From the Javadocs:
public static long currentTimeMillis()
Returns the current time in milliseconds. Note that while the unit of time of the return value is a millisecond, the granularity of the value depends on the underlying operating system and may be larger. For example, many operating systems measure time in units of tens of milliseconds.
I notice the same thing to: when timing, I noticed that all of my times were nicely divisible by 15 ms (e.g, 4095ms, etc.).
In short: it's the fact that Window's doesn't like telling you that 1ms has passed.
Free MagazinesGet these publications absolutely FREE for up to 12 months. There are no hidden fees and no obligation. Simply choose a title, complete the application form and submit it. Read more ...
|
|
|