Закрытие RandomAccessFile иногда занимает ровно 45 секунд
В моей программе закрытие 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
Ответы
Ответ 1
Это может быть антивирус McAfee, установленный на моей машине. Я должен был установить его... Но проблема также проявляется, если я отключу проверку доступа.
Только для проверки этого антивируса кто-то повторяет тест на своей машине (без антивируса), и я получаю ту же проблему.
Ответ 2
Это может быть деятельность по сбору мусора, вызванная открытием/закрытием большого количества объектов RandomAccessFile
; не может быть ничего волшебного около 45 секунд - это может быть просто время, которое требуется JVM на вашей машине, чтобы пересечь кучу, удаляя объекты для освобождения. Сказав это, 45 секунд - ужасно длинная пауза GC; Одно приложение, над которым я работал, недавно всегда страдал полным GC около 11 секунд.
Попробуйте контролировать свою программу с помощью 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
- это может создавать файлы в /var/tmp (или как угодно), на OS X, таким образом, используя файловая система в памяти вместо файловой системы на диске.