How to Measure EventQueue Performance in Java
I was working on my Download Manager and it is currently having an with the UI becoming unresponsive. I was under the impression that because of the number of events that can be sent to swing during a download the EventDispatchThread may be too busy. Now I have a way of measuring how many events are dispatched to the EventDispatchThread. I found useful information from this JavaSpecialist article. Here is how it works.
I wrote a small class that implements EventQueue and overrides dispatchEvent.
public class EventRateCounter extends EventQueue {
private long count;
private StopWatch watch;
public EventRateCounter() {
watch = new StopWatch();
watch.start();
}
@Override
protected void dispatchEvent(AWTEvent event) {
watch.add();
if(watch.getTimeMillis() > 1000) {
float rate = count / ((float) watch.getTimeMillis() / (float)1000);
System.out.println("swing event rate: " + rate + "/s");
watch.restart();
count = 0;
}
count++;
super.dispatchEvent(event);
}
}
EventRateCounter counts the number of events and the time elapsed for each call to dispatchEvent. Once the time goes over one second the number of events per second is calculated and printed.
Now that we have the class we need to replace the current EventQueue with this one. To do that use:
Toolkit.getDefaultToolkit().getSystemEventQueue().push(new EventRateCounter());
In the future, I would like to implement this in the UI for my program somewhere. Maybe in the status bar so that I know how many actions swing is dealing with. It would also be interesting to see how long each event takes to dispatch. It may be possible to see which events perform poorly and slow down the EventDispatchThread.
This same method can also be applied with a PropertyChangeListener to see what thread is being used (for SwingPropertyChangeSupport) and the rate of property changes. In my program every change to a Download is saved in a derby db.
The solution to the problem in my program is very smart. I'm going to implement a timed buffer that can grow instead of a fixed-length buffer. It will take input from a connection and saves it in buffer. When a certain amount of time has passed the buffer will be sent to the processor object which then triggers the property change events which then trigger the swing AWTEvents. The goal is to reduce the number of events to 12 per second. This will save the DB and Swing from updating all the time. Currently on my computer I have seen the DB update 200/s and Swing 100/s. This tells me that swing has a lot of events backed up in the queue.
Thanks to JavaSpecialists for providing an excellent article. I was not suToolkitrprised when JavaSpecialists came up in my google search.
StopWatch is a class I made to measure time and it is attached to the bottom of this post. Here is how it works. watch.start() starts the watch. watch.add() adds the time between calls to the internal time variable. watch.getTimeMillis() gets the time passed in milliseconds.
public class StopWatch {
protected static final long millisecond = 1000000;
/**
* number of miliseconds in a second
*/
protected static final long second = 1000 * millisecond;
/**
* number of miliseconds in a minute
*/
protected static final long minute = 60 * second;
/**
* number of miliseconds in a hour
*/
protected static final long hour = 60 * minute;
/**
* number of miliseconds in a day
*/
protected static final long day = 24 * hour;
private long time;
private long current;
public synchronized void start() {
current = System.nanoTime();
}
public synchronized void add() {
time += System.nanoTime() - current;
start();
}
public synchronized void restart() {
time = 0;
current = System.nanoTime();
}
public synchronized long getTime() {
return time;
}
public synchronized long getTimeMillis() {
return time / 1000000;
}
public synchronized void setTime(long time) {
this.time = time;
}
public synchronized String toString() {
long days = (time / day);
long hours = (time / hour) % 24;
long minutes = (time / minute) % 60;
long seconds = (time / second) % 60;
long milli = (time / millisecond) % 1000;
long nano = time % 1000000;
String sdays = (days < 10 ? "0" + days : ("" + days)) + ":";
String shours = (hours < 10 ? "0" + hours : ("" + hours)) + ":";
String sminutes = (minutes < 10 ? "0" + minutes : "" + minutes) + ":";
String sseconds = (seconds < 10 ? "0" + seconds : "" + seconds) + ":";
String smilli = (milli < 100 ? milli < 10 ? "00" + milli : "0" + milli : "" + milli) + ":";
String snano = nano < 100000 ? nano < 10000 ? nano < 1000 ? nano < 100 ? nano < 10 ? "00000" + nano : "0000" + nano : "000" + nano : "00" + nano : "0" + nano : "" + nano;
String postfix = days >= 1 ? "day" : hours >= 1 ? "hour" : minutes >= 1 ? "min" : seconds >= 1 ? "sec" : milli >= 1 ? "milli" : nano >= 1 ? "nano" : "";
return (days == 0 ? "" : sdays) + (days == 0 && hours == 0 ? "" : shours) + (days == 0 && hours == 0 && minutes == 0 ? "" : sminutes) + (days == 0 && hours == 0 && minutes == 0 && seconds == 0 ? "" : sseconds) + (days == 0 && hours == 0 && minutes == 0 && seconds == 0 && milli == 0 ? "" : smilli) + snano + " " + postfix;
}
}