Закрытие файла RandomAccessFile иногда занимает ровно 45 секунд - PullRequest
10 голосов
/ 21 января 2011

В моей программе закрытие файла 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

Ответы [ 2 ]

7 голосов
/ 22 января 2011

Это может быть антивирусом McAfee, установленным на моем компьютере.Мне пришлось его установить ... Но проблема также появляется, если я отключаю проверку при доступе.

Чтобы проверить, что это не антивирус, кто-то повторил тест на своем компьютере (без антивируса) иполучаю ту же проблему, я думаю.

0 голосов
/ 22 января 2011

Это может быть деятельностью по сбору мусора, вызванной открытием / закрытием большого количества RandomAccessFile объектов; около 45 секунд может не быть ничего волшебного - это может быть время, которое требуется JVM на вашей машине, чтобы пройти очистку кучи для освобождения объектов. Сказав это, 45 секунд - это ужасно длинная пауза GC; Одно приложение, над которым я работал в последнее время, всегда получало полный GC около 11 секунд.

Попробуйте выполнить мониторинг вашей программы, используя JConsole или JVisualVM , или при запуске программы попробуйте добавить следующие параметры:

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

Затем просмотрите файл gc.log , созданный для определения времени остановки приложения; если вы применяете свой код для печати временных меток, вы можете связать поведение close() с определенной активностью GC: * ​​1018 *

...
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 - это может создать файлы в / var / tmp (или как там его называют) в OS X, таким образом используя файловая система в памяти вместо дисковой файловой системы.

...