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?

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). — kdgregory, Dec 09 '14 at 15:13
@kdgregory I don't think there is a need to allocate extra memory if there is more than enough space available in the heap — skiwi, Dec 09 '14 at 15:15
Please compare your lambda with manually creating a `File` object, using `File.lastModified()`. — Pimgd, Dec 09 '14 at 15:17
@Pimgd - that appears to make a difference on my computer .... hmmm — rolfl, Dec 09 '14 at 15:22
@Pimgd Doesn't seem to be making a difference, memory usage still rising — skiwi, Dec 09 '14 at 15:25
Additionally, set `-Xmx` to 8 MB or so. See if it goes out of memory. — Pimgd, Dec 09 '14 at 15:29
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. — kdgregory, Dec 09 '14 at 15:37

Jatin · Answer 1 · 2014-12-10T09:39:24.000

I do not consider it as leak for following reasons:

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.
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
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
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:

enter image description here

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

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. — skiwi, Dec 10 '14 at 10:31
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… — Holger, Dec 10 '14 at 11:08
@skiwi 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 — Jatin, Dec 10 '14 at 11:20
@Holger It also happens without monitoring it via JVisualVM. — skiwi, Dec 10 '14 at 11:20
@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… — Holger, Dec 10 '14 at 12:38

Is Files.getLastModifiedTime() leaking memory?

1 Answers1