Metric Profiling and Daily Logging with Java

Working on a large-scale application, especially if your application will be delivered to lots of people, requires you to keep in mind that there are machines that may not run it as well as your own. Optimizing applications is crucial when working on serious projects. 

There are many advantages and useful information given by Java Profilers, which are available online for free, and through subscription systems.

 Let's make our own, simple Java Profiler that checks our disk usage (total space, free space, usable space), memory usage (initial memory, used heap memory, max heap memory, committed memory) and CPU usage (thread names, thread states, thread CPU time) and the application uptime. This simple profiler will also create a text log at the end of each day, storing some information that you could parse later on for statistics.

Note: This simple profiler isn't meant to be used on real applications. It's made with the intent to bring the reader closer to the workings of the JVM as well as bring to light how easy it is to obtain such information - hopefully inspiring someone to make their custom profiler which is a lot more advanced or simply making such an application for practice or the fun of it.

 Other Profilers:

If you're looking for some advanced profilers, here are a few of the most commonly used ones sorted by popularity:

 The Project:

I've started out making this design in the NetBeans Swing designer. 

We are relying on three beans for this project to work:

  • MemoryMXBean - The management interface for the memory system of the Java Virtual Machine. It follows two kinds of memory: Heap and Non-Heap memory. Heap memory is allocated to all class instances and arrays, while Non-Heap memory is allocated for an example to the method area. 
  • ThreadMXBean - The management interface for the thread system of the Java Virtual Machine. The Java Virtual Machine has a single instance of this bean and it can be used to monitor the state, name and CPU time for each thread. 
  • RuntimeMXBean - The management interface for the runtime system of the Java Virtual Machine. It defines several convenient methods for accessing system properties about the Java Virtual Machine.

The preceding instances can be obtained as follows:

MemoryMXBean memoryMXBean = ManagementFactory.getMemoryMXBean();

ThreadMXBean threadMXBean = ManagementFactory.getThreadMXBean();

RuntimeMXBean runtimeMXBean = ManagementFactory.getRuntimeMXBean();

This application only needs a few methods in the constructor:

public MetricApp() {

initComponents();

showInfo();

refreshEachSecond();

createLogAtEndOfDay();

}

So let's go over all of these now.

 showInfo() 

private void showInfo() {

File[] rootDrive = File.listRoots();

for(File drive : rootDrive) {

jComboBox1.addItem(drive.toString());

}


DefaultCaret caret = (DefaultCaret)jTextArea1.getCaret();

caret.setUpdatePolicy(DefaultCaret.NEVER_UPDATE);


actionListener = new ActionListener() {

@Override

public void actionPerformed(ActionEvent e) {

StringBuilder text = new StringBuilder();

for(Long threadID : threadMXBean.getAllThreadIds()) {

ThreadInfo info = threadMXBean.getThreadInfo(threadID);

text.append("Thread name: " + info.getThreadName() + "\n");

text.append("Thread State: " + info.getThreadState() + "\n");

text.append(String.format("CPU time: %s ns", threadMXBean.getThreadCpuTime(threadID)) + "\n");

text.append("\n");

}

jTextArea1.setText(text.toString());

jLabel7.setText(String.format("Initial memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getInit()/1073741824));

jLabel8.setText(String.format("Used heap memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getUsed()/1073741824));

jLabel9.setText(String.format("Max heap memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getUsed()/1073741824));

jLabel10.setText(String.format("Committed memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getCommitted()/1073741824));

drive = new File(jComboBox1.getSelectedItem().toString());

jLabel2.setText(String.format("Total space: %.2f GB", (double)drive.getTotalSpace()/1073741824));

jLabel3.setText(String.format("Free space: %.2f GB", (double)drive.getFreeSpace()/1073741824));

jLabel4.setText(String.format("Usable space: %.2f GB", (double)drive.getUsableSpace()/1073741824));

long uptime = runtimeMXBean.getUptime();

jLabel14.setText("Uptime: " + String.valueOf(uptime/1000 + "s"));

}

};

}

First, to add all of the available drives on your computer to the JComboBox we use an enhanced for loop and iterate the root drives to add them as separate items. 

Afterward, we set the update policy of the JTextArea caret to never update otherwise it would snap to the bottom of it each second. This way you're free to scroll up and down.

After which comes an ActionListener. This action listener will be used in the refreshEachSecond() method to run it each second and update this information. 

A StringBuilder object is used to append and store the text each time it is updated. Using another enhanced for loop, each of the threads is stored into a ThreadInfo object, which is then used to get the thread name, state and CPU time. The text is then set into the JTextArea

A String is formatted and the MemoryMXBean is used to get the wanted information. These methods return the memory in bytes, so they're divided by 1073741824 to represent gigabytes. This is done for each label and then the text is set for each.

Then, a new File object is created according to the selected item from the JComboBox. That File object is used to get total, free and usable space of the selected drive. These methods also return the memory in bytes, so they're divided to be representable as gigabytes.

In the end, the RuntimeMXBean is used to get the uptime of the application, which is returned in milliseconds. The label is then set to the appropriate value.

 createLogAtEndOfDay() 

private void createLogAtEndOfDay() throws FileNotFoundException, UnsupportedEncodingException {

Runnable runnable = new Runnable() {

@Override

public void run() {

PrintWriter writer = null;

LocalDateTime endOfDay = LocalDateTime.of(LocalDate.now(), LocalTime.MAX);

try {

writer = new PrintWriter(LocalDate.now()+"-log.txt", "UTF-8");

writer.println("---- LOG FILE FOR END OF DAY " + endOfDay + " ----");

writer.println("-- MEMORY USAGE --");

writer.println(String.format("Initial memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getInit()/1073741824));

writer.println(String.format("Used heap memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getUsed()/1073741824));

writer.println(String.format("Max heap memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getUsed()/1073741824));

writer.println( String.format("Committed memory: %.2f GB", (double)memoryMXBean.getHeapMemoryUsage().getCommitted()/1073741824));

writer.println("");

writer.println("-- DISK USAGE --");

File[] rootDrive = File.listRoots();

for(File drive : rootDrive) {

writer.println(drive);

writer.println(String.format("Total space: %.2f GB", (double)drive.getTotalSpace()/1073741824));

writer.println(String.format("Free space: %.2f GB", (double)drive.getFreeSpace()/1073741824));

writer.println(String.format("Usable space: %.2f GB" , (double)drive.getUsableSpace()/1073741824));

writer.println("");

}

uptime = runtimeMXBean.getUptime();

writer.println("Uptime: " + String.valueOf(uptime/1000 + "s"));

writer.close();

} catch (FileNotFoundException ex) {

Logger.getLogger(MetricApp.class.getName()).log(Level.SEVERE, null, ex);

} catch (UnsupportedEncodingException ex) {

Logger.getLogger(MetricApp.class.getName()).log(Level.SEVERE, null, ex);

} finally {

writer.close();

}

}

};

ZoneId zoneId = ZoneId.systemDefault();

long time = LocalDateTime.of(LocalDate.now(), LocalTime.MAX).atZone(zoneId).toEpochSecond() - System.currentTimeMillis()/1000;

long endTime = LocalDateTime.of(LocalDate.MAX, LocalTime.MAX).atZone(zoneId).toEpochSecond();

ScheduledExecutorService service = Executors.newSingleThreadScheduledExecutor();

service.scheduleAtFixedRate(runnable, time, endTime, TimeUnit.SECONDS);

}

A Runnable object is created, so that it could be repeated at the end of each day. The end of the current day in LocalDateTime is based on the current LocalDate and the maximum value of LocalTime

The try block uses the already shown code to write the data into a newly created file, stored in the project folder, with the name of the current day and a "-log" suffix.

In the end, the system default zone is used to calculate how many seconds are left to the end of this day, as well as a period that represents the delay for the next repetition of the method.

ScheduledExecutorService is used to run a runnable object with an initial delay and the period it waits for the next repetition. We run our runnable with an initial delay to the end of the current day, and a period of a day, in seconds - running the method on the end of each day.

 refreshEachSecond()

The only thing left to do is to refresh the whole GUI each second:

 public void refreshEachSecond() throws InterruptedException {

Timer timer = new Timer(1000, actionListener);

timer.setRepeats(true);

timer.start();

}

This is a simple method that uses a Timer to repeat the actionListener each second.

Running this application looks like this:

And the log it created looks like this: 

---- LOG FILE FOR END OF DAY 2018-08-06T23:59:59.999999999 ----

-- MEMORY USAGE --

Initial memory: 0.13 GB

Used heap memory: 0.01 GB

Max heap memory: 0.01 GB

Committed memory: 0.12 GB

-- DISK USAGE --

C:\

Total space: 118.75 GB

Free space: 5.36 GB

Usable space: 5.36 GB

D:\

Total space: 451.11 GB

Free space: 53.85 GB

Usable space: 53.85 GB

E:\

Total space: 931.51 GB

Free space: 185.39 GB

Usable space: 185.39 GB

F:\

Total space: 0.00 GB

Free space: 0.00 GB

Usable space: 0.00 GB

This log contains basic information, but it's included like this in the tutorial to show how to easily make a log file.

The source code is as always available on GitHub: