关闭 RandomAccessFile 有时需要 45 秒

Question

在我的程序中，关闭 java.util.RandomAccessFile 有时正好需要 45 秒（嗯，几乎正好：在 44.998 到 45.003 秒之间）。该程序创建并关闭许多小文件。通常关闭文件的速度非常快（0 到 0.1 秒之间）。如果我调试程序，它会卡在本机方法 RandomAccessFile.close0 中。

使用 FileOutputStream 而不是 RandomAccessFile 时也会出现同样的问题（这种情况下程序会在本机方法 FileOutputStream.close0 中被阻塞）。

有人知道那可能是什么吗？您能否在您的系统上重现该问题（我只能在 Mac 上重现该问题，不能在 Windows XP 上重现；我还没有在 Linux 上进行测试）？

---

更新2：

这似乎只发生在Mac OS X上。我使用JDK 1.6.0_22-b04。它发生在 32 位和 64 位上。在 Windows XP 上似乎不会发生。

我的测试用例是：

import java.io.File;
import java.io.RandomAccessFile;
public class TestFileClose {
    public static void main(String... args) throws Exception {
        for (int i = 0; i < 100000; i++) {
            String name = "test" + i;
            RandomAccessFile r = new RandomAccessFile(name, "rw");
            r.write(0);
            long t = System.currentTimeMillis();
            r.close();
            long close = System.currentTimeMillis() - t;
            if (close > 200) {
                System.out.println("closing " + name +
                        " took " + close + " ms!");
            }
            if (i % 2000 == 0) {
                System.out.println("test " + i + "/100000");
            }
            new File(name).delete();
        }
    }
}

我的机器上的示例输出：

test 0/100000
test 2000/100000
test 4000/100000
test 6000/100000
test 8000/100000
test 10000/100000
closing test10030 took 44998 ms!
test 12000/100000
test 14000/100000
test 16000/100000
closing test16930 took 44998 ms!
test 18000/100000
test 20000/100000

Answer 1

就我而言，我的计算机上安装了 McAfee 防病毒软件。我必须安装它（公司政策）...

如果我禁用按访问扫描，问题也会出现。

Answer 2

它可能是垃圾收集活动，由打开/关闭大量RandomAccessFile对象触发； 45 秒可能没有什么神奇之处——它可能只是机器上的 JVM 遍历堆清理以释放对象所花费的时间。话虽如此，45 秒是一个非常长的 GC 暂停；我最近开发的一个应用程序总是遭遇大约 11 秒的完整 GC。

尝试使用JConsole或JVisualVM监视您的程序，或者当您启动程序时尝试添加以下选项：

-verbose:gc -Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

然后查看gc.log > 生成文件以查看应用程序停止时间；如果您使用代码来打印时间戳，则可以将 close() 行为与特定 GC 活动联系起来：

...
if (close > 200) {
    System.out.println(new Date());
    System.out.println("closing " + name +
                    " took " + close + " ms!");
}
...

如果与 GC 相关，则在 gc.log 文件中，您将在程序输出文件的时间戳附近寻找完整的垃圾收集和/或应用程序停止时间。

修改堆设置（-Xmx=... 和 XX:MaxPermSize=...）可能会给您一个完全不同的配置文件。

顺便说一句，如果它是临时文件，请尝试使用 File file = File.createTempFile(prefix, suffix) 并将其传递到 RandomAccessFile 中 - 这可能会创建文件在 OS X 上的 /var/tmp（或任何名称）中，因此使用内存文件系统而不是基于磁盘的文件系统。