Is Files.getLastModifiedTime() leaking memory?

Question

I have encountered a bug where one of our server applications was using more and more memory every second pretty much and I have managed to filter out a short example that still shows that behavior:

public class TestGetLastModifiedTime {
    private static final Path PATH = Paths.get("D:\\test.txt");
    private static final ScheduledExecutorService SCHEDULER = Executors.newScheduledThreadPool(1);

    public static void main(String[] args) {
        SCHEDULER.scheduleAtFixedRate(() -> getLastModifiedTime(), 0, 1, TimeUnit.SECONDS);
    }

    private static void getLastModifiedTime() {
        try {
            FileTime lastModifiedTime = Files.getLastModifiedTime(PATH);
        } catch (IOException ex) {
            throw new UncheckedIOException(ex);
        }
    }
}

Running on Windows 8.1 and Java 8u20.

Via VisualVM I have observed that the maximum heap size does not grow and that the heap itself keeps increasing. Simultaneously I observe in Windows Task Manager that the spawned java.exe process keeps using (reserving) more memory every second.

The interesting part is that when I Perform GC from within VisualVM, all the used heap memory gets reset to practically zero and the used memory of the java.exe process does not shrink, as expected, as it is considered reserved.

However, after the GC has been done, then the memory usage still increases every second, while now there is surely enough free heap space.

The Metaspace is also unaffected.

To me this really smells and looks like the JVM has a memory leak.

Can anyone help me out and explain what is going on here?

Answer 1

I do not consider it as leak for following reasons:

1. You mention that when you trigger gc, the memory usage falls back to default. This is not how a leak works. When there is leak, those objects are strongly reachable and even after repetitive garbage collections, the heap size doesn't significantly decrease.
2. Growing heap does not mean a leak. It can also genuinely mean too many objects are getting created. Which is normal and perfectly fine. And in your case, as its being called in a loop. yes
3. On my machine, java -Xmx20M TestGetLastModifiedTime ran perfectly fine for 10 mins before I killed the process. If there was a leak, it would ultimately throw OutOfMemoryError or have too many repetitive gc's
4. If you observe in visualvm, the memory consumption jumped in between 2mb and 2.8mb. Which is hardly any suspicion for leak. Moreover this much memory consumption is expected, as Files.getLastModifiedTime(PATH), ExecutorService internally would creating small utility objects here and there. So it looks perfectly fine to me.

The behavior on my machine:

Of the point, that the Windows manager is showing higher heap usage. It is quite possible. JVM can reserve space if needed. It might be certainly ok with increasing the heap utilization than undergoing gc. Which perfectly makes sense (Why would you undergo austerity when you are rich?).

That is why tools like observing Windows Manager/free -m etc do not rightly give observation on whats happening internally. To get quick estimates, you might want to do:

jstat -gccapacity 9043  | tail -n 1 | awk '{ print $4, $5, $6, $10 }' | python -c "import sys; nums = [x.split(' ') for x in sys.stdin.readlines()]; print(str(sum([float(x) for x in nums[0]]) / 1024.0) + ' mb');"
# change the pid from 9043 to your jvm process id.
#jvm process id can be known by running `jcmd` command (available as part of jdk)

Which still gives you a better estimate than free -m/ Windows Manager