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?

Judon

I take it no exception is thrown? – Bloomers

This is how garbage collection works. The program keeps allocating memory that eventually turns into garbage. When it can't allocate more memory from the free pool, it collects the garbage. There would be a problem only if the heap didn't decrease after GC (whether triggered automatically by the JVM or manually). – Nickynico

@Bloomers No exceptions are thrown – Judon

@Nickynico I don't think there is a need to allocate extra memory if there is more than enough space available in the heap – Judon

Please compare your lambda with manually creating a File object, using File.lastModified(). – Nigeria

@Nigeria - that appears to make a difference on my computer .... hmmm – Arsenic

@Nigeria Doesn't seem to be making a difference, memory usage still rising – Judon

Additionally, set -Xmx to 8 MB or so. See if it goes out of memory. – Nigeria

So it's the Windows memory that your concerned about? Have you checked whether the commit charge is increasing, or just the process "Mem Usage" number? The latter is mostly meaningless. If the commit charge (on the Performance tab) increases, then there might be a problem. It's unlikely to be in Files.getLastModifiedTime(), but that's easy to check: run in an endless loop, and if the program isn't killed you know it's not to blame. More likely is the scheduled executor pool, but I suspect that what you're seeing is a misleading number that includes the stack allocationss of dead threads. – Nickynico

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

Gilreath

I was more thinking along the lines of a native resource leak, where the underlying C code in the JVM would be leaking memory when calling Files.getLastModifiedTime(), maybe I was not clear enough in my question. – Judon

When monitoring with JVisuaVM, I guess that the overhead of JMX constantly sending updates about the memory usage is way bigger than the memory consumption of one Files.getLastModifiedTime call per second… – Athalla

@Judon I am on Ubuntu. It looks ok on mine. It might be an Issue on windows. Such things can perform differently on different platforms. So you might still want to confirm yourself by applying similar logic in case of windows – Gilreath

@Athalla It also happens without monitoring it via JVisualVM. – Judon

@skiwi: I’ve understood that the problem exists without JVisualVM. What I wanted to emphasize is that the graphs produced by JVisualVM are likely to lead into the wrong direction when trying to analyse this specific problem. The side effects of JMX might even hide the problem while trying to analyse it… – Athalla