Охота на случайную ошибку — правдивая история

Эта статья опишет, что я сделал. Я дам обзор моего путешествия, чтобы на самом деле найти основную причину происходящего. Моя цель в этой статье — выделить примеры методов, которые вы можете использовать, чтобы на самом деле отследить странную и случайную ошибку.

В итоге я нашел довольно четкое объяснение того, что и почему произошло. И это не случайно, что в названии этой статьи есть «случайный».

Начало — В чем была проблема

Проблема заключалась в том, что при следовании руководству по использованию виртуальной машины разработки иногда запуск приложения занимал много времени, а затем приводил к сбою. У меня была проблема сразу, после запуска приложения дважды. У других людей была такая же проблема.

Мне сказали, что никто не знал, почему он так себя ведет, но перезапуск виртуальной машины, вероятно, исправит это. Это не для меня.

Но мне нравится копаться в проблемах — поэтому я хотел знать, что происходит не так.

Rake File to Solr

Произошла ошибка при запуске rake app:run иногда rake app:run . --trace --verbose запуска rake с --trace --verbose отладки --trace --verbose я смог увидеть, что приложение ожидает солнечного пятна для запуска службы поиска Apache Solr .

Таким образом, вопрос заключался в том, где процесс занимает все время? Для начала было неплохо, что грабли и солнечные пятна написаны на Ruby. Поэтому я прочитал код и добавил несколько выходных операторов, чтобы увидеть, какое из них заняло много времени. Оказалось, это был Java-процесс, запускающий Solr.

Копаться в Java

Apache Solr отправляет некоторый вывод в sdtout — но sunspot скрывает это от вас. Но так как любой вывод очень полезен при отладке, я хотел увидеть вывод.

Я использовал ps -aux чтобы найти точные аргументы командной строки, которые ps -aux и запустил процесс вручную из командной строки. К счастью, это заняло некоторое время — поэтому я знал, что проблема не в Ruby Code.

С помощью преобразователя портов nmap я обнаружил, что запуск службы занял от 2 секунд до более 2 минут. Но задание на грабли ждали только 10 секунд.

Теперь, имея вывод на консоль, я мог видеть, что Solr внутренне использует Jetty — и это была Jetty в версии 6.1.3 , которая занимала все время — в этом случае это заняло время. Поэтому я скачал тег для версии 6.1.3 из системы контроля версий и посмотрел код.

Я нашел системное свойство с именем DEBUG которое увеличивает производительность. Я включил его и увидел, что последний отладочный вывод, прежде чем это заняло так много времени, был посвящен запуску службы сеанса (я потерял указатель на код — к сожалению).

Это действительно не помогло мне. Я безуспешно пытался заставить журнал Jetty работать с log4j, чтобы в итоге увидеть больше — но мне не удалось и пришлось отказаться от вечера (2-й).

Отладка Java-кода

Так что, если вы ничего не получаете из журнала, вы все равно можете использовать отладчик. Однако код не работал на виртуальной машине — Ubuntu, но не на моей локальной машине. Но, к счастью, в Java есть удаленный отладчик .

Я запустил процесс Java с аргументами удаленной отладки и подключил слушатель в IntelliJ с помощью кода Jetty из SVN. Я пытался остановить выполнение в точке останова рядом с последним выводом журнала — но этот метод вызывался очень часто, и мне не удавалось достичь точки останова в нужный момент.

Однако, когда что-то занимает очень много времени, может быть полезно просто остановить запущенный процесс и посмотреть трассировку стека. Поэтому я остановил выполнение и искал последний кадр метода из Jetty, который вызывал JDK — и там я нашел следующий комментарий:

Решение

Наконец — я пошел на страницу вики Jetty, на которую ссылаются. Я обнаружил, что Java java.util.SecureRandom использует реальную энтропию операционной системы — которая может блокироваться, когда ее нет.

Решение со страницы вики, просто использовать обычный java.util.Random , было бы трудным, потому что файл конфигурации находится глубоко внутри sunspot и Solr. Но строка «NB. Некоторые обходные отчеты используют /dev/./urandom вместо / dev / urandom» дала мне подсказку: они должны были выглядеть иначе.

Я нашел решение и нашел в Stack Overflow , что вы можете заменить /dev/urandom random на /dev/./urandom в вашем Java-процессе. Это можно сделать, используя аргумент командной строки -Djava.security.egd=file:/dev/./urandom или заменив его в файле /usr/lib/jvm/java-6-openjdk/jre/lib/security/java.security (на коробке Ubuntu).

Так в чем дело? Безопасное случайное Java не примет /dev/urandom качестве источника для случайных чисел . /dev/urandom разблокирует, что означает, что он вернет случайные числа, которые можно угадать — когда нет реальной энтропии. Таким образом, Java по умолчанию /dev/random который будет блокировать и ждать, пока энтропия не присутствует.

Это причина, по которой блокировка очень маловероятна на компьютере производства или разработки — однако это произошло, когда использовалась виртуальная машина, которая не имеет большого сетевого трафика и ввода-вывода. Это случается особенно часто, когда вы часто перезапускаете приложение — как обычно, когда что-то не работает.

Исправление немного забавно. Java отклоняет /dev/urandom на основе строки. Он не отклоняет /dev/./urandom который, конечно, указывает на тот же потенциально небезопасный генератор случайных чисел.

Последние слова

Это исправление представляет потенциальную угрозу безопасности, но на виртуальной машине разработки это не проблема.

Как вы видите, обнаружение ошибки или проблемы в системе предполагает использование методов, которые приближают вас к основной причине. Однако золотого пути нет. Иногда одна техника не даст вам больше информации. Так что вам придется попробовать другую технику. Иногда ваше внутреннее чувство может помочь вам.

Прибыв сюда, что вы думаете об этой истории?

Ссылка: Охота на случайную ошибку — правдивая история от нашего партнера по JCG Йоханнеса Тонса в блоге блога Йоханнеса Тонса .