Огромная разница во времени поиска JNDI

Мы сталкиваемся с огромной разницей в времени отклика устаревшего веб-приложения J2EE, запущенного на сайте Weblogic 10.3. Система состоит из двух экземпляров сервера Weblogic (внешнего и внутреннего), которые работают на одной и той же физической серверной машине, и базы данных Oracle, работающей на отдельном хосте. Внешний измерительный инструмент предупреждает нас каждый раз, когда вход в систему занимает более четырех секунд. В последнее время такие предупреждения встречаются довольно часто. Просмотр журнала, написанного сервлетом, обрабатывающим запросы на вход, показывает, что время, затраченное на вызов EJB с фронт-энда на бэк-энд.

Пример измеренного времени:

time    ms   
8:40:43 25
8:42:14 26
8:44:04 26
8:44:25 26
8:44:47 26
8:46:06 26
8:46:41 7744
8:47:00 27
8:47:37 27
8:49:00 26
8:49:37 26
8:50:03 8213
8:50:57 27
8:51:04 26
8:51:06 25
8:57:26 2545
8:58:13 26
9:00:06 5195

Как видно, большинство запросов (70%, взятых из более крупной выборки) выполняются своевременно, но значительная их часть занимает очень много времени.

Шаги, выполненные в течение измеренного времени, являются следующими:

• JNDI поиск боба сеанса, предлагающего интерфейс аутентификации (front-end)
• Вызов метода аутентификации боба сеанса (frontend->backend)
• Резервирование JDBC соединения из пула соединений (backend)
• Сделать запрос к базе данных пользователей (размер таблицы очень умеренный и таблица должна быть правильно проиндексирована) (backend)
• Чтение результирующего множества, создание объекта пользователя POJO (backend)
• Возвращение объекта пользователя POJO (backend->frontend)

Нагрузка на серверную машину очень мала (99% простаивает), а количество пользователей очень умеренное. Количество свободной памяти, о которой сообщает Weblogic, варьируется от 60% до 90% на обоих серверах. Сбор мусора протоколируется. Большие коллекции встречаются редко и завершаются за 2-3 секунды. Кроме того, основные GC происходят не в то же время, когда видно длительное время отклика. Длительное время отклика происходит как в напряженные, так и не напряженные часы. Максимальный размер пула соединений JDBC в настоящее время установлен на 80, что больше, чем число одновременных пользователей.

Обновление:

Получил разрешение на перезагрузку системы с добавлением еще нескольких логов производительности. Журнал ясно показывает, что JNDI поиск - это та часть, на которую уходит время:

03:01:23.977 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:14:47.179 PERFORMANCE: looking up foo.bar.Bar from JNDI took 2332 ms
03:15:55.040 PERFORMANCE: looking up foo.bar.Bar from JNDI took 1585 ms
03:29:25.548 PERFORMANCE: looking up foo.bar.Bar from JNDI took 7 ms
03:31:09.010 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:44:25.587 PERFORMANCE: looking up foo.bar.Bar from JNDI took 6 ms
03:46:00.289 PERFORMANCE: looking up foo.bar.Bar from JNDI took 7 ms
03:59:28.028 PERFORMANCE: looking up foo.bar.Bar from JNDI took 2052 ms

Просмотр GC логов фронтэнда и бэкэнда показывает, что GC не выполняется, когда происходит медленный JNDI поиск.

При создании сессии контекст получается следующим образом:

Hashtable ht = new Hashtable();
ht.put(Context.PROVIDER_URL, url);
ht.put(Context.INITIAL_CONTEXT_FACTORY, "weblogic.jndi.WLInitialContextFactory");
jndiContext = new InitialContext(ht);

где url - это t3 url, указывающий на DNS имя и порт бэкенда сервера. Это должно быть нормально, не так ли?

Первое, что приходит на ум, это кэширование ссылок, полученных от JNDI, по крайней мере, это был предпочтительный путь 10 лет назад... Но не должна ли реализация InitialContext в Weblogic уже делать это кэширование, или она действительно получает ссылку с внутреннего сервера при каждом вызове?

Что может вызывать частые медленные поиски JNDI? Есть ли для этого обходной путь (например, кэширование справки по ссылкам)?